Kernel crash analysis

raymondwang — Tue, 11 Mar 2014 11:39:00 GMT

I use SabreSDB based board and system running past 2 days. It restart (my kernel panic timeout is 5s) today and I dump the /proc/last_kmsg as pasted below:

cat /proc/last_kmsg

Normal: 2347*4kB 1580*8kB 906*16kB 679*32kB 412*64kB 174*128kB 64*256kB 28*512kB 10*1024kB 3*2048kB 3*4096kB 1*8192kB 0*16384kB 0*32768kB = 174476kB

HighMem: 2577*4kB 1206*8kB 1384*16kB 350*32kB 111*64kB 24*128kB 7*256kB 2*512kB 0*1024kB 1*2048kB 1*4096kB 1*8192kB 1*16384kB 0*32768kB = 97012kB

20009 total pagecache pages

0 pages in swap cache

Swap cache stats: add 0, delete 0, find 0/0

Free swap = 0kB

Total swap = 0kB

262144 pages of RAM

70560 free pages

65307 reserved pages

5236 slab pages

119436 pages shared

0 pages swap cached

ERROR: v4l2 capture: Allocate dummy frame failed.

binder: release 10892:10892 transaction 845508 in, still active

binder: send failed reply for transaction 845508 to 10677:10694

Write initial setting done.

Write af fw start...

Write af fw end

Write initial setting done.

Write af fw start...

Write af fw end

new frame_rate is 1,capturemode is 0!

Writting resolution [2592x1944] done

wait 400 ms for state 7

new frame_rate is 1,capturemode is 6!

RequestHandle: page allocation failure: order:12, mode:0xd1

from

Mem-info:

Normal per-cpu:

CPU 0: hi: 186, btch: 31 usd: 166

CPU 1: hi: 186, btch: 31 usd: 160

HighMem per-cpu:

CPU 0: hi: 186, btch: 31 usd: 72

CPU 1: hi: 186, btch: 31 usd: 50

active_anon:91230 inactive_anon:85 isolated_anon:0

active_file:6803 inactive_file:15013 isolated_file:0

unevictable:250 dirty:8 writeback:0 unstable:0

free:64851 slab_reclaimable:1212 slab_unreclaimable:3999

mapped:8795 shmem:100 pagetables:3272 bounce:0

Normal free:173356kB min:2516kB low:3144kB high:3772kB active_anon:120584kB inactive_anon:32kB active_file:0kB inactive_file:116kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:396160kB mlocked:0kB dirty:0kB writeback:0kB mapped:168kB shmem:36kB slab_reclaimable:4848kB slab_unreclaimable:15996kB kernel_stack:5808kB pagetables:13088kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:174 all_unreclaimable? yes

lowmem_reserve[]: 0 3281 3281

HighMem free:86048kB min:408kB low:1072kB high:1740kB active_anon:244336kB inactive_anon:308kB active_file:27212kB inactive_file:59936kB unevictable:1000kB isolated(anon):0kB isolated(file):0kB present:419968kB mlocked:0kB dirty:32kB writeback:0kB mapped:35012kB shmem:364kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no

lowmem_reserve[]: 0 0 0

Normal: 2239*4kB 1595*8kB 912*16kB 681*32kB 413*64kB 174*128kB 64*256kB 28*512kB 9*1024kB 3*2048kB 3*4096kB 1*8192kB 0*16384kB 0*32768kB = 173364kB

HighMem: 2180*4kB 846*8kB 978*16kB 350*32kB 111*64kB 24*128kB 7*256kB 2*512kB 0*1024kB 1*2048kB 1*4096kB 1*8192kB 1*16384kB 0*32768kB = 86048kB

22172 total pagecache pages

0 pages in swap cache

Swap cache stats: add 0, delete 0, find 0/0

Free swap = 0kB

Total swap = 0kB

262144 pages of RAM

67853 free pages

65307 reserved pages

5211 slab pages

119615 pages shared

0 pages swap cached

ERROR: v4l2 capture: Allocate dummy frame failed.

otg udc vbus falling wakeup

try_wake_up_udc: udc out low power mode

qpower-charger qpower-charger.0: Charger charging

android_usb gadget: high speed config #1: android

mtp_open

binder: release 10956:10970 transaction 893416 in, still active

binder: send failed reply for transaction 893416 to 10677:10694

Write initial setting done.

Write af fw start...

Write af fw end

binder: 10677:10677 transaction failed 29189, size 72-4

Write initial setting done.

Write af fw start...

Write af fw end

new frame_rate is 1,capturemode is 0!

Writting resolution [2592x1944] done

wait 200 ms for state 7

new frame_rate is 1,capturemode is 6!

RequestHandle: page allocation failure: order:12, mode:0xd1

from

Mem-info:

Normal per-cpu:

CPU 0: hi: 186, btch: 31 usd: 0

CPU 1: hi: 186, btch: 31 usd: 0

HighMem per-cpu:

CPU 0: hi: 186, btch: 31 usd: 0

CPU 1: hi: 186, btch: 31 usd: 0

active_anon:91946 inactive_anon:82 isolated_anon:0

active_file:6850 inactive_file:20317 isolated_file:0

unevictable:250 dirty:5 writeback:0 unstable:0

free:59253 slab_reclaimable:1208 slab_unreclaimable:3968

mapped:9317 shmem:103 pagetables:3285 bounce:0

Normal free:175124kB min:2516kB low:3144kB high:3772kB active_anon:120224kB inactive_anon:32kB active_file:52kB inactive_file:28kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:396160kB mlocked:0kB dirty:0kB writeback:0kB mapped:168kB shmem:36kB slab_reclaimable:4832kB slab_unreclaimable:15872kB kernel_stack:5832kB pagetables:13140kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no

lowmem_reserve[]: 0 3281 3281

HighMem free:61888kB min:408kB low:1072kB high:1740kB active_anon:247560kB inactive_anon:296kB active_file:27348kB inactive_file:81240kB unevictable:1000kB isolated(anon):0kB isolated(file):0kB present:419968kB mlocked:0kB dirty:20kB writeback:0kB mapped:37100kB shmem:376kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no

lowmem_reserve[]: 0 0 0

Normal: 2399*4kB 1603*8kB 926*16kB 683*32kB 421*64kB 172*128kB 64*256kB 29*512kB 9*1024kB 3*2048kB 3*4096kB 1*8192kB 0*16384kB 0*32768kB = 175124kB

HighMem: 2348*4kB 866*8kB 542*16kB 197*32kB 80*64kB 19*128kB 8*256kB 3*512kB 1*1024kB 1*2048kB 0*4096kB 0*8192kB 1*16384kB 0*32768kB = 61888kB

27529 total pagecache pages

0 pages in swap cache

Swap cache stats: add 0, delete 0, find 0/0

Free swap = 0kB

Total swap = 0kB

262144 pages of RAM

61812 free pages

65307 reserved pages

5176 slab pages

120760 pages shared

0 pages swap cached

ERROR: v4l2 capture: Allocate dummy frame failed.

binder: release 11059:11059 transaction 918648 in, still active

binder: send failed reply for transaction 918648 to 10677:10694

Write initial setting done.

Write af fw start...

Write af fw end

request_suspend_state: sleep (0->3) at 18972971128598 (2014-03-11 08:46:54.785495259 UTC)

binder: release proc 4747, transaction 943406, not freed

request_suspend_state: wakeup (3->0) at 21305760322209 (2014-03-11 09:25:47.574689204 UTC)

binder: 2580:2645 transaction failed 29189, size 100-4

cpufreq_interactive_input_connect: connect to ft5x0x_ts

binder: 20162:20171 refcount change on invalid ref 36

qpower-charger qpower-charger.0: Charger charging stopped.

adb_release

adb_open

fsl_gadget_disconnect_event: udc enter low power mode

mtp_release

request_suspend_state: sleep (0->3) at 21447729545226 (2014-03-11 09:28:09.543912888 UTC)

ft5x0x_ts 1-0038: ft5x0x_read_data ft5x0x_i2c_read failed: -5

binder: release proc 14324, transaction 1032292, not freed

request_suspend_state: wakeup (3->0) at 24905329804970 (2014-03-11 10:25:47.144171632 UTC)

binder: 2580:2645 transaction failed 29189, size 100-4

cpufreq_interactive_input_connect: connect to ft5x0x_ts

binder: 20162:22058 refcount change on invalid ref 36

binder: transaction release 922987 bad handle 36

request_suspend_state: sleep (0->3) at 24985132379980 (2014-03-11 10:27:06.946747642 UTC)

request_suspend_state: wakeup (3->0) at 25435848549368 (2014-03-11 10:34:37.662916363 UTC)

cpufreq_interactive_input_connect: connect to ft5x0x_ts

binder: 2580:2645 transaction failed 29189, size 100-4

binder: 2826:24345 transaction failed 29189, size 60-0

request_suspend_state: sleep (0->3) at 25447856081035 (2014-03-11 10:34:49.670447363 UTC)

binder: 2689:2720 refcount change on invalid ref 49

request_suspend_state: wakeup (3->0) at 27484053057279 (2014-03-11 11:08:45.867423941 UTC)

cpufreq_interactive_input_connect: connect to ft5x0x_ts

binder: 2580:2645 transaction failed 29189, size 100-4

binder: 10677:10677 transaction failed 29189, size 72-4

Write initial setting done.

Write af fw start...

Write af fw end

new frame_rate is 1,capturemode is 0!

Writting resolution [2592x1944] done

wait 150 ms for state 7

new frame_rate is 1,capturemode is 6!

RequestHandle: page allocation failure: order:12, mode:0xd1

from

Mem-info:

Normal per-cpu:

CPU 0: hi: 186, btch: 31 usd: 0

CPU 1: hi: 186, btch: 31 usd: 62

HighMem per-cpu:

CPU 0: hi: 186, btch: 31 usd: 40

CPU 1: hi: 186, btch: 31 usd: 43

active_anon:112829 inactive_anon:112 isolated_anon:0

active_file:11622 inactive_file:19184 isolated_file:0

unevictable:250 dirty:0 writeback:0 unstable:0

free:25830 slab_reclaimable:1263 slab_unreclaimable:3997

mapped:14526 shmem:125 pagetables:3723 bounce:0

Normal free:99084kB min:2516kB low:3144kB high:3772kB active_anon:191776kB inactive_anon:100kB active_file:0kB inactive_file:64kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:396160kB mlocked:0kB dirty:0kB writeback:0kB mapped:240kB shmem:104kB slab_reclaimable:5052kB slab_unreclaimable:15988kB kernel_stack:6312kB pagetables:14892kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:99 all_unreclaimable? yes

lowmem_reserve[]: 0 3281 3281

HighMem free:4236kB min:408kB low:1072kB high:1740kB active_anon:259540kB inactive_anon:348kB active_file:46512kB inactive_file:76392kB unevictable:1000kB isolated(anon):0kB isolated(file):0kB present:419968kB mlocked:0kB dirty:0kB writeback:0kB mapped:57864kB shmem:396kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:185 all_unreclaimable? no

lowmem_reserve[]: 0 0 0

Normal: 550*4kB 513*8kB 499*16kB 536*32kB 309*64kB 117*128kB 34*256kB 19*512kB 8*1024kB 3*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 98960kB

HighMem: 249*4kB 149*8kB 66*16kB 1*32kB 3*64kB 0*128kB 1*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 4236kB

31106 total pagecache pages

0 pages in swap cache

Swap cache stats: add 0, delete 0, find 0/0

Free swap = 0kB

Total swap = 0kB

262144 pages of RAM

29141 free pages

71959 reserved pages

5269 slab pages

145536 pages shared

0 pages swap cached

ERROR: v4l2 capture: Allocate dummy frame failed.

binder: release 11229:24349 transaction 1171296 in, still active

binder: send failed reply for transaction 1171296 to 10677:10694

Write initial setting done.

Write af fw start...

Write af fw end

Write initial setting done.

Write af fw start...

Write af fw end

new frame_rate is 1,capturemode is 0!

modem wakeup

binder: 2826:29473 transaction failed 29189, size 60-0

modem wakeup

request_suspend_state: sleep (0->3) at 27992306733672 (2014-03-11 11:17:14.121101000 UTC)

binder: 29627:29638 transaction failed 29189, size 212-0

request_suspend_state: wakeup (3->0) at 28109530590353 (2014-03-11 11:19:11.344957681 UTC)

cpufreq_interactive_input_connect: connect to ft5x0x_ts

binder: 2689:20823 refcount change on invalid ref 49

binder: transaction release 1090695 bad handle 49

binder: 2580:2645 transaction failed 29189, size 100-4

binder: 2689:2720 refcount change on invalid ref 39

request_suspend_state: sleep (0->3) at 28120119281687 (2014-03-11 11:19:21.933648682 UTC)

Unable to handle kernel paging request at virtual address 00100108

pgd = cec7c000

[00100108] *pgd=00000000

Internal error: Oops: 5 [#1] PREEMPT SMP

Modules linked in: sd8xxx mlan

CPU: 0 Not tainted (3.0.35-00002-g98844ce-dirty #28)

PC is at logger_aio_write+0x1ac/0x420

LR is at logger_aio_write+0x11c/0x420

pc : [] lr : [] psr: 88000013

sp : d5bbfdd8 ip : c08f25a0 fp : 0000a6ea

r10: 001000fc r9 : 0000a75d r8 : d5bbfe18

r7 : 00000073 r6 : 000000a6 r5 : 0000a6ea r4 : c08c8200

r3 : c08c8238 r2 : c08c8238 r1 : 00000073 r0 : c09708a4

Flags: Nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user

Control: 10c53c7d Table: 1ec7c04a DAC: 00000015

PC: 0xc0485b04:

5b04 e0866001 e0855001 e1570006 e0055002 8afffff2 e584505c e1a02004 e5b2a038

5b24 e152000a e24aa004 e58d2004 0a000034 e58db018 e59db008 e58d9008 e59d900c

5b44 ea00000d e15b0005 23a03000 33a03001 e1590005 23833001 e3530000 128d8040

5b64 13a06000 1a000010 e59aa004 e59d3004 e153000a e24aa004 0a00001e e15b0009

5b84 e59a500c 8affffee e1590005 33a03000 23a03001 e15b0005 23a03000 e3530000

5ba4 128d8040 13a06000 0affffee e1a01005 e1a02008 e1a00004 ebfffe0e e5943060

5bc4 e2433001 e1d020b0 e2822018 e0866002 e0855002 e1570006 e0055003 8afffff2

5be4 e58a500c e59d3004 e59aa004 e153000a e24aa004 1affffe0 e59db018 e59d9008

LR: 0xc0485a74:

5a74 e1cd32ba 0a00009c e2843040 e58d3010 e2877018 e1a00003 eb07260d e5943058

5a94 e594505c e58d3008 e59d0008 e5943060 e0871000 e2432001 e0012002 e58d200c

5ab4 e1500002 9a0000c0 e1500005 e59d100c 23a02000 33a02001 e1510005 23822001

5ad4 e3520000 128d8040 13a06000 0a00000d e1a01005 e1a02008 e1a00004 ebfffe41

5af4 e5943060 e2432001 e1d010b0 e2811018 e0866001 e0855001 e1570006 e0055002

5b14 8afffff2 e584505c e1a02004 e5b2a038 e152000a e24aa004 e58d2004 0a000034

5b34 e58db018 e59db008 e58d9008 e59d900c ea00000d e15b0005 23a03000 33a03001

5b54 e1590005 23833001 e3530000 128d8040 13a06000 1a000010 e59aa004 e59d3004

SP: 0xd5bbfd58:

fd58 c00a77c0 00000000 c08c8230 00000000 00000000 00000001 d5bbfdac c00a77cc

fd78 c08c8224 0000040f 00000005 000000a6 00000073 c00472d0 c09708a4 00000073

fd98 c08c8238 c08c8238 c08c8200 0000a6ea 000000a6 00000073 d5bbfe18 0000a75d

fdb8 001000fc 0000a6ea c08f25a0 d5bbfdd8 c0485af4 c0485b84 88000013 ffffffff

fdd8 0000001b c08c8238 d5bbe000 0000a75d c08c8240 d5bbff08 00000003 0000a6ea

fdf8 531ef1ca 26907ce6 0018005b 00006ef0 00006ef0 531ef1ca 26907ce6 00002740

fe18 000019b4 c189a040 000019b4 00000000 000019b4 c189a040 00000001 fffffdee

fe38 d5bbff08 00000003 c04859d8 00000000 00000000 d5bbff88 bea94524 c012af6c

IP: 0xc08f2520:

2520 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

2540 00000000 00000000 00000000 00000000 00000000 d4000e40 00000000 00000000

2560 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

2580 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

25a0 d40090c0 00000017 00007530 00000000 3ffc0860 00004c4b ffffd8f0 ffffffff

25c0 00989680 00000000 fffb3cce ffffffff eec5a000 ffffffff 00000009 a6aaaaa2

25e0 531ef1ca 285a4066 00006e68 336ab30a 00000000 00000000 00000000 00000000

2600 ace17c9e 0b107fd0 00000000 00000000 00000000 00000000 00000000 00000000

R0: 0xc0970824:

0824 202c3833 1b002930 f0001800 f000006e ca00006e e6531ef1 4026907c 06000027

0844 6964654d 616c5061 00726579 6f727245 2d282072 302c3833 65790029 72650072

0864 20726f72 38332d28 2930202c 18001b00 006ef000 006ef000 1ef1ca00 d0d86653

0884 0027401e 654d0600 50616964 6579616c 72450072 20726f72 38332d28 0029302c

08a4 0018005b 00006ef0 00006ef0 531ef1ca 1ed0d866 00002740 64654d06 6c506169

08c4 72657961 74744100 74706d65 206f7420 66726570 206d726f 6b656573 69206f54

08e4 7277206e 20676e6f 74617473 6d203a65 79616c50 303d7265 62393578 35303630

0904 6d202c30 72727543 53746e65 65746174 1c00303d f0001800 f000006e ca00006e

R2: 0xc08c81b8:

81b8 00000000 00000000 c08c81c0 c08c81c0 00000000 00000000 00000000 c08c81d4

81d8 c08c81d4 c047fd50 c047ea14 00000000 00000000 00000000 000003e8 c04800cc

81f8 c00a4f74 00000000 c0966174 00000031 c07f1b14 c069bb14 c08c8170 c08c8274

8218 00000000 d427c800 00000000 00000000 00000000 00000000 c08c8230 c08c8230

8238 c08c8238 c08c8238 00000000 00000000 00000000 c08c824c c08c824c d403c080

8258 0000a6ea 0000a7a3 00040000 c09a6174 00000030 c07f1b20 c069bb14 c08c8210

8278 c08c82d8 00000000 d427c600 00000000 00000000 00000000 00000000 c08c8294

8298 c08c8294 c08c829c c08c829c 00000001 00000000 00000000 c08c82b0 c08c82b0

R3: 0xc08c81b8: