i.mx6 kernel panic

只看该作者 · 2015-11-2 13:21

大家好，
帮忙看一个kernel panic问题把，困扰很久了。
应用场景：车载
测试场景：
我们有一路倒车影像通过CVBS输入到TW8834(video decoder)，然后解出来的数据直接丢给IPU去处理显示。
不停的切换倒车影像，有很大几率导致kernel panic，下面是我分析的结果：

我们从panic信息，以及反汇编得出的结果来看
----------------------------------------------------------------------------
/* Fill black color for framebuffer */
tmp = (short *) fbi->screen_base;
c02ac7f4: e5943248    ldr r3, [r4, #584] ; 0x248
for (i = 0; i < (fbi->fix.line_length * fbi->var.yres)/2;
c02ac7f8: e0020291    mul r2, r1, r2
c02ac7fc: e1b020a2    lsrs r2, r2, #1
c02ac800: 0a000007    beq c02ac824 <prpvf_start.part.2+0x16c>
         i++, tmp++)
      *tmp = color;
c02ac804: e1a00007    mov r0, r7
c02ac808: e0c300b2    strh r0, [r3], #2
         cam->win.w.top);
-----------------------------------------------------------------------------
应该是screen_base这个fb buff指针为空导致的，这这个fb buff为什么为空，是因为：
-------------------------------------------------------------------
mxc_sdc_fb mxc_sdc_fb.0: Unable to allocate framebuffer memory
-------------------------------------------------------------------
fb buff申请内存失败，至于为什么申请内存失败，很有可能是系统内存不足。       从我模拟的情况来看，不停在泊车模式和正常模式之间切换，会有很大几率触发lowmemorrykill
下面的日志，虽然没有导致内核panic，但是已经触发lowmemorrykill，说明系统内存已经不够fb buff的申请了
---------------------------------------------------------------------------------------------------------------
[ 1874.945403] dls_reverse_svr: page allocation failure: order:8, mode:0xd1
[ 1874.952213] [<c0046944>] (unwind_backtrace+0x0/0x138) from [<c00c8ac8>] (warn_alloc_failed+0xc8/0x100)
[ 1874.961735] [<c00c8ac8>] (warn_alloc_failed+0xc8/0x100) from [<c00cafe8>] (_alloc_pages_nodemask+0x4c0/0x710)
[ 1874.975785] [<c00cafe8>] (_alloc_pages_nodemask+0x4c0/0x710) from [<c0049a30>] (_dma_alloc+0xa0/0x2fc)
[ 1874.987960] [<c0049a30>] (_dma_alloc+0xa0/0x2fc) from [<c004a268>] (dma_alloc_coherent+0x54/0x60)
[ 1874.997117] [<c004a268>] (dma_alloc_coherent+0x54/0x60) from [<c02ac968>] (prpvf_start.part.2+0x2b0/0x750)
[ 1875.006815] [<c02ac968>] (prpvf_start.part.2+0x2b0/0x750) from [<c02a745c>] (start_preview+0x44/0x184)
[ 1875.016158] [<c02a745c>] (start_preview+0x44/0x184) from [<c02aadcc>] (mxc_v4l_do_ioctl+0x1418/0x28ec)
[ 1875.025627] [<c02aadcc>] (mxc_v4l_do_ioctl+0x1418/0x28ec) from [<c029ac64>] (video_usercopy+0x98/0x4d4)
[ 1875.035051] [<c029ac64>] (video_usercopy+0x98/0x4d4) from [<c029a1fc>] (v4l2_ioctl+0x118/0x148)
[ 1875.044302] [<c029a1fc>] (v4l2_ioctl+0x118/0x148) from [<c0100dfc>] (do_vfs_ioctl+0x84/0x5c0)
[ 1875.053321] [<c0100dfc>] (do_vfs_ioctl+0x84/0x5c0) from [<c0101370>] (sys_ioctl+0x38/0x5c)
[ 1875.061640] [<c0101370>] (sys_ioctl+0x38/0x5c) from [<c003f900>] (ret_fast_syscall+0x0/0x30)
[ 1875.070105] Mem-info:
[ 1875.072385] Normal per-cpu:
[ 1875.075304] CPU 0: hi:  186, btch:  31 usd:  28
[ 1875.080136] CPU 1: hi:  186, btch:  31 usd:  42
[ 1875.084932] HighMem per-cpu:
[ 1875.087817] CPU 0: hi:  186, btch:  31 usd:  22
[ 1875.092638] CPU 1: hi:  186, btch:  31 usd:  64
[ 1875.097544] active_anon:133980 inactive_anon:54 isolated_anon:0
[ 1875.097549]  active_file:10986 inactive_file:22094 isolated_file:0
[ 1875.097553]  unevictable:112 dirty:0 writeback:0 unstable:0
[ 1875.097557]  free:7050 slab_reclaimable:1338 slab_unreclaimable:3127
[ 1875.097561]  mapped:14276 shmem:61 pagetables:2483 bounce:0
[ 1875.127350] Normal free:25964kB min:2548kB low:3184kB high:3820kB active_anon:260828kB inactive_anon:12kB active_file:15220kB inactive_file:21756kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:406400kB mlocked:0kB dirty:0kB writeback:0kB mapped:3920kB shmem:12kB slab_reclaimable:5352kB slab_unreclaimable:12508kB kernel_stack:4832kB pagetables:9932kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:21 all_unreclaimable? no
[ 1875.167391] lowmem_reserve[]: 0 2905 2905
[ 1875.171498] HighMem free:2236kB min:360kB low:940kB high:1524kB active_anon:275092kB inactive_anon:204kB active_file:28724kB inactive_file:66172kB unevictable:448kB isolated(anon):0kB isolated(file):0kB present:371840kB mlocked:0kB dirty:0kB writeback:0kB mapped:53184kB shmem:232kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:286 all_unreclaimable? no
[ 1875.210680] lowmem_reserve[]: 0 0 0
[ 1875.214233] Normal: 1085*4kB 273*8kB 118*16kB 53*32kB 25*64kB 27*128kB 24*256kB 12*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 27452kB
[ 1875.228290] HighMem: 217*4kB 23*8kB 8*16kB 5*32kB 4*64kB 1*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 2236kB
[ 1875.241663] 32650 total pagecache pages
[ 1875.270149] 262144 pages of RAM
[ 1875.273431] 8624 free pages
[ 1875.276228] 69677 reserved pages
[ 1875.279459] 4462 slab pages
[ 1875.282284] 150199 pages shared
[ 1875.285428] 0 pages swap cached
[ 1875.288573] Error to allocate vf buffer
[ 1875.563858] select 1741 (externalstorage), adj 15, size 4359, to kill
[ 1875.570370] select 2003 (d.process.media), adj 15, size 5411, to kill
[ 1875.576839] send sigkill to 2003 (d.process.media), adj 15, size 5411
[ 1875.791089] select 1741 (externalstorage), adj 15, size 4359, to kill
[ 1875.797588] select 2179 (.foton.contacts), adj 15, size 4593, to kill
[ 1875.804060] select 2193 (.dls.vuiservice), adj 15, size 7088, to kill
[ 1875.810539] send sigkill to 2193 (.dls.vuiservice), adj 15, size 7088
[ 1876.020133] select 1741 (externalstorage), adj 15, size 4359, to kill
[ 1876.026601] select 2179 (.foton.contacts), adj 15, size 4593, to kill
[ 1876.033097] send sigkill to 2179 (.foton.contacts), adj 15, size 4593
[ 1876.150233] select 1741 (externalstorage), adj 15, size 4359, to kill
[ 1876.156735] send sigkill to 1741 (externalstorage), adj 15, size 4359
[ 1876.460260] select 2133 (timeinitializer), adj 15, size 4261, to kill
[ 1876.466746] send sigkill to 2133 (timeinitializer), adj 15, size 4261
[ 1876.570515] select 2024 (.foton.settings), adj 15, size 4965, to kill
[ 1876.577039] send sigkill to 2024 (.foton.settings), adj 15, size 4965
[ 1876.800280] select 2219 (s.PhoneNumUtils), adj 15, size 4827, to kill
[ 1876.806767] send sigkill to 2219 (s.PhoneNumUtils), adj 15, size 4827
[ 1876.910248] select 2290 (oid.factorymode), adj 15, size 4242, to kill
[ 1876.916740] send sigkill to 2290 (oid.factorymode), adj 15, size 4242
[ 1878.962513] select 2095 (d.process.acore), adj 13, size 5601, to kill
[ 1878.968997] send sigkill to 2095 (d.process.acore), adj 13, size 5601

具体的日至已经上传到附件中，大家看看这个bug搞，需要什么log。

下面是出错代码附近的反汇编：
/* Fill black color for framebuffer */
tmp = (short *) fbi->screen_base;
c02ac7f4: e5943248    ldr r3, [r4, #584] ; 0x248
for (i = 0; i < (fbi->fix.line_length * fbi->var.yres)/2;
c02ac7f8: e0020291    mul r2, r1, r2
c02ac7fc: e1b020a2    lsrs r2, r2, #1
c02ac800: 0a000007    beq c02ac824 <prpvf_start.part.2+0x16c>
         i++, tmp++)
      *tmp = color;
c02ac804: e1a00007    mov r0, r7
c02ac808: e0c300b2    strh r0, [r3], #2
         cam->win.w.top);

/* Fill black color for framebuffer */
tmp = (short *) fbi->screen_base;
for (i = 0; i < (fbi->fix.line_length * fbi->var.yres)/2;
         i++, tmp++)
c02ac80c: e2877001    add r7, r7, #1
ipu_disp_set_window_pos(disp_ipu, MEM_FG_SYNC, cam->win.w.left,
         cam->win.w.top);

/* Fill black color for framebuffer */
tmp = (short *) fbi->screen_base;
for (i = 0; i < (fbi->fix.line_length * fbi->var.yres)/2;
c02ac810: e5942040    ldr r2, [r4, #64] ; 0x40
c02ac814: e5941108    ldr r1, [r4, #264] ; 0x108
c02ac818: e0020291    mul r2, r1, r2
c02ac81c: e15700a2    cmp r7, r2, lsr #1
c02ac820: 3afffff8    bcc c02ac808 <prpvf_start.part.2+0x150>
         i++, tmp++)
      *tmp = color;

只看该作者 · 2015-11-2 19:44

重新分析了日志，应该是DMA内存分配失败：
static int mxcfb_map_video_memory(struct fb_info *fbi)
{
if (fbi->fix.smem_len < fbi->var.yres_virtual * fbi->fix.line_length)
      fbi->fix.smem_len = fbi->var.yres_virtual *
                  fbi->fix.line_length;

fbi->screen_base = dma_alloc_writecombine(fbi->device,
            fbi->fix.smem_len,
            (dma_addr_t *)&fbi->fix.smem_start,
            GFP_DMA | GFP_KERNEL);
if (fbi->screen_base == 0) {
      dev_err(fbi->device, "[tpc-ipuv3]Unable to allocate framebuffer memory\n");
      fbi->fix.smem_len = 0;
      fbi->fix.smem_start = 0;
      return -EBUSY;
}

dev_err(fbi->device, "[tpc-ipuv3]allocated fb @ paddr=0x%08X, size=%d.\n",
      (uint32_t) fbi->fix.smem_start, fbi->fix.smem_len);

fbi->screen_size = fbi->fix.smem_len;

/* Clear the screen */
memset((char *)fbi->screen_base, 0, fbi->fix.smem_len);

return 0;
}

就是上面红色代码部分，意思是dma申请失败了。
但是我看了下，im.x6平台的dma地址映射范围足足有64M啊

[ 0.000000] Virtual kernel memory layout:
[ 0.000000]    vector  : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000]    fixmap  : 0xfff00000 - 0xfffe0000 ( 896 kB)
[ 0.000000]    DMA    : 0xfbe00000 - 0xffe00000 (  64 MB)
[ 0.000000]    vmalloc : 0xd9800000 - 0xf2000000 ( 392 MB)
[ 0.000000]    lowmem  : 0xc0000000 - 0xd9000000 ( 400 MB)
[ 0.000000]    pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
[ 0.000000]    modules : 0xbf000000 - 0xbfe00000 (  14 MB)
[ 0.000000]    .init : 0xc0008000 - 0xc0039000 ( 196 kB)
[ 0.000000]    .text : 0xc0039000 - 0xc06050f4 (5937 kB)
[ 0.000000]    .data : 0xc0606000 - 0xc0657b08 ( 327 kB)
[ 0.000000]       .bss : 0xc0657b2c - 0xc07e0c18 (1573 kB)

怎么会不够用呢？

只看该作者 · 2015-11-2 19:49

这个是申请DMA失败的日志：
[ 98.802009] dls_reverse_svr: page allocation failure: order:9, mode:0xd1
[ 98.808776] [<c0046944>] (unwind_backtrace+0x0/0x138) from [<c00c8ac8>] (warn_alloc_failed+0xc8/0x100)
[ 98.818515] [<c00c8ac8>] (warn_alloc_failed+0xc8/0x100) from [<c00cafe8>] (__alloc_pages_nodemask+0x4c0/0x710)
[ 98.835239] [<c00cafe8>] (__alloc_pages_nodemask+0x4c0/0x710) from [<c0049a30>] (__dma_alloc+0xa0/0x2fc)
[ 98.846448] [<c0049a30>] (__dma_alloc+0xa0/0x2fc) from [<c0049d04>] (dma_alloc_writecombine+0x24/0x2c)
[ 98.855850] [<c0049d04>] (dma_alloc_writecombine+0x24/0x2c) from [<c01dd248>] (mxcfb_set_par+0x1a4/0x808)
[ 98.868315] [<c01dd248>] (mxcfb_set_par+0x1a4/0x808) from [<c01d2ff0>] (fb_set_var+0x124/0x290)
[ 98.877191] [<c01d2ff0>] (fb_set_var+0x124/0x290) from [<c02ac7ac>] (prpvf_start.part.2+0x114/0x768)
[ 98.886382] [<c02ac7ac>] (prpvf_start.part.2+0x114/0x768) from [<c02a743c>] (start_preview+0x44/0x184)
[ 98.895725] [<c02a743c>] (start_preview+0x44/0x184) from [<c02aadac>] (mxc_v4l_do_ioctl+0x1418/0x28ec)
[ 98.905075] [<c02aadac>] (mxc_v4l_do_ioctl+0x1418/0x28ec) from [<c029ac44>] (video_usercopy+0x98/0x4d4)
[ 98.914502] [<c029ac44>] (video_usercopy+0x98/0x4d4) from [<c029a1dc>] (v4l2_ioctl+0x118/0x148)
[ 98.923244] [<c029a1dc>] (v4l2_ioctl+0x118/0x148) from [<c0100dfc>] (do_vfs_ioctl+0x84/0x5c0)
[ 98.931803] [<c0100dfc>] (do_vfs_ioctl+0x84/0x5c0) from [<c0101370>] (sys_ioctl+0x38/0x5c)
[ 98.940246] [<c0101370>] (sys_ioctl+0x38/0x5c) from [<c003f900>] (ret_fast_syscall+0x0/0x30)
[ 98.948702] Mem-info:
[ 98.951001] Normal per-cpu:
[ 98.953802] CPU 0: hi:  186, btch:  31 usd: 0
[ 98.958604] CPU 1: hi:  186, btch:  31 usd: 176
[ 98.963426] HighMem per-cpu:
[ 98.966317] CPU 0: hi:  186, btch:  31 usd: 0
[ 98.971253] CPU 1: hi:  186, btch:  31 usd: 159
[ 98.976065] active_anon:82943 inactive_anon:54 isolated_anon:0
[ 98.976069]  active_file:7718 inactive_file:49719 isolated_file:0
[ 98.976074]  unevictable:112 dirty:0 writeback:0 unstable:0
[ 98.976078]  free:34022 slab_reclaimable:1259 slab_unreclaimable:3098
[ 98.976082]  mapped:14693 shmem:61 pagetables:2353 bounce:0
[ 99.005635] Normal free:132668kB min:2548kB low:3184kB high:3820kB active_anon:152052kB inactive_anon:12kB active_file:9004kB inactive_file:30852kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:406400kB mlocked:0kB dirty:0kB writeback:0kB mapped:5288kB shmem:12kB slab_reclaimable:5036kB slab_unreclaimable:12392kB kernel_stack:4928kB pagetables:9412kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 99.005690] imx-esai imx-esai.0: Resetting ESAI!
[ 99.049763] imx-esai imx-esai.0: Resetting ESAI!
[ 99.049861] lowmem_reserve[]: 0 2905 2905
[ 99.049891] HighMem free:3916kB min:360kB low:940kB high:1524kB active_anon:179720kB inactive_anon:204kB active_file:22180kB inactive_file:167140kB unevictable:448kB isolated(anon):0kB isolated(file):0kB present:371840kB mlocked:0kB dirty:0kB writeback:0kB mapped:53484kB shmem:232kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:49 all_unreclaimable? no
[ 99.049913] lowmem_reserve[]: 0 0 0
[ 99.049923] Normal: 503*4kB 383*8kB 320*16kB 257*32kB 197*64kB 136*128kB 118*256kB 54*512kB 26*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 132916kB
[ 99.049958] HighMem: 219*4kB 92*8kB 34*16kB 9*32kB 7*64kB 2*128kB 1*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 3916kB
[ 99.049993] 57432 total pagecache pages
[ 99.073448] 262144 pages of RAM
[ 99.073454] 35516 free pages
[ 99.073459] 69911 reserved pages
[ 99.073463] 4335 slab pages
[ 99.073468] 153984 pages shared
[ 99.073473] 0 pages swap cached
[ 99.073484] mxc_sdc_fb mxc_sdc_fb.0: [tpc-ipuv3]Unable to allocate framebuffer memory
[ 99.073494] detected fb_set_par error, error code: -12
[ 99.073509] [tpc_vf]fb buff is null.