kernel Warning when using vivid with contiguous dma

DISCUSSION Dafna Hirschfeld 5 participants 8 messages Jul 22, 2019 – Jul 25, 2019

Subsystems (2)

Media (V4L/DVB) DMA mapping helpers

lore

Share & tools

lore

Dafna Hirschfeld

author

2019-07-22 11:21 UTC #0 lore raw

I loaded the vivid module with contiguous DMA and ran streaming with it with large image dimensions
here are the commans:

$ uname -a
Linux ubuntu 5.2.0-rc5+ #1 SMP Mon Jul 1 10:17:46 PDT 2019 x86_64
x86_64 x86_64 GNU/Linux
$ sudo modprobe -v vivid
allocators=1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,
1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1
$ v4l2-ctl -d0 --verbose -v
width=2592,height=1944,pixelformat=UYVY,bytesperline=5184
--stream-mmap --stream-to video.UYVY --list-buffers

Here is the warning that I got:

[  306.437224] WARNING: CPU: 1 PID: 2240 at mm/page_alloc.c:4639 __alloc_pages_nodemask+0x1f3/0x3b0
[  306.437235] Modules linked in: rc_cec vivid v4l2_tpg videobuf2_dma_contig v4l2_dv_timings v4l2_common videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev mc cec rc_core crct10dif_pclmul crc32_pclmul ghash_clmulni_intel vmw_balloon aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_rapl_perf snd_ens1371 snd_ac97_codec gameport ac97_bus snd_pcm joydev input_leds serio_raw snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore vmw_vsock_vmci_transport vsock vmw_vmci mac_hid sch_fq_codel vmwgfx ttm drm_kms_helper drm fb_sys_fops syscopyarea sysfillrect sysimgblt parport_pc ppdev lp parport ip_tables x_tables autofs4 psmouse ahci libahci e1000 mptspi mptscsih mptbase scsi_transport_spi i2c_piix4 pata_acpi
[  306.437273] CPU: 1 PID: 2240 Comm: v4l2-ctl Not tainted 5.2.0-rc5+ #1
[  306.437275] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018 [  306.437277] RIP: 0010:__alloc_pages_nodemask+0x1f3/0x3b0 [  306.437280] Code: fc fe ff ff 65 48 8b 04 25 c0 6d 01 00 48 05 a0 17 00 00 41 bf 01 00 00 00 48 89 45 b0 e9 de fe ff ff 81 e7 00 20 00 00 75 02 <0f> 0b 45 31 ff eb 95 44 8b 6d c0 65 8b 05 fb fd 76 46 89 c0 48 0f
[  306.437282] RSP: 0018:ffffa42584bd39c8 EFLAGS: 00010246 [  306.437284] RAX: 0000000000000000 RBX: 00000000ffffffff RCX:
0000000000000000
[  306.437285] RDX: 0000000000000000 RSI: 000000000000000c RDI:
0000000000000000
[  306.437287] RBP: ffffa42584bd3a20 R08: 0000000000000000 R09:
ffff9054df8072c0
[  306.437289] R10: ffff9054cf074600 R11: 0000000000000000 R12:
0000000000000cc4
[  306.437290] R13: ffffffffc08840d0 R14: 000000000000000c R15:
00000000ffffffff
[  306.437292] FS:  00007f842025f740(0000) GS:ffff9054dfe00000(0000) knlGS:0000000000000000
[  306.437294] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [  306.437296] CR2: 00007ffd81229000 CR3: 000000040ca28005 CR4:
00000000003606e0
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0
[  306.437358]  vb2_dc_alloc+0x79/0x110 [videobuf2_dma_contig] [  306.437365]  __vb2_queue_alloc+0x331/0x490 [videobuf2_common] [  306.437373]  vb2_core_reqbufs+0x2db/0x470 [videobuf2_common] [  306.437376]  ? __mutex_lock+0x2f5/0x930
[  306.437385]  vb2_ioctl_reqbufs+0x7e/0xb0 [videobuf2_v4l2] [  306.437393]  v4l_reqbufs+0x47/0x50 [videodev]
[  306.437400]  __video_do_ioctl+0x194/0x4d0 [videodev]
[  306.437408]  ? tomoyo_init_request_info+0x80/0x90
[  306.437416]  video_usercopy+0x1af/0x760 [videodev]
[  306.437422]  ? v4l_s_fmt+0x6a0/0x6a0 [videodev]
[  306.437437]  video_ioctl2+0x15/0x20 [videodev]
[  306.437442]  v4l2_ioctl+0x49/0x50 [videodev]
[  306.437445]  do_vfs_ioctl+0xa9/0x6d0
[  306.437448]  ? rcu_read_lock_sched_held+0x64/0x70
[  306.437453]  ? tomoyo_file_ioctl+0x19/0x20
[  306.437458]  ksys_ioctl+0x75/0x80
[  306.437462]  ? do_syscall_64+0x17/0x1e0
[  306.437466]  __x64_sys_ioctl+0x1a/0x20
[  306.437469]  do_syscall_64+0x65/0x1e0
[  306.437473]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  306.437475] RIP: 0033:0x7f841f1aa5d7
[  306.437478] Code: b3 66 90 48 8b 05 b1 48 2d 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 81 48 2d 00 f7 d8 64 89 01 48
[  306.437479] RSP: 002b:00007ffd812277c8 EFLAGS: 00000202 ORIG_RAX:
0000000000000010
[  306.437482] RAX: ffffffffffffffda RBX: 00007ffd812288e0 RCX:
00007f841f1aa5d7
[  306.437483] RDX: 00007ffd81227830 RSI: 00000000c0145608 RDI:
0000000000000003
[  306.437485] RBP: 00007ffd8122bd00 R08: 0000000000000000 R09:
0000562416280a46
[  306.437486] R10: 00000000000001b6 R11: 0000000000000202 R12:
00007ffd812288e0
[  306.437488] R13: 0000000000000002 R14: 0000000000000002 R15:
0000000000000000
[  306.437498] irq event stamp: 15058
[  306.437501] hardirqs last  enabled at (15057): [<ffffffffb96045a7>] do_syscall_64+0x17/0x1e0
[  306.437504] hardirqs last disabled at (15058): [<ffffffffb960384c>] trace_hardirqs_off_thunk+0x1a/0x1c
[  306.437506] softirqs last  enabled at (13490): [<ffffffffba40035a>] __do_softirq+0x35a/0x409
[  306.437509] softirqs last disabled at (13477): [<ffffffffb969eed6>] irq_exit+0xc6/0xd0
[  306.437511] ---[ end trace 89b603670b5a81e6 ]---
[  306.437516] vivid vivid.0: dma_alloc_coherent of size 16588800 failed

Mauro Carvalho Chehab

2019-07-22 11:38 UTC #1 lore raw

Em Mon, 22 Jul 2019 13:21:00 +0200
Dafna Hirschfeld <[email protected]> escreveu:

Quoted 8 lines

I loaded the vivid module with contiguous DMA and ran streaming with it with large image dimensions
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0 [  306.437343]  dma_direct_alloc_pages+0x24/0xf0 [  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0

Hmm... we had a recent regression affecting other media devices, reported via Kaffeine mailing list:

	https://bugs.kde.org/show_bug.cgi?id=408004#c35

While this one was for S/G, maybe it is somewhat related.

Thanks,
Mauro

Dafna Hirschfeld

author

2019-07-23 13:14 UTC #2 lore raw

Quoted 12 lines · Mauro Carvalho Chehab

Em Mon, 22 Jul 2019 13:21:00 +0200
Dafna Hirschfeld <[email protected]> escreveu:
Quoted 8 lines
I loaded the vivid module with contiguous DMA and ran streaming with
it with large image dimensions
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0

Quoted 7 lines

Hmm... we had a recent regression affecting other media devices, reported via Kaffeine mailing list:
	https://bugs.kde.org/show_bug.cgi?id=408004#c35
While this one was for S/G, maybe it is somewhat related.

Also, I compiled vivid as built-in into the kernel (not as a separate module) for nitrogen8m device (imx8) and set it to use contig dma for mem_ops. Then I get a crash when running the above command.
I use the master branch of git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git with this patch to vivid:

drivers/media/platform/vivid/vivid-core.c +1 -1

index bc2a176937a4..0531f36d7d0a 100644
@@ -140,7 +140,7 @@ static bool no_error_inj;
 module_param(no_error_inj, bool, 0444);
 MODULE_PARM_DESC(no_error_inj, " if set disable the error injecting controls");
 
-static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 0 };
+static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 1 };
 module_param_array(allocators, uint, NULL, 0444);
 MODULE_PARM_DESC(allocators, " memory allocator selection, default is 0.\n"
                             "\t\t    0 == vmalloc\n"

And then on the nitrogen8m device I get the following crash report which seems to be related to the cma allocation

ubuntu@bionic-dev64:~$ v4l2-ctl -d3 -v width=2592,height=1944,pixelformat=UYVY,bytesperline=5184 --stream-mmap --stream-to video.UYVY
[   70.139006] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.159829] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.166292] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.173006] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.181471] cma: cma_alloc(): returned (____ptrval____)
[   70.192449] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.198907] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.205625] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.205733] systemd-journald[204]: /var/log/journal/5cca8918401249538eacb5efd5b9b052/system.journal: Journal file corrupted, rotating.
[   70.214083] cma: cma_alloc(): returned (____ptrval____)
[   70.219867] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.237878] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.244599] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.253066] cma: cma_alloc(): returned (____ptrval____)
[   70.264893] cma: cma_release(page (____ptrval____))
[   70.272871] cma: cma_release(page (____ptrval____))
[   70.277800] BUG: Bad page state in process v4l2-ctl  pfn:b5a00
[   70.283652] page:ffff7e0001d68000 refcount:13 mapcount:0 mapping:0000000000000000 index:0x0 compound_mapcount: 0
[   70.293874] flags: 0xffff00000010000(head)
[   70.297999] raw: 0ffff00000010000 dead000000000100 dead000000000122 0000000000000000
[   70.305772] raw: 0000000000000000 0000000000000000 0000000dffffffff 0000000000000000
[   70.313526] page dumped because: nonzero _refcount
[   70.318327] Modules linked in:
[   70.321399] CPU: 2 PID: 482 Comm: v4l2-ctl Not tainted 5.3.0-rc1+ #159
[   70.327927] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.334196] Call trace:
[   70.336654]  dump_backtrace+0x0/0x148
[   70.340319]  show_stack+0x14/0x20
[   70.343640]  dump_stack+0x9c/0xc4
[   70.346959]  bad_page+0xe4/0x148
[   70.350188]  free_pages_check_bad+0x70/0xa8
[   70.354375]  __free_pages_ok+0x294/0x2b0
[   70.358301]  __free_pages+0x38/0x50
[   70.361795]  dma_free_contiguous+0x90/0x98
[   70.365892]  __dma_direct_free_pages+0x18/0x20
[   70.370338]  arch_dma_free+0x74/0x88
[   70.373916]  dma_direct_free+0x4c/0x58
[   70.377668]  dma_free_attrs+0x88/0xe0
[   70.381335]  vb2_dc_put+0x44/0x60
[   70.384653]  __vb2_buf_mem_free+0x68/0x110
[   70.388749]  __vb2_queue_free+0x398/0x538
[   70.392763]  vb2_core_queue_release+0x34/0x48
[   70.397122]  _vb2_fop_release+0x88/0x98
[   70.400960]  vb2_fop_release+0x28/0x50
[   70.404712]  vivid_fop_release+0x88/0x208
[   70.408725]  v4l2_release+0x6c/0xf0
[   70.412216]  __fput+0x8c/0x1f8
[   70.415270]  ____fput+0xc/0x18
[   70.418328]  task_work_run+0x94/0xb0
[   70.421907]  do_exit+0x2b0/0x9f8
[   70.425138]  do_group_exit+0x34/0x98
[   70.428717]  get_signal+0x104/0x678
[   70.432209]  do_notify_resume+0x2ac/0x380
[   70.436220]  work_pending+0x8/0x10
[   70.439648] Disabling lock debugging due to kernel taint
[   70.444974] BUG: Bad page state in process v4l2-ctl  pfn:b5a01
[   70.450822] page:ffff7e0001d68040 refcount:0 mapcount:0 mapping:dead000000000400 index:0x1 compound_mapcount: 0
[   70.451427] printk: systemd: 27 output lines suppressed due to ratelimiting
[   70.460924] flags: 0xffff00000000000()
[   70.460931] raw: 0ffff00000000000 ffff7e0001d68001 ffffffff01d60301 dead000000000400
[   70.467945] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[   70.471659] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[   70.479389] CPU: 1 PID: 1 Comm: systemd Tainted: G    B             5.3.0-rc1+ #159
[   70.479394] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.487058] page dumped because: non-NULL mapping
[   70.494782] Call trace:
[   70.494789]  dump_backtrace+0x0/0x148
[   70.494793]  show_stack+0x14/0x20
[   70.494799]  dump_stack+0x9c/0xc4
[   70.502460] Modules linked in:
[   70.508713]  panic+0x140/0x32c
[   70.508718]  complete_and_exit+0x0/0x20
[   70.508724]  do_group_exit+0x34/0x98
[   70.539649]  get_signal+0x104/0x678
[   70.543139]  do_notify_resume+0x2ac/0x380
[   70.547149]  work_pending+0x8/0x10
[   70.550553] CPU: 2 PID: 482 Comm: v4l2-ctl Tainted: G    B             5.3.0-rc1+ #159
[   70.550554] SMP: stopping secondary CPUs
[   70.562387] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.568653] Call trace:
[   70.571103]  dump_backtrace+0x0/0x148
[   70.574765]  show_stack+0x14/0x20
[   70.578081]  dump_stack+0x9c/0xc4
[   70.581398]  bad_page+0xe4/0x148
[   70.584627]  free_pages_check_bad+0x70/0xa8
[   70.588814]  __free_pages_ok+0x294/0x2b0
[   70.592737]  __free_pages+0x38/0x50
[   70.596229]  dma_free_contiguous+0x90/0x98
[   70.600327]  __dma_direct_free_pages+0x18/0x20
[   70.604771]  arch_dma_free+0x74/0x88
[   70.608347]  dma_direct_free+0x4c/0x58
[   70.612098]  dma_free_attrs+0x88/0xe0
[   70.615765]  vb2_dc_put+0x44/0x60
[   70.619082]  __vb2_buf_mem_free+0x68/0x110
[   70.623180]  __vb2_queue_free+0x398/0x538
[   70.627192]  vb2_core_queue_release+0x34/0x48
[   70.631551]  _vb2_fop_release+0x88/0x98
[   70.635387]  vb2_fop_release+0x28/0x50
[   70.639138]  vivid_fop_release+0x88/0x208
[   70.643149]  v4l2_release+0x6c/0xf0
[   70.646638]  __fput+0x8c/0x1f8
[   70.649693]  ____fput+0xc/0x18
[   70.652750]  task_work_run+0x94/0xb0
[   70.656326]  do_exit+0x2b0/0x9f8
[   70.659554]  do_group_exit+0x34/0x98
[   70.663130]  get_signal+0x104/0x678
[   70.666621]  do_notify_resume+0x2ac/0x380
[   70.670632]  work_pending+0x8/0x10
[   70.674036] Kernel Offset: disabled
[   70.677526] CPU features: 0x0002,2000200c
[   70.681535] Memory Limit: none
[   70.684599] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ]---

Dafna

Quoted 2 lines

Thanks,
Mauro

Hans Verkuil (hansverk)

2019-07-23 14:13 UTC #3 lore raw

Quoted 38 lines · Dafna Hirschfeld

Quoted 12 lines · Mauro Carvalho Chehab
Em Mon, 22 Jul 2019 13:21:00 +0200
Dafna Hirschfeld <[email protected]> escreveu:
Quoted 8 lines
I loaded the vivid module with contiguous DMA and ran streaming with
it with large image dimensions
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0
Quoted 7 lines
Hmm... we had a recent regression affecting other media devices, reported via Kaffeine mailing list:
	https://bugs.kde.org/show_bug.cgi?id=408004#c35
While this one was for S/G, maybe it is somewhat related.
Also, I compiled vivid as built-in into the kernel (not as a separate module) for nitrogen8m device (imx8) and set it to use contig dma for mem_ops. Then I get a crash when running the above command.
I use the master branch of git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git with this patch to vivid:
drivers/media/platform/vivid/vivid-core.c +1 -1
index bc2a176937a4..0531f36d7d0a 100644
@@ -140,7 +140,7 @@ static bool no_error_inj;
 module_param(no_error_inj, bool, 0444);
 MODULE_PARM_DESC(no_error_inj, " if set disable the error injecting controls");
 
-static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 0 };
+static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 1 };
 module_param_array(allocators, uint, NULL, 0444);
 MODULE_PARM_DESC(allocators, " memory allocator selection, default is 0.\n"
                             "\t\t    0 == vmalloc\n"

Quoted 7 lines

And then on the nitrogen8m device I get the following crash report which seems to be related to the cma allocation

ubuntu@bionic-dev64:~$ v4l2-ctl -d3 -v width=2592,height=1944,pixelformat=UYVY,bytesperline=5184 --stream-mmap --stream-to video.UYVY
[   70.139006] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.159829] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.166292] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.173006] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages

So it looks like the CMA area is too small. Look at the CONFIG_CMA_SIZE_MBYTES setting.

That explains why it fails.

Quoted 5 lines

[   70.181471] cma: cma_alloc(): returned (____ptrval____)
[   70.192449] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.198907] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.205625] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.205733] systemd-journald[204]: /var/log/journal/5cca8918401249538eacb5efd5b9b052/system.journal: Journal file corrupted, rotating.

Quoted 8 lines

[   70.214083] cma: cma_alloc(): returned (____ptrval____)
[   70.219867] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.237878] cma: cma_alloc: alloc failed, req-size: 4050 pages, ret: -12
[   70.244599] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.253066] cma: cma_alloc(): returned (____ptrval____)
[   70.264893] cma: cma_release(page (____ptrval____))
[   70.272871] cma: cma_release(page (____ptrval____))
[   70.277800] BUG: Bad page state in process v4l2-ctl  pfn:b5a00

But that shouldn't lead to this.

It could be a bug somewhere.

Does it work fine if you use a smaller resolution? Perhaps there is something wrong in error handling in vb2. These corner cases are not exactly tested very often (or at all!).

Regards,

Hans

Quoted 100 lines

[   70.283652] page:ffff7e0001d68000 refcount:13 mapcount:0 mapping:0000000000000000 index:0x0 compound_mapcount: 0
[   70.293874] flags: 0xffff00000010000(head)
[   70.297999] raw: 0ffff00000010000 dead000000000100 dead000000000122 0000000000000000
[   70.305772] raw: 0000000000000000 0000000000000000 0000000dffffffff 0000000000000000
[   70.313526] page dumped because: nonzero _refcount
[   70.318327] Modules linked in:
[   70.321399] CPU: 2 PID: 482 Comm: v4l2-ctl Not tainted 5.3.0-rc1+ #159
[   70.327927] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.334196] Call trace:
[   70.336654]  dump_backtrace+0x0/0x148
[   70.340319]  show_stack+0x14/0x20
[   70.343640]  dump_stack+0x9c/0xc4
[   70.346959]  bad_page+0xe4/0x148
[   70.350188]  free_pages_check_bad+0x70/0xa8
[   70.354375]  __free_pages_ok+0x294/0x2b0
[   70.358301]  __free_pages+0x38/0x50
[   70.361795]  dma_free_contiguous+0x90/0x98
[   70.365892]  __dma_direct_free_pages+0x18/0x20
[   70.370338]  arch_dma_free+0x74/0x88
[   70.373916]  dma_direct_free+0x4c/0x58
[   70.377668]  dma_free_attrs+0x88/0xe0
[   70.381335]  vb2_dc_put+0x44/0x60
[   70.384653]  __vb2_buf_mem_free+0x68/0x110
[   70.388749]  __vb2_queue_free+0x398/0x538
[   70.392763]  vb2_core_queue_release+0x34/0x48
[   70.397122]  _vb2_fop_release+0x88/0x98
[   70.400960]  vb2_fop_release+0x28/0x50
[   70.404712]  vivid_fop_release+0x88/0x208
[   70.408725]  v4l2_release+0x6c/0xf0
[   70.412216]  __fput+0x8c/0x1f8
[   70.415270]  ____fput+0xc/0x18
[   70.418328]  task_work_run+0x94/0xb0
[   70.421907]  do_exit+0x2b0/0x9f8
[   70.425138]  do_group_exit+0x34/0x98
[   70.428717]  get_signal+0x104/0x678
[   70.432209]  do_notify_resume+0x2ac/0x380
[   70.436220]  work_pending+0x8/0x10
[   70.439648] Disabling lock debugging due to kernel taint
[   70.444974] BUG: Bad page state in process v4l2-ctl  pfn:b5a01
[   70.450822] page:ffff7e0001d68040 refcount:0 mapcount:0 mapping:dead000000000400 index:0x1 compound_mapcount: 0
[   70.451427] printk: systemd: 27 output lines suppressed due to ratelimiting
[   70.460924] flags: 0xffff00000000000()
[   70.460931] raw: 0ffff00000000000 ffff7e0001d68001 ffffffff01d60301 dead000000000400
[   70.467945] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[   70.471659] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[   70.479389] CPU: 1 PID: 1 Comm: systemd Tainted: G    B             5.3.0-rc1+ #159
[   70.479394] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.487058] page dumped because: non-NULL mapping
[   70.494782] Call trace:
[   70.494789]  dump_backtrace+0x0/0x148
[   70.494793]  show_stack+0x14/0x20
[   70.494799]  dump_stack+0x9c/0xc4
[   70.502460] Modules linked in:
[   70.508713]  panic+0x140/0x32c
[   70.508718]  complete_and_exit+0x0/0x20
[   70.508724]  do_group_exit+0x34/0x98
[   70.539649]  get_signal+0x104/0x678
[   70.543139]  do_notify_resume+0x2ac/0x380
[   70.547149]  work_pending+0x8/0x10
[   70.550553] CPU: 2 PID: 482 Comm: v4l2-ctl Tainted: G    B             5.3.0-rc1+ #159
[   70.550554] SMP: stopping secondary CPUs
[   70.562387] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.568653] Call trace:
[   70.571103]  dump_backtrace+0x0/0x148
[   70.574765]  show_stack+0x14/0x20
[   70.578081]  dump_stack+0x9c/0xc4
[   70.581398]  bad_page+0xe4/0x148
[   70.584627]  free_pages_check_bad+0x70/0xa8
[   70.588814]  __free_pages_ok+0x294/0x2b0
[   70.592737]  __free_pages+0x38/0x50
[   70.596229]  dma_free_contiguous+0x90/0x98
[   70.600327]  __dma_direct_free_pages+0x18/0x20
[   70.604771]  arch_dma_free+0x74/0x88
[   70.608347]  dma_direct_free+0x4c/0x58
[   70.612098]  dma_free_attrs+0x88/0xe0
[   70.615765]  vb2_dc_put+0x44/0x60
[   70.619082]  __vb2_buf_mem_free+0x68/0x110
[   70.623180]  __vb2_queue_free+0x398/0x538
[   70.627192]  vb2_core_queue_release+0x34/0x48
[   70.631551]  _vb2_fop_release+0x88/0x98
[   70.635387]  vb2_fop_release+0x28/0x50
[   70.639138]  vivid_fop_release+0x88/0x208
[   70.643149]  v4l2_release+0x6c/0xf0
[   70.646638]  __fput+0x8c/0x1f8
[   70.649693]  ____fput+0xc/0x18
[   70.652750]  task_work_run+0x94/0xb0
[   70.656326]  do_exit+0x2b0/0x9f8
[   70.659554]  do_group_exit+0x34/0x98
[   70.663130]  get_signal+0x104/0x678
[   70.666621]  do_notify_resume+0x2ac/0x380
[   70.670632]  work_pending+0x8/0x10
[   70.674036] Kernel Offset: disabled
[   70.677526] CPU features: 0x0002,2000200c
[   70.681535] Memory Limit: none
[   70.684599] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ]---

Dafna

Quoted 2 lines

Thanks,
Mauro

Dafna Hirschfeld

author

2019-07-25 09:27 UTC #4 lore raw

Quoted 102 lines · Hans Verkuil (hansverk)

Quoted 51 lines · Dafna Hirschfeld
Quoted 12 lines · Mauro Carvalho Chehab
Em Mon, 22 Jul 2019 13:21:00 +0200
Dafna Hirschfeld <[email protected]> escreveu:
Quoted 8 lines
I loaded the vivid module with contiguous DMA and ran streaming with
it with large image dimensions
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0
Quoted 7 lines
Hmm... we had a recent regression affecting other media devices, reported via Kaffeine mailing list:
	https://bugs.kde.org/show_bug.cgi?id=408004#c35
While this one was for S/G, maybe it is somewhat related.
Also, I compiled vivid as built-in into the kernel (not as a separate module) for nitrogen8m device (imx8) and set it to use contig dma for mem_ops. Then I get a crash when running the above command.
I use the master branch of
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
with this patch to vivid:
drivers/media/platform/vivid/vivid-core.c +0 -0
index bc2a176937a4..0531f36d7d0a 100644
@@ -140,7 +140,7 @@ static bool no_error_inj;
  module_param(no_error_inj, bool, 0444);
MODULE_PARM_DESC(no_error_inj, " if set disable the error injecting controls");

-static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 0 };
+static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 1 }; module_param_array(allocators, uint, NULL, 0444); MODULE_PARM_DESC(allocators, " memory allocator selection, default is 0.\n"
"\t\t 0 == vmalloc\n"
And then on the nitrogen8m device I get the following crash report which seems to be related to the cma allocation
Quoted 11 lines
ubuntu@bionic-dev64:~$ v4l2-ctl -d3 -v
width=2592,height=1944,pixelformat=UYVY,bytesperline=5184 --stream-
mmap --stream-to video.UYVY
[   70.139006] cma: cma_alloc(cma (____ptrval____), count 4050,
align 8)
[   70.159829] cma: cma_alloc(cma (____ptrval____), count 4050,
align 8)
[   70.166292] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.173006] cma: number of available pages: 72@184+3886@4306=>
3958 free of 8192 total pages
So it looks like the CMA area is too small. Look at the CONFIG_CMA_SIZE_MBYTES
setting.
That explains why it fails.
Quoted 13 lines
[   70.181471] cma: cma_alloc(): returned (____ptrval____) [   70.192449] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.198907] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.205625] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.205733] systemd-journald[204]:
/var/log/journal/5cca8918401249538eacb5efd5b9b052/system.journal:
Journal file corrupted, rotating.
[   70.214083] cma: cma_alloc(): returned (____ptrval____) [   70.219867] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
Quoted 8 lines
[   70.237878] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.244599] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.253066] cma: cma_alloc(): returned (____ptrval____) [   70.264893] cma: cma_release(page (____ptrval____)) [   70.272871] cma: cma_release(page (____ptrval____)) [   70.277800] BUG: Bad page state in process v4l2-ctl  pfn:b5a00
But that shouldn't lead to this.
It could be a bug somewhere.
Does it work fine if you use a smaller resolution? Perhaps there is something
wrong in error handling in vb2. These corner cases are not exactly tested
very often (or at all!).

Quoted 3 lines

Regards,
Hans

Hi, I suspect that the error is in the cma code, the crash occurs first after the commit ""dma-contiguous: add dma_{alloc,free}_contiguous() helpers"

Dafna

Quoted 116 lines

Quoted 116 lines
[   70.283652] page:ffff7e0001d68000 refcount:13 mapcount:0 mapping:0000000000000000 index:0x0 compound_mapcount: 0 [   70.293874] flags: 0xffff00000010000(head)
[   70.297999] raw: 0ffff00000010000 dead000000000100 dead000000000122 0000000000000000
[   70.305772] raw: 0000000000000000 0000000000000000 0000000dffffffff 0000000000000000
[   70.313526] page dumped because: nonzero _refcount
[   70.318327] Modules linked in:
[   70.321399] CPU: 2 PID: 482 Comm: v4l2-ctl Not tainted 5.3.0- rc1+ #159
[   70.327927] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.334196] Call trace:
[   70.336654]  dump_backtrace+0x0/0x148
[   70.340319]  show_stack+0x14/0x20
[   70.343640]  dump_stack+0x9c/0xc4
[   70.346959]  bad_page+0xe4/0x148
[   70.350188]  free_pages_check_bad+0x70/0xa8
[   70.354375]  __free_pages_ok+0x294/0x2b0
[   70.358301]  __free_pages+0x38/0x50
[   70.361795]  dma_free_contiguous+0x90/0x98
[   70.365892]  __dma_direct_free_pages+0x18/0x20
[   70.370338]  arch_dma_free+0x74/0x88
[   70.373916]  dma_direct_free+0x4c/0x58
[   70.377668]  dma_free_attrs+0x88/0xe0
[   70.381335]  vb2_dc_put+0x44/0x60
[   70.384653]  __vb2_buf_mem_free+0x68/0x110
[   70.388749]  __vb2_queue_free+0x398/0x538
[   70.392763]  vb2_core_queue_release+0x34/0x48
[   70.397122]  _vb2_fop_release+0x88/0x98
[   70.400960]  vb2_fop_release+0x28/0x50
[   70.404712]  vivid_fop_release+0x88/0x208
[   70.408725]  v4l2_release+0x6c/0xf0
[   70.412216]  __fput+0x8c/0x1f8
[   70.415270]  ____fput+0xc/0x18
[   70.418328]  task_work_run+0x94/0xb0
[   70.421907]  do_exit+0x2b0/0x9f8
[   70.425138]  do_group_exit+0x34/0x98
[   70.428717]  get_signal+0x104/0x678
[   70.432209]  do_notify_resume+0x2ac/0x380
[   70.436220]  work_pending+0x8/0x10
[   70.439648] Disabling lock debugging due to kernel taint [   70.444974] BUG: Bad page state in process v4l2-ctl  pfn:b5a01 [   70.450822] page:ffff7e0001d68040 refcount:0 mapcount:0 mapping:dead000000000400 index:0x1 compound_mapcount: 0 [   70.451427] printk: systemd: 27 output lines suppressed due to ratelimiting
[   70.460924] flags: 0xffff00000000000()
[   70.460931] raw: 0ffff00000000000 ffff7e0001d68001 ffffffff01d60301 dead000000000400
[   70.467945] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[   70.471659] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[   70.479389] CPU: 1 PID: 1 Comm: systemd Tainted:
G    B             5.3.0-rc1+ #159
[   70.479394] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.487058] page dumped because: non-NULL mapping
[   70.494782] Call trace:
[   70.494789]  dump_backtrace+0x0/0x148
[   70.494793]  show_stack+0x14/0x20
[   70.494799]  dump_stack+0x9c/0xc4
[   70.502460] Modules linked in:
[   70.508713]  panic+0x140/0x32c
[   70.508718]  complete_and_exit+0x0/0x20
[   70.508724]  do_group_exit+0x34/0x98
[   70.539649]  get_signal+0x104/0x678
[   70.543139]  do_notify_resume+0x2ac/0x380
[   70.547149]  work_pending+0x8/0x10
[   70.550553] CPU: 2 PID: 482 Comm: v4l2-ctl Tainted:
G    B             5.3.0-rc1+ #159
[   70.550554] SMP: stopping secondary CPUs
[   70.562387] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.568653] Call trace:
[   70.571103]  dump_backtrace+0x0/0x148
[   70.574765]  show_stack+0x14/0x20
[   70.578081]  dump_stack+0x9c/0xc4
[   70.581398]  bad_page+0xe4/0x148
[   70.584627]  free_pages_check_bad+0x70/0xa8
[   70.588814]  __free_pages_ok+0x294/0x2b0
[   70.592737]  __free_pages+0x38/0x50
[   70.596229]  dma_free_contiguous+0x90/0x98
[   70.600327]  __dma_direct_free_pages+0x18/0x20
[   70.604771]  arch_dma_free+0x74/0x88
[   70.608347]  dma_direct_free+0x4c/0x58
[   70.612098]  dma_free_attrs+0x88/0xe0
[   70.615765]  vb2_dc_put+0x44/0x60
[   70.619082]  __vb2_buf_mem_free+0x68/0x110
[   70.623180]  __vb2_queue_free+0x398/0x538
[   70.627192]  vb2_core_queue_release+0x34/0x48
[   70.631551]  _vb2_fop_release+0x88/0x98
[   70.635387]  vb2_fop_release+0x28/0x50
[   70.639138]  vivid_fop_release+0x88/0x208
[   70.643149]  v4l2_release+0x6c/0xf0
[   70.646638]  __fput+0x8c/0x1f8
[   70.649693]  ____fput+0xc/0x18
[   70.652750]  task_work_run+0x94/0xb0
[   70.656326]  do_exit+0x2b0/0x9f8
[   70.659554]  do_group_exit+0x34/0x98
[   70.663130]  get_signal+0x104/0x678
[   70.666621]  do_notify_resume+0x2ac/0x380
[   70.670632]  work_pending+0x8/0x10
[   70.674036] Kernel Offset: disabled
[   70.677526] CPU features: 0x0002,2000200c
[   70.681535] Memory Limit: none
[   70.684599] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ]---
Dafna
Quoted 2 lines
Thanks,
Mauro

Nicolin Chen

2019-07-25 17:29 UTC #5 lore raw

Allow me to trim the message a bit.

Quoted 4 lines · Dafna Hirschfeld

Quoted 4 lines
Quoted 4 lines
[ 70.219867] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[ 70.237878] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12

It shows that cma_alloc() failed so the dma_alloc_contigudous() does fallback alloc_pages_node(). It should be same as previous __dma_direct_alloc_pages(), but would you like to confirm after partially reverting the change at kernel/dma/direct.c file? It is not necessary for debugging to entirely revert the commit as build break might happen since the helper functions are called by other files too. Something like this:

kernel/dma/direct.c +20 -4

index b67f0aa08aa3..6688e1cee7d1 100644
@@ -96,6 +96,8 @@ static bool dma_coherent_ok(struct device *dev, phys_addr_t phys, size_t size)
 struct page *__dma_direct_alloc_pages(struct device *dev, size_t size,
 		dma_addr_t *dma_handle, gfp_t gfp, unsigned long attrs)
 {
+	unsigned int count = PAGE_ALIGN(size) >> PAGE_SHIFT;
+	int page_order = get_order(size);
 	struct page *page = NULL;
 	u64 phys_mask;

@@ -107,9 +109,20 @@ struct page *__dma_direct_alloc_pages(struct device *dev, size_t size,
 	gfp |= __dma_direct_optimal_gfp_mask(dev, dev->coherent_dma_mask,
 			&phys_mask);
 again:
-	page = dma_alloc_contiguous(dev, size, gfp);
+	/* CMA can be used only in the context which permits sleeping */
+	if (gfpflags_allow_blocking(gfp)) {
+		page = dma_alloc_from_contiguous(dev, count, page_order,
+						 gfp & __GFP_NOWARN);
+		if (page && !dma_coherent_ok(dev, page_to_phys(page), size)) {
+			dma_release_from_contiguous(dev, page, count);
+			page = NULL;
+		}
+	}
+	if (!page)
+		page = alloc_pages_node(dev_to_node(dev), gfp, page_order);
+
 	if (page && !dma_coherent_ok(dev, page_to_phys(page), size)) {
-		dma_free_contiguous(dev, page, size);
+		__free_pages(page, page_order);
 		page = NULL;
 
 		if (IS_ENABLED(CONFIG_ZONE_DMA32) &&

@@ -141,7 +154,7 @@ void *dma_direct_alloc_pages(struct device *dev, size_t size,
 	if (PageHighMem(page)) {
 		/*
 		 * Depending on the cma= arguments and per-arch setup
-		 * dma_alloc_contiguous could return highmem pages.
+		 * dma_alloc_from_contiguous could return highmem pages.
 		 * Without remapping there is no way to return them here,
 		 * so log an error and fail.
 		 */

@@ -170,7 +183,10 @@ void *dma_direct_alloc_pages(struct device *dev, size_t size,
 
 void __dma_direct_free_pages(struct device *dev, size_t size, struct page *page)
 {
-	dma_free_contiguous(dev, page, size);
+	unsigned int count = PAGE_ALIGN(size) >> PAGE_SHIFT;
+
+	if (!dma_release_from_contiguous(dev, page, count))
+		__free_pages(page, get_order(size));
 }
 
 void dma_direct_free_pages(struct device *dev, size_t size, void *cpu_addr,

Quoted 21 lines

Quoted 21 lines
Quoted 21 lines
[   70.244599] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.253066] cma: cma_alloc(): returned (____ptrval____) [   70.264893] cma: cma_release(page (____ptrval____)) [   70.272871] cma: cma_release(page (____ptrval____)) [   70.277800] BUG: Bad page state in process v4l2-ctl  pfn:b5a00 [   70.283652] page:ffff7e0001d68000 refcount:13 mapcount:0 mapping:0000000000000000 index:0x0 compound_mapcount: 0 [   70.293874] flags: 0xffff00000010000(head)
[   70.297999] raw: 0ffff00000010000 dead000000000100 dead000000000122 0000000000000000
[   70.305772] raw: 0000000000000000 0000000000000000 0000000dffffffff 0000000000000000
[   70.313526] page dumped because: nonzero _refcount
[   70.318327] Modules linked in:
[   70.321399] CPU: 2 PID: 482 Comm: v4l2-ctl Not tainted 5.3.0- rc1+ #159
[   70.327927] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.334196] Call trace:
[   70.336654]  dump_backtrace+0x0/0x148

Quoted 8 lines

Quoted 8 lines
Quoted 8 lines
[   70.340319]  show_stack+0x14/0x20
[   70.343640]  dump_stack+0x9c/0xc4
[   70.346959]  bad_page+0xe4/0x148
[   70.350188]  free_pages_check_bad+0x70/0xa8
[   70.354375]  __free_pages_ok+0x294/0x2b0
[   70.358301]  __free_pages+0x38/0x50
[   70.361795]  dma_free_contiguous+0x90/0x98
[   70.365892]  __dma_direct_free_pages+0x18/0x20

Here shows cma_release() has failed as those pages aren't from CMA, so it uses the fallback __free_pages(). I just scrutinized my commit once again and found that the free routine has missed a PAGE_ALIGN() operation for the size parameter. Though it does not likely cause the problem, yet would you please try this?

kernel/dma/contiguous.c +2 -1

index bfc0c17f2a3d..a2d872a82be9 100644
@@ -266,7 +266,8 @@ struct page *dma_alloc_contiguous(struct device *dev, size_t size, gfp_t gfp)
  */
 void dma_free_contiguous(struct device *dev, struct page *page, size_t size)
 {
-       if (!cma_release(dev_get_cma_area(dev), page, size >> PAGE_SHIFT))
+       if (!cma_release(dev_get_cma_area(dev), page,
+                        PAGE_ALIGN(size) >> PAGE_SHIFT))
                __free_pages(page, get_order(size));
 }

Nicolin Chen

2019-07-25 23:43 UTC #6 lore raw

In reply to Dafna Hirschfeld

Just an update here:

After looking at the code and the logs here, submitted a fix:
https://lkml.org/lkml/2019/7/25/1432

I only added Dafna in the To-list but anyone is interested can find it in the maillist.

Thanks
Nicolin

Quoted 228 lines · Dafna Hirschfeld

Quoted 102 lines · Hans Verkuil (hansverk)
Quoted 51 lines · Dafna Hirschfeld
Quoted 12 lines · Mauro Carvalho Chehab
Em Mon, 22 Jul 2019 13:21:00 +0200
Dafna Hirschfeld <[email protected]> escreveu:
Quoted 8 lines
I loaded the vivid module with contiguous DMA and ran streaming with
it with large image dimensions
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0
Quoted 7 lines
Hmm... we had a recent regression affecting other media devices, reported via Kaffeine mailing list:
	https://bugs.kde.org/show_bug.cgi?id=408004#c35
While this one was for S/G, maybe it is somewhat related.
Also, I compiled vivid as built-in into the kernel (not as a separate module) for nitrogen8m device (imx8) and set it to use contig dma for mem_ops. Then I get a crash when running the above command.
I use the master branch of
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
with this patch to vivid:
drivers/media/platform/vivid/vivid-core.c +0 -0
index bc2a176937a4..0531f36d7d0a 100644
@@ -140,7 +140,7 @@ static bool no_error_inj;
  module_param(no_error_inj, bool, 0444);
MODULE_PARM_DESC(no_error_inj, " if set disable the error injecting controls");

-static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 0 };
+static unsigned int allocators[VIVID_MAX_DEVS] = { [0 ... (VIVID_MAX_DEVS - 1)] = 1 }; module_param_array(allocators, uint, NULL, 0444); MODULE_PARM_DESC(allocators, " memory allocator selection, default is 0.\n"
"\t\t 0 == vmalloc\n"
And then on the nitrogen8m device I get the following crash report which seems to be related to the cma allocation
Quoted 11 lines
ubuntu@bionic-dev64:~$ v4l2-ctl -d3 -v
width=2592,height=1944,pixelformat=UYVY,bytesperline=5184 --stream-
mmap --stream-to video.UYVY
[   70.139006] cma: cma_alloc(cma (____ptrval____), count 4050,
align 8)
[   70.159829] cma: cma_alloc(cma (____ptrval____), count 4050,
align 8)
[   70.166292] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.173006] cma: number of available pages: 72@184+3886@4306=>
3958 free of 8192 total pages
So it looks like the CMA area is too small. Look at the CONFIG_CMA_SIZE_MBYTES
setting.
That explains why it fails.
Quoted 13 lines
[   70.181471] cma: cma_alloc(): returned (____ptrval____) [   70.192449] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
[   70.198907] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.205625] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.205733] systemd-journald[204]:
/var/log/journal/5cca8918401249538eacb5efd5b9b052/system.journal:
Journal file corrupted, rotating.
[   70.214083] cma: cma_alloc(): returned (____ptrval____) [   70.219867] cma: cma_alloc(cma (____ptrval____), count 4050, align 8)
Quoted 8 lines
[   70.237878] cma: cma_alloc: alloc failed, req-size: 4050 pages,
ret: -12
[   70.244599] cma: number of available pages: 72@184+3886@4306=> 3958 free of 8192 total pages
[   70.253066] cma: cma_alloc(): returned (____ptrval____) [   70.264893] cma: cma_release(page (____ptrval____)) [   70.272871] cma: cma_release(page (____ptrval____)) [   70.277800] BUG: Bad page state in process v4l2-ctl  pfn:b5a00
But that shouldn't lead to this.
It could be a bug somewhere.
Does it work fine if you use a smaller resolution? Perhaps there is something
wrong in error handling in vb2. These corner cases are not exactly tested
very often (or at all!).
Quoted 3 lines
Regards,
Hans
Hi, I suspect that the error is in the cma code, the crash occurs first after the commit ""dma-contiguous: add dma_{alloc,free}_contiguous() helpers"
Dafna
Quoted 116 lines
Quoted 116 lines
[   70.283652] page:ffff7e0001d68000 refcount:13 mapcount:0 mapping:0000000000000000 index:0x0 compound_mapcount: 0 [   70.293874] flags: 0xffff00000010000(head)
[   70.297999] raw: 0ffff00000010000 dead000000000100 dead000000000122 0000000000000000
[   70.305772] raw: 0000000000000000 0000000000000000 0000000dffffffff 0000000000000000
[   70.313526] page dumped because: nonzero _refcount
[   70.318327] Modules linked in:
[   70.321399] CPU: 2 PID: 482 Comm: v4l2-ctl Not tainted 5.3.0- rc1+ #159
[   70.327927] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.334196] Call trace:
[   70.336654]  dump_backtrace+0x0/0x148
[   70.340319]  show_stack+0x14/0x20
[   70.343640]  dump_stack+0x9c/0xc4
[   70.346959]  bad_page+0xe4/0x148
[   70.350188]  free_pages_check_bad+0x70/0xa8
[   70.354375]  __free_pages_ok+0x294/0x2b0
[   70.358301]  __free_pages+0x38/0x50
[   70.361795]  dma_free_contiguous+0x90/0x98
[   70.365892]  __dma_direct_free_pages+0x18/0x20
[   70.370338]  arch_dma_free+0x74/0x88
[   70.373916]  dma_direct_free+0x4c/0x58
[   70.377668]  dma_free_attrs+0x88/0xe0
[   70.381335]  vb2_dc_put+0x44/0x60
[   70.384653]  __vb2_buf_mem_free+0x68/0x110
[   70.388749]  __vb2_queue_free+0x398/0x538
[   70.392763]  vb2_core_queue_release+0x34/0x48
[   70.397122]  _vb2_fop_release+0x88/0x98
[   70.400960]  vb2_fop_release+0x28/0x50
[   70.404712]  vivid_fop_release+0x88/0x208
[   70.408725]  v4l2_release+0x6c/0xf0
[   70.412216]  __fput+0x8c/0x1f8
[   70.415270]  ____fput+0xc/0x18
[   70.418328]  task_work_run+0x94/0xb0
[   70.421907]  do_exit+0x2b0/0x9f8
[   70.425138]  do_group_exit+0x34/0x98
[   70.428717]  get_signal+0x104/0x678
[   70.432209]  do_notify_resume+0x2ac/0x380
[   70.436220]  work_pending+0x8/0x10
[   70.439648] Disabling lock debugging due to kernel taint [   70.444974] BUG: Bad page state in process v4l2-ctl  pfn:b5a01 [   70.450822] page:ffff7e0001d68040 refcount:0 mapcount:0 mapping:dead000000000400 index:0x1 compound_mapcount: 0 [   70.451427] printk: systemd: 27 output lines suppressed due to ratelimiting
[   70.460924] flags: 0xffff00000000000()
[   70.460931] raw: 0ffff00000000000 ffff7e0001d68001 ffffffff01d60301 dead000000000400
[   70.467945] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[   70.471659] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[   70.479389] CPU: 1 PID: 1 Comm: systemd Tainted:
G    B             5.3.0-rc1+ #159
[   70.479394] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.487058] page dumped because: non-NULL mapping
[   70.494782] Call trace:
[   70.494789]  dump_backtrace+0x0/0x148
[   70.494793]  show_stack+0x14/0x20
[   70.494799]  dump_stack+0x9c/0xc4
[   70.502460] Modules linked in:
[   70.508713]  panic+0x140/0x32c
[   70.508718]  complete_and_exit+0x0/0x20
[   70.508724]  do_group_exit+0x34/0x98
[   70.539649]  get_signal+0x104/0x678
[   70.543139]  do_notify_resume+0x2ac/0x380
[   70.547149]  work_pending+0x8/0x10
[   70.550553] CPU: 2 PID: 482 Comm: v4l2-ctl Tainted:
G    B             5.3.0-rc1+ #159
[   70.550554] SMP: stopping secondary CPUs
[   70.562387] Hardware name: Boundary Devices i.MX8MQ Nitrogen8M (DT)
[   70.568653] Call trace:
[   70.571103]  dump_backtrace+0x0/0x148
[   70.574765]  show_stack+0x14/0x20
[   70.578081]  dump_stack+0x9c/0xc4
[   70.581398]  bad_page+0xe4/0x148
[   70.584627]  free_pages_check_bad+0x70/0xa8
[   70.588814]  __free_pages_ok+0x294/0x2b0
[   70.592737]  __free_pages+0x38/0x50
[   70.596229]  dma_free_contiguous+0x90/0x98
[   70.600327]  __dma_direct_free_pages+0x18/0x20
[   70.604771]  arch_dma_free+0x74/0x88
[   70.608347]  dma_direct_free+0x4c/0x58
[   70.612098]  dma_free_attrs+0x88/0xe0
[   70.615765]  vb2_dc_put+0x44/0x60
[   70.619082]  __vb2_buf_mem_free+0x68/0x110
[   70.623180]  __vb2_queue_free+0x398/0x538
[   70.627192]  vb2_core_queue_release+0x34/0x48
[   70.631551]  _vb2_fop_release+0x88/0x98
[   70.635387]  vb2_fop_release+0x28/0x50
[   70.639138]  vivid_fop_release+0x88/0x208
[   70.643149]  v4l2_release+0x6c/0xf0
[   70.646638]  __fput+0x8c/0x1f8
[   70.649693]  ____fput+0xc/0x18
[   70.652750]  task_work_run+0x94/0xb0
[   70.656326]  do_exit+0x2b0/0x9f8
[   70.659554]  do_group_exit+0x34/0x98
[   70.663130]  get_signal+0x104/0x678
[   70.666621]  do_notify_resume+0x2ac/0x380
[   70.670632]  work_pending+0x8/0x10
[   70.674036] Kernel Offset: disabled
[   70.677526] CPU features: 0x0002,2000200c
[   70.681535] Memory Limit: none
[   70.684599] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ]---
Dafna
Quoted 2 lines
Thanks,
Mauro

Hans Verkuil

2019-07-22 11:42 UTC #7 lore raw

In reply to Dafna Hirschfeld

Quoted 14 lines · Dafna Hirschfeld

I loaded the vivid module with contiguous DMA and ran streaming with it with large image dimensions
here are the commans:

$ uname -a
Linux ubuntu 5.2.0-rc5+ #1 SMP Mon Jul 1 10:17:46 PDT 2019 x86_64
x86_64 x86_64 GNU/Linux
$ sudo modprobe -v vivid
allocators=1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,
1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1
$ v4l2-ctl -d0 --verbose -v
width=2592,height=1944,pixelformat=UYVY,bytesperline=5184
--stream-mmap --stream-to video.UYVY --list-buffers

Quoted 4 lines

Here is the warning that I got:
[ 306.437224] WARNING: CPU: 1 PID: 2240 at mm/page_alloc.c:4639 __alloc_pages_nodemask+0x1f3/0x3b0

It's a limitation of the kernel: MAX_ORDER is defined as 11 in include/linux/mmzone.h, and there doesn't seem to be a CONFIG_FORCE_MAX_ZONEORDER on x86 that allows you to increase this value.

This limitation means that the kernel can't allocate contiguous memory larger than 4MB (2^(MAX_ORDER-1) * PAGE_SIZE).

I'm not sure if it is worth doing anything about it. In theory you can exclude enumerating formats with sizeimage > MAX_ORDER_NR_PAGES * PAGE_SIZE.

In any case, patches are welcome :-)

Regards,

Hans

Quoted 92 lines

[  306.437235] Modules linked in: rc_cec vivid v4l2_tpg videobuf2_dma_contig v4l2_dv_timings v4l2_common videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev mc cec rc_core crct10dif_pclmul crc32_pclmul ghash_clmulni_intel vmw_balloon aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_rapl_perf snd_ens1371 snd_ac97_codec gameport ac97_bus snd_pcm joydev input_leds serio_raw snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore vmw_vsock_vmci_transport vsock vmw_vmci mac_hid sch_fq_codel vmwgfx ttm drm_kms_helper drm fb_sys_fops syscopyarea sysfillrect sysimgblt parport_pc ppdev lp parport ip_tables x_tables autofs4 psmouse ahci libahci e1000 mptspi mptscsih mptbase scsi_transport_spi i2c_piix4 pata_acpi
[  306.437273] CPU: 1 PID: 2240 Comm: v4l2-ctl Not tainted 5.2.0-rc5+ #1
[  306.437275] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018 [  306.437277] RIP: 0010:__alloc_pages_nodemask+0x1f3/0x3b0 [  306.437280] Code: fc fe ff ff 65 48 8b 04 25 c0 6d 01 00 48 05 a0 17 00 00 41 bf 01 00 00 00 48 89 45 b0 e9 de fe ff ff 81 e7 00 20 00 00 75 02 <0f> 0b 45 31 ff eb 95 44 8b 6d c0 65 8b 05 fb fd 76 46 89 c0 48 0f
[  306.437282] RSP: 0018:ffffa42584bd39c8 EFLAGS: 00010246 [  306.437284] RAX: 0000000000000000 RBX: 00000000ffffffff RCX:
0000000000000000
[  306.437285] RDX: 0000000000000000 RSI: 000000000000000c RDI:
0000000000000000
[  306.437287] RBP: ffffa42584bd3a20 R08: 0000000000000000 R09:
ffff9054df8072c0
[  306.437289] R10: ffff9054cf074600 R11: 0000000000000000 R12:
0000000000000cc4
[  306.437290] R13: ffffffffc08840d0 R14: 000000000000000c R15:
00000000ffffffff
[  306.437292] FS:  00007f842025f740(0000) GS:ffff9054dfe00000(0000) knlGS:0000000000000000
[  306.437294] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [  306.437296] CR2: 00007ffd81229000 CR3: 000000040ca28005 CR4:
00000000003606e0
[  306.437327] Call Trace:
[  306.437338]  __dma_direct_alloc_pages+0xc9/0x1c0
[  306.437343]  dma_direct_alloc_pages+0x24/0xf0
[  306.437348]  dma_direct_alloc+0xe/0x10
[  306.437351]  dma_alloc_attrs+0x84/0xd0
[  306.437358]  vb2_dc_alloc+0x79/0x110 [videobuf2_dma_contig] [  306.437365]  __vb2_queue_alloc+0x331/0x490 [videobuf2_common] [  306.437373]  vb2_core_reqbufs+0x2db/0x470 [videobuf2_common] [  306.437376]  ? __mutex_lock+0x2f5/0x930
[  306.437385]  vb2_ioctl_reqbufs+0x7e/0xb0 [videobuf2_v4l2] [  306.437393]  v4l_reqbufs+0x47/0x50 [videodev]
[  306.437400]  __video_do_ioctl+0x194/0x4d0 [videodev]
[  306.437408]  ? tomoyo_init_request_info+0x80/0x90
[  306.437416]  video_usercopy+0x1af/0x760 [videodev]
[  306.437422]  ? v4l_s_fmt+0x6a0/0x6a0 [videodev]
[  306.437437]  video_ioctl2+0x15/0x20 [videodev]
[  306.437442]  v4l2_ioctl+0x49/0x50 [videodev]
[  306.437445]  do_vfs_ioctl+0xa9/0x6d0
[  306.437448]  ? rcu_read_lock_sched_held+0x64/0x70
[  306.437453]  ? tomoyo_file_ioctl+0x19/0x20
[  306.437458]  ksys_ioctl+0x75/0x80
[  306.437462]  ? do_syscall_64+0x17/0x1e0
[  306.437466]  __x64_sys_ioctl+0x1a/0x20
[  306.437469]  do_syscall_64+0x65/0x1e0
[  306.437473]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  306.437475] RIP: 0033:0x7f841f1aa5d7
[  306.437478] Code: b3 66 90 48 8b 05 b1 48 2d 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 81 48 2d 00 f7 d8 64 89 01 48
[  306.437479] RSP: 002b:00007ffd812277c8 EFLAGS: 00000202 ORIG_RAX:
0000000000000010
[  306.437482] RAX: ffffffffffffffda RBX: 00007ffd812288e0 RCX:
00007f841f1aa5d7
[  306.437483] RDX: 00007ffd81227830 RSI: 00000000c0145608 RDI:
0000000000000003
[  306.437485] RBP: 00007ffd8122bd00 R08: 0000000000000000 R09:
0000562416280a46
[  306.437486] R10: 00000000000001b6 R11: 0000000000000202 R12:
00007ffd812288e0
[  306.437488] R13: 0000000000000002 R14: 0000000000000002 R15:
0000000000000000
[  306.437498] irq event stamp: 15058
[  306.437501] hardirqs last  enabled at (15057): [<ffffffffb96045a7>] do_syscall_64+0x17/0x1e0
[  306.437504] hardirqs last disabled at (15058): [<ffffffffb960384c>] trace_hardirqs_off_thunk+0x1a/0x1c
[  306.437506] softirqs last  enabled at (13490): [<ffffffffba40035a>] __do_softirq+0x35a/0x409
[  306.437509] softirqs last disabled at (13477): [<ffffffffb969eed6>] irq_exit+0xc6/0xd0
[  306.437511] ---[ end trace 89b603670b5a81e6 ]---
[  306.437516] vivid vivid.0: dma_alloc_coherent of size 16588800 failed