Open stepandr47 opened 2 years ago
Hi @stepandr47
Did you install the udev rules? If not please run seabreeze_os_setup
.
Also try running the code without calling list_devices()
first.
If that didn't solve it, please verify that the spectrometer is working by running it on a different machine with the original spectrasuite or oceanview software.
Cheers, Andreas :smiley:
Hi Andreas,
I have tried running it without list_devices() and I get the same result.
Below is the rule created by seabreeze_os_setup for my sensor:
I have verified functionality using the OceanView software with no issue. It is able to read signals successfully and varies based on the amount of light coming in as expected. Please let me know if there is any other information that would be useful for you.
Thanks for the quick reply.
Which version of pyusb
are your running?
import usb; print(usb.__version__)
Based on the image below it is version number 1.2.1
So from your other issue, it seems that you have a flame-t running reliably? Is your ubuntu machine a raspberry pi? and if so does the flame-t work reliably with the pi? If the Flame-T works well on the same machine:
You could try testing a few different versions of pyusb: 1.1.0, 1.2.0, 1.2.1
If that doesn't work we'll have to figure out what the important difference is between the setup in https://github.com/ap--/python-seabreeze/pull/98 and yours. So if you have access to a windows machine I would try running the hdx together with pyseabreeze there.
I can't really provide any hands-on help with debugging because I don't have an HDX...
Yeah that is correct. I am able to do everything fine with the Flame-T. I have a test setup on a Ubuntu VM and a raspberry pi. The Flame-T works with both setups, but I can't get the HDX to work on either. I don't have the HDX with me today, so I will get back to you tomorrow on testing different versions of pyusb.
Okay great. That's valuable information 👍 So we can at least rule out some strange installation issues.
The pyusb versions are a longshot, but it's a super quick test.
Another longshot would be: (packet captures for the OceanFX seem to indicate that the oceanview software uses protocol version 0x0000 to trigger the default OBP protocol of the spectrometer, and since the OceanHDX is also a OBP protocol spectrometer, maybe this will have an effect.)
# run this before any other code
from seabreeze.pyseabreeze.protocol import OBPProtocol
OBPProtocol.OBP.HEADER_PROTOCOL_VERSION = 0x0000
I tried the different versions of pyusb on Ubuntu. I tried each of them with and without the OBPProtocol addition stated in your last comment. It was unable to connect in all case.
I just now tried connecting to the device on Windows and it worked without any issues. I was also able to get data from it.
Any ideas what could be causing the issue on Ubuntu? The only difference I can think of currently is the driver that gets installed when you connect it to the OceanView software.
Okay. This is great. At least we know now that it's some difference between the OSes that's unrelated to the pyusb version.
Hmmm :thinking:
A simple thing I would try is to setup a virtualenv with seabreeze as root on the linux machine and run your test code as root. That rules out that it's some sort of permission issue.
Also try running your script via:
LIBUSB_DEBUG=4 PYUSB_DEBUG=debug python your_code.py
and maybe compare the debug output between linux and windows.
I'm pretty sure we'll be able to figure out what's causing this :+1:
Running the script as root on Ubuntu got the same timeout error. I haven't looked through it yet but below are the outputs from linux. LIBUSB_DEBUG and PYUSB_DEBUG are not recognized on windows. During a quick search I was unable to find how to resolve this issue. One other thing worth mentioning is on windows I was only able to get it working when in a conda environment. I didn't realize my terminal was in one in the morning when I tested, but when I just tested now it won't work without being in the conda environment. Do to that I tried running the ubuntu setup in a conda environment, but it still gets the timed out error.
Linux Output:
To get the same output for windows, you need to set them as environment variables:
set LIBUSB_DEBUG=4
set PYUSB_DEBUG=debug
python your_code.py
(I think that's the right way for cmd.exe, powershell might be different)
Was able to get these debugs working by adding these lines to the start of the script in windows. Noticed your comment after finding this way: import os os.environ['PYUSB_DEBUG'] = 'debug' os.environ['LIBUSB_DEBUG'] = '4'
Windows Output:
Hi @stepandr47
hmm, I was hoping we'd see that the libusb version would differ between the two. As it is, it is probably a bit hard to compare. (the linux output you posted seems to be from an interactive session and the windows output lacks the pyusb debug info)
Could you save the following script on both your windows and linux machine and run it again and copy the full output of the script to this issue:
# test_open_hdx.py
import os
os.environ['LIBUSB_DEBUG'] = "4"
os.environ['PYUSB_DEBUG'] = "debug"
import seabreeze
seabreeze.use('pyseabreeze')
from seabreeze.spectrometers import Spectrometer
print("=== SPECTROMETER OPEN ===")
spec = Spectrometer.from_first_available()
print("=== SPECTROMETER STOP ===")
print(spec)
the following command should work in your linux shell AND in the windows cmd prompt:
python test_open_hdx.py > output.txt 2>&1
It should write all output to the output.txt
file.
Linux Output:
2021-09-23 14:43:24,769 DEBUG:usb.backend.libusb1:_LibUSB.__init__(<CDLL '/home/ubuntu/anaconda3/envs/seabreeze-test/lib/libusb-1.0.so.0', handle 56411679e4c0 at 0x7fed8eccbdc0>)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000023] [0000e75a] libusb: debug [libusb_init] created default context
[ 0.000041] [0000e75a] libusb: debug [libusb_init] libusb v1.0.24.11584
[ 0.000054] [0000e75a] libusb: debug [get_kernel_version] reported kernel version is 5.11.0-34-generic
[ 0.000087] [0000e75a] libusb: debug [op_init] found usbfs at /dev/bus/usb
[ 0.000097] [0000e75a] libusb: debug [op_init] max iso packet length is (likely) 98304 bytes
[ 0.000109] [0000e75a] libusb: debug [op_init] sysfs is available
[ 0.000523] [0000e75e] libusb: debug [linux_udev_event_thread_main] udev event thread entering
[ 0.003073] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: usb2 detached: 0
[ 0.003109] [0000e75a] libusb: debug [linux_get_device_address] scan usb2
[ 0.003155] [0000e75a] libusb: debug [linux_get_device_address] bus=2 dev=1
[ 0.003164] [0000e75a] libusb: debug [linux_enumerate_device] busnum 2 devaddr 1 session_id 513
[ 0.003172] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 2/1 (session 513)
[ 0.003317] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: 2-1 detached: 0
[ 0.003328] [0000e75a] libusb: debug [linux_get_device_address] scan 2-1
[ 0.003364] [0000e75a] libusb: debug [linux_get_device_address] bus=2 dev=2
[ 0.003373] [0000e75a] libusb: debug [linux_enumerate_device] busnum 2 devaddr 2 session_id 514
[ 0.003380] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 2/2 (session 514)
[ 0.003417] [0000e75a] libusb: debug [linux_get_parent_info] dev 0x56411658ae10 (2-1) has parent 0x5641165ca140 (usb2) port 1
[ 0.003508] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: 2-2 detached: 0
[ 0.003519] [0000e75a] libusb: debug [linux_get_device_address] scan 2-2
[ 0.003554] [0000e75a] libusb: debug [linux_get_device_address] bus=2 dev=3
[ 0.003563] [0000e75a] libusb: debug [linux_enumerate_device] busnum 2 devaddr 3 session_id 515
[ 0.003570] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 2/3 (session 515)
[ 0.003611] [0000e75a] libusb: debug [linux_get_parent_info] dev 0x56411631bb20 (2-2) has parent 0x5641165ca140 (usb2) port 2
[ 0.003710] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: 2-2.1 detached: 0
[ 0.003720] [0000e75a] libusb: debug [linux_get_device_address] scan 2-2.1
[ 0.003757] [0000e75a] libusb: debug [linux_get_device_address] bus=2 dev=13
[ 0.003766] [0000e75a] libusb: debug [linux_enumerate_device] busnum 2 devaddr 13 session_id 525
[ 0.003773] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 2/13 (session 525)
[ 0.003813] [0000e75a] libusb: debug [linux_get_parent_info] dev 0x564116543fe0 (2-2.1) has parent 0x56411631bb20 (2-2) port 1
[ 0.003902] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
[ 0.003913] [0000e75a] libusb: debug [linux_get_device_address] scan usb1
[ 0.003949] [0000e75a] libusb: debug [linux_get_device_address] bus=1 dev=1
[ 0.003958] [0000e75a] libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
[ 0.003965] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
[ 0.004083] [0000e75a] libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
[ 0.004093] [0000e75a] libusb: debug [linux_get_device_address] scan 1-1
[ 0.004129] [0000e75a] libusb: debug [linux_get_device_address] bus=1 dev=28
[ 0.004138] [0000e75a] libusb: debug [linux_enumerate_device] busnum 1 devaddr 28 session_id 284
[ 0.004145] [0000e75a] libusb: debug [linux_enumerate_device] allocating new device for 1/28 (session 284)
[ 0.004201] [0000e75a] libusb: debug [linux_get_parent_info] dev 0x56411660c9d0 (1-1) has parent 0x5641165440f0 (usb1) port 1
[ 0.004277] [0000e75a] libusb: debug [usbi_add_event_source] add fd 6 events 1
[ 0.004291] [0000e75a] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.004298] [0000e75a] libusb: debug [usbi_add_event_source] add fd 7 events 1
2021-09-23 14:43:24,773 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 14:43:24,774 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.004848] [0000e75a] libusb: debug [libusb_get_device_list]
2021-09-23 14:43:24,774 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304acd0>)
[ 0.005061] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:24,774 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x7fed8304acd0>)
[ 0.005365] [0000e75a] libusb: debug [libusb_open] open 1.28
[ 0.005404] [0000e75a] libusb: debug [usbi_add_event_source] add fd 8 events 4
2021-09-23 14:43:24,775 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304aeb0>)
[ 0.005526] [0000e75a] libusb: debug [libusb_reset_device]
2021-09-23 14:43:25,246 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304aeb0>)
[ 0.478259] [0000e75a] libusb: debug [libusb_close]
[ 0.478361] [0000e75a] libusb: debug [usbi_remove_event_source] remove fd 8
2021-09-23 14:43:25,248 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304af10>)
[ 0.479477] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,249 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8305e0a0>)
[ 0.480537] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,250 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304af70>)
[ 0.481675] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,251 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8305e100>)
[ 0.482907] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,253 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304afd0>)
[ 0.483987] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,254 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x7fed8304acd0>)
[ 0.485518] [0000e75a] libusb: debug [libusb_open] open 1.28
[ 0.485698] [0000e75a] libusb: debug [usbi_add_event_source] add fd 8 events 4
2021-09-23 14:43:25,255 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0x7fed8ee48760>)
[ 0.486583] [0000e75a] libusb: debug [libusb_reset_device]
2021-09-23 14:43:25,733 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x7fed8ee48760>)
[ 0.964215] [0000e75a] libusb: debug [libusb_close]
[ 0.964255] [0000e75a] libusb: debug [usbi_remove_event_source] remove fd 8
2021-09-23 14:43:25,734 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 14:43:25,734 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.965012] [0000e75a] libusb: debug [libusb_get_device_list]
2021-09-23 14:43:25,734 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>)
[ 0.965322] [0000e75a] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:43:25,735 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x7fed8304ad60>)
[ 0.965955] [0000e75a] libusb: debug [libusb_open] open 1.28
[ 0.966034] [0000e75a] libusb: debug [usbi_add_event_source] add fd 8 events 4
2021-09-23 14:43:25,735 DEBUG:usb.backend.libusb1:_LibUSB.is_kernel_driver_active(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 0)
[ 0.966239] [0000e75a] libusb: debug [libusb_kernel_driver_active] interface 0
2021-09-23 14:43:25,735 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.966505] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,736 DEBUG:usb.backend.libusb1:_LibUSB.set_configuration(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 1)
[ 0.967037] [0000e75a] libusb: debug [libusb_set_configuration] configuration 1
2021-09-23 14:43:25,753 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.983753] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,753 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0)
2021-09-23 14:43:25,753 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.984297] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,754 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0, 0)
2021-09-23 14:43:25,754 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0)
2021-09-23 14:43:25,754 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.985048] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,754 DEBUG:usb.backend.libusb1:_LibUSB.claim_interface(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 0)
[ 0.985448] [0000e75a] libusb: debug [libusb_claim_interface] interface 0
2021-09-23 14:43:25,755 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.985989] [0000e75a] libusb: debug [libusb_alloc_transfer] transfer 0x56411670f858
[ 0.986018] [0000e75a] libusb: debug [libusb_submit_transfer] transfer 0x56411670f858
[ 0.986033] [0000e75a] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.986059] [0000e75a] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.986096] [0000e75a] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.986113] [0000e75a] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.986134] [0000e75a] libusb: debug [usbi_wait_for_events] poll() 3 fds with timeout in 60000ms
[ 0.988468] [0000e75a] libusb: debug [usbi_wait_for_events] poll() returned 1
[ 0.988524] [0000e75a] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.988542] [0000e75a] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.988556] [0000e75a] libusb: debug [handle_bulk_completion] all URBs in transfer reaped --> complete!
[ 0.988571] [0000e75a] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.988588] [0000e75a] libusb: debug [usbi_handle_transfer_completion] transfer 0x56411670f858 has callback 0x7fed83033b90
[ 0.988604] [0000e75a] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.988621] [0000e75a] libusb: debug [libusb_free_transfer] transfer 0x56411670f858
2021-09-23 14:43:25,758 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.989063] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,758 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0)
2021-09-23 14:43:25,759 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.989620] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,759 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0, 0)
2021-09-23 14:43:25,760 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0)
2021-09-23 14:43:25,760 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.991089] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,760 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 1, 0, 0, 0)
2021-09-23 14:43:25,761 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0, 0, 0)
2021-09-23 14:43:25,761 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x7fed8304ad60>, 0)
[ 0.991930] [0000e75a] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:43:25,761 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.992458] [0000e75a] libusb: debug [libusb_alloc_transfer] transfer 0x5641166c80d8
[ 0.992486] [0000e75a] libusb: debug [libusb_submit_transfer] transfer 0x5641166c80d8
[ 0.992500] [0000e75a] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.992525] [0000e75a] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.992566] [0000e75a] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.992582] [0000e75a] libusb: debug [usbi_wait_for_events] poll() 3 fds with timeout in 60000ms
[ 1.993297] [0000e75a] libusb: debug [usbi_wait_for_events] poll() returned 1
[ 1.993530] [0000e75a] libusb: debug [libusb_cancel_transfer] transfer 0x5641166c80d8
[ 1.997455] [0000e75a] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 1.997755] [0000e75a] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 1.997833] [0000e75a] libusb: debug [usbi_wait_for_events] poll() 3 fds with timeout in 60000ms
[ 1.997877] [0000e75a] libusb: debug [usbi_wait_for_events] poll() returned 1
[ 1.997917] [0000e75a] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 1.997946] [0000e75a] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 1.997972] [0000e75a] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 1.998197] [0000e75a] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 1.998255] [0000e75a] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 1.998281] [0000e75a] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 1.998311] [0000e75a] libusb: debug [usbi_handle_transfer_completion] transfer 0x5641166c80d8 has callback 0x7fed83033b90
[ 1.998338] [0000e75a] libusb: debug [sync_transfer_cb] actual_length=0
[ 1.998371] [0000e75a] libusb: debug [libusb_free_transfer] transfer 0x5641166c80d8
=== SPECTROMETER OPEN ===
Traceback (most recent call last):
File "/home/ubuntu/Documents/test_open_hdx.py", line 11, in <module>
spec = Spectrometer.from_first_available()
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/spectrometers.py", line 87, in from_first_available
for dev in list_devices():
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/spectrometers.py", line 36, in list_devices
return list_devices._api.list_devices()
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/api.py", line 104, in list_devices
dev.open()
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/devices.py", line 353, in open
self._serial_number = self.get_serial_number()
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/devices.py", line 393, in get_serial_number
serial_len = ord(protocol.query(0x00000101))
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/protocol.py", line 372, in query
return self.receive(timeout_ms=timeout_ms)
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/protocol.py", line 313, in receive
response = self.transport.read(size=64, timeout_ms=timeout_ms)
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/seabreeze/pyseabreeze/transport.py", line 250, in read
return self._device.pyusb_device.read(endpoint, size, timeout=timeout_ms)
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/usb/core.py", line 1029, in read
ret = fn(
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/usb/_debug.py", line 62, in do_trace
return f(*args, **named_args)
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/usb/backend/libusb1.py", line 846, in bulk_read
return self.__read(self.lib.libusb_bulk_transfer,
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/usb/backend/libusb1.py", line 954, in __read
_check(retval)
File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/usb/backend/libusb1.py", line 602, in _check
raise USBTimeoutError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBTimeoutError: [Errno 110] Operation timed out
2021-09-23 14:43:26,794 DEBUG:usb.backend.libusb1:_LibUSB.release_interface(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>, 0)
[ 2.024823] [0000e75a] libusb: debug [libusb_release_interface] interface 0
2021-09-23 14:43:26,794 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x7fed8304ac70>)
[ 2.025427] [0000e75a] libusb: debug [libusb_close]
[ 2.025481] [0000e75a] libusb: debug [usbi_remove_event_source] remove fd 8
2021-09-23 14:43:26,795 DEBUG:usb.backend.libusb1:_LibUSB._finalize_object()
[ 2.025910] [0000e75a] libusb: debug [libusb_exit]
[ 2.025953] [0000e75a] libusb: debug [libusb_exit] destroying default context
[ 2.026135] [0000e75a] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 2.026223] [0000e75a] libusb: debug [handle_events] event sources modified, reallocating event data
[ 2.026265] [0000e75a] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 0ms
[ 2.026299] [0000e75a] libusb: debug [usbi_wait_for_events] poll() returned 0
[ 2.026324] [0000e75a] libusb: debug [libusb_unref_device] destroy device 1.28
[ 2.026351] [0000e75a] libusb: debug [libusb_unref_device] destroy device 1.1
[ 2.026377] [0000e75a] libusb: debug [libusb_unref_device] destroy device 2.13
[ 2.026403] [0000e75a] libusb: debug [libusb_unref_device] destroy device 2.3
[ 2.026430] [0000e75a] libusb: debug [libusb_unref_device] destroy device 2.2
[ 2.026455] [0000e75a] libusb: debug [libusb_unref_device] destroy device 2.1
[ 2.026481] [0000e75a] libusb: debug [usbi_remove_event_source] remove fd 7
[ 2.026527] [0000e75a] libusb: debug [usbi_remove_event_source] remove fd 6
[ 2.026828] [0000e75e] libusb: debug [linux_udev_event_thread_main] udev event thread exiting
Windows Output:
2021-09-23 14:57:29,833 DEBUG:usb.backend.libusb1:_LibUSB.__init__(<WinDLL 'C:\Users\astephen\Anaconda3\envs\seabreeze-test\Library\bin\libusb-1.0.dll', handle 7ffb354e0000 at 0x18e1fed4eb0>)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000063] [00002d14] libusb: debug [libusb_init] created default context
[ 0.000086] [00002d14] libusb: debug [libusb_init] libusb v1.0.24.11584
[ 0.000154] [00002d14] libusb: debug [get_windows_version] Windows 10 64-bit
[ 0.000177] [00002d14] libusb: debug [htab_create] using 1021 entries hash table
[ 0.000641] [00002d14] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.000914] [00002d14] libusb: info [winusbx_init] libusbK DLL is not available
[ 0.002100] [00002d14] libusb: info [windows_init] UsbDk backend is not available
[ 0.002233] [00002d14] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000358 events 0
[ 0.002257] [00002d14] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.002266] [00002d14] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000380 events 0
2021-09-23 14:57:29,835 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 14:57:29,835 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.002865] [00002d14] libusb: debug [libusb_get_device_list]
[ 0.002988] [00003128] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.014861] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [51]
[ 0.014978] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [52]
[ 0.015084] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [53]
[ 0.015172] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [54]
[ 0.015494] [00002d14] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.015559] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [7]
[ 0.015955] [00002d14] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.016040] [00002d14] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.016052] [00002d14] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.016060] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [1E]
[ 0.016458] [00002d14] libusb: debug [get_api_type] driver(s): WINUSB
[ 0.016518] [00002d14] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.016527] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [39]
[ 0.016824] [00002d14] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_1C26&SUBSYS_21CF17AA&REV_04\3&B1BFB68&0&E8' bus number 1
[ 0.016882] [00002d14] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_1C2D&SUBSYS_21CF17AA&REV_04\3&B1BFB68&0&D0' bus number 2
[ 0.017914] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [52]
[ 0.114514] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.115399] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[ 0.115550] [00002d14] libusb: debug [init_device] (bus: 1, addr: 1, depth: 1, port: 1): 'USB\VID_8087&PID_0024\5&2DF2E661&0&1'
[ 0.116696] [00002d14] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB20\4&35D3A64E&0' reports 3 ports
[ 0.116837] [00002d14] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB20\4&35D3A64E&0'
[ 0.117359] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [7]
[ 0.117617] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.117706] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 216 bytes)
[ 0.117763] [00002d14] libusb: debug [init_device] (bus: 2, addr: 2, depth: 2, port: 4): 'USB\VID_0A5C&PID_217F\60D819AF2C20'
[ 0.118322] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.118739] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.122161] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 93 bytes)
[ 0.122326] [00002d14] libusb: debug [init_device] (bus: 1, addr: 2, depth: 2, port: 5): 'USB\VID_17EF&PID_1003\6&37ACA2D4&0&5'
[ 0.123291] [00002d14] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB20\4&3423CC03&0' reports 3 ports
[ 0.123408] [00002d14] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB20\4&3423CC03&0'
[ 0.123952] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [51]
[ 0.124184] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.125032] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[ 0.125165] [00002d14] libusb: debug [init_device] (bus: 2, addr: 1, depth: 1, port: 1): 'USB\VID_8087&PID_0024\5&C22FC1F&0&1'
[ 0.125712] [00002d14] libusb: debug [winusb_get_device_list] extra GUID: {DBBAD306-1786-4F2E-A8AB-340D45F0653F}
[ 0.125780] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [39]
[ 0.126011] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.127015] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 32 bytes)
[ 0.127211] [00002d14] libusb: debug [init_device] (bus: 2, addr: 3, depth: 2, port: 2): 'USB\VID_2457&PID_2003\HDX01168'
[ 0.138371] [00002d14] libusb: debug [get_api_type] driver(s): WINUSB
[ 0.138656] [00002d14] libusb: debug [get_api_type] matched driver name against WinUSB
2021-09-23 14:57:29,974 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B580>)
[ 0.141411] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,975 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B730>)
[ 0.142334] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,976 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B5E0>)
[ 0.143146] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,976 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B790>)
[ 0.143918] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,977 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>)
[ 0.144651] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,978 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B7F0>)
[ 0.145400] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,979 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B5B0>)
[ 0.146150] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:29,979 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x0000018E1FF6B5B0>)
[ 0.146863] [00002d14] libusb: debug [libusb_open] open 2.3
2021-09-23 14:57:29,980 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B7C0>)
[ 0.147474] [00002d14] libusb: debug [libusb_reset_device]
2021-09-23 14:57:29,982 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B7C0>)
[ 0.148703] [00002d14] libusb: debug [libusb_close]
[ 0.149458] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.2
[ 0.149546] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.149578] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.149792] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.0
2021-09-23 14:57:29,983 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x0000018E1FF6B5B0>)
[ 0.150419] [00002d14] libusb: debug [libusb_open] open 2.3
2021-09-23 14:57:29,984 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D6CDE80>)
[ 0.151042] [00002d14] libusb: debug [libusb_reset_device]
2021-09-23 14:57:29,984 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D6CDE80>)
[ 0.151543] [00002d14] libusb: debug [libusb_close]
[ 0.151834] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.3
[ 0.151879] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.1
[ 0.151904] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.0
2021-09-23 14:57:29,985 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 14:57:29,986 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.152867] [00002d14] libusb: debug [libusb_get_device_list]
[ 0.192601] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [51]
[ 0.192767] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [52]
[ 0.192900] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [53]
[ 0.193028] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [54]
[ 0.193495] [00002d14] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.193590] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [7]
[ 0.194178] [00002d14] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.194301] [00002d14] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.194320] [00002d14] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.194331] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [1E]
[ 0.194932] [00002d14] libusb: debug [get_api_type] driver(s): WINUSB
[ 0.195022] [00002d14] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.195037] [00002d14] libusb: debug [winusb_get_device_list] allocating new device for session [39]
[ 0.195482] [00002d14] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_1C26&SUBSYS_21CF17AA&REV_04\3&B1BFB68&0&E8' bus number 1
[ 0.195550] [00002d14] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_1C2D&SUBSYS_21CF17AA&REV_04\3&B1BFB68&0&D0' bus number 2
[ 0.196994] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [52]
[ 0.197104] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.197686] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[ 0.197743] [00002d14] libusb: debug [init_device] (bus: 1, addr: 1, depth: 1, port: 1): 'USB\VID_8087&PID_0024\5&2DF2E661&0&1'
[ 0.198115] [00002d14] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB20\4&35D3A64E&0' reports 3 ports
[ 0.198161] [00002d14] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB20\4&35D3A64E&0'
[ 0.198359] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [7]
[ 0.198462] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.198496] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 216 bytes)
[ 0.198517] [00002d14] libusb: debug [init_device] (bus: 2, addr: 2, depth: 2, port: 4): 'USB\VID_0A5C&PID_217F\60D819AF2C20'
[ 0.198709] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.198797] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.202067] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 93 bytes)
[ 0.202101] [00002d14] libusb: debug [init_device] (bus: 1, addr: 2, depth: 2, port: 5): 'USB\VID_17EF&PID_1003\6&37ACA2D4&0&5'
[ 0.202397] [00002d14] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB20\4&3423CC03&0' reports 3 ports
[ 0.202446] [00002d14] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB20\4&3423CC03&0'
[ 0.202636] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [51]
[ 0.202722] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.203299] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[ 0.203334] [00002d14] libusb: debug [init_device] (bus: 2, addr: 1, depth: 1, port: 1): 'USB\VID_8087&PID_0024\5&C22FC1F&0&1'
[ 0.203534] [00002d14] libusb: debug [winusb_get_device_list] extra GUID: {DBBAD306-1786-4F2E-A8AB-340D45F0653F}
[ 0.203559] [00002d14] libusb: debug [winusb_get_device_list] found existing device for session [39]
[ 0.203639] [00002d14] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.204441] [00002d14] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 32 bytes)
[ 0.204474] [00002d14] libusb: debug [init_device] (bus: 2, addr: 3, depth: 2, port: 2): 'USB\VID_2457&PID_2003\HDX01168'
[ 0.206137] [00002d14] libusb: debug [get_api_type] driver(s): WINUSB
[ 0.206230] [00002d14] libusb: debug [get_api_type] matched driver name against WinUSB
2021-09-23 14:57:30,040 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B640>)
[ 0.207345] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,040 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B520>)
[ 0.207638] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,041 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B580>)
[ 0.208008] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,041 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B7C0>)
[ 0.208320] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,041 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B5E0>)
[ 0.208613] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,041 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B730>)
[ 0.208899] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,042 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>)
[ 0.209203] [00002d14] libusb: debug [libusb_get_device_descriptor]
2021-09-23 14:57:30,042 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>)
[ 0.209581] [00002d14] libusb: debug [libusb_open] open 2.3
2021-09-23 14:57:30,042 DEBUG:usb.backend.libusb1:_LibUSB.is_kernel_driver_active(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 0)
[ 0.209827] [00002d14] libusb: debug [libusb_kernel_driver_active] interface 0
2021-09-23 14:57:30,042 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.210051] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,043 DEBUG:usb.backend.libusb1:_LibUSB.set_configuration(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 1)
[ 0.210321] [00002d14] libusb: debug [libusb_set_configuration] configuration 1
[ 0.210340] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.210352] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.210363] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.210481] [00002d14] libusb: debug [libusb_claim_interface] interface 0
[ 0.210622] [00002d14] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.210643] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 0.210655] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 0.210768] [00002d14] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 0.210784] [00002d14] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 0.210794] [00002d14] libusb: debug [windows_force_sync_completion] transfer 0000018E1F921758, length 0
[ 0.210806] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.210816] [00002d14] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.210827] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.210840] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.210852] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.210862] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 0
[ 0.210873] [00002d14] libusb: debug [libusb_release_interface] interface 0
[ 0.210884] [00002d14] libusb: debug [auto_release] auto-released interface 0
[ 0.210895] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.210908] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.210920] [00002d14] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.210931] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,045 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.212219] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,045 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,045 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.212652] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,045 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0, 0)
2021-09-23 14:57:30,046 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,046 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.213268] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,046 DEBUG:usb.backend.libusb1:_LibUSB.claim_interface(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 0)
[ 0.213569] [00002d14] libusb: debug [libusb_claim_interface] interface 0
[ 0.213676] [00002d14] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.213695] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 0.213707] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
2021-09-23 14:57:30,046 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.214069] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.214087] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.214098] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.214118] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.214134] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.214211] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.214227] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.214503] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.214567] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.214608] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.214624] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.214638] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.214652] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.214663] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.214675] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,047 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.214983] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,048 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,048 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.215578] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,048 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0, 0)
2021-09-23 14:57:30,048 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,049 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.216214] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,049 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 1, 0, 0, 0)
2021-09-23 14:57:30,049 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,049 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.216786] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,050 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.217135] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.217153] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.217165] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.217180] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.217191] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.217272] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.217288] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.217575] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.217650] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.217694] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.217709] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.217723] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.217738] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.217749] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.217762] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,051 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.218123] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.218141] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.218152] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.218166] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.218176] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.218243] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.218259] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.218353] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.218446] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.218494] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.218507] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.218520] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.218534] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.218545] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.218557] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,052 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.218850] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.218867] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.218878] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.218891] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.218903] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.218969] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.218985] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.219252] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.219339] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.219376] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.219390] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.219413] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.219432] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.219444] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.219457] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,053 DEBUG:usb.backend.libusb1:_LibUSB.release_interface(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>, 0)
[ 0.219738] [00002d14] libusb: debug [libusb_release_interface] interface 0
2021-09-23 14:57:30,053 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>)
[ 0.219977] [00002d14] libusb: debug [libusb_reset_device]
2021-09-23 14:57:30,053 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1FF6B520>)
[ 0.220171] [00002d14] libusb: debug [libusb_close]
[ 0.220298] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.2
[ 0.220321] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.220333] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.220343] [00002d14] libusb: debug [libusb_unref_device] destroy device 1.0
2021-09-23 14:57:30,054 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>)
[ 0.220554] [00002d14] libusb: debug [libusb_open] open 2.3
2021-09-23 14:57:30,054 DEBUG:usb.backend.libusb1:_LibUSB.is_kernel_driver_active(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 0)
[ 0.220841] [00002d14] libusb: debug [libusb_kernel_driver_active] interface 0
2021-09-23 14:57:30,054 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.221076] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,055 DEBUG:usb.backend.libusb1:_LibUSB.set_configuration(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1)
[ 0.221335] [00002d14] libusb: debug [libusb_set_configuration] configuration 1
[ 0.221355] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.221363] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.221371] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.221380] [00002d14] libusb: debug [libusb_claim_interface] interface 0
[ 0.221452] [00002d14] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.221465] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 0.221472] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 0.221533] [00002d14] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 0.221542] [00002d14] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 0.221548] [00002d14] libusb: debug [windows_force_sync_completion] transfer 0000018E1F921758, length 0
[ 0.221557] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.221564] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.221572] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.221580] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.221587] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 0
[ 0.221594] [00002d14] libusb: debug [libusb_release_interface] interface 0
[ 0.221601] [00002d14] libusb: debug [auto_release] auto-released interface 0
[ 0.221608] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.221617] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.221624] [00002d14] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.221705] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,055 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.221994] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.222284] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0, 0)
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.222671] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,056 DEBUG:usb.backend.libusb1:_LibUSB.claim_interface(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 0)
[ 0.222864] [00002d14] libusb: debug [libusb_claim_interface] interface 0
[ 0.222954] [00002d14] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.222967] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 0.222975] [00002d14] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
2021-09-23 14:57:30,057 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.223190] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.223201] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.223209] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.223218] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.223225] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.223291] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.223309] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.223672] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.223725] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.223750] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.223761] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.223772] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.223784] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.223793] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.223801] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,057 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.223976] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,057 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.224272] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0, 0)
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.224681] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 1, 0, 0, 0)
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0, 0, 0)
2021-09-23 14:57:30,058 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0x0000018E1FF6B670>, 0)
[ 0.225067] [00002d14] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 14:57:30,059 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.225344] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.225358] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.225365] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.225375] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.225382] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.225433] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.225444] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.225778] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.225852] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.225878] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.225888] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.225897] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.225907] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.225914] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.225922] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,059 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.226176] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.226188] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.226195] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.226204] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.226211] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.226258] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.226269] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.226337] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.226390] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.226415] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.226426] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.226437] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.226448] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.226457] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.226465] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,060 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.226661] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.226672] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.226680] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.226688] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.226696] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.226743] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.226753] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.226916] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.226961] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.226986] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.226996] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.227007] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.227019] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.227028] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.227036] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,061 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 0, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.227369] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.227381] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.227389] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.227398] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.227405] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.227456] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.227466] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.227785] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.227884] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.227919] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.227929] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.227944] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.227958] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.227966] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.227974] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,061 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.228174] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.228186] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.228193] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.228202] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.228209] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.228257] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.228268] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.228337] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.228387] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.228412] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.228423] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.228433] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.228445] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.228454] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.228462] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,062 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.228684] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.228696] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.228704] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.228712] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.228720] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.228767] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.228777] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.228838] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.228919] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.228954] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.228963] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.228971] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.228980] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.228988] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.229000] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,062 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.229199] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.229211] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.229218] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.229227] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.229234] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.229296] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.229308] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.229716] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.229771] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.229796] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.229807] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.229829] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.229845] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.229858] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.229869] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,063 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.230109] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.230121] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.230128] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.230137] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.230144] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.230191] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.230202] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.230571] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.230664] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.230690] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.230700] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.230708] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.230718] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.230726] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.230734] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,064 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.230938] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.230953] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.230961] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.230970] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.230977] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.231040] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.231054] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.231378] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.231434] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.231460] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.231470] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.231481] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.231493] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.231502] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.231510] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,065 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.231733] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.231745] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.231753] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.231761] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.231769] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.231817] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.231827] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.232149] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.232243] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.232268] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.232279] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.232288] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.232298] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.232305] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.232313] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,066 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.232508] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.232520] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.232527] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.232541] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.232552] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.232598] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.232609] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.232946] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.232991] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.233016] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.233027] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.233037] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.233049] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.233058] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.233066] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,067 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.233287] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.233299] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.233306] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.233315] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.233323] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.233369] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.233379] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.233539] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.233623] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.233652] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.233667] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.233676] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.233686] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.233693] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.233701] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,067 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.233897] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.233918] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.233931] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.233948] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.233956] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.234002] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.234012] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.234084] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.234136] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.234163] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.234174] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.234185] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.234196] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.234205] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.234213] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,068 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.234434] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.234446] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.234453] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.234462] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.234470] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.234517] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.234527] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.234577] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.234599] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.234614] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.234621] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.234629] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.234637] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.234645] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.234652] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,068 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.234832] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.234843] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.234850] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.234859] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.234866] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.234908] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.234918] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.235250] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.235324] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.235350] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.235444] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.235459] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.235469] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.235476] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.235484] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,069 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 5, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.235717] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.235729] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.235736] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.235745] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.235753] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.235800] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.235810] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.236130] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.236202] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.236228] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.236238] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.236264] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.236279] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.236293] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.236302] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,070 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.236521] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.236534] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.236542] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.236551] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.236558] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.236606] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.236616] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.236941] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.236997] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.237022] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.237032] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.237043] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.237055] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.237068] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.237080] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,071 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 6, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.237311] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.237323] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.237330] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.237339] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.237347] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.237394] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.237405] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.237750] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.237831] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.237856] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.237866] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.237875] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.237884] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.237892] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.237900] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,071 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.238124] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.238137] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.238145] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.238154] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.238175] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.238229] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.238241] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.238563] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.238624] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.238649] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.238660] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.238670] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.238682] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.238691] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.238700] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,072 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 17, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 7, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.238929] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.238944] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.238952] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.238961] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.238968] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.239015] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.239026] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.239087] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.239131] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.239157] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.239167] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.239178] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.239190] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.239199] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.239207] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,073 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.239405] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.239417] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.239424] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.239433] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.239440] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.239487] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.239498] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.239842] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.239931] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.239956] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.239966] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.239974] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.239984] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.239991] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.239999] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,074 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 0, 1, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.240382] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.240394] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.240406] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.240418] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.240426] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.240474] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.240485] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.240802] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.240896] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.240921] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.240931] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.240941] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.240951] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.240958] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.240966] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,074 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.241212] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.241224] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.241231] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.241242] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.241249] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.241296] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.241306] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.241641] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.241687] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.241713] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.241723] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.241734] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.241746] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.241755] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.241763] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,075 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.242008] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.242022] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.242029] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.242038] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.242046] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.242107] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.242123] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.242444] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.242541] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.242566] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.242577] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.242586] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.242596] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.242603] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.242611] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,076 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.242810] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.242822] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.242829] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.242838] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.242845] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.242893] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.242903] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.243239] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.243321] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.243346] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.243356] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.243365] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.243375] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.243382] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.243390] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,077 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.243611] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.243622] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.243629] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.243638] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.243646] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.243692] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.243703] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.244018] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.244079] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.244109] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.244123] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.244134] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.244146] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.244153] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.244162] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,078 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.244358] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.244370] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.244377] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.244386] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.244393] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.244438] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.244449] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.244772] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.244856] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.244882] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.244892] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.244902] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.244911] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.244919] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.244927] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,078 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.245145] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.245157] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.245164] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.245173] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.245180] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.245227] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.245241] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.245328] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.245359] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.245381] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.245398] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.245406] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.245415] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.245427] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.245439] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,079 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.245644] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.245656] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.245663] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.245672] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.245679] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.245726] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.245737] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.246059] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.246116] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.246142] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.246152] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.246163] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.246175] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.246184] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.246192] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,080 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 24, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.246461] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.246473] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.246481] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.246490] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.246497] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] writing 64 bytes
[ 0.246544] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.246554] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.246866] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.246937] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.246962] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.246973] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.246983] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.246995] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.247004] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.247012] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
2021-09-23 14:57:30,080 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.247211] [00002d14] libusb: debug [libusb_alloc_transfer] transfer 0000018E1F921758
[ 0.247226] [00002d14] libusb: debug [libusb_submit_transfer] transfer 0000018E1F921758
[ 0.247235] [00002d14] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.247245] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 81 with interface 0
[ 0.247252] [00002d14] libusb: debug [winusbx_submit_bulk_transfer] reading 64 bytes
[ 0.247301] [00002d14] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.247312] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.247636] [00003128] libusb: debug [windows_iocp_thread] transfer 0000018E1F921758 completed, length 64
[ 0.247697] [00002d14] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.247722] [00002d14] libusb: debug [handle_event_trigger] event triggered
[ 0.247733] [00002d14] libusb: debug [windows_handle_transfer_completion] handling transfer 0000018E1F921758 completion with errcode 0, length 64
[ 0.247743] [00002d14] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.247755] [00002d14] libusb: debug [usbi_handle_transfer_completion] transfer 0000018E1F921758 has callback 00007FFB354E8BF0
[ 0.247764] [00002d14] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.247772] [00002d14] libusb: debug [libusb_free_transfer] transfer 0000018E1F921758
=== SPECTROMETER OPEN ===
=== SPECTROMETER STOP ===
<Spectrometer HDX:HDX01168>
2021-09-23 14:57:30,083 DEBUG:usb.backend.libusb1:_LibUSB.release_interface(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>, 0)
[ 0.250441] [00002d14] libusb: debug [libusb_release_interface] interface 0
2021-09-23 14:57:30,083 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0x0000018E1D9EDF10>)
[ 0.250579] [00002d14] libusb: debug [libusb_close]
[ 0.250673] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.3
[ 0.250685] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.1
[ 0.250692] [00002d14] libusb: debug [libusb_unref_device] destroy device 2.0
2021-09-23 14:57:30,083 DEBUG:usb.backend.libusb1:_LibUSB._finalize_object()
[ 0.250843] [00002d14] libusb: debug [libusb_exit]
[ 0.250854] [00002d14] libusb: debug [libusb_exit] destroying default context
[ 0.250861] [00002d14] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000380
[ 0.250879] [00002d14] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000358
[ 0.251001] [00003128] libusb: debug [windows_iocp_thread] I/O completion thread exiting
Hi @stepandr47 Thanks for the clean debug logs ❤️ I asked for advice on how to best proceed with the debugging at pyusb/pyusb#390 I'm sure they'll be able to help.
So, new things to test:
The first Linux output came from a Ubuntu VM. Below is the output from my current Raspberry Pi setup that I had captured yesterday. I won't be able to test with wireshark until Monday as I don't have the sensor with me today. What specifically should I be looking for when going through packets on wireshark? Are you wanting me to just capture using pcap and just post the pcap file here?
Raspberry Pi Output:
2021-09-23 20:15:26,550 DEBUG:usb.backend.libusb1:_LibUSB.__init__(<CDLL 'libusb-1.0.so.0', handle 208c318 at 0xb4cda610>)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000026] [000001ff] libusb: debug [libusb_init] created default context
[ 0.000068] [000001ff] libusb: debug [libusb_init] libusb v1.0.22.11312
[ 0.000138] [000001ff] libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
[ 0.000164] [000001ff] libusb: debug [get_kernel_version] reported kernel version is 5.4.83-v7l+
[ 0.000177] [000001ff] libusb: debug [op_init] bulk continuation flag supported
[ 0.000189] [000001ff] libusb: debug [op_init] zero length packet flag supported
[ 0.000201] [000001ff] libusb: debug [op_init] max iso packet length is (likely) 49152 bytes
[ 0.000229] [000001ff] libusb: debug [op_init] sysfs can relate devices
[ 0.000241] [000001ff] libusb: debug [op_init] sysfs has complete descriptors
[ 0.000575] [00000203] libusb: debug [linux_udev_event_thread_main] udev event thread entering.
[ 0.005170] [000001ff] libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
[ 0.005192] [000001ff] libusb: debug [linux_get_device_address] scan usb1
[ 0.005289] [000001ff] libusb: debug [linux_get_device_address] bus=1 dev=1
[ 0.005304] [000001ff] libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
[ 0.005317] [000001ff] libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
[ 0.005621] [000001ff] libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
[ 0.005637] [000001ff] libusb: debug [linux_get_device_address] scan 1-1
[ 0.005726] [000001ff] libusb: debug [linux_get_device_address] bus=1 dev=2
[ 0.005740] [000001ff] libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
[ 0.005753] [000001ff] libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
[ 0.005840] [000001ff] libusb: debug [linux_get_parent_info] Dev 0x20af5b0 (1-1) has parent 0x20af2b8 (usb1) port 1
[ 0.006083] [000001ff] libusb: debug [linux_get_device_address] getting address for device: 1-1.2 detached: 0
[ 0.006099] [000001ff] libusb: debug [linux_get_device_address] scan 1-1.2
[ 0.006189] [000001ff] libusb: debug [linux_get_device_address] bus=1 dev=3
[ 0.006203] [000001ff] libusb: debug [linux_enumerate_device] busnum 1 devaddr 3 session_id 259
[ 0.006215] [000001ff] libusb: debug [linux_enumerate_device] allocating new device for 1/3 (session 259)
[ 0.006303] [000001ff] libusb: debug [linux_get_parent_info] Dev 0x209d3e8 (1-1.2) has parent 0x20af5b0 (1-1) port 2
[ 0.006553] [000001ff] libusb: debug [linux_get_device_address] getting address for device: usb2 detached: 0
[ 0.006568] [000001ff] libusb: debug [linux_get_device_address] scan usb2
[ 0.006656] [000001ff] libusb: debug [linux_get_device_address] bus=2 dev=1
[ 0.006670] [000001ff] libusb: debug [linux_enumerate_device] busnum 2 devaddr 1 session_id 513
[ 0.006682] [000001ff] libusb: debug [linux_enumerate_device] allocating new device for 2/1 (session 513)
[ 0.006842] [000001ff] libusb: debug [usbi_add_pollfd] add fd 6 events 1
[ 0.006869] [000001ff] libusb: debug [usbi_io_init] using timerfd for timeouts
[ 0.006882] [000001ff] libusb: debug [usbi_add_pollfd] add fd 8 events 1
2021-09-23 20:15:26,558 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 20:15:26,558 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.007703] [000001ff] libusb: debug [libusb_get_device_list]
2021-09-23 20:15:26,559 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb5d82a10>)
[ 0.008181] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:26,559 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4ba6470>)
[ 0.008668] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:26,560 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0xb4ba6470>)
[ 0.009143] [000001ff] libusb: debug [libusb_open] open 1.3
[ 0.009202] [000001ff] libusb: debug [usbi_add_pollfd] add fd 9 events 4
2021-09-23 20:15:26,560 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0xb4ba6410>)
[ 0.009397] [000001ff] libusb: debug [libusb_reset_device]
2021-09-23 20:15:26,790 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0xb4ba6410>)
[ 0.239256] [000001ff] libusb: debug [libusb_close]
[ 0.239278] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 9
2021-09-23 20:15:26,790 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4ba6410>)
[ 0.239584] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:26,790 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4ba6570>)
[ 0.239887] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:26,791 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0xb4ba6470>)
[ 0.240261] [000001ff] libusb: debug [libusb_open] open 1.3
[ 0.240316] [000001ff] libusb: debug [usbi_add_pollfd] add fd 9 events 4
2021-09-23 20:15:26,791 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0xb65c5b30>)
[ 0.240506] [000001ff] libusb: debug [libusb_reset_device]
2021-09-23 20:15:27,020 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0xb65c5b30>)
[ 0.469211] [000001ff] libusb: debug [libusb_close]
[ 0.469232] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 9
2021-09-23 20:15:27,020 INFO:usb.core:find(): using backend "usb.backend.libusb1"
2021-09-23 20:15:27,020 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices()
[ 0.469729] [000001ff] libusb: debug [libusb_get_device_list]
2021-09-23 20:15:27,021 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4b98830>)
[ 0.469999] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:27,021 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>)
[ 0.470288] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:27,021 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0xb4ba65d0>)
[ 0.470865] [000001ff] libusb: debug [libusb_open] open 1.3
[ 0.470923] [000001ff] libusb: debug [usbi_add_pollfd] add fd 9 events 4
2021-09-23 20:15:27,022 DEBUG:usb.backend.libusb1:_LibUSB.is_kernel_driver_active(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 0)
[ 0.471109] [000001ff] libusb: debug [libusb_kernel_driver_active] interface 0
2021-09-23 20:15:27,022 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.471354] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,022 DEBUG:usb.backend.libusb1:_LibUSB.set_configuration(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 1)
[ 0.471716] [000001ff] libusb: debug [libusb_set_configuration] configuration 1
2021-09-23 20:15:27,024 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.473220] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,024 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,024 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.473706] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,025 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0, 0)
2021-09-23 20:15:27,025 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,025 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.474579] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,026 DEBUG:usb.backend.libusb1:_LibUSB.claim_interface(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 0)
[ 0.474990] [000001ff] libusb: debug [libusb_claim_interface] interface 0
2021-09-23 20:15:27,026 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.475350] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x208c6f0
[ 0.475368] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x208c6f0
[ 0.475382] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.475402] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.475438] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.475452] [000001ff] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.475476] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.475499] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 0.475516] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.475529] [000001ff] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.475541] [000001ff] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.475554] [000001ff] libusb: debug [disarm_timerfd]
[ 0.475570] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x208c6f0 has callback 0xb4b63494
[ 0.475583] [000001ff] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.475598] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x208c6f0
2021-09-23 20:15:27,026 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.475921] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,027 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,027 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.476456] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,027 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0, 0)
2021-09-23 20:15:27,028 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,028 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.477157] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,028 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 1, 0, 0, 0)
2021-09-23 20:15:27,028 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,028 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.477832] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,029 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.478419] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x1fb7f78
[ 0.478438] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x1fb7f78
[ 0.478452] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.478470] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.478504] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.478518] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.478541] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 0.478561] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.478573] [000001ff] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.478586] [000001ff] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.478599] [000001ff] libusb: debug [disarm_timerfd]
[ 0.478613] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x1fb7f78 has callback 0xb4b63494
[ 0.478626] [000001ff] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.478641] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x1fb7f78
2021-09-23 20:15:27,030 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.479105] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x208faf0
[ 0.479123] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x208faf0
[ 0.479136] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.479153] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.479181] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.479194] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.479216] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 0.479231] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.479244] [000001ff] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.479256] [000001ff] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.479268] [000001ff] libusb: debug [disarm_timerfd]
[ 0.479283] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x208faf0 has callback 0xb4b63494
[ 0.479296] [000001ff] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.479310] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x208faf0
2021-09-23 20:15:27,030 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.479615] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x2034858
[ 0.479632] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x2034858
[ 0.479645] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.479661] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.479687] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.479700] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.479756] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 0.479777] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.479789] [000001ff] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.479801] [000001ff] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.479838] [000001ff] libusb: debug [disarm_timerfd]
[ 0.479853] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x2034858 has callback 0xb4b63494
[ 0.479866] [000001ff] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.479881] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x2034858
2021-09-23 20:15:27,031 DEBUG:usb.backend.libusb1:_LibUSB.release_interface(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>, 0)
[ 0.480218] [000001ff] libusb: debug [libusb_release_interface] interface 0
2021-09-23 20:15:27,031 DEBUG:usb.backend.libusb1:_LibUSB.reset_device(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>)
[ 0.480480] [000001ff] libusb: debug [libusb_reset_device]
2021-09-23 20:15:27,260 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0xb4ba64d0>)
[ 0.709312] [000001ff] libusb: debug [libusb_close]
[ 0.709342] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 9
2021-09-23 20:15:27,260 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4b98b90>)
[ 0.709687] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:27,261 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb.backend.libusb1._Device object at 0xb4ba66f0>)
[ 0.710102] [000001ff] libusb: debug [libusb_get_device_descriptor]
2021-09-23 20:15:27,261 DEBUG:usb.backend.libusb1:_LibUSB.open_device(<usb.backend.libusb1._Device object at 0xb4ba65d0>)
[ 0.710487] [000001ff] libusb: debug [libusb_open] open 1.3
[ 0.710543] [000001ff] libusb: debug [usbi_add_pollfd] add fd 9 events 4
2021-09-23 20:15:27,261 DEBUG:usb.backend.libusb1:_LibUSB.is_kernel_driver_active(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 0)
[ 0.710721] [000001ff] libusb: debug [libusb_kernel_driver_active] interface 0
2021-09-23 20:15:27,261 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.710907] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,262 DEBUG:usb.backend.libusb1:_LibUSB.set_configuration(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 1)
[ 0.711206] [000001ff] libusb: debug [libusb_set_configuration] configuration 1
2021-09-23 20:15:27,263 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.712343] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,263 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,263 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.712807] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,264 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0, 0)
2021-09-23 20:15:27,264 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,264 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.713460] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,264 DEBUG:usb.backend.libusb1:_LibUSB.claim_interface(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 0)
[ 0.713825] [000001ff] libusb: debug [libusb_claim_interface] interface 0
2021-09-23 20:15:27,265 DEBUG:usb.backend.libusb1:_LibUSB.bulk_write(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 1, 0, array('B', [193, 192, 0, 17, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 20, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 197, 196, 195, 194]), 1000)
[ 0.714177] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x205b170
[ 0.714195] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x205b170
[ 0.714234] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.714255] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.714290] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.714304] [000001ff] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.714327] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.714351] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 0.714368] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=64
[ 0.714381] [000001ff] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.714393] [000001ff] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.714406] [000001ff] libusb: debug [disarm_timerfd]
[ 0.714421] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x205b170 has callback 0xb4b63494
[ 0.714434] [000001ff] libusb: debug [sync_transfer_cb] actual_length=64
[ 0.714449] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x205b170
2021-09-23 20:15:27,265 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.714701] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,266 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,266 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.715163] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,266 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0, 0)
2021-09-23 20:15:27,266 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,266 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.715794] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,267 DEBUG:usb.backend.libusb1:_LibUSB.get_endpoint_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 1, 0, 0, 0)
2021-09-23 20:15:27,267 DEBUG:usb.backend.libusb1:_LibUSB.get_interface_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0, 0, 0)
2021-09-23 20:15:27,267 DEBUG:usb.backend.libusb1:_LibUSB.get_configuration_descriptor(<usb.backend.libusb1._Device object at 0xb4ba65d0>, 0)
[ 0.716447] [000001ff] libusb: debug [libusb_get_config_descriptor] index 0
2021-09-23 20:15:27,267 DEBUG:usb.backend.libusb1:_LibUSB.bulk_read(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 129, 0, array('B', [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 1000)
[ 0.716875] [000001ff] libusb: debug [libusb_alloc_transfer] transfer 0x2052e68
[ 0.716892] [000001ff] libusb: debug [libusb_submit_transfer] transfer 0x2052e68
[ 0.716906] [000001ff] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.716925] [000001ff] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
[ 0.716956] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.716971] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 1.716958] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 1.717020] [000001ff] libusb: debug [handle_events] timerfd triggered
[ 1.717054] [000001ff] libusb: debug [libusb_cancel_transfer] transfer 0x2052e68
[ 1.717179] [000001ff] libusb: debug [disarm_timerfd]
[ 1.717224] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 1.717309] [000001ff] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 1.717364] [000001ff] libusb: debug [handle_events] poll() returned 1
[ 1.717402] [000001ff] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 1.717434] [000001ff] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 1.717465] [000001ff] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 1.717494] [000001ff] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 1.717525] [000001ff] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 1.717555] [000001ff] libusb: debug [disarm_timerfd]
[ 1.717589] [000001ff] libusb: debug [usbi_handle_transfer_completion] transfer 0x2052e68 has callback 0xb4b63494
[ 1.717620] [000001ff] libusb: debug [sync_transfer_cb] actual_length=0
[ 1.717656] [000001ff] libusb: debug [libusb_free_transfer] transfer 0x2052e68
=== SPECTROMETER OPEN ===
Traceback (most recent call last):
File "test_open_hdx.py", line 11, in <module>
spec = Spectrometer.from_first_available()
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/spectrometers.py", line 89, in from_first_available
return cls(dev)
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/spectrometers.py", line 58, in __init__
self.open() # always open the device here to allow caching values
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/spectrometers.py", line 344, in open
self._dev.open()
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/pyseabreeze/devices.py", line 353, in open
self._serial_number = self.get_serial_number()
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/pyseabreeze/devices.py", line 393, in get_serial_number
serial_len = ord(protocol.query(0x00000101))
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/pyseabreeze/protocol.py", line 372, in query
return self.receive(timeout_ms=timeout_ms)
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/pyseabreeze/protocol.py", line 313, in receive
response = self.transport.read(size=64, timeout_ms=timeout_ms)
File "/home/pi/.local/lib/python3.7/site-packages/seabreeze/pyseabreeze/transport.py", line 250, in read
return self._device.pyusb_device.read(endpoint, size, timeout=timeout_ms)
File "/home/pi/.local/lib/python3.7/site-packages/usb/core.py", line 1034, in read
self.__get_timeout(timeout))
File "/home/pi/.local/lib/python3.7/site-packages/usb/_debug.py", line 62, in do_trace
return f(*args, **named_args)
File "/home/pi/.local/lib/python3.7/site-packages/usb/backend/libusb1.py", line 851, in bulk_read
timeout)
File "/home/pi/.local/lib/python3.7/site-packages/usb/backend/libusb1.py", line 954, in __read
_check(retval)
File "/home/pi/.local/lib/python3.7/site-packages/usb/backend/libusb1.py", line 602, in _check
raise USBTimeoutError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBTimeoutError: [Errno 110] Operation timed out
2021-09-23 20:15:28,290 DEBUG:usb.backend.libusb1:_LibUSB.release_interface(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>, 0)
[ 1.739881] [000001ff] libusb: debug [libusb_release_interface] interface 0
2021-09-23 20:15:28,291 DEBUG:usb.backend.libusb1:_LibUSB.close_device(<usb.backend.libusb1._DeviceHandle object at 0xb6661d50>)
[ 1.740349] [000001ff] libusb: debug [libusb_close]
[ 1.740398] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 9
2021-09-23 20:15:28,291 DEBUG:usb.backend.libusb1:_LibUSB._finalize_object()
[ 1.740837] [000001ff] libusb: debug [libusb_exit]
[ 1.740869] [000001ff] libusb: debug [libusb_exit] destroying default context
[ 1.740903] [000001ff] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 1.740931] [000001ff] libusb: debug [handle_events] poll fds modified, reallocating
[ 1.740975] [000001ff] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[ 1.741011] [000001ff] libusb: debug [handle_events] poll() returned 0
[ 1.741085] [000001ff] libusb: debug [libusb_unref_device] destroy device 2.1
[ 1.741117] [000001ff] libusb: debug [libusb_unref_device] destroy device 1.3
[ 1.741145] [000001ff] libusb: debug [libusb_unref_device] destroy device 1.2
[ 1.741174] [000001ff] libusb: debug [libusb_unref_device] destroy device 1.1
[ 1.741202] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 6
[ 1.741290] [000001ff] libusb: debug [usbi_remove_pollfd] remove fd 8
[ 1.741420] [00000203] libusb: debug [linux_udev_event_thread_main] udev event thread exiting
What specifically should I be looking for when going through packets on wireshark? Are you wanting me to just capture using pcap and just post the pcap file here?
If you could just post the pcap file that would be great. Tbh, I'm not entirely sure what to look for either. Which is why I think having the pcap file will make it a lot easier to ask the libusb experts for further advice.
If you compare for example your virtual machine logs with the Pi logs, you can see, that they error in different parts of the code. The VM log errors on the first read, whereas the Pi log goes through a few more commands before it errors.
Interestingly both error when requesting the length of the serial number buffer, just after the device gets opened. I will open a new branch and increase the write/read timeout for that command to something large. Maybe that solves the issue.
Command 1 : pip3 install git+https://github.com/ap--/python-seabreeze.git@hdx-increased-timeout-test
Command 2: git clone https://github.com/ap--/python-seabreeze.git cd python-seabreeze git fetch hdx-increased-timeout-test git checkout feature hdx-increased-timeout-test cd python-seabreeze pip3 install .
I am unsure what I did wrong for installing a specific branch on my Ubuntu VM. The above commands to install a specific branch work on windows, but when I try it on my Ubuntu VM I get the below output. I see that it says libusb not found at the end, but libusb is already installed so I am unsure what is causing that.
Ouput: Processing /home/ubuntu/Documents/python-seabreeze DEPRECATION: A future pip version will change local packages to be built in-place without first copying to a temporary directory. We recommend you use --use-feature=in-tree-build to test your packages with this new behavior before it becomes the default. pip 21.3 will remove support for this functionality. You can find discussion regarding this at pypa/pip#7555. Installing build dependencies ... done Getting requirements to build wheel ... error ERROR: Command errored out with exit status 1: command: /home/ubuntu/anaconda3/envs/seabreeze-test/bin/python3.9 /home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py get_requires_for_build_wheel /tmp/tmpkrt1q8iw cwd: /tmp/pip-req-build-u9268cpc Complete output (22 lines): Traceback (most recent call last): File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py", line 349, in main() File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py", line 331, in main json_out['return_val'] = hook(**hook_input['kwargs']) File "/home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py", line 117, in get_requires_for_build_wheel return hook(config_settings) File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/setuptools/build_meta.py", line 154, in get_requires_for_build_wheel return self._get_build_requires( File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/setuptools/build_meta.py", line 135, in _get_build_requires self.run_setup() File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/setuptools/build_meta.py", line 258, in run_setup super(_BuildMetaLegacyBackend, File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/setuptools/build_meta.py", line 150, in run_setup exec(compile(code, file, 'exec'), locals()) File "setup.py", line 71, in compile_opts = pkgconfig.parse("libusb") File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/pkgconfig/pkgconfig.py", line 248, in parse _raise_if_not_exists(package) File "/tmp/pip-build-env-o1v4khou/overlay/lib/python3.9/site-packages/pkgconfig/pkgconfig.py", line 103, in _raise_if_not_exists raise PackageNotFoundError(package) pkgconfig.pkgconfig.PackageNotFoundError: libusb not found WARNING: Discarding file:///home/ubuntu/Documents/python-seabreeze. Command errored out with exit status 1: /home/ubuntu/anaconda3/envs/seabreeze-test/bin/python3.9 /home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py get_requires_for_build_wheel /tmp/tmpkrt1q8iw Check the logs for full command output. ERROR: Command errored out with exit status 1: /home/ubuntu/anaconda3/envs/seabreeze-test/bin/python3.9 /home/ubuntu/anaconda3/envs/seabreeze-test/lib/python3.9/site-packages/pip/_vendor/pep517/in_process/_in_process.py get_requires_for_build_wheel /tmp/tmpkrt1q8iw Check the logs for full command output.
You need to follow: https://python-seabreeze.readthedocs.io/en/latest/install.html#step-1-linux
probably you're missing: sudo apt-get install git-all build-essential libusb-dev
That was it thanks. I installed that branch on windows, ubuntu and RPi. Still only working on windows. I have also captured the pcap for windows and ubuntu. I am unsure of a good way to do this on a RPi via ssh. Both of the files can be found in the below zip file. pcap_files.zip
Just a quick question: do you connect the spectrometer through a USB hub on the PI? Just looking at the packet captures it seems the VM communicates through a USB hub. The Windows captures don't mention a hub.
I did the packet capture through Windows Wireshark while the device was connected to a Ubuntu VM. So windows seems to see it from the VM as a USB hub.
So just to be clear, the three test systems are:
And neither in 1+2 nor in 3 is a physical USB hub involved.
Yes that is all correct
Okay, so the packet capture was not conclusive. https://github.com/pyusb/pyusb/issues/390#issuecomment-928607736 I guess we continue the Quest and our next stop is the linux-usb mailing list. :crossed_swords: :european_castle: :dragon:
In the meantime we should investigate if the control requests are problematic.
This all relates to this class: https://github.com/ap--/python-seabreeze/blob/5ed92090d773932b04c5cc4da3cee3709516767d/src/seabreeze/pyseabreeze/transport.py#L161
Basically pyseabreeze grew organically out of the predecessor package python-oceanoptics
and I refactored everything back then to adhere to the same api that libseabreeze exposed. It's possible that the order of calls made in there is incorrect, but has not affected a significant amount of the userbase so far.
So, if you could create two more packet captures from the linux VM for the following two scripts, that would allow us to check if there are differences between the two backends. NOTE: this would need to be done with the Flame-T
# cseabreeze test
import seabreeze
seabreeze.use('cseabreeze')
from seabreeze.spectrometers import Spectrometer
print(Spectrometer.from_first_available())
# pyseabreeze test
import seabreeze
seabreeze.use('pyseabreeze')
from seabreeze.spectrometers import Spectrometer
print(Spectrometer.from_first_available())
Below are the two pcap files stored in a zip folder. One for pyseabreeze and one for cseabreeze when using the above scripts to detect the Flame-T. These were both run on the Ubuntu VM.
I have witnessed a similar behavior before when running Linux (I think it was Ubuntu) in a VM and connecting to the HDX through USB. In my experience the connection was working when I installed the correct version of libusb there. For life of me I cannot remember which version was it as I'm currently running HDX on a daily basis through the ethernet with a highly experimental fork of the library.
Hi @Lavikjo Thanks, that's valuable information! Do you at least remember if you built libusb from source or installed a pre-packaged version?
Cheers, Andreas 😃
Hi @stepandr47
Given Lavikjo's comment so far, I think it might be worth trying different pyusb backends.
I pushed changes to the master branch that allow requesting a specific backend for pyusb
via pyseabreeze
.
Please install the latest version of python-seabreeze from the master branch and try if one of those might work for you:
# pyseabreeze using libusb1 (this is what currently doesn't work for you)
import seabreeze
print(seabreeze.__version__)
seabreeze.use('pyseabreeze', pyusb_backend='libusb1')
from seabreeze.spectrometers import Spectrometer
print(Spectrometer.from_first_available())
# pyseabreeze using libusb0 (you might have to `apt install libusb-0.1-4`)
import seabreeze
print(seabreeze.__version__)
seabreeze.use('pyseabreeze', pyusb_backend='libusb0')
from seabreeze.spectrometers import Spectrometer
print(Spectrometer.from_first_available())
# pyseabreeze using openusb (you might have to `apt install libopenusb0`)
import seabreeze
print(seabreeze.__version__)
seabreeze.use('pyseabreeze', pyusb_backend='openusb')
from seabreeze.spectrometers import Spectrometer
print(Spectrometer.from_first_available())
Hi @Lavikjo Thanks, that's valuable information! Do you at least remember if you built libusb from source or installed a pre-packaged version?
Cheers, Andreas 😃
Most likely it was something pre-built from aptitude.
The outputs for each script can be seen below.
1.3.0.post23+gf277e90
Traceback (most recent call last):
File "libusb1.py", line 5, in <module>
print(Spectrometer.from_first_available())
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 87, in from_first_available
for dev in list_devices():
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 36, in list_devices
return list_devices._api.list_devices()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/api.py", line 104, in list_devices
dev.open()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 345, in open
self._serial_number = self.get_serial_number()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 385, in get_serial_number
serial_len = ord(protocol.query(0x00000101))
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 369, in query
return self.receive(timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 310, in receive
response = self.transport.read(size=64, timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/transport.py", line 250, in read
return self._device.pyusb_device.read(endpoint, size, timeout=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/core.py", line 1029, in read
ret = fn(
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb1.py", line 846, in bulk_read
return self.__read(self.lib.libusb_bulk_transfer,
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb1.py", line 954, in __read
_check(retval)
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb1.py", line 602, in _check
raise USBTimeoutError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBTimeoutError: [Errno 110] Operation timed out
1.3.0.post23+gf277e90
Traceback (most recent call last):
File "libusb0.py", line 5, in <module>
print(Spectrometer.from_first_available())
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 87, in from_first_available
for dev in list_devices():
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 36, in list_devices
return list_devices._api.list_devices()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/api.py", line 104, in list_devices
dev.open()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 345, in open
self._serial_number = self.get_serial_number()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 385, in get_serial_number
serial_len = ord(protocol.query(0x00000101))
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 369, in query
return self.receive(timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 310, in receive
response = self.transport.read(size=64, timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/transport.py", line 250, in read
return self._device.pyusb_device.read(endpoint, size, timeout=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/core.py", line 1029, in read
ret = fn(
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb0.py", line 553, in bulk_read
return self.__read(_lib.usb_bulk_read,
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb0.py", line 692, in __read
ret = int(_check(fn(
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/libusb0.py", line 446, in _check
raise USBTimeoutError(errmsg, ret, -ret)
usb.core.USBTimeoutError: [Errno 110] b'could not get bound driver: No data available'
1.3.0.post23+gf277e90
Traceback (most recent call last):
File "openusb.py", line 5, in <module>
print(Spectrometer.from_first_available())
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 87, in from_first_available
for dev in list_devices():
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/spectrometers.py", line 36, in list_devices
return list_devices._api.list_devices()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/api.py", line 104, in list_devices
dev.open()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 345, in open
self._serial_number = self.get_serial_number()
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/devices.py", line 385, in get_serial_number
serial_len = ord(protocol.query(0x00000101))
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 369, in query
return self.receive(timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/protocol.py", line 310, in receive
response = self.transport.read(size=64, timeout_ms=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/seabreeze/pyseabreeze/transport.py", line 250, in read
return self._device.pyusb_device.read(endpoint, size, timeout=timeout_ms)
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/core.py", line 1029, in read
ret = fn(
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/openusb.py", line 664, in bulk_read
_check(_lib.openusb_bulk_xfer(dev_handle, intf, ep, byref(request)))
File "/home/ubuntu/.local/lib/python3.8/site-packages/usb/backend/openusb.py", line 510, in _check
raise USBTimeoutError(_lib.openusb_strerror(ret), ret, _openusb_errno[ret])
usb.core.USBTimeoutError: [Errno 110] b'I/O timeout'
Hi @stepandr47, I'm having the same issue, have we had any changes since your first report?
I'm having the same issue with the FX as well. I have one on hand and can provide any wireshark or usb debug logs as needed.
I'm seeing the same issue with Ubuntu 22.04 and also Raspberry Pi running Raspian. Interestingly, I can get it to work periodically on Ubuntu Desktop. Usb debug logs here:
Same problem here with a HDX connected by usb on a dell laptop. I've tried libusb0 and libusb1.
Interestingly when I use seabreeze.use('pyseabreeze', pyusb_backend='openusb') and run list_devices():
If I'm using csearbreeze, I always get an empty list, without error.
It seems a lot of debugging have been tried, but I can help if necessary...
I'm also in a similar condition, spectrometer works with cbreeze, but when I try to use pyseabreeze, I get an error saying that the usb port is busy.... my spectrometer is QEPRO
I'm also in a similar condition, spectrometer works with cbreeze, but when I try to use pyseabreeze, I get an error saying that the usb port is busy.... my spectrometer is QEPRO
@dstr951 Please open a new issue for the QEPRO.
This is now possible if connecting via Ethernet.
spectrometer and system information
current problem
I am unable to connect to the HDX spectrometer. When I run list_devices() it displays:![image](https://user-images.githubusercontent.com/47436247/134058429-cdab3061-e12c-41f4-a680-aebe6ad2f14d.png)
This is the correct serial number for my device. I then have tried to connect to the device with from_serial_number(HDX01168) or from_first_available(). Both of these will give the below output on the first attempt:![image](https://user-images.githubusercontent.com/47436247/134058825-7afb4e61-0516-47f7-9bfe-f2b077b3081d.png)
Looking through the tickets I noticed that HDX support has been added, so I am unsure what I am doing incorrectly here.
steps to reproduce
Run below code with the HDX connected:
It seems like other users have gotten functionality working for an HDX spectrometer so I was wondering what I am doing incorrectly in the above implmentation.