Hi Laurent, Tomasz, Jacopo, > -----Original Message----- > From: Jacopo Mondi [mailto:jacopo@xxxxxxxxxx] > Sent: Wednesday, January 09, 2019 8:41 AM > To: Tomasz Figa <tfiga@xxxxxxxxxxxx> > Cc: Zhi, Yong <yong.zhi@xxxxxxxxx>; Mani, Rajmohan > <rajmohan.mani@xxxxxxxxx>; Qiu, Tian Shu <tian.shu.qiu@xxxxxxxxx>; Cao, > Bingbu <bingbu.cao@xxxxxxxxx>; Laurent Pinchart > <laurent.pinchart@xxxxxxxxxxxxxxxx>; Linux Media Mailing List <linux- > media@xxxxxxxxxxxxxxx>; Sakari Ailus <sakari.ailus@xxxxxxxxxxxxxxx>; Mauro > Carvalho Chehab <mchehab@xxxxxxxxxx>; Hans Verkuil > <hans.verkuil@xxxxxxxxx>; Hu, Jerry W <jerry.w.hu@xxxxxxxxx>; Toivonen, > Tuukka <tuukka.toivonen@xxxxxxxxx> > Subject: Re: [PATCH v7 00/16] Intel IPU3 ImgU patchset > > Hello, > > On Tue, Jan 08, 2019 at 03:54:34PM +0900, Tomasz Figa wrote: > > Hi Raj, Yong, Bingbu, Tianshu, > > > > On Fri, Dec 21, 2018 at 12:04 PM Tomasz Figa <tfiga@xxxxxxxxxxxx> wrote: > > > > > > On Fri, Dec 21, 2018 at 7:24 AM Laurent Pinchart > > > <laurent.pinchart@xxxxxxxxxxxxxxxx> wrote: > > > > > > > > Hellon > > > > > > > > On Sunday, 16 December 2018 09:26:18 EET Laurent Pinchart wrote: > > > > > Hello Yong, > > > > > > > > > > Could you please have a look at the crash reported below ? > > > > > > > > A bit more information to help you debugging this. I've enabled > > > > KASAN in the kernel configuration, and get the following use-after-free > reports. > > I tested as well using the ipu-process.sh script shared by Laurent, with the > following command line: > ./ipu3-process.sh --out 2560x1920 --vf 1920x1080 frame-2592x1944.cio2 > > and I got a very similar trace available at: > https://paste.debian.net/hidden/5855e15a/ > > Please note I have been able to process a set of images (with KASAN enabled > the machine does not freeze) but the kernel log gets flooded and it is not > possible to process any other frame after this. > > The issue is currently quite annoying and it's a blocker for libcamera > development on IPU3. Please let me know if I can support with more testing. > > Thanks > j > > > > > > > > > [ 166.332920] > > > > > ================================================================ > == > > > > [ 166.332937] BUG: KASAN: use-after-free in > > > > __cached_rbnode_delete_update+0x36/0x202 > > > > [ 166.332944] Read of size 8 at addr ffff888133823718 by task > > > > yavta/1305 > > > > > > > > [ 166.332955] CPU: 3 PID: 1305 Comm: yavta Tainted: G C 4.20.0- > rc6+ #3 > > > > [ 166.332958] Hardware name: HP Soraka/Soraka, BIOS 08/30/2018 [ > > > > 166.332959] Call Trace: > > > > [ 166.332967] dump_stack+0x5b/0x81 [ 166.332974] > > > > print_address_description+0x65/0x227 > > > > [ 166.332979] ? __cached_rbnode_delete_update+0x36/0x202 > > > > [ 166.332983] kasan_report+0x247/0x285 [ 166.332989] > > > > __cached_rbnode_delete_update+0x36/0x202 > > > > [ 166.332995] private_free_iova+0x57/0x6d [ 166.332999] > > > > __free_iova+0x23/0x31 [ 166.333011] ipu3_dmamap_free+0x118/0x1d6 > > > > [ipu3_imgu] > > > > > > Thanks Laurent, I think this is a very good hint. It looks like > > > we're basically freeing and already freed IOVA and corrupting some > > > allocator state? > > > > Did you have any luck in reproducing and fixing this double free issue? > > This issue is either hard to reproduce or comes with different signatures with the updated yavta (that now supports meta output) with the 4.4 kernel that I have been using. I am switching to 4.20-rc6 for better reproducibility. Enabling KASAN also results in storage space issues on my Chrome device. Will enable this just for ImgU to get ahead and get back with more updates. > > Best regards, > > Tomasz > > > > > > > > > [ 166.333022] ipu3_css_pool_cleanup+0x25/0x2f [ipu3_imgu] [ > > > > 166.333032] ipu3_css_pipeline_cleanup+0x79/0xcf [ipu3_imgu] [ > > > > 166.333043] ipu3_css_stop_streaming+0x2fe/0x4dc [ipu3_imgu] [ > > > > 166.333056] imgu_s_stream+0xc0/0x6c0 [ipu3_imgu] [ 166.333067] > > > > ? ipu3_all_nodes_streaming+0x1ee/0x20d [ipu3_imgu] [ 166.333079] > > > > ipu3_vb2_stop_streaming+0x27c/0x2d2 [ipu3_imgu] [ 166.333088] > > > > __vb2_queue_cancel+0xa8/0x705 [videobuf2_common] [ 166.333096] ? > > > > __mutex_lock_interruptible_slowpath+0xf/0xf > > > > [ 166.333104] vb2_core_streamoff+0x68/0xf8 [videobuf2_common] [ > > > > 166.333123] __video_do_ioctl+0x625/0x887 [videodev] [ > > > > 166.333142] ? copy_overflow+0x14/0x14 [videodev] [ 166.333147] > > > > ? slab_free_freelist_hook+0x46/0x94 [ 166.333151] ? > > > > kfree+0x107/0x1a0 [ 166.333169] video_usercopy+0x3a3/0x8ae > > > > [videodev] [ 166.333187] ? copy_overflow+0x14/0x14 [videodev] [ > > > > 166.333203] ? v4l_enumstd+0x49/0x49 [videodev] [ 166.333207] ? > > > > __wake_up_common+0x342/0x342 [ 166.333215] ? > > > > atomic_long_add_return+0x15/0x24 [ 166.333219] ? > > > > ldsem_up_read+0x15/0x29 [ 166.333223] ? tty_write+0x4c6/0x4d8 [ > > > > 166.333227] ? n_tty_receive_char_special+0x1152/0x1152 > > > > [ 166.333244] ? video_usercopy+0x8ae/0x8ae [videodev] [ > > > > 166.333260] v4l2_ioctl+0xb7/0xc5 [videodev] [ 166.333266] > > > > vfs_ioctl+0x76/0x89 [ 166.333271] do_vfs_ioctl+0xb33/0xb7e [ > > > > 166.333275] ? __switch_to_asm+0x40/0x70 [ 166.333279] ? > > > > __switch_to_asm+0x40/0x70 [ 166.333282] ? > > > > __switch_to_asm+0x34/0x70 [ 166.333286] ? > > > > __switch_to_asm+0x40/0x70 [ 166.333290] ? > > > > ioctl_preallocate+0x174/0x174 [ 166.333294] ? > > > > __switch_to+0x71c/0xb00 [ 166.333299] ? > > > > compat_start_thread+0x6b/0x6b [ 166.333302] ? > > > > __switch_to_asm+0x34/0x70 [ 166.333305] ? > > > > __switch_to_asm+0x40/0x70 [ 166.333309] ? mmdrop+0x12/0x23 [ > > > > 166.333313] ? finish_task_switch+0x34d/0x3de [ 166.333319] ? > > > > __schedule+0x1004/0x1045 [ 166.333325] ? > > > > firmware_map_remove+0x119/0x119 [ 166.333330] > > > > ksys_ioctl+0x50/0x70 [ 166.333335] __x64_sys_ioctl+0x82/0x89 [ > > > > 166.333340] do_syscall_64+0xa0/0xd2 [ 166.333345] > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > [ 166.333349] RIP: 0033:0x7f2481541f47 [ 166.333354] Code: 00 00 > > > > 00 48 8b 05 51 6f 2c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff > > > > c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 > > > > f0 ff ff 73 01 c3 48 8b 0d 21 6f 2c 00 f7 d8 64 89 01 48 [ > > > > 166.333357] RSP: 002b:00007fffd6aff9b8 EFLAGS: 00000246 ORIG_RAX: > > > > 0000000000000010 [ 166.333362] RAX: ffffffffffffffda RBX: > > > > 0000000000000000 RCX: 00007f2481541f47 [ 166.333364] RDX: > > > > 00007fffd6aff9c4 RSI: 0000000040045613 RDI: 0000000000000003 [ > > > > 166.333367] RBP: 0000555f1c494af8 R08: 00007f247f34c000 R09: > > > > 00007f2481c24700 [ 166.333369] R10: 0000000000000020 R11: > > > > 0000000000000246 R12: 0000555f1c494b06 [ 166.333372] R13: > > > > 0000000000000004 R14: 00007fffd6affb90 R15: 00007fffd6b00825 > > > > > > > > [ 166.333383] Allocated by task 1305: > > > > [ 166.333389] kasan_kmalloc+0x8a/0x98 [ 166.333392] > > > > slab_post_alloc_hook+0x31/0x51 [ 166.333396] > > > > kmem_cache_alloc+0xd7/0x174 [ 166.333399] alloc_iova+0x24/0x2ea > > > > [ 166.333407] ipu3_dmamap_alloc+0x193/0x83f [ipu3_imgu] [ > > > > 166.333415] ipu3_css_pool_init+0x80/0xdf [ipu3_imgu] [ > > > > 166.333424] ipu3_css_start_streaming+0x58df/0x5ddc [ipu3_imgu] [ > > > > 166.333433] imgu_s_stream+0x2dd/0x6c0 [ipu3_imgu] [ 166.333442] > > > > ipu3_vb2_start_streaming+0x35f/0x3de [ipu3_imgu] [ 166.333449] > > > > vb2_start_streaming+0x164/0x33b [videobuf2_common] [ 166.333455] > > > > vb2_core_streamon+0x1a1/0x208 [videobuf2_common] [ 166.333471] > > > > __video_do_ioctl+0x625/0x887 [videodev] [ 166.333487] > > > > video_usercopy+0x3a3/0x8ae [videodev] [ 166.333501] > > > > v4l2_ioctl+0xb7/0xc5 [videodev] [ 166.333505] > > > > vfs_ioctl+0x76/0x89 [ 166.333508] do_vfs_ioctl+0xb33/0xb7e [ > > > > 166.333511] ksys_ioctl+0x50/0x70 [ 166.333514] > > > > __x64_sys_ioctl+0x82/0x89 [ 166.333518] do_syscall_64+0xa0/0xd2 > > > > [ 166.333521] entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > > > > > [ 166.333526] Freed by task 1301: > > > > [ 166.333532] __kasan_slab_free+0xfa/0x11c [ 166.333535] > > > > slab_free_freelist_hook+0x46/0x94 [ 166.333538] > > > > kmem_cache_free+0x7b/0x172 [ 166.333542] __free_iova+0x23/0x31 [ > > > > 166.333550] ipu3_dmamap_free+0x118/0x1d6 [ipu3_imgu] [ > > > > 166.333557] ipu3_css_pool_cleanup+0x25/0x2f [ipu3_imgu] [ > > > > 166.333566] ipu3_css_pipeline_cleanup+0x79/0xcf [ipu3_imgu] [ > > > > 166.333574] ipu3_css_stop_streaming+0x2fe/0x4dc [ipu3_imgu] [ > > > > 166.333584] imgu_s_stream+0xc0/0x6c0 [ipu3_imgu] [ 166.333593] > > > > ipu3_vb2_stop_streaming+0x27c/0x2d2 [ipu3_imgu] [ 166.333599] > > > > __vb2_queue_cancel+0xa8/0x705 [videobuf2_common] [ 166.333606] > > > > vb2_core_streamoff+0x68/0xf8 [videobuf2_common] [ 166.333621] > > > > __video_do_ioctl+0x625/0x887 [videodev] [ 166.333637] > > > > video_usercopy+0x3a3/0x8ae [videodev] [ 166.333652] > > > > v4l2_ioctl+0xb7/0xc5 [videodev] [ 166.333655] > > > > vfs_ioctl+0x76/0x89 [ 166.333658] do_vfs_ioctl+0xb33/0xb7e [ > > > > 166.333662] ksys_ioctl+0x50/0x70 [ 166.333665] > > > > __x64_sys_ioctl+0x82/0x89 [ 166.333668] do_syscall_64+0xa0/0xd2 > > > > [ 166.333671] entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > > > > > [ 166.333678] The buggy address belongs to the object at > ffff888133823700 > > > > which belongs to the cache iommu_iova of size 40 [ > > > > 166.333685] The buggy address is located 24 bytes inside of > > > > 40-byte region [ffff888133823700, > > > > ffff888133823728) [ 166.333690] The buggy address belongs to the page: > > > > [ 166.333696] page:ffffea0004ce0880 count:1 mapcount:0 > > > > mapping:ffff8881519e8640 index:0x0 compound_mapcount: 0 [ > > > > 166.333703] flags: 0x200000000010200(slab|head) [ 166.333710] > > > > raw: 0200000000010200 ffffea0004dfc488 ffff88814bfbde70 > > > > ffff8881519e8640 [ 166.333717] raw: 0000000000000000 > > > > 0000000000120012 00000001ffffffff 0000000000000000 [ 166.333720] > > > > page dumped because: kasan: bad access detected > > > > > > > > [ 166.333726] Memory state around the buggy address: > > > > [ 166.333732] ffff888133823600: fc fc fc fc fc fc fc fc fc fc fc > > > > fc fc fc fc fc [ 166.333737] ffff888133823680: fc fc fc fc fc fc > > > > fc fc fc fc fc fc fc fc fc fc [ 166.333742] >ffff888133823700: fb fb fb fb fb fc fc > fc fc fc fc fc fc fc fc fc > > > > [ 166.333745] ^ > > > > [ 166.333750] ffff888133823780: fc fc fc fc fc fc fc fc fc fc fc > > > > fc fc fc fc fc [ 166.333755] ffff888133823800: fc fc fc fc fc fc > > > > fc fc fc fc fc fc fc fc fc fc [ 166.333759] > > > > > ================================================================ > == > > > > [ 166.333762] Disabling lock debugging due to kernel taint [ > > > > 166.333764] > > > > > ================================================================ > == > > > > [ 166.333770] BUG: KASAN: double-free or invalid-free in > > > > kmem_cache_free+0x7b/0x172 > > > > > > > > [ 166.333780] CPU: 3 PID: 1305 Comm: yavta Tainted: G B C 4.20.0- > rc6+ #3 > > > > [ 166.333782] Hardware name: HP Soraka/Soraka, BIOS 08/30/2018 [ > > > > 166.333783] Call Trace: > > > > [ 166.333789] dump_stack+0x5b/0x81 [ 166.333795] > > > > print_address_description+0x65/0x227 > > > > [ 166.333799] ? kmem_cache_free+0x7b/0x172 [ 166.333803] > > > > kasan_report_invalid_free+0x67/0xa0 > > > > [ 166.333807] ? kmem_cache_free+0x7b/0x172 [ 166.333812] > > > > __kasan_slab_free+0x86/0x11c [ 166.333817] > > > > slab_free_freelist_hook+0x46/0x94 [ 166.333822] > > > > kmem_cache_free+0x7b/0x172 [ 166.333826] ? __free_iova+0x23/0x31 > > > > [ 166.333831] __free_iova+0x23/0x31 [ 166.333840] > > > > ipu3_dmamap_free+0x118/0x1d6 [ipu3_imgu] [ 166.333851] > > > > ipu3_css_pool_cleanup+0x25/0x2f [ipu3_imgu] [ 166.333861] > > > > ipu3_css_pipeline_cleanup+0x79/0xcf [ipu3_imgu] [ 166.333872] > > > > ipu3_css_stop_streaming+0x2fe/0x4dc [ipu3_imgu] [ 166.333885] > > > > imgu_s_stream+0xc0/0x6c0 [ipu3_imgu] [ 166.333896] ? > > > > ipu3_all_nodes_streaming+0x1ee/0x20d [ipu3_imgu] [ 166.333908] > > > > ipu3_vb2_stop_streaming+0x27c/0x2d2 [ipu3_imgu] [ 166.333917] > > > > __vb2_queue_cancel+0xa8/0x705 [videobuf2_common] [ 166.333923] ? > > > > __mutex_lock_interruptible_slowpath+0xf/0xf > > > > [ 166.333932] vb2_core_streamoff+0x68/0xf8 [videobuf2_common] [ > > > > 166.333950] __video_do_ioctl+0x625/0x887 [videodev] [ > > > > 166.333970] ? copy_overflow+0x14/0x14 [videodev] [ 166.333974] > > > > ? slab_free_freelist_hook+0x46/0x94 [ 166.333979] ? > > > > kfree+0x107/0x1a0 [ 166.333997] video_usercopy+0x3a3/0x8ae > > > > [videodev] [ 166.334015] ? copy_overflow+0x14/0x14 [videodev] [ > > > > 166.334031] ? v4l_enumstd+0x49/0x49 [videodev] [ 166.334035] ? > > > > __wake_up_common+0x342/0x342 [ 166.334042] ? > > > > atomic_long_add_return+0x15/0x24 [ 166.334046] ? > > > > ldsem_up_read+0x15/0x29 [ 166.334050] ? tty_write+0x4c6/0x4d8 [ > > > > 166.334054] ? n_tty_receive_char_special+0x1152/0x1152 > > > > [ 166.334071] ? video_usercopy+0x8ae/0x8ae [videodev] [ > > > > 166.334087] v4l2_ioctl+0xb7/0xc5 [videodev] [ 166.334092] > > > > vfs_ioctl+0x76/0x89 [ 166.334097] do_vfs_ioctl+0xb33/0xb7e [ > > > > 166.334101] ? __switch_to_asm+0x40/0x70 [ 166.334105] ? > > > > __switch_to_asm+0x40/0x70 [ 166.334108] ? > > > > __switch_to_asm+0x34/0x70 [ 166.334111] ? > > > > __switch_to_asm+0x40/0x70 [ 166.334116] ? > > > > ioctl_preallocate+0x174/0x174 [ 166.334120] ? > > > > __switch_to+0x71c/0xb00 [ 166.334124] ? > > > > compat_start_thread+0x6b/0x6b [ 166.334127] ? > > > > __switch_to_asm+0x34/0x70 [ 166.334130] ? > > > > __switch_to_asm+0x40/0x70 [ 166.334134] ? mmdrop+0x12/0x23 [ > > > > 166.334137] ? finish_task_switch+0x34d/0x3de [ 166.334143] ? > > > > __schedule+0x1004/0x1045 [ 166.334148] ? > > > > firmware_map_remove+0x119/0x119 [ 166.334153] > > > > ksys_ioctl+0x50/0x70 [ 166.334158] __x64_sys_ioctl+0x82/0x89 [ > > > > 166.334163] do_syscall_64+0xa0/0xd2 [ 166.334167] > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > [ 166.334171] RIP: 0033:0x7f2481541f47 [ 166.334175] Code: 00 00 > > > > 00 48 8b 05 51 6f 2c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff > > > > c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 > > > > f0 ff ff 73 01 c3 48 8b 0d 21 6f 2c 00 f7 d8 64 89 01 48 [ > > > > 166.334177] RSP: 002b:00007fffd6aff9b8 EFLAGS: 00000246 ORIG_RAX: > > > > 0000000000000010 [ 166.334181] RAX: ffffffffffffffda RBX: > > > > 0000000000000000 RCX: 00007f2481541f47 [ 166.334184] RDX: > > > > 00007fffd6aff9c4 RSI: 0000000040045613 RDI: 0000000000000003 [ > > > > 166.334186] RBP: 0000555f1c494af8 R08: 00007f247f34c000 R09: > > > > 00007f2481c24700 [ 166.334189] R10: 0000000000000020 R11: > > > > 0000000000000246 R12: 0000555f1c494b06 [ 166.334191] R13: > > > > 0000000000000004 R14: 00007fffd6affb90 R15: 00007fffd6b00825 > > > > [snip]
