Fix: Hanging inside hid_close() #143

Closed
vozhyk-com wants to merge 1 commit from fix-issue-142 into master
vozhyk-com commented 2020-02-01 06:46:11 -06:00 (Migrated from github.com)

#142

Function hid_close() waits exit of read_thread().
Thread read_thread() at the end sets
libusb_cancel_transfer(dev->transfer);
and goes to
while (!dev->cancelled)
libusb_handle_events_completed(usb_context, &dev->cancelled);

where libusb calls function read_callback() that should set dev->cancelled to 1.

The problem is: in normal transfer->status should be LIBUSB_TRANSFER_CANCELLED,
but time to time it is LIBUSB_TRANSFER_COMPLETED, I do not know why.
in that case dev->cancelled never set to 1 and we hang in a while().

#142 Function hid_close() waits exit of read_thread(). Thread read_thread() at the end sets libusb_cancel_transfer(dev->transfer); and goes to while (!dev->cancelled) libusb_handle_events_completed(usb_context, &dev->cancelled); where libusb calls function read_callback() that should set dev->cancelled to 1. The problem is: in normal transfer->status should be LIBUSB_TRANSFER_CANCELLED, but time to time it is LIBUSB_TRANSFER_COMPLETED, I do not know why. in that case dev->cancelled never set to 1 and we hang in a while().
Youw commented 2020-02-01 07:09:49 -06:00 (Migrated from github.com)

In case of LIBUSB_TRANSFER_COMPLETED, libusb_handle_events_completed(usb_context, &dev->cancelled); supposed to set dev->cancelled to TRUE, and it shouldn't be the case

Maybe there is a race condition which we do not encounter for yet, and we better find and fix it, as even if this patch fixes the behaviour, I think leaving hidden race condition is not a good thing to do in general

In case of `LIBUSB_TRANSFER_COMPLETED`, `libusb_handle_events_completed(usb_context, &dev->cancelled);` supposed to set `dev->cancelled` to `TRUE`, and it shouldn't be the case Maybe there is a race condition which we do not encounter for yet, and we better find and fix it, as even if this patch fixes the behaviour, I think leaving hidden race condition is not a good thing to do in general
Youw commented 2020-02-01 07:12:24 -06:00 (Migrated from github.com)

@LudovicRousseau would you mind to take a look at this? Just because you know how libusb works (at least better than me) you might be able to save us some time
Thanks

@LudovicRousseau would you mind to take a look at this? Just because you know how libusb works (at least better than me) you might be able to save us some time Thanks
LudovicRousseau commented 2020-02-01 08:54:03 -06:00 (Migrated from github.com)

I am not a HIDAPI expert. In fact I do not use this API any more since a few years now.

I don't see why adding a new call to libusb_cancel_transfer(dev->transfer); would solve the issue. The first libusb_cancel_transfer() should be enough.

Maybe the test in while(!dev->cancelled) should be updated to also handle the LIBUSB_TRANSFER_COMPLETED case?

I am not a HIDAPI expert. In fact I do not use this API any more since a few years now. I don't see why adding a new call to `libusb_cancel_transfer(dev->transfer);` would solve the issue. The first `libusb_cancel_transfer()` should be enough. Maybe the test in `while(!dev->cancelled)` should be updated to also handle the `LIBUSB_TRANSFER_COMPLETED` case?
vozhyk-com commented 2020-02-01 09:30:48 -06:00 (Migrated from github.com)

I don't see why adding a new call to libusb_cancel_transfer(dev->transfer); would solve the issue. The first libusb_cancel_transfer() should be enough.

You are right, but time to time it is not work.
New call at the end sets status to LIBUSB_TRANSFER_CANCELLED.

The question is why first call 'libusb_cancel_transfer(dev->transfer);' does not do this?
By the way it is not a first call 'libusb_cancel_transfer(dev->transfer);', first call do hid_close() before join to read_thread().
I do not see any other thread that use libusb and can change status to LIBUSB_TRANSFER_COMPLETED.

> I don't see why adding a new call to `libusb_cancel_transfer(dev->transfer);` would solve the issue. The first `libusb_cancel_transfer()` should be enough. You are right, but time to time it is not work. New call at the end sets status to LIBUSB_TRANSFER_CANCELLED. The question is why first call 'libusb_cancel_transfer(dev->transfer);' does not do this? By the way it is not a first call 'libusb_cancel_transfer(dev->transfer);', first call do hid_close() before join to read_thread(). I do not see any other thread that use libusb and can change status to LIBUSB_TRANSFER_COMPLETED.
vozhyk-com commented 2020-02-01 10:08:35 -06:00 (Migrated from github.com)

libusb_cancel_transfer() - function that asynchronously cancels a transfer.
I did try to wait until status will be changed to LIBUSB_TRANSFER_CANCELLED,
but it is not work.
`
diff --git a/libusb/hid.c b/libusb/hid.c
index 92fb021..af93360 100644
--- a/libusb/hid.c
+++ b/libusb/hid.c
@@ -844,8 +844,14 @@ static void *read_thread(void *param)
if no transfers are pending, but that's OK. */
libusb_cancel_transfer(dev->transfer);

+ printf("status[%d]\n", dev->transfer->status);
+ while (dev->transfer->status != LIBUSB_TRANSFER_CANCELLED) {
+ usleep(50);
+ printf("status[%d] != LIBUSB_TRANSFER_CANCELLED... wait...\n", dev->transfer->status);
+ }
+
while (!dev->cancelled)
libusb_handle_events_completed(usb_context, &dev->cancelled);
`
Test output:


iteration: 209, hid_close() done
iteration: 210, going to call hid_close()
status[3]
iteration: 210, hid_close() done
iteration: 211, going to call hid_close()
status[0]
status[0] != LIBUSB_TRANSFER_CANCELLED... wait...
status[0] != LIBUSB_TRANSFER_CANCELLED... wait...
status[0] != LIBUSB_TRANSFER_CANCELLED... wait...
status[0] != LIBUSB_TRANSFER_CANCELLED... wait...

and so on infinitely...

libusb_cancel_transfer() - function that asynchronously cancels a transfer. I did try to wait until status will be changed to LIBUSB_TRANSFER_CANCELLED, but it is not work. ` diff --git a/libusb/hid.c b/libusb/hid.c index 92fb021..af93360 100644 --- a/libusb/hid.c +++ b/libusb/hid.c @@ -844,8 +844,14 @@ static void *read_thread(void *param) if no transfers are pending, but that's OK. */ libusb_cancel_transfer(dev->transfer); \+ printf("status[%d]\n", dev->transfer->status); \+ while (dev->transfer->status != LIBUSB_TRANSFER_CANCELLED) { \+ usleep(50); \+ printf("status[%d] != LIBUSB_TRANSFER_CANCELLED... wait...\n", dev->transfer->status); \+ } \+ while (!dev->cancelled) libusb_handle_events_completed(usb_context, &dev->cancelled); ` Test output: *** iteration: 209, hid_close() done iteration: 210, going to call hid_close() status[3] iteration: 210, hid_close() done iteration: 211, going to call hid_close() status[0] status[0] != LIBUSB_TRANSFER_CANCELLED... wait... status[0] != LIBUSB_TRANSFER_CANCELLED... wait... status[0] != LIBUSB_TRANSFER_CANCELLED... wait... status[0] != LIBUSB_TRANSFER_CANCELLED... wait... and so on infinitely...
Youw commented 2020-02-02 10:25:42 -06:00 (Migrated from github.com)

One more thing: @vozhyk-com what version/build of LibUSB are you using?

Since you're able to reproduce the original issue (I don't have my Linux machine available right now), could you try one more thing? - Enable libusb debug output (in your #142 example): libusb_set_option(ctx, LIBUSB_OPTION_LOG_LEVEL, LIBUSB_LOG_LEVEL_DEBUG); (maybe inside hid_init, for a specific libusb context), and share the output when it hangs.

One more thing: @vozhyk-com what version/build of LibUSB are you using? Since you're able to reproduce the original issue (I don't have my Linux machine available right now), could you try one more thing? - Enable libusb debug output (in your #142 example): `libusb_set_option(ctx, LIBUSB_OPTION_LOG_LEVEL, LIBUSB_LOG_LEVEL_DEBUG);` (maybe inside `hid_init`, for a specific libusb context), and share the output when it hangs.
vozhyk-com commented 2020-02-02 12:35:15 -06:00 (Migrated from github.com)

hidtest.log.tar.gz
See line 47907, it is the last iteration of call of hid_close()

I use Debian 10:

Package: libusb-1.0-0
Version: 2:1.0.22-2
Priority: optional
Section: libs
Source: libusb-1.0
Maintainer: Aurelien Jarno aurel32@debian.org
Installed-Size: 136 kB
Depends: libc6 (>= 2.17), libudev1 (>= 183)
Homepage: http://www.libusb.info
Tag: role::shared-lib
Download-Size: 55.3 kB
APT-Manual-Installed: no
APT-Sources: http://deb.debian.org/debian stable/main amd64 Packages

[hidtest.log.tar.gz](https://github.com/libusb/hidapi/files/4144916/hidtest.log.tar.gz) See line 47907, it is the last iteration of call of hid_close() I use Debian 10: Package: libusb-1.0-0 Version: 2:1.0.22-2 Priority: optional Section: libs Source: libusb-1.0 Maintainer: Aurelien Jarno <aurel32@debian.org> Installed-Size: 136 kB Depends: libc6 (>= 2.17), libudev1 (>= 183) Homepage: http://www.libusb.info Tag: role::shared-lib Download-Size: 55.3 kB APT-Manual-Installed: no APT-Sources: http://deb.debian.org/debian stable/main amd64 Packages
Youw commented 2020-09-26 16:17:14 -05:00 (Migrated from github.com)

Closing in favor of #189

Closing in favor of #189

Pull request closed

Sign in to join this conversation.
No reviewers
No milestone
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
gh-libusb/hidapi!143
No description provided.