Hello, I guess value of priv->urb might be NULL. But I'd like to confirm whether the NULL pointer is sdev or udev. (priv must not be NULL). In the code http://elixir.free-electrons.com/linux/latest/source/drivers/usb/usbip/stub_main.c#L250, could you find message L.255 or L.259 in your message log? To modify log level, $ cat /proc/sys/kernel/printk 4 4 1 7 $ echo "4 7" | sudo tee /proc/sys/kernel/printk $ cat /proc/sys/kernel/printk 4 7 1 7 If the urb is NULL, it may be the race condition with stub_recv_cmd_submit(). If so, stub_priv_alloc() must not link the list and link priv to the list at end of stub_recv_cmd_submit(). At linking priv to the list, error return if the sdev->ud.tcp_socket is NULL. Best Regards, nobuo.iwata // > -----Original Message----- > From: Michael Grzeschik [mailto:mgr@xxxxxxxxxxxxxx] > Sent: Wednesday, May 10, 2017 9:54 PM > To: fx IWATA NOBUO <Nobuo.Iwata@xxxxxxxxxxxxxxx> > Cc: linux-usb@xxxxxxxxxxxxxxx; kernel@xxxxxxxxxxxxxx > Subject: usbip issue in stub_shutdown_connection while stub_complete > triggers > > > Hi Nuobo, > > I am currently trying to resolve an issue regarding a similar problem > to the one that your patch is solving: > > usbip: safe completion against usb_kill_urb() > > In some cases, when we still have urbs pending to complete and > meanwhile > the stack calls stub_shutdown_connection, we run into NULL pointer > reference > in stub_device_cleanup_urbs. > > [ 67.021314] Unable to handle kernel NULL pointer dereference at > virtual address 00000040 > [ 67.032067] pgd = c0004000 > [ 67.035406] [00000040] *pgd=00000000 > [ 67.039121] Internal error: Oops: 17 [#1] PREEMPT ARM > [ 67.044205] Modules linked in: usbip_host usbip_core ci_hdrc_imx > ci_hdrc extcon_core ehci_hcd usbcore usb_common uio_pdrv_genirq > usbmisc_imx lm75 > [ 67.057441] CPU: 0 PID: 127 Comm: kworker/u2:2 Not tainted 4.11.0-0+ > #3 > [ 67.064083] Hardware name: Freescale i.MX35 (Device Tree Support) > [ 67.070260] Workqueue: usbip_event event_handler [usbip_core] > [ 67.076053] task: c7966fe0 task.stack: c793e000 > [ 67.080644] PC is at stub_device_cleanup_urbs+0xb4/0x178 > [usbip_host] > [ 67.087123] LR is at __lock_is_held+0x5c/0x98 > [ 67.091514] pc : [<bf079e80>] lr : [<c0059480>] psr: 60000013 > [ 67.091514] sp : c793fe50 ip : c793fdc8 fp : c793fe84 > [ 67.103023] r10: c5af7eac r9 : c5b6a740 r8 : 00000100 > [ 67.108277] r7 : 00000200 r6 : c5af7e84 r5 : c5af7e00 r4 : 00000000 > [ 67.114833] r3 : 04208060 r2 : 00000000 r1 : c078cce0 r0 : 00000001 > [ 67.121391] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM > Segment none > [ 67.128556] Control: 00c5387d Table: 85bd8008 DAC: 00000051 > [ 67.134331] Process kworker/u2:2 (pid: 127, stack limit = 0xc793e188) > [ 67.140801] Stack: (0xc793fe50 to 0xc7940000) > [ 67.145195] fe40: c5af7ebc > c5af7eb4 bf0732f4 c5af7e00 > [ 67.153416] fe60: c5af7e04 c5af7e84 bf0732f4 bf07331c 00000000 > bf0732f4 c793feb4 c793fe88 > [ 67.161636] fe80: bf0795b4 bf079dd8 bf0794c4 c5a0fb80 c5af7e04 > bf0732d4 bf0732f4 bf07331c > [ 67.169857] fea0: 00000000 bf0732f4 c793fedc c793feb8 bf071ef8 > bf0794d0 bf073324 c78e8020 > [ 67.178078] fec0: c7806000 c7807100 c07cbe18 c0798b9d c793ff44 > c793fee0 c003dbd0 bf071e00 > [ 67.186297] fee0: 00000001 00000000 c003dae8 c003e1a0 c7806000 > c7806010 00000000 00000000 > [ 67.194516] ff00: bf073324 c094a7d0 00000000 bf073264 00000000 > 00000000 00000001 c78e8020 > [ 67.202736] ff20: c780603c c78e8038 00000088 c7806000 c7806000 > c078f020 c793ff7c c793ff48 > [ 67.210956] ff40: c003e29c c003d9dc 00000000 c795e4c0 c78e8020 > c7937180 00000000 c795e4c0 > [ 67.219177] ff60: c78e8020 c003e124 c788be48 c79371c0 c793ffac > c793ff80 c00450a0 c003e130 > [ 67.227395] ff80: c7948fa0 c795e4c0 c0044f74 00000000 00000000 > 00000000 00000000 00000000 > [ 67.235614] ffa0: 00000000 c793ffb0 c0010590 c0044f80 00000000 > 00000000 00000000 00000000 > [ 67.243831] ffc0: 00000000 00000000 00000000 00000000 00000000 > 00000000 00000000 00000000 > [ 67.252049] ffe0: 00000000 00000000 00000000 00000000 00000013 > 00000000 00000000 00000000 > [ 67.260249] Backtrace: > [ 67.262784] [<bf079dcc>] (stub_device_cleanup_urbs [usbip_host]) > from [<bf0795b4>] (stub_shutdown_connection+0xf0/0x1d8 > [usbip_host]) > [ 67.274825] r10:bf0732f4 r9:00000000 r8:bf07331c r7:bf0732f4 > r6:c5af7e84 r5:c5af7e04 > [ 67.282681] r4:c5af7e00 > [ 67.285291] [<bf0794c4>] (stub_shutdown_connection [usbip_host]) > from [<bf071ef8>] (event_handler+0x104/0x1b8 [usbip_core]) > [ 67.296464] r10:bf0732f4 r9:00000000 r8:bf07331c r7:bf0732f4 > r6:bf0732d4 r5:c5af7e04 > [ 67.304323] r4:c5a0fb80 r3:bf0794c4 > [ 67.307961] [<bf071df4>] (event_handler [usbip_core]) from > [<c003dbd0>] (process_one_work+0x200/0x70c) > [ 67.317310] r10:c0798b9d r8:c07cbe18 r7:c7807100 r6:c7806000 > r5:c78e8020 r4:bf073324 > [ 67.325178] [<c003d9d0>] (process_one_work) from [<c003e29c>] > (worker_thread+0x178/0x4cc) > [ 67.333396] r10:c078f020 r9:c7806000 r8:c7806000 r7:00000088 > r6:c78e8038 r5:c780603c > [ 67.341252] r4:c78e8020 > [ 67.343833] [<c003e124>] (worker_thread) from [<c00450a0>] > (kthread+0x12c/0x16c) > [ 67.351270] r10:c79371c0 r9:c788be48 r8:c003e124 r7:c78e8020 > r6:c795e4c0 r5:00000000 > [ 67.359126] r4:c7937180 > [ 67.361711] [<c0044f74>] (kthread) from [<c0010590>] > (ret_from_fork+0x14/0x24) > [ 67.368972] r10:00000000 r9:00000000 r8:00000000 r7:00000000 > r6:00000000 r5:c0044f74 > [ 67.376831] r4:c795e4c0 r3:c7948fa0 > [ 67.380446] Code: e59f20c8 e1a01009 e5920368 eb4276d9 (e5940040) > [ 67.386920] ---[ end trace 2417e815c07cde80 ]--- > > I traced it so far that the stub_shutdown_connection is cleaning the priv > pointer with the urb from the priv_init list. In the next step the completion > handler from the currently "to be cleaned" urb returns. From there the > issues > begin. For me this seems like a locking or order of operations problem. So > far > I am not to familiar enough with the usbip stack to see the obvious fix for > that issue. > > kworker/u2:1-13 [000] ...1 41.158647: stub_shutdown_connection > <-event_handler > kworker/u2:1-13 [000] ...1 41.161280: stub_device_cleanup_urbs > <-stub_shutdown_connection > kworker/u2:1-13 [000] .n.1 41.616762: stub_device_cleanup_urbs: > got priv from priv_init > kworker/u2:1-13 [000] .n.1 41.616779: stub_device_cleanup_urbs: > in stub_device_cleanup_urbs: handling priv: c5656820 > kworker/u2:1-13 [000] .n.1 41.621294: stub_device_cleanup_urbs: > free urb c5ab1b00 > kworker/u2:1-13 [000] dns3 41.847264: stub_complete > <-__usb_hcd_giveback_urb > kworker/u2:1-13 [000] dns2 41.847298: stub_complete: in > stub_complete: handling priv: c5656820, urb c5ab1b00 > kworker/u2:1-13 [000] .... 42.084826: stub_device_cleanup_urbs: > got priv from priv_init > kworker/u2:1-13 [000] .... 42.084840: stub_device_cleanup_urbs: > in stub_device_cleanup_urbs: handling priv: c5656180 > kworker/u2:1-13 [000] .... 42.089277: stub_device_cleanup_urbs: > free urb (null) > > After that issue, for some reason I see the system also running into further > allocation problems in completely other function stacks in the kernel. > Probably > resulting from the kmem_cache_free on an invalid pointer priv. > > [ 219.619706] Unable to handle kernel NULL pointer dereference at > virtual address 00000000 > [ 219.628373] pgd = c5ba0000 > [ 219.631160] [00000000] *pgd=00000000, *pte=00000001, > *ppte=00000001 > [ 219.637936] Internal error: Oops: 17 [#1] PREEMPT ARM > [ 219.643022] Modules linked in: usbip_host usbip_core ci_hdrc_imx > ci_hdrc extcon_core ehci_hcd usbcore usb_common uio_pdrv_genirq > usbmisc_imx lm75 > [ 219.656247] CPU: 0 PID: 1112 Comm: ps Not tainted 4.11.0-0+ #3 > [ 219.662105] Hardware name: Freescale i.MX35 (Device Tree Support) > [ 219.668227] task: c5b7e480 task.stack: c5aec000 > [ 219.672802] PC is at alloc_inode+0x1c/0xb0 > [ 219.676935] LR is at new_inode_pseudo+0x18/0x50 > [ 219.681499] pc : [<c0140318>] lr : [<c0141d70>] psr: 60000013 > [ 219.681499] sp : c5aeded0 ip : c5aedee8 fp : c5aedee4 > [ 219.693006] r10: 00000000 r9 : c5aec000 r8 : c07c1430 > [ 219.698259] r7 : 00000000 r6 : 00000001 r5 : c78d9800 r4 : 00000001 > [ 219.704813] r3 : 00000000 r2 : 00000001 r1 : 00000001 r0 : c78d9800 > [ 219.711370] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM > Segment none > [ 219.718533] Control: 00c5387d Table: 85ba0008 DAC: 00000051 > [ 219.724306] Process ps (pid: 1112, stack limit = 0xc5aec188) > [ 219.729993] Stack: (0xc5aeded0 to 0xc5aee000) > [ 219.734387] dec0: 00000001 > 00080801 c5aedefc c5aedee8 > [ 219.742606] dee0: c0141d70 c0140308 00000001 00080801 c5aedf14 > c5aedf00 c036bf70 c0141d64 > [ 219.750824] df00: 00000000 00000001 c5aedf4c c5aedf18 c036c060 > c036bf58 00000000 00000076 > [ 219.759043] df20: c0553a78 c0798bf9 c5b7e480 00080801 00000007 > 00000119 c00106a4 00000000 > [ 219.767263] df40: c5aedf6c c5aedf50 c036c3cc c036c014 c5aedf7c > 00000000 c00430d8 00000000 > [ 219.775481] df60: c5aedfa4 c5aedf70 c036d758 c036c384 b6f6130c > 00000007 c5aedf94 c5aedf88 > [ 219.783700] df80: c005f064 b6f4d56c b6f6130c 00000007 00000119 > c00106a4 00000000 c5aedfa8 > [ 219.791918] dfa0: c0010500 c036d72c b6f4d56c b6f6130c 00000001 > 00080801 00000000 00000000 > [ 219.800137] dfc0: b6f4d56c b6f6130c 00000007 00000119 0000000b > 00000000 b6f4d56c bef5096c > [ 219.808355] dfe0: 00000000 bef508b4 b6f2f0a0 b6efdf6c 60000010 > 00000001 00000000 00000000 > [ 219.816555] Backtrace: > [ 219.819057] [<c01402fc>] (alloc_inode) from [<c0141d70>] > (new_inode_pseudo+0x18/0x50) > [ 219.826917] r5:00080801 r4:00000001 > [ 219.830537] [<c0141d58>] (new_inode_pseudo) from [<c036bf70>] > (sock_alloc+0x24/0xbc) > [ 219.838310] r5:00080801 r4:00000001 > [ 219.841923] [<c036bf4c>] (sock_alloc) from [<c036c060>] > (__sock_create+0x58/0x33c) > [ 219.849520] r4:00000001 r3:00000000 > [ 219.853132] [<c036c008>] (__sock_create) from [<c036c3cc>] > (sock_create+0x54/0x5c) > [ 219.860741] r10:00000000 r8:c00106a4 r7:00000119 r6:00000007 > r5:00080801 r4:c5b7e480 > [ 219.868609] [<c036c378>] (sock_create) from [<c036d758>] > (SyS_socket+0x38/0xbc) > [ 219.875943] r4:00000000 > [ 219.878525] [<c036d720>] (SyS_socket) from [<c0010500>] > (ret_fast_syscall+0x0/0x1c) > [ 219.886218] r8:c00106a4 r7:00000119 r6:00000007 r5:b6f6130c > r4:b6f4d56c > [ 219.892956] Code: e92d4000 e8bd4000 e5903024 e1a05000 (e5933000) > [ 219.899277] ---[ end trace 118d02b9c07cde80 ]--- > > Regards, > Michael Grzeschik > > -- > Pengutronix e.K. | > | > Industrial Linux Solutions | http://www.pengutronix.de/ > | > Peiner Str. 6-8, 31137 Hildesheim, Germany | Phone: +49-5121-206917-0 > | > Amtsgericht Hildesheim, HRA 2686 | Fax: > +49-5121-206917-5555 | -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
