Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

1.0.26-rc1 test matrix #1099

Closed
13 of 14 tasks
tormodvolden opened this issue Mar 27, 2022 · 27 comments
Closed
13 of 14 tasks

1.0.26-rc1 test matrix #1099

tormodvolden opened this issue Mar 27, 2022 · 27 comments
Labels
Release Related to release and milestone
Milestone

Comments

@tormodvolden
Copy link
Contributor

tormodvolden commented Mar 27, 2022

For as many platforms as possible we want to test building and a run of the RC. At least xusb or lsusb -v should be tested. Please use the libusb-1.0.26-rc1.tar.bz2 tarball, and not a git checkout. Use the included configure script, no autogen or bootstrap needed.

Also more application testing is welcome, in particular those who had issues in 1.0.25.

Major platforms

Linux x86_64

  • build: gcc 9.3 (Ubuntu 20.04), gcc 11.2 (Arch Linux)
  • run: xusb, lsusb, dfu-util, libfreenect

Linux arm64 (Raspbian buster)

  • build: gcc 8.3 OK (with and without udev)
  • run: xusb, lsusb, dfu-util

Windows 10 64-bit

  • build: (appveyor does this)
  • run: xusb, libfreenect (crossbuild MinGW)

macOS 12 Intel, macOS 12 ARM64

(mcuee, see following posts)

Other platforms

Windows 32-bit

  • build: (appveyor cross-build on 64-bit)
  • run: dfu-util, lsusb - at least test 32-bit builds on 64-bit OS

macOS 11.6.1 Intel

  • build: Apple clang version 13.0.0 (built both for 11.6 and 10.7)
  • run: lsusb, dfu-util, pyusb

NetBSD, OpenBSD, Haiku

(mcuee, see following posts)

Applications

  • isochronous streaming with libfreenect on XBox - with WinUSB (!)
  • isochronous IN & OUT streaming with custom device (WinUSB, Linux)
  • HackRF HS bulk streaming (WinUSB, Linux)
  • gutenberg printer drivers
@tormodvolden tormodvolden added this to the 1.0.26 milestone Mar 27, 2022
@tormodvolden tormodvolden pinned this issue Mar 27, 2022
@mcuee mcuee added the Release Related to release and milestone label Mar 28, 2022
@mcuee
Copy link
Member

mcuee commented Mar 28, 2022

Let me try the following. I will see what I can do with more difficult testing involved more transfer type including isochronous transfer.

macOS 12.3 ARM64 (mac Mini M1)

  • build: Apple clang 13.1.6
  • run: xusb, listdev, testlibusb, stress (from libusb project), lsusb, libftdi 1.5 release (find_all, eeprom)

macOS 12.3 x86_64 using Rosetta Translation, not native (mac Mini M1)

  • build:Apple clang 13.1.6
  • run: xusb, listdev, testlibusb, stress (from libusb project), lsusb, libftdi 1.5 release (find_all, eeprom)

Linux x86_64 (Ubuntu 20.04)

  • build: gcc 9.4, known warnings in umockdev
  • run: xusb, listdev, testlibusb, stress and umockdev (from libusb project); lsusb, libftdi 1.5 release (find_all, eeprom)

Linux ARM32 (Raspberry Pi 400 running Raspberry Pi OS Bullseye 32 bit)

  • build: gcc 10.2.1
  • run: xusb, listdev, testlibusb, stress (from libusb project), lsusb, libftdi 1.5 release (find_all, eeprom)

Linux ARM64 (Raspberry Pi 400 running Raspberry Pi OS Bullseye 64 bit)

  • build: gcc 10.2.1
  • run: xusb, listdev, testlibusb, stress (from libusb project), lsusb, libftdi 1.5 release (find_all, eeprom)

Windows VS2019 64 bit (Windows 11 x64 laptop)

  • build:
  • run: xusb, listdev, testlibusb, stress (from libusb project); libftdi 1.5 release (find_all, eeprom)

Windows VS2019 32 bit (Windows 11 x64 laptop)

  • build:
  • run: xusb, listdev, testlibusb, stress (from libusb project); libftdi 1.5 release (find_all, eeprom)

Windows MinGW 64 bit (Windows 11 x64 laptop)

  • build: MSYS2 MinGW-w64 64bit GCC 11.2.0, OK with warnings.
  • run: xusb, listdev, testlibusb, stress (from libusb project)

Windows MinGW 32 bit (Windows 11 x64 laptop)

  • build: MinGW-w64 32 bit GCC 11.2.0, OK with warnings.
  • run: xusb, listdev, testlibusb, stress (from libusb project)

I will carry out the tests on the following platforms as well using Virtualbox VMs under the Windows 11 x64 laptop.

OpenBSD 64 bit (x86_64) -- OpenBSD 7.0 release, VirtualBox VM

  • build: OpenBSD clang 11.1.0
  • run: xusb, listdev, testlibusb, stress (from libusb project)

NetBSD 64 bit (x86_64) -- NetBSD 9.2 release, VirtualBox VM

  • build: NetNSD GCC 7.5.0 OK
  • run: xusb, listdev, testlibusb, stress (from libusb project) --OK

Haiku 64 bit (x86_64) -- r1beta3 release, VirtualBox VM

  • build: build: gcc 8.3.0 Failed -- needs some fixes from Haiku OS side. This does not need to be fixed in libusb-1.0.26 release.
  • run:

@mcuee
Copy link
Member

mcuee commented Mar 28, 2022

Not so sure who will be able to test the following. But we should just proceed with the release if nobody chimed in to test the following platforms.

Solaris 64 bit (x86_64)

  • build:
  • run:

Haiku 64 bit (x86_64) -- probably more recent build (snapshot build)

  • build:
  • run:

Windows on ARM 32 bit

  • build: VS2019: OK
  • run: no machine to test

Windows on ARM 64 bit

  • build: VS2019: OK
  • run: no machine to test

@mcuee
Copy link
Member

mcuee commented Mar 28, 2022

This may be specific to usbutils under macOS (Homebrew formular usbutils).

mcuee@mcuees-Mac-mini libusb-1.0.26-rc1 % brew reinstall libusb
==> Cloning https://github.com/libusb/libusb.git
Updating /Users/mcuee/Library/Caches/Homebrew/libusb--git
From https://github.com/libusb/libusb
   4622bfc..78de7dc  master     -> origin/master
==> Checking out branch master
Already on 'master'
Your branch is behind 'origin/master' by 25 commits, and can be fast-forwarded.
  (use "git pull" to update your local branch)
HEAD is now at 78de7dc libusb 1.0.26-rc1
==> Reinstalling libusb 
==> ./autogen.sh
==> ./configure --prefix=/opt/homebrew/Cellar/libusb/HEAD-78de7dc
==> make install
🍺  /opt/homebrew/Cellar/libusb/HEAD-78de7dc: 22 files, 595KB, built in 17 seconds
==> Running `brew cleanup libusb`...
Disable this behaviour by setting HOMEBREW_NO_INSTALL_CLEANUP.
Hide these hints with HOMEBREW_NO_ENV_HINTS (see `man brew`).

mcuee@mcuees-Mac-mini libusb-1.0.26-rc1 % brew reinstall usbutils
==> Downloading https://mirrors.edge.kernel.org/pub/linux/utils/usb/usbutils/usb
Already downloaded: /Users/mcuee/Library/Caches/Homebrew/downloads/efeb221070cbeb34bf109ccc7027b9cf51afc64ddb820b93ed88a018fc0e92b1--usbutils-007.tar.xz
==> Reinstalling mikhailai/misc/usbutils 
==> ./configure --prefix=/opt/homebrew/Cellar/usbutils/007
==> make install AM_LDFLAGS= SUBDIRS= bin_SCRIPTS= man_MANS=lsusb.8
🍺  /opt/homebrew/Cellar/usbutils/007: 13 files, 821KB, built in 8 seconds
==> Running `brew cleanup usbutils`...
Disable this behaviour by setting HOMEBREW_NO_INSTALL_CLEANUP.
Hide these hints with HOMEBREW_NO_ENV_HINTS (see `man brew`).

mcuee@mcuees-Mac-mini libusb-1.0.26-rc1 % lsusb
libusb: warning [libusb_init] installing new context as implicit default
Bus 002 Device 006: ID 0bda:5411 Realtek Semiconductor Corp. 
Bus 002 Device 005: ID 05e3:0749 Genesys Logic, Inc. 
Bus 002 Device 004: ID 0bda:0411 Realtek Semiconductor Corp. 
Bus 002 Device 003: ID 0b95:1790 ASIX Electronics Corp. 
Bus 002 Device 002: ID 0bda:0411 Realtek Semiconductor Corp. 
Bus 002 Device 001: ID 0bda:5411 Realtek Semiconductor Corp. 
libusb: warning [libusb_exit] device 2.6 still referenced
libusb: warning [libusb_exit] device 2.5 still referenced
libusb: warning [libusb_exit] device 2.4 still referenced
libusb: warning [libusb_exit] device 2.3 still referenced
libusb: warning [libusb_exit] device 2.2 still referenced
libusb: warning [libusb_exit] device 2.1 still referenced```

@tormodvolden
Copy link
Contributor Author

tormodvolden commented Mar 28, 2022

usbutils 007 is from 2013... Didn't we get latest usbutils properly into homebrew recently? Or are you somehow stuck with mikhailai's version?

@mcuee
Copy link
Member

mcuee commented Mar 28, 2022

MSYS2 MinGW gcc 11.2 still have the same warning as in 1.0.25 release. But I think the understanding is that it seems to be a gcc issue. So we do not need to fix this.

Ref:

$ make
make  all-recursive
make[1]: Entering directory '/c/work/libusb/libusb-1.0.26-rc1/build64'
Making all in libusb
make[2]: Entering directory '/c/work/libusb/libusb-1.0.26-rc1/build64/libusb'
  CC       core.lo
  CC       descriptor.lo
  CC       hotplug.lo
  CC       io.lo
  CC       strerror.lo
  CC       sync.lo
  CC       os/events_windows.lo
  CC       os/threads_windows.lo
  RC       libusb-1.0.lo
  CC       os/windows_common.lo
  CC       os/windows_usbdk.lo
  CC       os/windows_winusb.lo
../../libusb/os/windows_winusb.c: In function 'winusbx_copy_transfer_data':
../../libusb/os/windows_winusb.c:97:32: warning: implicit conversion from 'enum libusb_error' to 'enum libusb_transfer_status' [-Wenum-conversion]
   97 |                         return LIBUSB_ERROR_ACCESS;     \
      |                                ^~~~~~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c:97:32: note: in definition of macro 'CHECK_WINUSBX_AVAILABLE'
   97 |                         return LIBUSB_ERROR_ACCESS;     \
      |                                ^~~~~~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c: In function '_hid_get_descriptor.constprop':
../../libusb/os/windows_winusb.c:3358:21: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3358 |         id->bLength = LIBUSB_DT_INTERFACE_SIZE;
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3359:29: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3359 |         id->bDescriptorType = LIBUSB_DT_INTERFACE;
      |         ~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3360:30: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3360 |         id->bInterfaceNumber = 0;
      |         ~~~~~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3361:31: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3361 |         id->bAlternateSetting = 0;
      |         ~~~~~~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3362:27: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3362 |         id->bNumEndpoints = num_endpoints;
      |         ~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3363:29: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3363 |         id->bInterfaceClass = 3;
      |         ~~~~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3364:32: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3364 |         id->bInterfaceSubClass = 0;
      |         ~~~~~~~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3365:32: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3365 |         id->bInterfaceProtocol = 0;
      |         ~~~~~~~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3366:24: warning: array subscript 'struct libusb_interface_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3366 |         id->iInterface = 0;
      |         ~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3372:29: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3372 |                 ed->bLength = LIBUSB_DT_ENDPOINT_SIZE;
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3373:37: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3373 |                 ed->bDescriptorType = LIBUSB_DT_ENDPOINT;
      |                 ~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3374:38: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3374 |                 ed->bEndpointAddress = HID_IN_EP;
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3375:34: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3375 |                 ed->bmAttributes = 3;
      |                 ~~~~~~~~~~~~~~~~~^~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3376:36: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3376 |                 ed->wMaxPacketSize = hid_priv->input_report_size - 1;
      |                 ~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
../../libusb/os/windows_winusb.c:3377:31: warning: array subscript 'struct libusb_endpoint_descriptor[0]' is partly outside array bounds of 'char[41]' [-Warray-bounds]
 3377 |                 ed->bInterval = 10;
      |                 ~~~~~~~~~~~~~~^~~~
../../libusb/os/windows_winusb.c:3326:14: note: while referencing 'tmp'
 3326 |         char tmp[HID_MAX_CONFIG_DESC_SIZE];
      |              ^~~
  CCLD     libusb-1.0.la
  DLLTOOL  .libs/libusb-1.0.dll.a
make[2]: Leaving directory '/c/work/libusb/libusb-1.0.26-rc1/build64/libusb'
Making all in examples
make[2]: Entering directory '/c/work/libusb/libusb-1.0.26-rc1/build64/examples'
  CC       dpfp.o
  CCLD     dpfp.exe
  CC       dpfp_threaded-dpfp.o
  CCLD     dpfp_threaded.exe
  CC       ezusb.o
  CC       fxload.o
  CCLD     fxload.exe
  CC       hotplugtest.o
  CCLD     hotplugtest.exe
  CC       listdevs.o
  CCLD     listdevs.exe
  CC       sam3u_benchmark.o
  CCLD     sam3u_benchmark.exe
  CC       testlibusb.o
  CCLD     testlibusb.exe
  CC       xusb.o
  CCLD     xusb.exe
make[2]: Leaving directory '/c/work/libusb/libusb-1.0.26-rc1/build64/examples'
Making all in tests
make[2]: Entering directory '/c/work/libusb/libusb-1.0.26-rc1/build64/tests'
  CC       stress.o
  CC       testlib.o
  CCLD     stress.exe
make[2]: Leaving directory '/c/work/libusb/libusb-1.0.26-rc1/build64/tests'
make[2]: Entering directory '/c/work/libusb/libusb-1.0.26-rc1/build64'
make[2]: Leaving directory '/c/work/libusb/libusb-1.0.26-rc1/build64'
make[1]: Leaving directory '/c/work/libusb/libusb-1.0.26-rc1/build64'

@tormodvolden
Copy link
Contributor Author

tormodvolden commented Mar 28, 2022

Yes, I think the "array subscript" warnings doesn't point to a real problem, but we should ideally fix the code so that the compiler also is convinced it is fine. However the "implicit cast" is new and a real issue (filed in #1100) that can result in wrong error messages at least.

@mcuee
Copy link
Member

mcuee commented Mar 28, 2022

The warnings for umockdev is known under Ubuntu 20.04.

umockdev.c:37:32: warning: unknown option after ‘#pragma GCC diagnostic’ kind [-Wpragmas]
   37 | #pragma GCC diagnostic ignored "-Wanalyzer-malloc-leak"
      |                                ^~~~~~~~~~~~~~~~~~~~~~~~
umockdev.c:38:32: warning: unknown option after ‘#pragma GCC diagnostic’ kind [-Wpragmas]
   38 | #pragma GCC diagnostic ignored "-Wanalyzer-file-leak"
      |                                ^~~~~~~~~~~~~~~~~~~~~~

@hjelmn
Copy link
Member

hjelmn commented Mar 28, 2022

We broke fuzzing somehow. Plan to take a look today to see how we can best fix it.

@tormodvolden
Copy link
Contributor Author

We broke fuzzing somehow. Plan to take a look today to see how we can best fix it.

Do you refer to CIFuzz? The issue in this log is missing pkg-config (pkg.m4 macro) when running bootstrap. I found the log at https://bugs.chromium.org/p/oss-fuzz/issues/list searching for proj:libusb but is there a "button" or dashboard for this?

@agoodney
Copy link
Contributor

agoodney commented Mar 28, 2022

MacOS 10.11.6

  • build (Xcode project)
  • build (command line, Xcode provided compiler clang-800.0.42.1)
  • run (xusb, listdev)

Solaris 11.4

  • build (gcc 7.3.0)
  • run (xusb, listdev)

@mcuee

@hjelmn
Copy link
Member

hjelmn commented Mar 28, 2022

Yes. CIFuzz.

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Using pyusb to test cystream FW bulk_loopback (high speed USB)

#!/usr/bin/python

### quick mod from https://github.com/danielkucera/cyusb3014-breakout/blob/master/software/loopback-test.py

import usb.core
import usb.util
import time
import _thread

# find our device
dev = usb.core.find(idVendor=0x04b4, idProduct=0x1003)

# was it found?
if dev is None:
    raise ValueError('Device not found')

# set the active configuration. With no arguments, the first
# configuration will be the active one
dev.set_configuration()

# get an endpoint instance
cfg = dev.get_active_configuration()

dev.set_interface_altsetting(interface = 0, alternate_setting = 2)
intf = cfg[(0,2)]

print(intf)

ep = usb.util.find_descriptor(
    intf,
    custom_match = \
    lambda e: \
        e.bEndpointAddress == 0x06)
        
ep2 = usb.util.find_descriptor(
    intf,
    custom_match = \
    lambda e: \
        e.bEndpointAddress == 0x82)

assert ep is not None
assert ep2 is not None

print ('ep:',ep)
print ('ep2:',ep2)

chunkr = 2**16
chunkw = 2**16

print ("Starting CYUSB FX2 CyStream python bulk loopback test")

def read_loop():
    start = time.time()
    trans = 0
    while True:
        data = dev.read(0x82, chunkr, 1000)
        trans = trans + len(data)
        if time.time() > start + 1:
            bps = trans/(time.time() - start)
            print ("Transfered %d kB/s" % (bps/(1024)) )
            trans = 0
            start = time.time()

def write_loop():
    dat = "A"*chunkw
    while True:
        try:
            ep.write(dat)
        except:
            pass

_thread.start_new_thread( write_loop, () )

read_loop()

Windows result using libusbk driver or WinUSB driver (results are similar).

(py39x64venv) PS C:\work\libusb\python_usb> python .\cyusb_fx2_bulk_loopback-test_python3.py
    INTERFACE 0, 2: Vendor Specific ========================
     bLength            :    0x9 (9 bytes)
     bDescriptorType    :    0x4 Interface
     bInterfaceNumber   :    0x0
     bAlternateSetting  :    0x2
     bNumEndpoints      :    0x2
     bInterfaceClass    :   0xff Vendor Specific
     bInterfaceSubClass :    0x0
     bInterfaceProtocol :    0x0
     iInterface         :    0x0
      ENDPOINT 0x82: Bulk IN ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :  0x200 (512 bytes)
       bInterval        :    0x0
      ENDPOINT 0x6: Bulk OUT ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :  0x200 (512 bytes)
       bInterval        :    0x0
ep:       ENDPOINT 0x6: Bulk OUT ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :  0x200 (512 bytes)
       bInterval        :    0x0
ep2:       ENDPOINT 0x82: Bulk IN ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :  0x200 (512 bytes)
       bInterval        :    0x0
Starting CYUSB3014 python loopback test
Transfered 30424 kB/s
Transfered 29803 kB/s
Transfered 29833 kB/s
Transfered 29889 kB/s
Transfered 29114 kB/s
Transfered 29627 kB/s
Transfered 29584 kB/s
Transfered 29424 kB/s
Transfered 29338 kB/s
...

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Using pyusb to test cystream FW isochronous transfer_loopback (high speed USB)

#!/usr/bin/python

### quick mod from https://github.com/danielkucera/cyusb3014-breakout/blob/master/software/loopback-test.py

import usb.core
import usb.util
import time
import _thread

# find our device
dev = usb.core.find(idVendor=0x04b4, idProduct=0x1003)

# was it found?
if dev is None:
    raise ValueError('Device not found')

# set the active configuration. With no arguments, the first
# configuration will be the active one
dev.set_configuration()

# get an endpoint instance
cfg = dev.get_active_configuration()

dev.set_interface_altsetting(interface = 0, alternate_setting = 6)
intf = cfg[(0,6)]

print(intf)

ep = usb.util.find_descriptor(
    intf,
    custom_match = \
    lambda e: \
        e.bEndpointAddress == 0x06)
        
ep2 = usb.util.find_descriptor(
    intf,
    custom_match = \
    lambda e: \
        e.bEndpointAddress == 0x82)

assert ep is not None
assert ep2 is not None

print ('ep:',ep)
print ('ep2:',ep2)

chunkr = 2**16
chunkw = 2**16

print ("Starting CYUSB FX2LP CyStream python isoc loopback test")

def read_loop():
    start = time.time()
    trans = 0
    while True:
        data = dev.read(0x82, chunkr, 1000)
        trans = trans + len(data)
        if time.time() > start + 1:
            bps = trans/(time.time() - start)
            print ("Transfered %d kB/s" % (bps/(1024)) )
            trans = 0
            start = time.time()

def write_loop():
    dat = "A"*chunkw
    while True:
        try:
            ep.write(dat)
        except:
            pass

_thread.start_new_thread( write_loop, () )

read_loop()

Windows 11 test result using libusbk driver (WinUSB does not work well for isoc transfer now).

(py39x64venv) PS C:\work\libusb\python_usb> python .\cyusb_fx2_isoc_loopback-test_python3.py
    INTERFACE 0, 6: Vendor Specific ========================
     bLength            :    0x9 (9 bytes)
     bDescriptorType    :    0x4 Interface
     bInterfaceNumber   :    0x0
     bAlternateSetting  :    0x6
     bNumEndpoints      :    0x2
     bInterfaceClass    :   0xff Vendor Specific
     bInterfaceSubClass :    0x0
     bInterfaceProtocol :    0x0
     iInterface         :    0x0
      ENDPOINT 0x82: Isochronous IN ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
      ENDPOINT 0x6: Isochronous OUT ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
ep:       ENDPOINT 0x6: Isochronous OUT ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
ep2:       ENDPOINT 0x82: Isochronous IN ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
Starting CYUSB3014 python loopback test
Transfered 6722 kB/s
Transfered 6196 kB/s
Transfered 6266 kB/s
Transfered 6424 kB/s
Transfered 6123 kB/s
Transfered 6217 kB/s
Transfered 6259 kB/s
Transfered 6288 kB/s
Transfered 6175 kB/s
Transfered 6124 kB/s
Transfered 6291 kB/s
Transfered 6224 kB/s
Transfered 6205 kB/s
...

WinUSB driver will have an error.

Starting CYUSB FX2LP CyStream python isoc loopback test
Traceback (most recent call last):
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 74, in <module>
    read_loop()
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 56, in read_loop
    data = dev.read(0x82, chunkr, 1000)
  File "C:\work\python\py39x64venv\lib\site-packages\usb\core.py", line 1029, in read
    ret = fn(
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 846, in bulk_read
    return self.__read(self.lib.libusb_bulk_transfer,
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 954, in __read
    _check(retval)
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 604, in _check
    raise USBError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBError: [Errno 5] Input/Output Error

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

usbutils 007 is from 2013... Didn't we get latest usbutils properly into homebrew recently? Or are you somehow stuck with mikhailai's version?

Oops I was using the older version from mikhailai. Once I remore the old brew tap and install the latest usbutils, it is now okay. Sorry for the false alarming.

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Further tested fxload example under my Mac Mini M1 and it works fine as well.

mcuee@mcuees-Mac-mini libusb-1.0.26-rc1_arm64 % ./examples/fxload -t fx2lp -i ./CYStream.hex           
found device 'Cypress EZ-USB FX2LP (68013A/68014A/68015A/68016A)' [04b4:8613] (2,10)
microcontroller type: fx2lp
./CYStream.hex: type Intel HEX
stop CPU
... WROTE: 2749 bytes, 40 segments, avg 68
reset CPU

After that I use Cyusb SDK macOS version example (which use libcyusb on top of libusb) to test isoc transfer and it seems to work fine.

mcuee@mcuees-Mac-mini examples % brew info libusb
libusb: stable 1.0.25 (bottled), HEAD
Library for USB device access
https://libusb.info/
/opt/homebrew/Cellar/libusb/HEAD-78de7dc (22 files, 595KB) *
  Built from source on 2022-03-28 at 17:07:11
/opt/homebrew/Cellar/libusb/1.0.25 (22 files, 570.7KB)
  Poured from bottle on 2022-03-08 at 16:20:41
From: https://github.com/Homebrew/homebrew-core/blob/HEAD/Formula/libusb.rb
License: LGPL-2.1-or-later
==> Options
--HEAD
	Install HEAD version
==> Analytics
install: 133,187 (30 days), 380,926 (90 days), 938,479 (365 days)
install-on-request: 12,836 (30 days), 34,667 (90 days), 96,174 (365 days)
build-error: 147 (30 days)

mcuee@mcuees-Mac-mini lib % make
g++ -dynamiclib libcyusb.c -o libcyusb.0.1.dylib -L/opt/Homebrew/lib -l usb-1.0
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
ln -sf libcyusb.0.1.dylib libcyusb.dylib
mcuee@mcuees-Mac-mini lib % file libcyusb.dylib 
libcyusb.dylib: Mach-O 64-bit dynamically linked shared library arm64

mcuee@mcuees-Mac-mini examples % make
g++ -o cyisowrite_test	        cyisowrite_test.c	       -L../lib -l cyusb -L /opt/Homebrew/lib -l usb-1.0
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
g++ -o cyisoread_test	        cyisoread_test.c	       -L../lib   -l cyusb -L /opt/Homebrew/lib -l usb-1.0
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
g++ -o cybulk_reader	        cybulk_reader.c         -L../lib -l cyusb
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
g++ -o cybulk_writer	        cybulk_writer.c	       -L../lib       -l cyusb
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
g++ -o cybulkread_performance   cybulkread_performance.c  -L../lib    -l cyusb 
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
cybulkread_performance.c:34:9: warning: comparison of array 'buf' equal to a null pointer is always false [-Wtautological-pointer-compare]
    if (buf == NULL){
        ^~~    ~~~~
1 warning generated.
g++ -o cybulkwrite_performance  cybulkwrite_performance.c -L../lib   -l cyusb 
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
cybulkwrite_performance.c:35:9: warning: comparison of array 'buf' equal to a null pointer is always false [-Wtautological-pointer-compare]
    if (buf == NULL){
        ^~~    ~~~~
1 warning generated.
g++ -o download_fx2             download_fx2.c            -L../lib   -lcyusb
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]
g++ -o download_fx3             download_fx3.c            -L../lib   -lcyusb
clang: warning: treating 'c' input as 'c++' when in C++ mode, this behavior is deprecated [-Wdeprecated]

mcuee@mcuees-Mac-mini examples % ./cyisowrite_test 4096

Packet size is 512 

***************************
 Total Packets sent: 4096 
 Pkts Succeeded    : 4096 
 Pkts Failed       : 0 
****************************

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Cyusb 3 SuperSpeed isochronous transfer works fine under macOS as well using the Cypress USB SDK macOS version.

mcuee@mcuees-Mac-mini examples % ./download_fx3 -t RAM -i ../fx3_images/cyfxisosrcsink.img
FX3 firmware programming to RAM completed
mcuee@mcuees-Mac-mini examples % ./cyisoread_test 
Usage of binary ./isoread_test <num packets> 
 Ex: ./isoread_test 64 
mcuee@mcuees-Mac-mini examples % ./cyisoread_test 4096

Packet size is 1024 

***************************
 Total Packets Received: 4096 
 Pkts Succeeded    : 4096 
 Pkts Failed       : 0 
****************************
mcuee@mcuees-Mac-mini examples % ./cyisowrite_test 4096

Packet size is 1024 

***************************
 Total Packets sent: 4096 
 Pkts Succeeded    : 4096 
 Pkts Failed       : 0 
****************************

Cyusb 3 Super USB Bulk transfer works fine as well (using async API)

mcuee@mcuees-Mac-mini examples % ./download_fx3 -t RAM -i ../fx3_images/cyfxbulksrcsink.img 
FX3 firmware programming to RAM completed

mcuee@mcuees-Mac-mini examples % ./cybulkread_performance 
Usage ./cybulkread_performance <Count of 4mb records sent to device> 
 Ex: ./cybulkread_performance 800 
 Host will send 4 * 800 mb to Device 

mcuee@mcuees-Mac-mini examples % ./cybulkread_performance 100
***IMPORTANT 
 To Run read performance test Make sure FX3/FX2 has been loaded with bulksrcsink firmware 
Else Test will fail 
Successfully claimed interface
Read Successfully (4194304 * 100) bytes in 15.775096 seconds 

mcuee@mcuees-Mac-mini examples % ./cybulkwrite_performance 
Usage ./cybulkwrite_performance <Count of 4mb records sent to device> 
 Ex: ./cybulkwrite_performance 800 
 Host will send 4 * 800 mb to Device 

mcuee@mcuees-Mac-mini examples % ./cybulkwrite_performance 100
***IMPORTANT 
 To Run Write performance test Make sure FX3/FX2 has been loaded with bulksrcsink firmware 
Else Test will fail 

Successfully claimed interface
Transfered Successfully (4194304 * 100) bytes in  12.996220 seconds 

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

isoc under Linux is also good with Cyusb FX3 SDK 1.0.5 under Ubuntu Linux 20.04 (x86_64) with libusb-1.0.26rc1.
Here the GUI cyusb works (qt5 based, with fork from https://github.com/Ho-Ro/cyusb_linux)
https://i.imgur.com/O3oJWZ9.png

CLI version test program also works.

mcuee@UbuntuSwift3:~/build/cyusb/cyusb_linux/src$ ./09_cyusb_performance -e 131 -s 16 -q 16 -d 1
Found device 04b4 00f1 (FX3 Streamer Example)
./09_cyusb_performance: Found endpoint 0x83 in interface 0, setting 1
./09_cyusb_performance: Starting test with the following parameters
	Request size     : 0x10
	Queue depth      : 0x10
	Test duration    : 0x1
	Endpoint to test : 0x83

	Endpoint type    : 0x1
	Max packet size  : 0x6000
Transfer Counts: 16 pass 0 fail
Data rate: 188033.664881 KBps

Transfer Counts: 32 pass 0 fail
Data rate: 193578.877721 KBps

Transfer Counts: 48 pass 0 fail
Data rate: 191557.024381 KBps

Transfer Counts: 64 pass 0 fail
Data rate: 191557.024381 KBps

Transfer Counts: 80 pass 0 fail
Data rate: 192066.022695 KBps

Transfer Counts: 96 pass 0 fail
Data rate: 192342.610275 KBps

Transfer Counts: 112 pass 0 fail
Data rate: 191994.000187 KBps

Transfer Counts: 128 pass 0 fail
Data rate: 191628.719356 KBps

Transfer Counts: 144 pass 0 fail
Data rate: 191934.022680 KBps

Transfer Counts: 160 pass 0 fail
Data rate: 192024.003000 KBps

Transfer Counts: 176 pass 0 fail
Data rate: 192126.082742 KBps

Transfer Counts: 192 pass 0 fail
Data rate: 191886.067647 KBps

Transfer Counts: 208 pass 0 fail
Data rate: 192030.004688 KBps

Transfer Counts: 224 pass 0 fail
Data rate: 192096.048024 KBps

Transfer Counts: 240 pass 0 fail
Data rate: 192523.423056 KBps

Transfer Counts: 256 pass 0 fail
Data rate: 191712.431353 KBps

Transfer Counts: 272 pass 0 fail
Data rate: 192024.003000 KBps

Transfer Counts: 288 pass 0 fail
Data rate: 192078.031700 KBps

Transfer Counts: 304 pass 0 fail
Data rate: 191994.000187 KBps

Transfer Counts: 320 pass 0 fail
Data rate: 191676.545829 KBps

./09_cyusb_performance: Test duration is complete. Stopping transfers
16 requests are pending
15 requests are pending
Transfer Counts: 336 pass 0 fail
Data rate: 6077.007074 KBps

./09_cyusb_performance: Transfers completed
./09_cyusb_performance: Test completed

mcuee@UbuntuSwift3:~/build/cyusb/cyusb_linux/src$ ./09_cyusb_performance -e 3 -s 16 -q 16 -d 1
Found device 04b4 00f1 (FX3 Streamer Example)
./09_cyusb_performance: Found endpoint 0x3 in interface 0, setting 1
./09_cyusb_performance: Starting test with the following parameters
	Request size     : 0x10
	Queue depth      : 0x10
	Test duration    : 0x1
	Endpoint to test : 0x3

	Endpoint type    : 0x1
	Max packet size  : 0x6000
Transfer Counts: 16 pass 0 fail
Data rate: 189664.752732 KBps

Transfer Counts: 32 pass 0 fail
Data rate: 191784.242727 KBps

Transfer Counts: 48 pass 0 fail
Data rate: 192892.126083 KBps

Transfer Counts: 64 pass 0 fail
Data rate: 191056.657752 KBps

Transfer Counts: 80 pass 0 fail
Data rate: 192156.126853 KBps

Transfer Counts: 96 pass 0 fail
Data rate: 191934.022680 KBps

Transfer Counts: 112 pass 0 fail
Data rate: 192108.060784 KBps

Transfer Counts: 128 pass 0 fail
Data rate: 191862.099116 KBps

Transfer Counts: 144 pass 0 fail
Data rate: 192018.001688 KBps

Transfer Counts: 160 pass 0 fail
Data rate: 192372.722149 KBps

Transfer Counts: 176 pass 0 fail
Data rate: 191736.362502 KBps

Transfer Counts: 192 pass 0 fail
Data rate: 191916.036734 KBps

Transfer Counts: 208 pass 0 fail
Data rate: 192042.009190 KBps

Transfer Counts: 224 pass 0 fail
Data rate: 192090.042207 KBps

Transfer Counts: 240 pass 0 fail
Data rate: 191910.042168 KBps

Transfer Counts: 256 pass 0 fail
Data rate: 192162.136803 KBps

Transfer Counts: 272 pass 0 fail
Data rate: 191306.513887 KBps

Transfer Counts: 288 pass 0 fail
Data rate: 192204.216981 KBps

Transfer Counts: 304 pass 0 fail
Data rate: 191826.157545 KBps

Transfer Counts: 320 pass 0 fail
Data rate: 192420.920764 KBps

Transfer Counts: 336 pass 0 fail
Data rate: 191443.616988 KBps

Transfer Counts: 352 pass 0 fail
Data rate: 192174.157831 KBps

Transfer Counts: 368 pass 0 fail
Data rate: 192481.203008 KBps

Transfer Counts: 384 pass 0 fail
Data rate: 192469.143537 KBps

Transfer Counts: 400 pass 0 fail
Data rate: 191958.009185 KBps

Transfer Counts: 416 pass 0 fail
Data rate: 191850.117096 KBps

./09_cyusb_performance: Test duration is complete. Stopping transfers
16 requests are pending
15 requests are pending
Transfer Counts: 432 pass 0 fail
Data rate: 6092.433642 KBps

./09_cyusb_performance: Transfers completed
./09_cyusb_performance: Test completed


@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

@tormodvolden

WinUSB driver will have an error. It shows "winusbx_submit_bulk_transfer" in the debug log even though the endpoint is isoc endpoint.

Starting CYUSB FX2LP CyStream python isoc loopback test
Traceback (most recent call last):
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 74, in <module>
    read_loop()
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 56, in read_loop
    data = dev.read(0x82, chunkr, 1000)
  File "C:\work\python\py39x64venv\lib\site-packages\usb\core.py", line 1029, in read
    ret = fn(
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 846, in bulk_read
    return self.__read(self.lib.libusb_bulk_transfer,
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 954, in __read
    _check(retval)
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 604, in _check
    raise USBError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBError: [Errno 5] Input/Output Error
click for the full debug log
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000015] [00001070] libusb: debug [libusb_init] libusb v1.0.26.11717-rc1
[ 0.000024] [00001070] libusb: debug [usbi_add_event_source] add HANDLE 000000000000010C events 0
[ 0.000031] [00001070] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.000033] [00001070] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000118 events 0
[ 0.000061] [00001070] libusb: debug [get_windows_version] Windows 11 64-bit
[ 0.000064] [00001070] libusb: debug [htab_create] using 1021 entries hash table
[ 0.000786] [00001070] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.000991] [00001070] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.002808] [00001070] libusb: info [windows_init] UsbDk backend is not available
[ 0.002864] [00001070] libusb: warning [libusb_init] installing new context as implicit default
[ 0.002943] [00001070] libusb: debug [libusb_get_device_list]  
[ 0.003692] [00000448] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.009349] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [5]
[ 0.009394] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [6]
[ 0.009749] [00001070] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.009775] [00001070] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.009795] [00001070] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.009796] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [1F]
[ 0.009913] [00001070] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.009936] [00001070] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.009940] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [34]
[ 0.010027] [00001070] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.010046] [00001070] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.010048] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [37]
[ 0.010200] [00001070] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.010217] [00001070] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.010220] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [63]
[ 0.010297] [00001070] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.010315] [00001070] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.010317] [00001070] libusb: debug [winusb_get_device_list] allocating new device for session [64]
[ 0.010498] [00001070] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0' bus number 1
[ 0.010526] [00001070] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68' bus number 2
[ 0.011073] [00001070] libusb: debug [winusb_get_device_list] found existing device for session [34]
[ 0.011130] [00001070] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.011142] [00001070] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.011153] [00001070] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 10): 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.011200] [00001070] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.011207] [00001070] libusb: debug [winusb_get_device_list] found existing device for session [63]
[ 0.011239] [00001070] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.011253] [00001070] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 512 bytes)
[ 0.011260] [00001070] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 5): 'USB\VID_04F2&PID_B6DD\0001'
[ 0.011322] [00001070] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.011341] [00001070] libusb: debug [winusb_get_device_list] found existing device for session [1F]
[ 0.011392] [00001070] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.011399] [00001070] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[ 0.011405] [00001070] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 7): 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.011506] [00001070] libusb: debug [winusb_get_device_list] extra GUID: {7AE8D8A0-B9B0-7E4C-5BD5-E43203D34924}
[ 0.011512] [00001070] libusb: debug [winusb_get_device_list] found existing device for session [37]
[ 0.011559] [00001070] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.011568] [00001070] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 135 bytes)
[ 0.011573] [00001070] libusb: debug [init_device] (bus: 1, addr: 31, depth: 1, port: 1): 'USB\VID_04B4&PID_1003\5&586B51A&0&1'
[ 0.011728] [00001070] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&12C539F&0&0' reports 16 ports
[ 0.011781] [00001070] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.011874] [00001070] libusb: debug [winusb_get_device_list] found existing device for session [64]
[ 0.011919] [00001070] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.011924] [00001070] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 84 bytes)
[ 0.011930] [00001070] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 3): 'USB\VID_046D&PID_C52B\5&586B51A&0&3'
[ 0.012072] [00001070] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' reports 5 ports
[ 0.012086] [00001070] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.012270] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.012286] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012288] [00001070] libusb: debug [set_composite_interface] interface[1] = \\?\HID#VID_046D&PID_C52B&MI_01&COL01#7&1119BFB4&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.012342] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.012361] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.012380] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.012398] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.012419] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.012433] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012434] [00001070] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL02\7&1119BFB4&0&0001
[ 0.012454] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.012469] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012470] [00001070] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL03\7&1119BFB4&0&0002
[ 0.012486] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.012506] [00001070] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.012520] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012521] [00001070] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL04\7&1119BFB4&0&0003
[ 0.012535] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012537] [00001070] libusb: debug [set_composite_interface] interface[2] = \\?\HID#VID_046D&PID_C52B&MI_02&COL01#7&12BD7E0E&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.012550] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012551] [00001070] libusb: debug [set_composite_interface] interface[2] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_02&COL02\7&12BD7E0E&0&0001
[ 0.012565] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012566] [00001070] libusb: debug [set_composite_interface] interface[2] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_02&COL03\7&12BD7E0E&0&0002
[ 0.012580] [00001070] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.012581] [00001070] libusb: debug [set_composite_interface] interface[0] = \\?\HID#VID_046D&PID_C52B&MI_00#7&34F0FD76&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}\KBD
[ 0.012987] [00001070] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.013009] [00001070] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.013012] [00001070] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.013309] [00001070] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.014032] [00001070] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.014579] [00001070] libusb: debug [libusb_get_device_descriptor]  
[ 0.014706] [00001070] libusb: debug [libusb_get_device_descriptor]  
[ 0.014784] [00001070] libusb: debug [libusb_get_device_descriptor]  
[ 0.014830] [00001070] libusb: debug [libusb_get_device_descriptor]  
[ 0.014895] [00001070] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.014900] [00001070] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.014904] [00001070] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.014908] [00001070] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.014911] [00001070] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.014962] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015038] [00001070] libusb: debug [libusb_open] open 1.31
[ 0.015078] [00001070] libusb: debug [libusb_set_configuration] configuration 1
[ 0.015086] [00001070] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.015089] [00001070] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.015100] [00001070] libusb: debug [libusb_claim_interface] interface 0
[ 0.015202] [00001070] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.015215] [00001070] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.015243] [00001070] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 0.015245] [00001070] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 0.015247] [00001070] libusb: debug [windows_force_sync_completion] transfer 000001777058EF80, length 0
[ 0.015258] [00001070] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.015260] [00001070] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.015263] [00001070] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.015315] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.015404] [00001070] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.015415] [00001070] libusb: debug [handle_event_trigger] event triggered
[ 0.015417] [00001070] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 0, length 0
[ 0.015425] [00001070] libusb: debug [libusb_release_interface] interface 0
[ 0.015429] [00001070] libusb: debug [auto_release] auto-released interface 0
[ 0.015430] [00001070] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.015435] [00001070] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.015437] [00001070] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.015439] [00001070] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.015467] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015551] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015593] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015634] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015680] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015701] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015721] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015737] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015752] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.015774] [00001070] libusb: debug [libusb_claim_interface] interface 0
[ 0.015837] [00001070] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.015843] [00001070] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.015869] [00001070] libusb: debug [libusb_set_interface_alt_setting] interface 0 altsetting 6
[ 0.016834] [00001070] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.016843] [00001070] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 0.016853] [00001070] libusb: debug [winusbx_configure_endpoints] failed to set PIPE_TRANSFER_TIMEOUT for control endpoint 82
[ 0.016857] [00001070] libusb: debug [winusbx_configure_endpoints] failed to disable SHORT_PACKET_TERMINATE for endpoint 82
[ 0.016861] [00001070] libusb: debug [winusbx_configure_endpoints] failed to disable IGNORE_SHORT_PACKETS for endpoint 82
[ 0.016865] [00001070] libusb: debug [winusbx_configure_endpoints] failed to enable ALLOW_PARTIAL_READS for endpoint 82
[ 0.016869] [00001070] libusb: debug [winusbx_configure_endpoints] failed to enable AUTO_CLEAR_STALL for endpoint 82
[ 0.016872] [00001070] libusb: debug [winusbx_configure_endpoints] failed to set PIPE_TRANSFER_TIMEOUT for control endpoint 06
[ 0.016876] [00001070] libusb: debug [winusbx_configure_endpoints] failed to disable SHORT_PACKET_TERMINATE for endpoint 06
[ 0.016879] [00001070] libusb: debug [winusbx_configure_endpoints] failed to disable IGNORE_SHORT_PACKETS for endpoint 06
[ 0.016883] [00001070] libusb: debug [winusbx_configure_endpoints] failed to enable ALLOW_PARTIAL_READS for endpoint 06
[ 0.016887] [00001070] libusb: debug [winusbx_configure_endpoints] failed to enable AUTO_CLEAR_STALL for endpoint 06
[ 0.016901] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.016980] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017028] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017081] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017104] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017127] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017285] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017316] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017349] [00001070] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017447] [00001070] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.017451] [00001070] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.017454] [00001070] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 82 with interface 0
[ 0.017456] [00001070] libusb: debug [winusbx_submit_bulk_transfer] reading 65536 bytes
[ 0.017465] [00001070] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.017467] [00001070] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.017473] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.017493] [00001070] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.017492] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017503] [00001070] libusb: debug [handle_event_trigger] event triggered
[ 0.017507] [00001070] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.017526] [00001070] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.017532] [00001070] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.017534] [00001070] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.017536] [00001070] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.017539] [00001070] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.017551] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017589] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017629] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017655] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017683] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
    INTERFACE 0, 6: Vendor Specific ========================
     bLength            :    0x9 (9 bytes)
     bDescriptorType    :    0x4 Interface
     bInterfaceNumber   :    0x0
     bAlternateSetting  :    0x6
     bNumEndpoints      :    0x2
     bInterfaceClass    :   0xff Vendor Specific
     bInterfaceSubClass :    0x0
     bInterfaceProtocol :    0x0
     iInterface         :    0x0 
      ENDPOINT 0x82: Isochronous IN ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
      ENDPOINT 0x6: Isochronous OUT ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
Traceback (most recent call last):
       bInterval        :    0x1
ep:       ENDPOINT 0x6: Isochronous OUT ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x6 OUT
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
ep2:       ENDPOINT 0x82: Isochronous IN ========================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x82 IN
       bmAttributes     :    0x1 Isochronous
       wMaxPacketSize   :  0x400 (1024 bytes)
       bInterval        :    0x1
Starting CYUSB FX2LP CyStream python isoc loopback test
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 74, in <module>
[ 0.017847] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.017889] [000033a0] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018004] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018008] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018011] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018013] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018041] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018043] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018052] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.018068] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018073] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018075] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.018149] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018154] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018156] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018158] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018160] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.018200] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018202] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018205] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018209] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018220] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018224] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018226] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.018238] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018241] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018243] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.018250] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018253] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018257] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018260] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018262] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
    read_loop()
[ 0.018326] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018333] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018336] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018338] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018350] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018354] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018355] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.018366] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018369] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018371] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.018378] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018380] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
  File "C:\work\libusb\python_usb\cyusb_fx2_isoc_loopback-test_python3.py", line 56, in read_loop
[ 0.018383] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018388] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018391] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.018446] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018452] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018455] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018456] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018465] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018468] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018469] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.018477] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018481] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018483] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.018489] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018491] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018494] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018496] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018499] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.018564] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018569] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018572] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018573] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018582] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018584] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018610] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
    data = dev.read(0x82, chunkr, 1000)
[ 0.018626] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018629] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018631] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
  File "C:\work\python\py39x64venv\lib\site-packages\usb\core.py", line 1029, in read
[ 0.018635] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018637] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018639] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018640] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018642] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.018672] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.018675] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018681] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.018683] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.018692] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018694] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018699] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.018714] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018724] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.018727] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.018735] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.018737] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018740] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.018745] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018747] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
    ret = fn(
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 846, in bulk_read
[ 0.019032] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019039] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019043] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019046] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019059] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019061] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019062] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019075] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019079] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019081] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019089] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019092] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019095] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019097] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019100] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019192] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019196] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019199] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019201] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019210] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019212] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019218] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019226] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019231] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019233] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019242] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019245] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019248] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019250] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019253] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019331] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019336] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019339] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019341] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019350] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019352] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019354] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019364] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019368] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019370] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019384] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019389] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019392] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019394] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019397] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019455] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019459] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019461] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019463] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019471] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
    return self.__read(self.lib.libusb_bulk_transfer,
[ 0.019473] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019475] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 954, in __read
[ 0.019487] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019490] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019493] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019499] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019501] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019504] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019507] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019509] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019539] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019543] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019545] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019547] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019554] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019556] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019558] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019569] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019572] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019574] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019579] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019582] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019584] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019587] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019592] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019705] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019721] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019727] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019729] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019744] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019747] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019796] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019807] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019813] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019815] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019822] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019824] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019827] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019829] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019831] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019882] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019885] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019888] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.019890] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.019900] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019902] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.019904] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.019915] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.019918] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.019920] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.019925] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.019926] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.019929] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.019931] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.019933] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.019996] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.019999] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.020003] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020005] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020013] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020015] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.020016] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.020026] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.020029] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.020031] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.020036] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.020039] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.020041] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.020043] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.020045] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
    _check(retval)
  File "C:\work\python\py39x64venv\lib\site-packages\usb\backend\libusb1.py", line 604, in _check
[ 0.020135] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.020141] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.020145] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020148] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020161] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020164] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.020164] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.020176] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.020180] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.020186] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.020192] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.020194] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.020197] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.020199] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.020202] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.020340] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.020345] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.020348] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020350] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020360] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020362] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.020366] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.020376] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.020379] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.020381] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.020389] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.020391] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.020394] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.020397] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.020399] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.020460] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.020464] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.020467] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020470] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020477] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020478] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.020482] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.020490] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.020493] [000033a0] libusb: debug [handle_event_trigger] event triggered
[ 0.020495] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.020500] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.020502] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.020505] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.020506] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.020509] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.020538] [000033a0] libusb: debug [libusb_submit_transfer] transfer 000001777058EF80
[ 0.020542] [000033a0] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.020545] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020547] [000033a0] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020554] [000033a0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020556] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
    raise USBError(_strerror(ret), ret, _libusb_errno[ret])
[ 0.020559] [00000448] libusb: debug [windows_iocp_thread] transfer 000001777058EF80 completed, length 0
[ 0.020570] [000033a0] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.020573] [000033a0] libusb: debug [handle_event_trigger] event triggered
usb.core.USBError: [Errno 5] Input/Output Error
[ 0.020575] [000033a0] libusb: debug [windows_handle_transfer_completion] handling transfer 000001777058EF80 completion with errcode 87, length 0
[ 0.020580] [000033a0] libusb: error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
[ 0.020583] [000033a0] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.020585] [000033a0] libusb: debug [usbi_handle_transfer_completion] transfer 000001777058EF80 has callback 00007FF898AE98A0
[ 0.020588] [000033a0] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.020590] [000033a0] libusb: debug [libusb_free_transfer] transfer 000001777058EF80
[ 0.020763] [00001070] libusb: debug [libusb_release_interface] interface 0
[ 0.020798] [00001070] libusb: debug [libusb_close]  
[ 0.021690] [00001070] libusb: debug [libusb_unref_device] destroy device 1.31
[ 0.021699] [00001070] libusb: debug [libusb_unref_device] destroy device 1.0
libusb: debug [libusb_open] open 1.31
[ 0.021742] [00001070] libusb: debug [libusb_exit]  
[ 0.021752] [00000448] libusb: debug [windows_iocp_thread] I/O completion thread exiting
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
libusb: debug [libusb_open] open 1.31
[ 0.022225] [00001070] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000118
[ 0.022235] [00001070] libusb: debug [usbi_remove_event_source] remove HANDLE 000000000000010C
libusb: debug [libusb_open] open 1.31

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Somehow even for libusbk driver, it shows "winusbx_submit_bulk_transfer" even though the endpoint is isoc endpoint. So I am thinking that the debug log is not correct.

click for full debug log
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000014] [00001c10] libusb: debug [libusb_init] libusb v1.0.26.11717-rc1
[ 0.000023] [00001c10] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000114 events 0
[ 0.000048] [00001c10] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.000050] [00001c10] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000120 events 0
[ 0.000063] [00001c10] libusb: debug [get_windows_version] Windows 11 64-bit
[ 0.000066] [00001c10] libusb: debug [htab_create] using 1021 entries hash table
[ 0.000896] [00001c10] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.001102] [00001c10] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.002772] [00001c10] libusb: info [windows_init] UsbDk backend is not available
[ 0.002830] [00001c10] libusb: warning [libusb_init] installing new context as implicit default
[ 0.002916] [00001c10] libusb: debug [libusb_get_device_list]  
[ 0.003381] [00001374] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.012161] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [5]
[ 0.012213] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [6]
[ 0.012712] [00001c10] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.012748] [00001c10] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.012753] [00001c10] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.012756] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [1F]
[ 0.012880] [00001c10] libusb: debug [get_api_type] driver(s): libusbK
[ 0.012908] [00001c10] libusb: debug [get_api_type] matched driver name against libusbK
[ 0.012910] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [25]
[ 0.013068] [00001c10] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.013108] [00001c10] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.013113] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [35]
[ 0.013329] [00001c10] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.013352] [00001c10] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.013354] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [63]
[ 0.013456] [00001c10] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.013481] [00001c10] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.013484] [00001c10] libusb: debug [winusb_get_device_list] allocating new device for session [64]
[ 0.013702] [00001c10] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0' bus number 1
[ 0.013738] [00001c10] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68' bus number 2
[ 0.014437] [00001c10] libusb: debug [winusb_get_device_list] found existing device for session [35]
[ 0.014502] [00001c10] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.014515] [00001c10] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.014525] [00001c10] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 10): 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.014575] [00001c10] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.014580] [00001c10] libusb: debug [winusb_get_device_list] found existing device for session [63]
[ 0.014617] [00001c10] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.014629] [00001c10] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 512 bytes)
[ 0.014635] [00001c10] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 5): 'USB\VID_04F2&PID_B6DD\0001'
[ 0.014696] [00001c10] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.014701] [00001c10] libusb: debug [winusb_get_device_list] found existing device for session [1F]
[ 0.014739] [00001c10] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.014750] [00001c10] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[ 0.014756] [00001c10] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 7): 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.014859] [00001c10] libusb: debug [winusb_get_device_list] extra GUID: {A366578D-D29C-7D3F-2246-16A1FA2E478B}
[ 0.014866] [00001c10] libusb: debug [winusb_get_device_list] found existing device for session [25]
[ 0.014914] [00001c10] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.014922] [00001c10] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 135 bytes)
[ 0.014928] [00001c10] libusb: debug [init_device] (bus: 1, addr: 32, depth: 1, port: 1): 'USB\VID_04B4&PID_1003\5&586B51A&0&1'
[ 0.015152] [00001c10] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&12C539F&0&0' reports 16 ports
[ 0.015218] [00001c10] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.015347] [00001c10] libusb: debug [winusb_get_device_list] found existing device for session [64]
[ 0.015419] [00001c10] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.015428] [00001c10] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 84 bytes)
[ 0.015437] [00001c10] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 3): 'USB\VID_046D&PID_C52B\5&586B51A&0&3'
[ 0.015699] [00001c10] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' reports 5 ports
[ 0.015731] [00001c10] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.015999] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.016030] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016034] [00001c10] libusb: debug [set_composite_interface] interface[1] = \\?\HID#VID_046D&PID_C52B&MI_01&COL01#7&1119BFB4&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.016116] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.016154] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.016187] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.016221] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.016258] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.016282] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016288] [00001c10] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL02\7&1119BFB4&0&0001
[ 0.016320] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.016348] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016353] [00001c10] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL03\7&1119BFB4&0&0002
[ 0.016379] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.016414] [00001c10] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.016440] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016445] [00001c10] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_01&COL04\7&1119BFB4&0&0003
[ 0.016468] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016473] [00001c10] libusb: debug [set_composite_interface] interface[2] = \\?\HID#VID_046D&PID_C52B&MI_02&COL01#7&12BD7E0E&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.016495] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016499] [00001c10] libusb: debug [set_composite_interface] interface[2] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_02&COL02\7&12BD7E0E&0&0001
[ 0.016522] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016527] [00001c10] libusb: debug [set_composite_interface] interface[2] already set - ignoring HID collection: HID\VID_046D&PID_C52B&MI_02&COL03\7&12BD7E0E&0&0002
[ 0.016549] [00001c10] libusb: debug [winusb_get_device_list] setting composite interface for [64]:
[ 0.016553] [00001c10] libusb: debug [set_composite_interface] interface[0] = \\?\HID#VID_046D&PID_C52B&MI_00#7&34F0FD76&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}\KBD
[ 0.017095] [00001c10] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.017126] [00001c10] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.017130] [00001c10] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.017442] [00001c10] libusb: debug [get_api_type] driver(s): libusbK
[ 0.017462] [00001c10] libusb: debug [get_api_type] matched driver name against libusbK
[ 0.017877] [00001c10] libusb: debug [libusb_get_device_descriptor]  
[ 0.017959] [00001c10] libusb: debug [libusb_get_device_descriptor]  
[ 0.018017] [00001c10] libusb: debug [libusb_get_device_descriptor]  
[ 0.018049] [00001c10] libusb: debug [libusb_get_device_descriptor]  
[ 0.018076] [00001c10] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.018081] [00001c10] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.018084] [00001c10] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.018086] [00001c10] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.018088] [00001c10] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.018102] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018141] [00001c10] libusb: debug [libusb_open] open 1.32
[ 0.018169] [00001c10] libusb: debug [libusb_set_configuration] configuration 1
[ 0.018175] [00001c10] libusb: debug [libusb_submit_transfer] transfer 000001F7BFF26A20
[ 0.018177] [00001c10] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.018185] [00001c10] libusb: debug [libusb_claim_interface] interface 0
[ 0.018232] [00001c10] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.018239] [00001c10] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.018276] [00001c10] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 0.018280] [00001c10] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 0.018281] [00001c10] libusb: debug [windows_force_sync_completion] transfer 000001F7BFF26A20, length 0
[ 0.018279] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDC80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018287] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDC80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018288] [00001c10] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018289] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDC80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018290] [00001c10] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.018292] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDC80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018294] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.018295] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018301] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018303] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018305] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018308] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018310] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018312] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDD60 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018316] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BFF26A20 completed, length 0
[ 0.018326] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.018331] [00001c10] libusb: debug [handle_event_trigger] event triggered
[ 0.018333] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BFF26A20 completion with errcode 0, length 0
[ 0.018338] [00001c10] libusb: debug [libusb_release_interface] interface 0
[ 0.018344] [00001c10] libusb: debug [auto_release] auto-released interface 0
[ 0.018348] [00001c10] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.018352] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BFF26A20 has callback 00007FF8BF5098A0
[ 0.018354] [00001c10] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.018357] [00001c10] libusb: debug [libusb_free_transfer] transfer 000001F7BFF26A20
[ 0.018379] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018421] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018454] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018491] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018518] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018541] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018564] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018585] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018605] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.018631] [00001c10] libusb: debug [libusb_claim_interface] interface 0
[ 0.018657] [00001c10] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.018662] [00001c10] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.018691] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED640 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018692] [00001c10] libusb: debug [libusb_set_interface_alt_setting] interface 0 altsetting 6
[ 0.018694] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED640 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018696] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED640 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018698] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED640 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018700] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018702] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018703] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018705] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018707] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018708] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.018710] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939ED720 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019391] [00001c10] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 0.019396] [00001c10] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 0.019452] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019452] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EE050 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019460] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019462] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019464] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019466] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019470] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019472] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019474] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019476] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019480] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019482] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019484] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019486] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019490] [00001374] libusb: debug [windows_iocp_thread] ignoring overlapped 0000004A939EDF80 for handle 000001F7BF70DDF0 (device 1.32)
[ 0.019521] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019568] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019632] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019659] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019683] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019794] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019828] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019863] [00001c10] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.019970] [00001c10] libusb: debug [libusb_submit_transfer] transfer 000001F7BFF26A20
[ 0.019975] [00001c10] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.019978] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 82 with interface 0
[ 0.019980] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] reading 65536 bytes
[ 0.020034] [00001c10] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.020039] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.020037] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020084] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020118] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020151] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020175] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020200] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020223] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020245] [00001b28] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.020318] [00001b28] libusb: debug [libusb_submit_transfer] transfer 000001F7BF70C940
[ 0.020323] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.020325] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.020368] [00001b28] libusb: debug [libusb_handle_events_timeout_completed] another thread is doing event handling
[ 0.032908] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BFF26A20 completed, length 65536
[ 0.032934] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BF70C940 completed, length 65536
[ 0.032940] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.032947] [00001c10] libusb: debug [handle_event_trigger] event triggered
[ 0.032950] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BFF26A20 completion with errcode 0, length 65536
[ 0.032954] [00001c10] libusb: debug [arm_timer_for_next_timeout] next timeout originally 1000ms
[ 0.032958] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BFF26A20 has callback 00007FF8BF5098A0
[ 0.032961] [00001c10] libusb: debug [sync_transfer_cb] actual_length=65536
[ 0.032962] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BF70C940 completion with errcode 0, length 65536
[ 0.032964] [00001c10] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.032967] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BF70C940 has callback 00007FF8BF5098A0
[ 0.032969] [00001c10] libusb: debug [sync_transfer_cb] actual_length=65536
[ 0.032975] [00001c10] libusb: debug [libusb_free_transfer] transfer 000001F7BFF26A20
[ 0.033034] [00001b28] libusb: debug [libusb_free_transfer] transfer 000001F7BF70C940
[ 0.033116] [00001c10] libusb: debug [libusb_submit_transfer] transfer 000001F7BFF26A20
[ 0.033121] [00001c10] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.033125] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 82 with interface 0
[ 0.033127] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] reading 65536 bytes
[ 0.033174] [00001b28] libusb: debug [libusb_submit_transfer] transfer 000001F7BF70C940
[ 0.033183] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.033186] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.033198] [00001c10] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.033201] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.033227] [00001b28] libusb: debug [libusb_handle_events_timeout_completed] another thread is doing event handling
[ 0.040970] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BFF26A20 completed, length 57344
[ 0.040991] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BF70C940 completed, length 57344
[ 0.041110] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.041123] [00001c10] libusb: debug [handle_event_trigger] event triggered
[ 0.041126] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BFF26A20 completion with errcode 0, length 57344
[ 0.041130] [00001c10] libusb: debug [arm_timer_for_next_timeout] next timeout originally 1000ms
[ 0.041134] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BFF26A20 has callback 00007FF8BF5098A0
[ 0.041136] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.041137] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BF70C940 completion with errcode 0, length 57344
[ 0.041139] [00001c10] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.041142] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BF70C940 has callback 00007FF8BF5098A0
[ 0.041144] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.041151] [00001c10] libusb: debug [libusb_free_transfer] transfer 000001F7BFF26A20
[ 0.041157] [00001b28] libusb: debug [libusb_free_transfer] transfer 000001F7BF70C940
[ 0.041242] [00001c10] libusb: debug [libusb_submit_transfer] transfer 000001F7BFF26A20
[ 0.041248] [00001c10] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.041251] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 82 with interface 0
[ 0.041253] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] reading 65536 bytes
[ 0.041311] [00001c10] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.041315] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.041344] [00001b28] libusb: debug [libusb_submit_transfer] transfer 000001F7BF70C940
[ 0.041356] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.041358] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.041405] [00001b28] libusb: debug [libusb_handle_events_timeout_completed] another thread is doing event handling
[ 0.048987] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BFF26A20 completed, length 57344
[ 0.048994] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BF70C940 completed, length 57344
[ 0.049106] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.049113] [00001c10] libusb: debug [handle_event_trigger] event triggered
[ 0.049115] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BFF26A20 completion with errcode 0, length 57344
[ 0.049118] [00001c10] libusb: debug [arm_timer_for_next_timeout] next timeout originally 1000ms
[ 0.049121] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BFF26A20 has callback 00007FF8BF5098A0
[ 0.049123] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.049124] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BF70C940 completion with errcode 0, length 57344
[ 0.049126] [00001c10] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.049128] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BF70C940 has callback 00007FF8BF5098A0
[ 0.049130] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.049135] [00001c10] libusb: debug [libusb_free_transfer] transfer 000001F7BFF26A20
[ 0.049142] [00001b28] libusb: debug [libusb_free_transfer] transfer 000001F7BF70C940
[ 0.049199] [00001c10] libusb: debug [libusb_submit_transfer] transfer 000001F7BFF26A20
[ 0.049204] [00001c10] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.049207] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 82 with interface 0
[ 0.049208] [00001c10] libusb: debug [winusbx_submit_bulk_transfer] reading 65536 bytes
[ 0.049252] [00001c10] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.049257] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.049294] [00001b28] libusb: debug [libusb_submit_transfer] transfer 000001F7BF70C940
[ 0.049304] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 06 with interface 0
[ 0.049307] [00001b28] libusb: debug [winusbx_submit_bulk_transfer] writing 65536 bytes
[ 0.049350] [00001b28] libusb: debug [libusb_handle_events_timeout_completed] another thread is doing event handling
[ 0.056956] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BFF26A20 completed, length 57344
[ 0.056964] [00001374] libusb: debug [windows_iocp_thread] transfer 000001F7BF70C940 completed, length 57344
[ 0.057073] [00001c10] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.057080] [00001c10] libusb: debug [handle_event_trigger] event triggered
[ 0.057082] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BFF26A20 completion with errcode 0, length 57344
[ 0.057085] [00001c10] libusb: debug [arm_timer_for_next_timeout] next timeout originally 1000ms
[ 0.057088] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BFF26A20 has callback 00007FF8BF5098A0
[ 0.057090] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.057091] [00001c10] libusb: debug [windows_handle_transfer_completion] handling transfer 000001F7BF70C940 completion with errcode 0, length 57344
[ 0.057094] [00001c10] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.057099] [00001c10] libusb: debug [usbi_handle_transfer_completion] transfer 000001F7BF70C940 has callback 00007FF8BF5098A0
[ 0.057101] [00001c10] libusb: debug [sync_transfer_cb] actual_length=57344
[ 0.057107] [00001c10] libusb: debug [libusb_free_transfer] transfer 000001F7BFF26A20
[ 0.057114] [00001b28] libusb: debug [libusb_free_transfer] transfer 000001F7BF70C940
skipped the rest as it is too long

@mcuee
Copy link
Member

mcuee commented Mar 29, 2022

Same thing reported here. It shows "winusbx_submit_bulk_transfer" in the debug log.

@tormodvolden
Copy link
Contributor Author

tormodvolden commented Mar 29, 2022

Interesting. Let's open a separate ticket for this (or carry on in 759) to not spam the RC testing. We don't expect WinUSB isoch to work correctly. It is indeed using winusbx_submit_bulk_transfer() because we see writing 65536 bytes. Do you have some isoch test in C, without pyusb?

@tormodvolden
Copy link
Contributor Author

tormodvolden commented Mar 29, 2022

I managed to cross-build latest libfreenect (with latest freeglut) for Windows, using MinGW on Ubuntu - this was a feat in itself. It actually works, isochronous (IN) streaming over WinUSB from an Xbox 360 Kinect camera.

Edit: Confirmed that also isochronous OUT works with a custom device on WinUSB, although reported packet transferred lengths are zero. The data is transferred in both directions, but the log shows:
error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
both for OUT and IN transfers. Then in both cases the transfer is submitted again, now with success and the packet actual_length correct for IN but zero for OUT. I wonder if it is just missing actual_length assignment for WinUSB/OUT in winusbx_copy_transfer_data() that is the reason for the zero lengths reported, see #1105. I cannot rule out that the custom firmware is causing the error 87, but on Linux everything seems fine.

@mcuee
Copy link
Member

mcuee commented Mar 30, 2022

Interesting. Let's open a separate ticket for this (or carry on in 759) to not spam the RC testing. We don't expect WinUSB isoch to work correctly. It is indeed using winusbx_submit_bulk_transfer() because we see writing 65536 bytes. Do you have some isoch test in C, without pyusb?

That is the problem. All my known-good FW are tested with libusbk Kbench or Cypress FX3 USB SDK host tools, they are not using libusb under Windows. That is why I was using pyusb -- but pyusb may not be correct. I will see if I can try other methods. But I thiink we are good to go for libusb-1.0.26 with regard to isocu transfer support.

@mcuee
Copy link
Member

mcuee commented Apr 3, 2022

One more test with HID device under Windows.
FW for PIC1887J50 and host code here.
https://github.com/mcuee/picusb/tree/master/lvr_genhid_mod

It seems to work fine. The host code sends one extra byte to see if the device will respond or not.

$ ./libusb1_lvrhid8.exe
Successfully find the LVR Generic HID device
Successfully set usb configuration 1
Successfully claimed interface
Testing control transfer using loop back test of feature report
03, 04; 21, 21; 22, 22; 23, 00;
Testing control transfer using loop back test of input/output report
02, 01; 31, 31; 32, 32; 33, 00;
Testing interrupt transfer using loop back test of input/output report
02, 01; 41, 41; 42, 42; 43, 00;

@mcuee
Copy link
Member

mcuee commented Apr 3, 2022

Edit: Confirmed that also isochronous OUT works with a custom device on WinUSB, although reported packet transferred lengths are zero. The data is transferred in both directions, but the log shows:
error [windows_handle_transfer_completion] detected I/O error 87: [87] The parameter is incorrect.
both for OUT and IN transfers. Then in both cases the transfer is submitted again, now with success and the packet actual_length correct for IN but zero for OUT. I wonder if it is just missing actual_length assignment for WinUSB/OUT in winusbx_copy_transfer_data() that is the reason for the zero lengths reported, see #1105. I cannot rule out that the custom firmware is causing the error 87, but on Linux everything seems fine.

Your test results seem to be in line with some of my test results, like the transfer size report as 0 and Error 87.

@martinling
Copy link
Contributor

As requested by @tormodvolden I've run some tests with HackRF.

We're pretty sensitive to any transfer throughput issues since we stream at 40MB/s with little latency margin, and we do it with bulk transfers.

I tested on Linux, and on Windows with the WinUSB backend. I ran hackrf_transfer in transmit and receive mode, hackrf_sweep, and a test program we've been using called hackrf_loop which repeatedly starts & stops streaming.

Everything seems to work fine on both Linux and Windows with 1.0.26-rc1 and I don't see any changes to our streaming performance there - Windows has latency problems at full sample rate, but that's unchanged across libusb releases.

I had previously been running 1.0.24, so I also tested 1.0.25 to see if we had been affected by bugs in that release.

On 1.0.25, hackrf_transfer on Windows segfaults just before normal exit, after printing:

libusb: debug [libusb_free_transfer] transfer 000001e6f888a5b8

That problem is fixed by 1.0.26-rc1.

@tormodvolden
Copy link
Contributor Author

@martinling Thanks a lot for your testing and success report!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Release Related to release and milestone
Projects
None yet
Development

No branches or pull requests

5 participants