Re: crash by cdc_acm driver in kernels 4.8-rc1/5

From: Wim Osterholt
Date: Tue Oct 18 2016 - 10:51:45 EST

On Tue, Oct 18, 2016 at 02:18:43PM +0200, Oliver Neukum wrote:
> Oct 18 14:05:07 linux-dtbq.site kernel: usb 1-9: Manufacturer: Conexant
> Oct 18 14:05:07 linux-dtbq.site kernel: usb 1-9: SerialNumber: 12345678

With that unique serial number it must be that very device. :-)

> It definitely does not crash and is probed and your .config is not
> extremely unusual.
> I am afraid unless you test the last patch I sent we will not make
> progress. Something odd is going on.

Whell, I DID test that patch and it already crashed before it could print
anything. That's why the output I sent you looked the same.

Once again, this time on 4.9-rc1.
Applied your patch 0001-CDC-ACM-more-paranoid-debugging to cdc_acm.c .

Did
> > dmesg -c
> > echo 9 > /proc/sysrq-trigger
> > modprobe cdc_acm
> > echo "module cdc_acm +mpf" > /sys/kernel/debug/dynamic_debug/control
> >
> > [plug your device in]
> >
> > and provide the full output of dmesg after that.

Got
[ 765.409057] sysrq: SysRq : Changing Loglevel
[ 765.416465] sysrq: Loglevel set to 9
[ 778.299271] usbcore: registered new interface driver cdc_acm
[ 778.301921] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 833.204100] usb 6-1: new full-speed USB device number 2 using uhci_hcd
[ 833.411088] usb 6-1: New USB device found, idVendor=0572, idProduct=1340
[ 833.412127] usb 6-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 833.416129] usb 6-1: Product: USB Modem
[ 833.420123] usb 6-1: Manufacturer: Conexant
[ 833.420126] usb 6-1: SerialNumber: 12345678
[ 833.473854] cdc_acm:acm_probe: cdc_acm 6-1:1.0: interfaces are valid
[ 833.473876] BUG: unable to handle kernel NULL pointer dereference at 00000249
[ 833.473882] IP: [<e08fca6e>] acm_probe+0x540/0xd00 [cdc_acm]
[ 833.473885] *pde = 00000000
[ 833.473887] Oops: 0000 [#1] SMP
[ 833.473925] Modules linked in: cdc_acm nouveau video drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm agpgart i2c_algo_bit cfg80211 rfkill binfmt_misc svgalib_helper(O) snd_pcm_oss snd_mixer_oss fbcon bitblit softcursor font tileblit sr9700 dm9601 snd_hda_codec_generic usbnet usb_storage snd_hda_intel mii snd_hda_codec tg3 snd_hwdep snd_hda_core ptp pps_core snd_pcm libphy gpio_ich snd_timer firmware_class lpc_ich pcspkr ppdev snd ohci_pci mfd_core ohci_hcd floppy wmi uhci_hcd soundcore parport_pc acpi_cpufreq ehci_pci parport ehci_hcd processor button
[ 833.473928] CPU: 0 PID: 4 Comm: kworker/0:0 Tainted: G O 4.9.0-rc1 #1
[ 833.473930] Hardware name: Hewlett-Packard HP xw4300 Workstation/0A00h, BIOS 786D3 v01.08 03/10/2006
[ 833.473935] Workqueue: usb_hub_wq hub_event
[ 833.473937] task: df4e15c0 task.stack: df4f4000
[ 833.473939] EIP: 0060:[<e08fca6e>] EFLAGS: 00010202 CPU: 0
[ 833.473942] EIP is at acm_probe+0x540/0xd00 [cdc_acm]
[ 833.473944] EAX: 00000246 EBX: dc4b2800 ECX: e08fe594 EDX: 00000000
[ 833.473945] ESI: 00000100 EDI: 00000000 EBP: df4f5c18 ESP: df4f5b80
[ 833.473947] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 833.473949] CR0: 80050033 CR2: 00000249 CR3: 1c8c4000 CR4: 00000690
[ 833.473950] Stack:
[ 833.473956] 00003a20 00003de7 0000000f df4a9d50 00000000 00000000 00000010 00000040
[ 833.473960] 00000080 00000246 dee5f000 d9614d80 d960e070 00000001 d2aee100 d960e000
[ 833.473965] d2aee138 dee5f400 dee5f000 00000000 c82931b0 00000004 00000246 df4f5c00
[ 833.473966] Call Trace:
[ 833.473975] [<c04d43f0>] ? __mutex_unlock_slowpath+0xf4/0xfc
[ 833.473978] [<c03d071c>] ? usb_probe_interface+0x17b/0x1f6
[ 833.473980] [<c03d071c>] ? usb_probe_interface+0x17b/0x1f6
[ 833.473984] [<c036396f>] ? driver_probe_device+0x17b/0x30e
[ 833.473986] [<c036396f>] ? driver_probe_device+0x17b/0x30e
[ 833.473989] [<c03620b4>] ? bus_for_each_drv+0x59/0x68
[ 833.473991] [<c03620b4>] ? bus_for_each_drv+0x59/0x68
[ 833.473993] [<c036371d>] ? __device_attach+0x91/0x105
[ 833.473996] [<c0363c03>] ? driver_allows_async_probing+0x2f/0x2f
[ 833.473998] [<c0362d3c>] ? bus_probe_device+0x27/0x6b
[ 833.474000] [<c0362d3c>] ? bus_probe_device+0x27/0x6b
[ 833.474002] [<c03614c4>] ? device_add+0x28d/0x4c0
[ 833.474006] [<c03cf081>] ? usb_set_configuration+0x594/0x5d7
[ 833.474008] [<c03cf081>] ? usb_set_configuration+0x594/0x5d7
[ 833.474012] [<c03d6878>] ? generic_probe+0x3b/0x67
[ 833.474014] [<c03d6878>] ? generic_probe+0x3b/0x67
[ 833.474016] [<c03d0588>] ? usb_probe_device+0x49/0x62
[ 833.474017] [<c03d053f>] ? usb_suspend+0xcd/0xcd
[ 833.474020] [<c036396f>] ? driver_probe_device+0x17b/0x30e
[ 833.474022] [<c036396f>] ? driver_probe_device+0x17b/0x30e
[ 833.474024] [<c03620b4>] ? bus_for_each_drv+0x59/0x68
[ 833.474026] [<c03620b4>] ? bus_for_each_drv+0x59/0x68
[ 833.474028] [<c036371d>] ? __device_attach+0x91/0x105
[ 833.474031] [<c0363c03>] ? driver_allows_async_probing+0x2f/0x2f
[ 833.474033] [<c0362d3c>] ? bus_probe_device+0x27/0x6b
[ 833.474035] [<c0362d3c>] ? bus_probe_device+0x27/0x6b
[ 833.474037] [<c03614c4>] ? device_add+0x28d/0x4c0
[ 833.474041] [<c035c1f7>] ? add_device_randomness+0x84/0x9c
[ 833.474043] [<c03c7508>] ? usb_new_device+0x29d/0x3b5
[ 833.474045] [<c03c7508>] ? usb_new_device+0x29d/0x3b5
[ 833.474048] [<c03c8c37>] ? hub_event+0xb32/0xed8
[ 833.474050] [<c03c8c37>] ? hub_event+0xb32/0xed8
[ 833.474052] [<c03c7ff4>] ? usb_remote_wakeup+0x6f/0x7d
[ 833.474056] [<c0148b8f>] ? process_one_work+0x174/0x2bc
[ 833.474058] [<c0148b8f>] ? process_one_work+0x174/0x2bc
[ 833.474061] [<c014916e>] ? worker_thread+0x22c/0x2f7
[ 833.474063] [<c0148f42>] ? rescuer_thread+0x242/0x242
[ 833.474065] [<c014c5ea>] ? kthread+0xa5/0xaa
[ 833.474067] [<c014c545>] ? kthread_park+0x4c/0x4c
[ 833.474070] [<c04d5f83>] ? ret_from_fork+0x1b/0x28
[ 833.474096] Code: 14 89 83 b4 04 00 00 8b 45 90 89 43 04 8b 45 ac 89 43 08 8b 85 7c ff ff ff 89 83 c0 04 00 00 8b 45 a4 89 03 8b 45 c0 85 c0 74 0a <0f> b6 40 03 89 83 c8 04 00 00 f6 45 9c 04 74 07 83 a3 c8 04 00
[ 833.474100] EIP: [<e08fca6e>]
[ 833.474101] acm_probe+0x540/0xd00 [cdc_acm]
[ 833.474101] SS:ESP 0068:df4f5b80
[ 833.474102] CR2: 0000000000000249
[ 833.474105] ---[ end trace c01a346ab38875ab ]---
[ 833.474138] BUG: unable to handle kernel paging request at ffffffec
[ 833.474142] IP: [<c014cd62>] kthread_data+0xf/0x13
[ 833.474144] *pde = 0077e067 *pte = 00000000
[ 833.474145]
[ 833.474147] Oops: 0000 [#2] SMP
[ 833.474177] Modules linked in: cdc_acm nouveau video drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm agpgart i2c_algo_bit cfg80211 rfkill binfmt_misc svgalib_helper(O) snd_pcm_oss snd_mixer_oss fbcon bitblit softcursor font tileblit sr9700 dm9601 snd_hda_codec_generic usbnet usb_storage snd_hda_intel mii snd_hda_codec tg3 snd_hwdep snd_hda_core ptp pps_core snd_pcm libphy gpio_ich snd_timer firmware_class lpc_ich pcspkr ppdev snd ohci_pci mfd_core ohci_hcd floppy wmi uhci_hcd soundcore parport_pc acpi_cpufreq ehci_pci parport ehci_hcd processor button
[ 833.474180] CPU: 0 PID: 4 Comm: kworker/0:0 Tainted: G D O 4.9.0-rc1 #1
[ 833.474181] Hardware name: Hewlett-Packard HP xw4300 Workstation/0A00h, BIOS 786D3 v01.08 03/10/2006
[ 833.474189] task: df4e15c0 task.stack: df4f4000
[ 833.474191] EIP: 0060:[<c014cd62>] EFLAGS: 00010002 CPU: 0
[ 833.474193] EIP is at kthread_data+0xf/0x13
[ 833.474195] EAX: 00000000 EBX: df4e15c0 ECX: dfb95050 EDX: df4e15c0
[ 833.474196] ESI: df4e1874 EDI: df4e15c0 EBP: df4f5f4c ESP: df4f5f48
[ 833.474198] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 833.474200] CR0: 80050033 CR2: 00000014 CR3: 1c8c4000 CR4: 00000690
[ 833.474201] Stack:
[ 833.474206] c0149297 df4f5f70 c04d289f df401d80 c01e3800 dfb94b80 00000001 df4e15c0
[ 833.474211] df4f5f98 df4e15c0 df4f5f7c c0153935 df4f5d50 df4f5fac c0139f19 01000000
[ 833.474215] df4e17ec df4e0000 00000001 00000000 df4f5f98 df4f5f98 00000009 df4f6000
[ 833.474216] Call Trace:
[ 833.474219] [<c0149297>] ? wq_worker_sleeping+0xd/0x75
[ 833.474222] [<c04d289f>] ? __schedule+0xb7/0x3d0
[ 833.474225] [<c01e3800>] ? kmem_cache_free+0x73/0xf3
[ 833.474228] [<c0153935>] ? do_task_dead+0x35/0x37
[ 833.474232] [<c0139f19>] ? do_exit+0x735/0x75b
[ 833.474234] [<c04d6f99>] ? rewind_stack_do_exit+0x11/0x13
[ 833.474261] Code: 8d 64 12 4e c0 8d 0c 95 00 00 00 00 29 cb b9 02 00 00 00 89 da 5b 5d e9 db fd ff ff 55 89 e5 3e 8d 74 26 00 8b 80 84 02 00 00 5d <8b> 40 ec c3 55 89 e5 52 3e 8d 74 26 00 b9 04 00 00 00 8b 90 84
[ 833.474264] EIP: [<c014cd62>]
[ 833.474265] kthread_data+0xf/0x13
[ 833.474265] SS:ESP 0068:df4f5f48
[ 833.474266] CR2: 00000000ffffffec
[ 833.474268] ---[ end trace c01a346ab38875ac ]---
[ 833.474269] Fixing recursive fault but reboot is needed!

> When I decode it, seems to crash in acm_alloc_minor() which does not make
> sense. It is likely that our kernels or compilers are a bit different.
> Could you please call gdb on your kernel module cdc-acm.ko
>and do:
>
> list *(acm_probe+0x4ee)

I guess you'd want this time list *(acm_probe+0x540) because 540 is now
reported at [ 833.473882] IP: [<e08fca6e>] acm_probe+0x540/0xd00 [cdc_acm].

# gdb ./cdc-acm.ko
GNU gdb (Gentoo 7.10.1 vanilla) 7.10.1
Copyright (C) 2015 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "i686-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://bugs.gentoo.org/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./cdc-acm.ko...done.
(gdb) list *(acm_probe+0x540)
0x1a92 is in acm_probe (drivers/usb/class/cdc-acm.c:1340).
1335 acm->control = control_interface;
1336 acm->data = data_interface;
1337 acm->minor = minor;
1338 acm->dev = usb_dev;
1339 if (h.usb_cdc_acm_descriptor)
1340 acm->ctrl_caps = h.usb_cdc_acm_descriptor->bmCapabilities;
1341 if (quirks & NO_CAP_LINE)
1342 acm->ctrl_caps &= ~USB_CDC_CAP_LINE;
1343 acm->ctrlsize = ctrlsize;
1344 acm->readsize = readsize;
(gdb)
quit


Curiously enough, when I do that on 0x4ee, then I seen something that
reminds me of your patches:

(gdb) list *(acm_probe+0x4ee)
0x1a40 is in acm_probe (drivers/usb/class/cdc-acm.c:1332).
1327 WARN_ON(!epctrl);
1328 ctrlsize = usb_endpoint_maxp(epctrl);
1329 WARN_ON(!epread);
1330 readsize = usb_endpoint_maxp(epread) *
1331 (quirks == SINGLE_RX_URB ? 1 : 2);
1332 acm->combined_interfaces = combined_interfaces;
1333 WARN_ON(!epwrite);
1334 acm->writesize = usb_endpoint_maxp(epwrite) * 20;
1335 acm->control = control_interface;
1336 acm->data = data_interface;
(gdb)
quit


Regards, Wim.