Linux-USB Archive on lore.kernel.org
 help / color / Atom feed
* possible deadlock in usb_deregister_dev
@ 2019-08-05 11:58 syzbot
  2019-08-09 18:18 ` syzbot
  0 siblings, 1 reply; 6+ messages in thread
From: syzbot @ 2019-08-05 11:58 UTC (permalink / raw)
  To: andreyknvl, gregkh, linux-kernel, linux-usb, syzkaller-bugs

Hello,

syzbot found the following crash on:

HEAD commit:    e96407b4 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan.git usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=13b5bc8a600000
kernel config:  https://syzkaller.appspot.com/x/.config?x=792eb47789f57810
dashboard link: https://syzkaller.appspot.com/bug?extid=a64a382964bf6c71a9c0
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com

usb 4-1: USB disconnect, device number 85
======================================================
WARNING: possible circular locking dependency detected
5.3.0-rc2+ #24 Not tainted
------------------------------------------------------
kworker/0:2/105 is trying to acquire lock:
000000003db0b025 (minor_rwsem){++++}, at: usb_deregister_dev  
drivers/usb/core/file.c:238 [inline]
000000003db0b025 (minor_rwsem){++++}, at: usb_deregister_dev+0x61/0x270  
drivers/usb/core/file.c:230

but task is already holding lock:
000000000afbf30c (iowarrior_open_disc_lock){+.+.}, at:  
iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (iowarrior_open_disc_lock){+.+.}:
        __mutex_lock_common kernel/locking/mutex.c:930 [inline]
        __mutex_lock+0x158/0x1360 kernel/locking/mutex.c:1077
        iowarrior_open+0x8a/0x2a0 drivers/usb/misc/iowarrior.c:600
        usb_open+0x1df/0x270 drivers/usb/core/file.c:48
        chrdev_open+0x219/0x5c0 fs/char_dev.c:414
        do_dentry_open+0x494/0x1120 fs/open.c:797
        do_last fs/namei.c:3416 [inline]
        path_openat+0x1430/0x3f50 fs/namei.c:3533
        do_filp_open+0x1a1/0x280 fs/namei.c:3563
        do_sys_open+0x3c0/0x580 fs/open.c:1089
        do_syscall_64+0xb7/0x580 arch/x86/entry/common.c:296
        entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (iowarrior_mutex){+.+.}:
        __mutex_lock_common kernel/locking/mutex.c:930 [inline]
        __mutex_lock+0x158/0x1360 kernel/locking/mutex.c:1077
        iowarrior_open+0x23/0x2a0 drivers/usb/misc/iowarrior.c:589
        usb_open+0x1df/0x270 drivers/usb/core/file.c:48
        chrdev_open+0x219/0x5c0 fs/char_dev.c:414
        do_dentry_open+0x494/0x1120 fs/open.c:797
        do_last fs/namei.c:3416 [inline]
        path_openat+0x1430/0x3f50 fs/namei.c:3533
        do_filp_open+0x1a1/0x280 fs/namei.c:3563
        do_sys_open+0x3c0/0x580 fs/open.c:1089
        do_syscall_64+0xb7/0x580 arch/x86/entry/common.c:296
        entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (minor_rwsem){++++}:
        check_prev_add kernel/locking/lockdep.c:2405 [inline]
        check_prevs_add kernel/locking/lockdep.c:2507 [inline]
        validate_chain kernel/locking/lockdep.c:2897 [inline]
        __lock_acquire+0x1f7c/0x3b50 kernel/locking/lockdep.c:3880
        lock_acquire+0x127/0x320 kernel/locking/lockdep.c:4412
        down_write+0x92/0x150 kernel/locking/rwsem.c:1500
        usb_deregister_dev drivers/usb/core/file.c:238 [inline]
        usb_deregister_dev+0x61/0x270 drivers/usb/core/file.c:230
        iowarrior_disconnect+0xa8/0x2c0 drivers/usb/misc/iowarrior.c:873
        usb_unbind_interface+0x1bd/0x8a0 drivers/usb/core/driver.c:423
        __device_release_driver drivers/base/dd.c:1120 [inline]
        device_release_driver_internal+0x404/0x4c0 drivers/base/dd.c:1151
        bus_remove_device+0x2dc/0x4a0 drivers/base/bus.c:556
        device_del+0x420/0xb10 drivers/base/core.c:2288
        usb_disable_device+0x211/0x690 drivers/usb/core/message.c:1237
        usb_disconnect+0x284/0x8d0 drivers/usb/core/hub.c:2199
        hub_port_connect drivers/usb/core/hub.c:4949 [inline]
        hub_port_connect_change drivers/usb/core/hub.c:5213 [inline]
        port_event drivers/usb/core/hub.c:5359 [inline]
        hub_event+0x1454/0x3640 drivers/usb/core/hub.c:5441
        process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
        worker_thread+0x96/0xe20 kernel/workqueue.c:2415
        kthread+0x318/0x420 kernel/kthread.c:255
        ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352

other info that might help us debug this:

Chain exists of:
   minor_rwsem --> iowarrior_mutex --> iowarrior_open_disc_lock

  Possible unsafe locking scenario:

        CPU0                    CPU1
        ----                    ----
   lock(iowarrior_open_disc_lock);
                                lock(iowarrior_mutex);
                                lock(iowarrior_open_disc_lock);
   lock(minor_rwsem);

  *** DEADLOCK ***

6 locks held by kworker/0:2/105:
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:226 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:620 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:647 [inline]
  #0: 00000000aba84ede ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x827/0x1530 kernel/workqueue.c:2240
  #1: 0000000058d65fe1 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x85b/0x1530 kernel/workqueue.c:2244
  #2: 000000006a2f7a8f (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1220 [inline]
  #2: 000000006a2f7a8f (&dev->mutex){....}, at: hub_event+0x17c/0x3640  
drivers/usb/core/hub.c:5387
  #3: 00000000eddd5fcd (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1220 [inline]
  #3: 00000000eddd5fcd (&dev->mutex){....}, at: usb_disconnect+0x91/0x8d0  
drivers/usb/core/hub.c:2190
  #4: 000000009478eeb7 (&dev->mutex){....}, at:  
device_release_driver_internal+0x23/0x4c0 drivers/base/dd.c:1148
  #5: 000000000afbf30c (iowarrior_open_disc_lock){+.+.}, at:  
iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867

stack backtrace:
CPU: 0 PID: 105 Comm: kworker/0:2 Not tainted 5.3.0-rc2+ #24
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xca/0x13e lib/dump_stack.c:113
  check_noncircular+0x345/0x3e0 kernel/locking/lockdep.c:1741
  check_prev_add kernel/locking/lockdep.c:2405 [inline]
  check_prevs_add kernel/locking/lockdep.c:2507 [inline]
  validate_chain kernel/locking/lockdep.c:2897 [inline]
  __lock_acquire+0x1f7c/0x3b50 kernel/locking/lockdep.c:3880
  lock_acquire+0x127/0x320 kernel/locking/lockdep.c:4412
  down_write+0x92/0x150 kernel/locking/rwsem.c:1500
  usb_deregister_dev drivers/usb/core/file.c:238 [inline]
  usb_deregister_dev+0x61/0x270 drivers/usb/core/file.c:230
  iowarrior_disconnect+0xa8/0x2c0 drivers/usb/misc/iowarrior.c:873
  usb_unbind_interface+0x1bd/0x8a0 drivers/usb/core/driver.c:423
  __device_release_driver drivers/base/dd.c:1120 [inline]
  device_release_driver_internal+0x404/0x4c0 drivers/base/dd.c:1151
  bus_remove_device+0x2dc/0x4a0 drivers/base/bus.c:556
  device_del+0x420/0xb10 drivers/base/core.c:2288
  usb_disable_device+0x211/0x690 drivers/usb/core/message.c:1237
  usb_disconnect+0x284/0x8d0 drivers/usb/core/hub.c:2199
  hub_port_connect drivers/usb/core/hub.c:4949 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5213 [inline]
  port_event drivers/usb/core/hub.c:5359 [inline]
  hub_event+0x1454/0x3640 drivers/usb/core/hub.c:5441
  process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
  worker_thread+0x96/0xe20 kernel/workqueue.c:2415
  kthread+0x318/0x420 kernel/kthread.c:255
  ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
iowarrior 4-1:0.236: I/O-Warror #0 now disconnected
usb 4-1: new high-speed USB device number 86 using dummy_hcd
usb 4-1: Using ep0 maxpacket: 8
usb 4-1: config 0 has an invalid interface number: 171 but max is 0
usb 4-1: config 0 has no interface number 0
usb 4-1: New USB device found, idVendor=14f7, idProduct=0500,  
bcdDevice=ac.d6
usb 4-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 4-1: config 0 descriptor??
technisat-usb2: could not set alternate setting to 0
technisat-usb2: firmware version: 251.126
dvb-usb: found a 'Technisat SkyStar USB HD (DVB-S/S2)' in warm state.
dvb-usb: will pass the complete MPEG2 transport stream to the software  
demuxer.
dvbdev: DVB: registering new adapter (Technisat SkyStar USB HD (DVB-S/S2))
usb 4-1: media controller created
technisat-usb2: i2c-error: out failed 53 = -22
dvb-usb: MAC address reading failed.
dvbdev: dvb_create_media_entity: media entity 'dvb-demux' registered.
technisat-usb2: i2c-error: out failed 68 = -22
dvb-usb: no frontend was attached by 'Technisat SkyStar USB HD (DVB-S/S2)'
Registered IR keymap rc-technisat-usb2
rc_core: Loaded IR protocol module ir-rc5-decoder, but protocol rc-5 still  
not available
rc rc0: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0
input: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0/input262
dvb-usb: schedule remote query interval to 100 msecs.
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully initialized and  
connected.
usb 4-1: USB disconnect, device number 86
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully deinitialized and  
disconnected.
usb 5-1: USB disconnect, device number 48
usb 2-1: USB disconnect, device number 98
metro-usb ttyUSB0: Metrologic USB to Serial converter now disconnected from  
ttyUSB0
metro_usb 2-1:0.123: device disconnected
usb 2-1: new low-speed USB device number 99 using dummy_hcd
usb 2-1: config index 0 descriptor too short (expected 63259, got 46)
usb 2-1: config 0 has an invalid interface number: 123 but max is 0
usb 2-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 2-1: config 0 has no interface number 0
usb 2-1: config 0 interface 123 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 2-1: New USB device found, idVendor=0c2e, idProduct=0720,  
bcdDevice=43.fe
usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 2-1: config 0 descriptor??
metro_usb 2-1:0.123: Metrologic USB to Serial converter detected
usb 2-1: Metrologic USB to Serial converter now attached to ttyUSB0
usb 4-1: new high-speed USB device number 89 using dummy_hcd
usb 4-1: Using ep0 maxpacket: 8
usb 4-1: config 0 has an invalid interface number: 171 but max is 0
usb 4-1: config 0 has no interface number 0
usb 4-1: New USB device found, idVendor=14f7, idProduct=0500,  
bcdDevice=ac.d6
usb 4-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 4-1: config 0 descriptor??
technisat-usb2: could not set alternate setting to 0
technisat-usb2: firmware version: 25.147
dvb-usb: found a 'Technisat SkyStar USB HD (DVB-S/S2)' in warm state.
dvb-usb: will pass the complete MPEG2 transport stream to the software  
demuxer.
dvbdev: DVB: registering new adapter (Technisat SkyStar USB HD (DVB-S/S2))
usb 4-1: media controller created
technisat-usb2: i2c-error: out failed 53 = -22
dvb-usb: MAC address reading failed.
dvbdev: dvb_create_media_entity: media entity 'dvb-demux' registered.
technisat-usb2: i2c-error: out failed 68 = -22
dvb-usb: no frontend was attached by 'Technisat SkyStar USB HD (DVB-S/S2)'
Registered IR keymap rc-technisat-usb2
rc_core: Loaded IR protocol module ir-rc5-decoder, but protocol rc-5 still  
not available
rc rc0: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0
input: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0/input265
dvb-usb: schedule remote query interval to 100 msecs.
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully initialized and  
connected.
usb 4-1: USB disconnect, device number 89
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully deinitialized and  
disconnected.
usb 4-1: new high-speed USB device number 90 using dummy_hcd
usb 4-1: Using ep0 maxpacket: 8
usb 4-1: config 0 has an invalid interface number: 171 but max is 0
usb 4-1: config 0 has no interface number 0
usb 4-1: New USB device found, idVendor=14f7, idProduct=0500,  
bcdDevice=ac.d6
usb 4-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 4-1: config 0 descriptor??
technisat-usb2: could not set alternate setting to 0
technisat-usb2: firmware version: 39.225
dvb-usb: found a 'Technisat SkyStar USB HD (DVB-S/S2)' in warm state.
dvb-usb: will pass the complete MPEG2 transport stream to the software  
demuxer.
dvbdev: DVB: registering new adapter (Technisat SkyStar USB HD (DVB-S/S2))
usb 4-1: media controller created
technisat-usb2: i2c-error: out failed 53 = -22
dvb-usb: MAC address reading failed.
dvbdev: dvb_create_media_entity: media entity 'dvb-demux' registered.
technisat-usb2: i2c-error: out failed 68 = -22
dvb-usb: no frontend was attached by 'Technisat SkyStar USB HD (DVB-S/S2)'
Registered IR keymap rc-technisat-usb2
rc_core: Loaded IR protocol module ir-rc5-decoder, but protocol rc-5 still  
not available
rc rc0: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0
input: Technisat SkyStar USB HD (DVB-S/S2) as  
/devices/platform/dummy_hcd.3/usb4/4-1/rc/rc0/input266
dvb-usb: schedule remote query interval to 100 msecs.
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully initialized and  
connected.
usb 4-1: USB disconnect, device number 90
dvb-usb: Technisat SkyStar USB HD (DVB-S/S2) successfully deinitialized and  
disconnected.


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Re: possible deadlock in usb_deregister_dev
  2019-08-06 14:22 possible deadlock in usb_deregister_dev Oliver Neukum
@ 2019-08-06 14:22 ` syzbot
  0 siblings, 0 replies; 6+ messages in thread
From: syzbot @ 2019-08-06 14:22 UTC (permalink / raw)
  To: Oliver Neukum
  Cc: andreyknvl, gregkh, linux-kernel, linux-usb, oneukum, syzkaller-bugs

> Am Montag, den 05.08.2019, 04:58 -0700 schrieb syzbot:
>> Hello,

>> syzbot found the following crash on:

>> HEAD commit:    e96407b4 usb-fuzzer: main usb gadget fuzzer driver
>> git tree:       https://github.com/google/kasan.git usb-fuzzer
>> console output: https://syzkaller.appspot.com/x/log.txt?x=13b5bc8a600000
>> kernel config:   
>> https://syzkaller.appspot.com/x/.config?x=792eb47789f57810
>> dashboard link:  
>> https://syzkaller.appspot.com/bug?extid=a64a382964bf6c71a9c0
>> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)

>> Unfortunately, I don't have any reproducer for this crash yet.

>> IMPORTANT: if you fix the bug, please add the following tag to the  
>> commit:
>> Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com

> #syz test: https://github.com/google/kasan.git e96407b4

This crash does not have a reproducer. I cannot test it.


>  From 973e82b3f583113e4d7fe5cd2f918a16022c4e38 Mon Sep 17 00:00:00 2001
> From: Oliver Neukum <oneukum@suse.com>
> Date: Tue, 6 Aug 2019 16:17:54 +0200
> Subject: [PATCH] usb: iowarrior: fix deadlock on disconnect

> We have to drop the mutex before we close() upon disconnect()
> as close() needs the lock. This is safe to do by dropping the
> mutex as intfdata is already set to NULL, so open() will fail.

> Fixes: 03f36e885fc26 ("USB: open disconnect race in iowarrior")
> Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com
> Signed-off-by: Oliver Neukum <oneukum@suse.com>
> ---
>   drivers/usb/misc/iowarrior.c | 7 ++++---
>   1 file changed, 4 insertions(+), 3 deletions(-)

> diff --git a/drivers/usb/misc/iowarrior.c b/drivers/usb/misc/iowarrior.c
> index ba05dd80a020..f5bed9f29e56 100644
> --- a/drivers/usb/misc/iowarrior.c
> +++ b/drivers/usb/misc/iowarrior.c
> @@ -866,19 +866,20 @@ static void iowarrior_disconnect(struct  
> usb_interface *interface)
>   	dev = usb_get_intfdata(interface);
>   	mutex_lock(&iowarrior_open_disc_lock);
>   	usb_set_intfdata(interface, NULL);
> +	/* prevent device read, write and ioctl */
> +	dev->present = 0;

>   	minor = dev->minor;
> +	mutex_unlock(&iowarrior_open_disc_lock);
> +	/* give back our minor - this will call close() locks need to be  
> dropped at this point*/

> -	/* give back our minor */
>   	usb_deregister_dev(interface, &iowarrior_class);

>   	mutex_lock(&dev->mutex);

>   	/* prevent device read, write and ioctl */
> -	dev->present = 0;

>   	mutex_unlock(&dev->mutex);
> -	mutex_unlock(&iowarrior_open_disc_lock);

>   	if (dev->opened) {
>   		/* There is a process that holds a filedescriptor to the device ,
> --
> 2.16.4


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: possible deadlock in usb_deregister_dev
  2019-08-05 11:58 syzbot
@ 2019-08-09 18:18 ` syzbot
  2019-08-09 19:32   ` Alan Stern
  0 siblings, 1 reply; 6+ messages in thread
From: syzbot @ 2019-08-09 18:18 UTC (permalink / raw)
  To: andreyknvl, gregkh, linux-kernel, linux-usb, oneukum, syzkaller-bugs

syzbot has found a reproducer for the following crash on:

HEAD commit:    e96407b4 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan.git usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=15bf780e600000
kernel config:  https://syzkaller.appspot.com/x/.config?x=cfa2c18fb6a8068e
dashboard link: https://syzkaller.appspot.com/bug?extid=a64a382964bf6c71a9c0
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16787574600000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=136cc4d2600000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com

usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 2
======================================================
WARNING: possible circular locking dependency detected
5.3.0-rc2+ #25 Not tainted
------------------------------------------------------
kworker/0:1/12 is trying to acquire lock:
00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev  
drivers/usb/core/file.c:238 [inline]
00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev+0x61/0x270  
drivers/usb/core/file.c:230

but task is already holding lock:
000000001d1989ef (iowarrior_open_disc_lock){+.+.}, at:  
iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (iowarrior_open_disc_lock){+.+.}:
        __mutex_lock_common kernel/locking/mutex.c:930 [inline]
        __mutex_lock+0x158/0x1360 kernel/locking/mutex.c:1077
        iowarrior_open+0x8a/0x2a0 drivers/usb/misc/iowarrior.c:600
        usb_open+0x1df/0x270 drivers/usb/core/file.c:48
        chrdev_open+0x219/0x5c0 fs/char_dev.c:414
        do_dentry_open+0x494/0x1120 fs/open.c:797
        do_last fs/namei.c:3416 [inline]
        path_openat+0x1430/0x3f50 fs/namei.c:3533
        do_filp_open+0x1a1/0x280 fs/namei.c:3563
        do_sys_open+0x3c0/0x580 fs/open.c:1089
        do_syscall_64+0xb7/0x580 arch/x86/entry/common.c:296
        entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (iowarrior_mutex){+.+.}:
        __mutex_lock_common kernel/locking/mutex.c:930 [inline]
        __mutex_lock+0x158/0x1360 kernel/locking/mutex.c:1077
        iowarrior_open+0x23/0x2a0 drivers/usb/misc/iowarrior.c:589
        usb_open+0x1df/0x270 drivers/usb/core/file.c:48
        chrdev_open+0x219/0x5c0 fs/char_dev.c:414
        do_dentry_open+0x494/0x1120 fs/open.c:797
        do_last fs/namei.c:3416 [inline]
        path_openat+0x1430/0x3f50 fs/namei.c:3533
        do_filp_open+0x1a1/0x280 fs/namei.c:3563
        do_sys_open+0x3c0/0x580 fs/open.c:1089
        do_syscall_64+0xb7/0x580 arch/x86/entry/common.c:296
        entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (minor_rwsem){++++}:
        check_prev_add kernel/locking/lockdep.c:2405 [inline]
        check_prevs_add kernel/locking/lockdep.c:2507 [inline]
        validate_chain kernel/locking/lockdep.c:2897 [inline]
        __lock_acquire+0x1f7c/0x3b50 kernel/locking/lockdep.c:3880
        lock_acquire+0x127/0x320 kernel/locking/lockdep.c:4412
        down_write+0x92/0x150 kernel/locking/rwsem.c:1500
        usb_deregister_dev drivers/usb/core/file.c:238 [inline]
        usb_deregister_dev+0x61/0x270 drivers/usb/core/file.c:230
        iowarrior_disconnect+0xa8/0x2c0 drivers/usb/misc/iowarrior.c:873
        usb_unbind_interface+0x1bd/0x8a0 drivers/usb/core/driver.c:423
        __device_release_driver drivers/base/dd.c:1120 [inline]
        device_release_driver_internal+0x404/0x4c0 drivers/base/dd.c:1151
        bus_remove_device+0x2dc/0x4a0 drivers/base/bus.c:556
        device_del+0x420/0xb10 drivers/base/core.c:2288
        usb_disable_device+0x211/0x690 drivers/usb/core/message.c:1237
        usb_disconnect+0x284/0x8d0 drivers/usb/core/hub.c:2199
        hub_port_connect drivers/usb/core/hub.c:4949 [inline]
        hub_port_connect_change drivers/usb/core/hub.c:5213 [inline]
        port_event drivers/usb/core/hub.c:5359 [inline]
        hub_event+0x1454/0x3640 drivers/usb/core/hub.c:5441
        process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
        worker_thread+0x96/0xe20 kernel/workqueue.c:2415
        kthread+0x318/0x420 kernel/kthread.c:255
        ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352

other info that might help us debug this:

Chain exists of:
   minor_rwsem --> iowarrior_mutex --> iowarrior_open_disc_lock

  Possible unsafe locking scenario:

        CPU0                    CPU1
        ----                    ----
   lock(iowarrior_open_disc_lock);
                                lock(iowarrior_mutex);
                                lock(iowarrior_open_disc_lock);
   lock(minor_rwsem);

  *** DEADLOCK ***

6 locks held by kworker/0:1/12:
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:226 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:620 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:647 [inline]
  #0: 0000000016a35280 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x827/0x1530 kernel/workqueue.c:2240
  #1: 0000000001908f5f ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x85b/0x1530 kernel/workqueue.c:2244
  #2: 00000000894e02c9 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1220 [inline]
  #2: 00000000894e02c9 (&dev->mutex){....}, at: hub_event+0x17c/0x3640  
drivers/usb/core/hub.c:5387
  #3: 00000000e2dd0256 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1220 [inline]
  #3: 00000000e2dd0256 (&dev->mutex){....}, at: usb_disconnect+0x91/0x8d0  
drivers/usb/core/hub.c:2190
  #4: 0000000021bbb80a (&dev->mutex){....}, at:  
device_release_driver_internal+0x23/0x4c0 drivers/base/dd.c:1148
  #5: 000000001d1989ef (iowarrior_open_disc_lock){+.+.}, at:  
iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867

stack backtrace:
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 5.3.0-rc2+ #25
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xca/0x13e lib/dump_stack.c:113
  check_noncircular+0x345/0x3e0 kernel/locking/lockdep.c:1741
  check_prev_add kernel/locking/lockdep.c:2405 [inline]
  check_prevs_add kernel/locking/lockdep.c:2507 [inline]
  validate_chain kernel/locking/lockdep.c:2897 [inline]
  __lock_acquire+0x1f7c/0x3b50 kernel/locking/lockdep.c:3880
  lock_acquire+0x127/0x320 kernel/locking/lockdep.c:4412
  down_write+0x92/0x150 kernel/locking/rwsem.c:1500
  usb_deregister_dev drivers/usb/core/file.c:238 [inline]
  usb_deregister_dev+0x61/0x270 drivers/usb/core/file.c:230
  iowarrior_disconnect+0xa8/0x2c0 drivers/usb/misc/iowarrior.c:873
  usb_unbind_interface+0x1bd/0x8a0 drivers/usb/core/driver.c:423
  __device_release_driver drivers/base/dd.c:1120 [inline]
  device_release_driver_internal+0x404/0x4c0 drivers/base/dd.c:1151
  bus_remove_device+0x2dc/0x4a0 drivers/base/bus.c:556
  device_del+0x420/0xb10 drivers/base/core.c:2288
  usb_disable_device+0x211/0x690 drivers/usb/core/message.c:1237
  usb_disconnect+0x284/0x8d0 drivers/usb/core/hub.c:2199
  hub_port_connect drivers/usb/core/hub.c:4949 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5213 [inline]
  port_event drivers/usb/core/hub.c:5359 [inline]
  hub_event+0x1454/0x3640 drivers/usb/core/hub.c:5441
  process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
  worker_thread+0x96/0xe20 kernel/workqueue.c:2415
  kthread+0x318/0x420 kernel/kthread.c:255
  ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected
usb 1-1: new low-speed USB device number 3 using dummy_hcd
usb 1-1: config 0 has an invalid interface number: 236 but max is 0
usb 1-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 1-1: config 0 has no interface number 0
usb 1-1: config 0 interface 236 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 1-1: New USB device found, idVendor=07c0, idProduct=1501,  
bcdDevice=74.a0
usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 5
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected
usb 1-1: new low-speed USB device number 6 using dummy_hcd
usb 1-1: config 0 has an invalid interface number: 236 but max is 0
usb 1-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 1-1: config 0 has no interface number 0
usb 1-1: config 0 interface 236 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 1-1: New USB device found, idVendor=07c0, idProduct=1501,  
bcdDevice=74.a0
usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 7
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected
usb 1-1: new low-speed USB device number 8 using dummy_hcd
usb 1-1: config 0 has an invalid interface number: 236 but max is 0
usb 1-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 1-1: config 0 has no interface number 0
usb 1-1: config 0 interface 236 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 1-1: New USB device found, idVendor=07c0, idProduct=1501,  
bcdDevice=74.a0
usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 8
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected
usb 1-1: new low-speed USB device number 9 using dummy_hcd
usb 1-1: config 0 has an invalid interface number: 236 but max is 0
usb 1-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 1-1: config 0 has no interface number 0
usb 1-1: config 0 interface 236 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 1-1: New USB device found, idVendor=07c0, idProduct=1501,  
bcdDevice=74.a0
usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 9
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected
usb 1-1: new low-speed USB device number 10 using dummy_hcd
usb 1-1: config 0 has an invalid interface number: 236 but max is 0
usb 1-1: config 0 has an invalid descriptor of length 0, skipping remainder  
of the config
usb 1-1: config 0 has no interface number 0
usb 1-1: config 0 interface 236 altsetting 0 endpoint 0x81 is Bulk;  
changing to Interrupt
usb 1-1: New USB device found, idVendor=07c0, idProduct=1501,  
bcdDevice=74.a0
usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 1-1: config 0 descriptor??
iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
attached to iowarrior0
usb 1-1: USB disconnect, device number 11
iowarrior 1-1:0.236: I/O-Warror #0 now disconnected


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: possible deadlock in usb_deregister_dev
  2019-08-09 18:18 ` syzbot
@ 2019-08-09 19:32   ` Alan Stern
  2019-08-12 12:11     ` Andrey Konovalov
  0 siblings, 1 reply; 6+ messages in thread
From: Alan Stern @ 2019-08-09 19:32 UTC (permalink / raw)
  To: syzbot
  Cc: andreyknvl, gregkh, linux-kernel, linux-usb, oneukum, syzkaller-bugs

On Fri, 9 Aug 2019, syzbot wrote:

> syzbot has found a reproducer for the following crash on:
> 
> HEAD commit:    e96407b4 usb-fuzzer: main usb gadget fuzzer driver
> git tree:       https://github.com/google/kasan.git usb-fuzzer
> console output: https://syzkaller.appspot.com/x/log.txt?x=15bf780e600000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=cfa2c18fb6a8068e
> dashboard link: https://syzkaller.appspot.com/bug?extid=a64a382964bf6c71a9c0
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16787574600000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=136cc4d2600000
> 
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com
> 
> usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> usb 1-1: config 0 descriptor??
> iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now  
> attached to iowarrior0
> usb 1-1: USB disconnect, device number 2
> ======================================================
> WARNING: possible circular locking dependency detected
> 5.3.0-rc2+ #25 Not tainted
> ------------------------------------------------------
> kworker/0:1/12 is trying to acquire lock:
> 00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev  
> drivers/usb/core/file.c:238 [inline]
> 00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev+0x61/0x270  
> drivers/usb/core/file.c:230
> 
> but task is already holding lock:
> 000000001d1989ef (iowarrior_open_disc_lock){+.+.}, at:  
> iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867
> 
> which lock already depends on the new lock.

https://syzkaller.appspot.com/bug?extid=ca52394faa436d8131df is 
undoubtedly a duplicate of this.

Alan Stern


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: possible deadlock in usb_deregister_dev
  2019-08-09 19:32   ` Alan Stern
@ 2019-08-12 12:11     ` Andrey Konovalov
  2019-08-12 12:31       ` syzbot
  0 siblings, 1 reply; 6+ messages in thread
From: Andrey Konovalov @ 2019-08-12 12:11 UTC (permalink / raw)
  To: Alan Stern
  Cc: syzbot, Greg Kroah-Hartman, LKML, USB list, oneukum, syzkaller-bugs

[-- Attachment #1: Type: text/plain, Size: 2126 bytes --]

On Fri, Aug 9, 2019 at 9:32 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Fri, 9 Aug 2019, syzbot wrote:
>
> > syzbot has found a reproducer for the following crash on:
> >
> > HEAD commit:    e96407b4 usb-fuzzer: main usb gadget fuzzer driver
> > git tree:       https://github.com/google/kasan.git usb-fuzzer
> > console output: https://syzkaller.appspot.com/x/log.txt?x=15bf780e600000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=cfa2c18fb6a8068e
> > dashboard link: https://syzkaller.appspot.com/bug?extid=a64a382964bf6c71a9c0
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16787574600000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=136cc4d2600000
> >
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com
> >
> > usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> > usb 1-1: config 0 descriptor??
> > iowarrior 1-1:0.236: IOWarrior product=0x1501, serial= interface=236 now
> > attached to iowarrior0
> > usb 1-1: USB disconnect, device number 2
> > ======================================================
> > WARNING: possible circular locking dependency detected
> > 5.3.0-rc2+ #25 Not tainted
> > ------------------------------------------------------
> > kworker/0:1/12 is trying to acquire lock:
> > 00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev
> > drivers/usb/core/file.c:238 [inline]
> > 00000000cd63e8f1 (minor_rwsem){++++}, at: usb_deregister_dev+0x61/0x270
> > drivers/usb/core/file.c:230
> >
> > but task is already holding lock:
> > 000000001d1989ef (iowarrior_open_disc_lock){+.+.}, at:
> > iowarrior_disconnect+0x45/0x2c0 drivers/usb/misc/iowarrior.c:867
> >
> > which lock already depends on the new lock.
>
> https://syzkaller.appspot.com/bug?extid=ca52394faa436d8131df is
> undoubtedly a duplicate of this.

I've marked it as one, thanks!

Now that we have a reproducer, let's retry Oliver's fix:

#syz test: https://github.com/google/kasan.git e96407b4

[-- Attachment #2: iowarrior.patch --]
[-- Type: text/x-patch, Size: 952 bytes --]

diff --git a/drivers/usb/misc/iowarrior.c b/drivers/usb/misc/iowarrior.c
index ba05dd80a020..f5bed9f29e56 100644
--- a/drivers/usb/misc/iowarrior.c
+++ b/drivers/usb/misc/iowarrior.c
@@ -866,19 +866,20 @@ static void iowarrior_disconnect(struct usb_interface *interface)
 	dev = usb_get_intfdata(interface);
 	mutex_lock(&iowarrior_open_disc_lock);
 	usb_set_intfdata(interface, NULL);
+	/* prevent device read, write and ioctl */
+	dev->present = 0;
 
 	minor = dev->minor;
+	mutex_unlock(&iowarrior_open_disc_lock);
+	/* give back our minor - this will call close() locks need to be dropped at this point*/
 
-	/* give back our minor */
 	usb_deregister_dev(interface, &iowarrior_class);
 
 	mutex_lock(&dev->mutex);
 
 	/* prevent device read, write and ioctl */
-	dev->present = 0;
 
 	mutex_unlock(&dev->mutex);
-	mutex_unlock(&iowarrior_open_disc_lock);
 
 	if (dev->opened) {
 		/* There is a process that holds a filedescriptor to the device ,

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: possible deadlock in usb_deregister_dev
  2019-08-12 12:11     ` Andrey Konovalov
@ 2019-08-12 12:31       ` syzbot
  0 siblings, 0 replies; 6+ messages in thread
From: syzbot @ 2019-08-12 12:31 UTC (permalink / raw)
  To: andreyknvl, gregkh, linux-kernel, linux-usb, oneukum, stern,
	syzkaller-bugs

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger  
crash:

Reported-and-tested-by:  
syzbot+a64a382964bf6c71a9c0@syzkaller.appspotmail.com

Tested on:

commit:         e96407b4 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=cfa2c18fb6a8068e
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=16a8a38c600000

Note: testing is done by a robot and is best-effort only.

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, back to index

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-08-06 14:22 possible deadlock in usb_deregister_dev Oliver Neukum
2019-08-06 14:22 ` syzbot
  -- strict thread matches above, loose matches on Subject: below --
2019-08-05 11:58 syzbot
2019-08-09 18:18 ` syzbot
2019-08-09 19:32   ` Alan Stern
2019-08-12 12:11     ` Andrey Konovalov
2019-08-12 12:31       ` syzbot

Linux-USB Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-usb/0 linux-usb/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-usb linux-usb/ https://lore.kernel.org/linux-usb \
		linux-usb@vger.kernel.org
	public-inbox-index linux-usb

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-usb


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git