Date: Wed, 26 Sep 2018 15:44:26 +0000 From: bugzilla-noreply@freebsd.org To: usb@FreeBSD.org Subject: [Bug 231742] libusb_handle_events_completed() does not return after a transfer is cancelled Message-ID: <bug-231742-19105@https.bugs.freebsd.org/bugzilla/>
next in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D231742 Bug ID: 231742 Summary: libusb_handle_events_completed() does not return after a transfer is cancelled Product: Base System Version: 10.4-STABLE Hardware: Any OS: Any Status: New Severity: Affects Some People Priority: --- Component: usb Assignee: usb@FreeBSD.org Reporter: ludovic.rousseau+freebsd@gmail.com Hello, This bug may be related to Bug #231076. This time I use 2 USB devices instead of 1. When my program exits it stops every USB transfers. I use interrupts transf= ers with a long timeout to read card events. So with 2 readers I have 2 such USB interrupt transfers. The first transfer is cancelled fine and I can close the reader connection. The second transfer is also cancelled with no error but libusb_handle_events_completed() does NOT return and my program is blocked. Here is a log trace when 1 reader is used: ^CLIBUSB_FUNCTION: libusb_handle_events_locked leave 01528296 [679490304] pcscdaemon.c:193:signal_thread() Received signal: 2 00000011 [679490304] pcscdaemon.c:226:signal_thread() Preparing for suicide LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit 00000012 [683937920] ccid_usb.c:1333:InterruptRead() ret: -10 00000007 [683937920] ccid_usb.c:1336:InterruptRead()=20 00000005 [683937920] ccid_usb.c:1331:InterruptRead()=20 LIBUSB_FUNCTION: libusb_handle_events_timeout_completed enter LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb10_handle_events_sub enter 01658982 [679490944] hotplug_libusb.c:403:HPRescanUsbBus() Hotplug stopped 00010624 [679489664] readerfactory.c:1353:RFCleanupReaders() entering clean= ing function 00000008 [679489664] readerfactory.c:1362:RFCleanupReaders() Stopping reade= r: Inside Secure AT90SCR200 00 00 00000005 [679489664] readerfactory.c:610:RFRemoveReader() UnrefReader() cou= nt was: 1 00000003 [679489664] eventhandler.c:175:EHDestroyEventHandler() Stomping thread. 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB1, usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB2, usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000004 [679489664] eventhandler.c:200:EHDestroyEventHandler() Request stopping of polling thread 00000004 [679489664] ifdhandler.c:346:IFDHStopPolling() usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) LIBUSB_FUNCTION: libusb_cancel_transfer enter libusb10.c:1556 LIBUSB_FUNCTION: libusb_cancel_transfer leave retval: 0 LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit 00000809 [683937920] ccid_usb.c:1333:InterruptRead() ret: 0 00000005 [683937920] ccid_usb.c:1355:InterruptRead()=20 00000004 [683937920] ccid_usb.c:1362:InterruptRead() after (0) (3) 00000004 [683937920] ccid_usb.c:1377:InterruptRead() InterruptRead (0/2): 3 00425691 [683937920] eventhandler.c:504:EHStatusHandlerThread() Die 00000030 [679489664] eventhandler.c:215:EHDestroyEventHandler() Thread stom= ped. 00000007 [679489664] readerfactory.c:1126:RFUnInitializeReader() Attempting shutdown of Inside Secure AT90SCR200 00 00. 00000006 [679489664] ifdhandler.c:284:IFDHCloseChannel() usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000006 [679489664] -> 000000 63 00 00 00 00 00 09 00 00 00=20 LIBUSB_FUNCTION: libusb_bulk_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer leave 0 LIBUSB_FUNCTION: libusb_handle_events_timeout_completed enter LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb10_handle_events_sub enter LIBUSB_TRANSFER: sync I/O done LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit LIBUSB_FUNCTION: libusb_bulk_transfer leave LIBUSB_FUNCTION: libusb_bulk_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer leave 0 LIBUSB_FUNCTION: libusb_handle_events_timeout_completed enter LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb10_handle_events_sub enter LIBUSB_TRANSFER: sync I/O done LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit LIBUSB_FUNCTION: libusb_bulk_transfer leave 00000310 [679489664] <- 000000 81 00 00 00 00 00 09 01 00 00=20 00000004 [679489664] ccid_usb.c:942:CloseUSB() Closing USB device: 0/2 00000003 [679489664] ccid_usb.c:952:CloseUSB() Last slot closed. Release resources 00008782 [679489664] ccid_usb.c:189:close_libusb_if_needed() libusb_exit 00000016 [679489664] readerfactory.c:987:RFUnloadReader() Unloading reader driver. 00000027 [679489664] winscard_svc.c:155:ContextsDeinitialize() remaining threads: 0 00000005 [679489664] pcscdaemon.c:785:at_exit() cleaning /var/run/pcscd Now a trace when 2 readers are used: ^C02182975 [679490304] pcscdaemon.c:193:signal_thread() Received signal: 2 00000011 [679490304] pcscdaemon.c:226:signal_thread() Preparing for suicide 00971124 [679490944] hotplug_libusb.c:403:HPRescanUsbBus() Hotplug stopped 00933563 [679489664] readerfactory.c:1353:RFCleanupReaders() entering clean= ing function 00000008 [679489664] readerfactory.c:1362:RFCleanupReaders() Stopping reade= r: Inside Secure AT90SCR200 00 00 00000005 [679489664] readerfactory.c:610:RFRemoveReader() UnrefReader() cou= nt was: 1 00000004 [679489664] eventhandler.c:175:EHDestroyEventHandler() Stomping thread. 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB1, usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB2, usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000003 [679489664] eventhandler.c:200:EHDestroyEventHandler() Request stopping of polling thread 00000004 [679489664] ifdhandler.c:346:IFDHStopPolling() usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) LIBUSB_FUNCTION: libusb_cancel_transfer enter libusb10.c:1556 LIBUSB_FUNCTION: libusb_cancel_transfer leave retval: 0 LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit 00000817 [683937920] ccid_usb.c:1333:InterruptRead() ret: 0 00000006 [683937920] ccid_usb.c:1355:InterruptRead()=20 00000005 [683937920] ccid_usb.c:1362:InterruptRead() after (0) (3) 00000005 [683937920] ccid_usb.c:1377:InterruptRead() InterruptRead (0/2): 3 LIBUSB_FUNCTION: libusb_wait_for_event ERROR tv LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb_wait_for_event enter 00425967 [683937920] eventhandler.c:504:EHStatusHandlerThread() Die 00000037 [679489664] eventhandler.c:215:EHDestroyEventHandler() Thread stom= ped. 00000007 [679489664] readerfactory.c:1126:RFUnInitializeReader() Attempting shutdown of Inside Secure AT90SCR200 00 00. 00000008 [679489664] ifdhandler.c:284:IFDHCloseChannel() usb:2406/6407:libusb-1.0:0:2:0 (lun: 0) 00000006 [679489664] -> 000000 63 00 00 00 00 00 09 00 00 00=20 LIBUSB_FUNCTION: libusb_bulk_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer leave 0 LIBUSB_FUNCTION: libusb_handle_events_timeout_completed enter LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb10_handle_events_sub enter LIBUSB_TRANSFER: sync I/O done LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit LIBUSB_FUNCTION: libusb_bulk_transfer leave LIBUSB_FUNCTION: libusb_bulk_transfer enter LIBUSB_FUNCTION: libusb_submit_transfer enter LIBUSB_FUNCTION: libusb_wait_for_event ERROR tv LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb_wait_for_event enter LIBUSB_FUNCTION: libusb_submit_transfer leave 0 LIBUSB_FUNCTION: libusb_handle_events_timeout_completed enter LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb10_handle_events_sub enter LIBUSB_TRANSFER: sync I/O done LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_timeout_completed exit LIBUSB_FUNCTION: libusb_bulk_transfer leave LIBUSB_FUNCTION: libusb_wait_for_event ERROR tv LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb_wait_for_event enter 00000325 [679489664] <- 000000 81 00 00 00 00 00 09 01 00 00=20 00000014 [679489664] ccid_usb.c:942:CloseUSB() Closing USB device: 0/2 00000003 [679489664] ccid_usb.c:952:CloseUSB() Last slot closed. Release resources 00008720 [679489664] readerfactory.c:1362:RFCleanupReaders() Stopping reade= r: SMSC USX101x Reader (EF149371) 01 00 00000006 [679489664] readerfactory.c:610:RFRemoveReader() UnrefReader() cou= nt was: 1 00000003 [679489664] eventhandler.c:175:EHDestroyEventHandler() Stomping thread. 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB1, usb:0424/1100:libusb-1.0:0:3:0 (lun: 10000) 00000004 [679489664] ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB2, usb:0424/1100:libusb-1.0:0:3:0 (lun: 10000) 00000004 [679489664] eventhandler.c:200:EHDestroyEventHandler() Request stopping of polling thread 00000004 [679489664] ifdhandler.c:346:IFDHStopPolling() usb:0424/1100:libusb-1.0:0:3:0 (lun: 10000) LIBUSB_FUNCTION: libusb_cancel_transfer enter libusb10.c:1556 LIBUSB_FUNCTION: libusb_cancel_transfer leave retval: 0 I modified libUSB to add some more debug. The 2 traces are identical except for this sequence: LIBUSB_FUNCTION: libusb_wait_for_event ERROR tv LIBUSB_FUNCTION: libusb_handle_events_locked leave LIBUSB_FUNCTION: libusb_handle_events_locked enter LIBUSB_FUNCTION: libusb_wait_for_event enter libusb_wait_for_event() returns because it is in the case "tv =3D=3D NULL" = at https://github.com/freebsd/freebsd/blob/master/lib/libusb/libusb10_io.c#L312 The sequence is present 3 times in the case of 2 USB devices. it looks like libusb_cancel_transfer() has (also) an impact to another transfer. I use the same libUSB context for the 2 devices and all the USB transfers. I added logs in libusb_cancel_transfer(). For the 2 transfers that I cancel= the program goes into the case /* make sure the queue doesn't stall */ at line = 1544 https://github.com/freebsd/freebsd/blob/master/lib/libusb/libusb10.c#L1544 I always get this problem when I quit my program with 2 USB devices. So it = is easy to reproduce. Thanks --=20 You are receiving this mail because: You are the assignee for the bug.=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-231742-19105>