Closed masoudr closed 2 years ago
Hello, thanks for the very detailed report.
At a glance I do not see anything wrong with the code structure.
The only less-usual thing I see is the creation of a second context in is_connected
, but this is supposed to work so it is definitely not wrong. It just maybe less commonly exercised than single-context-at-a-time, so bugs could be hiding there that others would not have caught, so in the spirit of trying to eliminate all possible causes I prefer to mention it.
On to the error: this looks like a double-free, somehow, which points at a double-close
(possibly close
-then-__del__
) of the USBDevice
. This method has code supposed to prevent this from happening, and barring any race-condition this should work. This minimal test-case being single-threaded there should be no race here, so there must be something else I am not seeing.
Could you add the following line as first line of USBDevice.close
(it should become line 1781), and re-run the test ?
print('<USBDevice %x>.close called, self.device_p=%r (%s)' % (id(self), self.device_p, bool(self.device_p))
What is really strange is that when I call the close
method in __del__
it works, but when I call it within the main I get the exception. BTW I added what you said.
True
write: True
read: bytearray(b'AAAAAAAAAA')
<USBDevice 1e58feff070>.close called, self.device_p=<usb1.libusb1.LP_libusb_device object at 0x000001E591DF3440> (True)
<USBDevice 1e58feff070>.close called, self.device_p=None (False)
<USBDevice 1e58fefad00>.close called, self.device_p=<usb1.libusb1.LP_libusb_device object at 0x000001E591DF37C0> (True)
<USBDevice 1e58fefa460>.close called, self.device_p=<usb1.libusb1.LP_libusb_device object at 0x000001E591DF3B40> (True)
Exception ignored in: <function USBDevice.__del__ at 0x000001E591DAA9D0>
Traceback (most recent call last):
File "C:\Users\ABC\AppData\Roaming\Python\Python39\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\Users\ABC\AppData\Roaming\Python\Python39\site-packages\usb1\__init__.py", line 1791, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
What is really strange is that when I call the
close
method in__del__
it works, but when I call it within the main I get the exception
Interpreter shutdown is doing very unusual things when trying to call every destructor.
Like replacing all module globals with None
, and I believe also breaking cycles.
This is why I went with context-manager-based instance lifetime control: this provides unambiguous teardown ordering, as it happens before reaching interpreter shutdown but instead whywhile control is going up the stack.
BTW I added what you said.
Thanks, and these outputs all look fine to me: there is no obvious reason why a null pointer appears here.
Actually I don't have a problem with that but cause my unit tests to fail.
import unittest
from core import USB
class TestUSB(unittest.TestCase):
"""Test USB Functions"""
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
MSG = 100 * bytearray(b"A")
def setUp(self) -> None:
self.usb = USB(self.PRODUCT_ID, self.VENDOR_ID,
self.ENDPOINT_IN, self.ENDPOINT_OUT)
self.assertTrue(self.usb.open())
def tearDown(self) -> None:
pass
def test_read_write(self):
self.assertTrue(self.usb.is_connected())
self.assertTrue(self.usb.write(self.MSG))
self.assertTrue(self.MSG == self.usb.read())
I'm sorry but I do not understand what you mean in your latest comment.
Suppose I don't call self.close()
explicitly, it won't give me the exception, and the program closes normally. But in my unit test, it throws the exception even without calling self.close()
and that is strange for me.
If I stick to my gut feeling that this is an interpreter-shutdown-specific issue, one thing I can think of is that maybe the presence/absence of __del__
methods on the involved classes can make a difference. Python's garbage collector behaves differently when a class has a __del__
method.
When I wrote the first few version of python-libusb1 I thought I would be able to get away with freeing memory in __del__
methods, so I added them in multiple classes. It is only much later that I realized there is no way around using context management for reliable memory de-allocation. So I added __enter__
/__exit__
, close
for any code which does not naturally lend itself to the context manager approach, plus some data structures to locate the managed instances and close
them. But I had to maintain backward compatibility, so __del__
methods still remain today, with their sometimes weird gc effects.
So I am not too surprised that relying on __del__
to close everything during interpreter shutdown causes some issue. What I still do not understand here is why when you added an explicit close
call you were getting errors - and the null-pointer was never visible in the logs I made you add. Maybe you can increase the amount of debug prints, like in every __del__
method to track the order in which they get called ? Also adding a print before and after the explicit close
call, to see if the issue happens while close is still running, or if it is after it has returned, hence during interpreter shutdown. Including repr(self)
or id(self)
in these prints would be good.
Interestingly I do not have any issues under my Mac Mini M1 running macOS Big Sur 11.5 ARM64 version with the test code mentioned in the first post. Recently I got the Cypress FX3 board and it is a wonderful board to play with USB under different OS (Windows, macOS and Linux for me).
pyusb/pyusb_test/usb1 via 🐍 v3.9.6 (py396venv) ❯ python3 cyusb_fx3_bulkloop.py
True
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
But I can reproduce the issue under Windows with the official Python 3.9.6 x64 version.
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~0 -0 !]> python .\cyusb_fx3_loopback_python_libusb1.py
True
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Exception ignored in: <function USBDevice.__del__ at 0x0000015C8C6DC0D0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1790, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
And if I use MSYS2 MinGW64 Python, it actually segfaults.
MINGW64 /c/work/libusb/python_usb
$ python cyusb_fx3_loopback_python_libusb1.py
True
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Segmentation fault
With Windows Python, the full debug log (LIBUSB_DEBUG=4). Not so sure if this helps.
The following debug log seems to be a bit suspicious. Is it possible that only the default context was detroyed and not the second second context?
[ 0.149948] [0000671c] libusb: debug [libusb_unref_device] destroy device 1.7
[ 0.151450] [0000671c] libusb: debug [libusb_exit]
[ 0.151561] [0000671c] libusb: debug [libusb_exit] destroying default context
[ 0.151621] [0000671c] libusb: warning [libusb_exit] some libusb_devices were leaked
Normally the debug log should be something like the following, without the leak warning.
Releasing interface 0...
[ 0.069721] [00003b24] libusb: debug [libusb_release_interface] interface 0
Closing device...
[ 0.069807] [00003b24] libusb: debug [libusb_close]
[ 0.069899] [00003b24] libusb: debug [libusb_unref_device] destroy device 1.12
[ 0.069948] [00003b24] libusb: debug [libusb_unref_device] destroy device 1.0
[ 0.070005] [00003b24] libusb: debug [libusb_exit]
[ 0.070047] [00003b24] libusb: debug [libusb_exit] destroying default context
[ 0.070093] [00003b24] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000001FC
[ 0.070142] [00003b24] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000A4
[ 0.070409] [00003be8] libusb: debug [windows_iocp_thread] I/O completion thread exiting
The following debug log seems to be a bit suspicious. Is it possible that only the default context was detroyed and not the second second context?
Not true. Even if I comment out the following line, it still has the same problem.
#print(usb.is_connected())
This looks like a specific issue with Windows, it may be a libusb issue or a python-libusb1 issue, but more like a python-libusb1 issue to me. I will try out under Linux to see if the issue is there or not.
No issues on libusb under my Linux machine (Raspberry Pi 400 running 64bit Ubuntu Linux ARM).
python_usb on master [?] via 🐍 v3.9.5 ❯ python3 cyusb_fx3_bulkloop_py3_libusb1.py
True
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
And no leak from the debug log either.
[ 0.060471] [00003943] libusb: debug [libusb_free_transfer] transfer 0x3cf45e40
[ 0.060707] [00003943] libusb: debug [libusb_release_interface] interface 0
[ 0.060834] [00003943] libusb: debug [libusb_close]
[ 0.060862] [00003943] libusb: debug [usbi_remove_event_source] remove fd 7
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
[ 0.061099] [00003943] libusb: debug [libusb_exit]
[ 0.061168] [00003945] libusb: debug [linux_udev_event_thread_main] udev event thread exiting
[ 0.061354] [00003943] libusb: debug [libusb_unref_device] destroy device 3.1
[ 0.061377] [00003943] libusb: debug [libusb_unref_device] destroy device 2.2
[ 0.061392] [00003943] libusb: debug [libusb_unref_device] destroy device 2.1
[ 0.061407] [00003943] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.061421] [00003943] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.061435] [00003943] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.061451] [00003943] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.061466] [00003943] libusb: debug [usbi_remove_event_source] remove fd 4
[ 0.061494] [00003943] libusb: debug [usbi_remove_event_source] remove fd 3
@vpelletier Since the fault seems to happen because libusb_unref_device() is called after libusb_exit() and that seems to cause problem under Windows (but no problems under Linux), the following dirty hack seems to sort out the issue.
diff --git a/usb1/__init__.py b/usb1/__init__.py
index 0d08688..f131196 100644
--- a/usb1/__init__.py
+++ b/usb1/__init__.py
@@ -1787,9 +1787,9 @@ class USBDevice(object):
closable.close()
if not self.device_p:
return
- self.__libusb_unref_device(self.device_p)
+ # self.__libusb_unref_device(self.device_p)
# pylint: disable=redefined-outer-name
- byref = self.__byref
+ # byref = self.__byref
# pylint: enable=redefined-outer-name
descriptor_list = self.__configuration_descriptor_list
while descriptor_list:
(py39venv) C:\work\libusb\python_usb [master ≡ +8 ~0 -0 !]> python .\cyusb_fx3_bulkloop_py_libusb1.py
True
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
But of course this does not seem to be the right fix as seen in the warnings of the debug log.
[ 0.147365] [000055d8] libusb: debug [libusb_release_interface] interface 0
[ 0.147480] [000055d8] libusb: debug [libusb_close]
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
[ 0.147793] [000055d8] libusb: debug [libusb_exit]
[ 0.147897] [000052c0] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 0.149451] [000055d8] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000130
[ 0.149568] [000055d8] libusb: debug [usbi_remove_event_source] remove HANDLE 000000000000013C
[ 0.149703] [000055d8] libusb: warning [libusb_exit] device 1.28 still referenced
[ 0.149755] [000055d8] libusb: warning [libusb_exit] device 1.4 still referenced
[ 0.149807] [000055d8] libusb: warning [libusb_exit] device 1.40 still referenced
[ 0.149858] [000055d8] libusb: warning [libusb_exit] device 1.15 still referenced
[ 0.149909] [000055d8] libusb: warning [libusb_exit] device 1.6 still referenced
[ 0.149961] [000055d8] libusb: warning [libusb_exit] device 2.0 still referenced
[ 0.150016] [000055d8] libusb: warning [libusb_exit] device 1.0 still referenced
I have raised https://github.com/libusb/libusb/issues/974 to see if libusb can do better, at least for Windows.
Thanks for the extensive testing and debugging.
The following debug log seems to be a bit suspicious. Is it possible that only the default context was detroyed and not the second second context?
One particularity of python-libusb1 is that my code never uses the default context, because this seemed the sane thing to do, and it was mapping very well in the object world. I suspect this may differ from most uses, and could cause unusual codepaths to be exercised. Could the windows backend accidentally rely on this ?
The default context destruction triggering warnings about ~still-referenced devices~ leaked libusb_devices
looks to me as another hint that there may be some confusion about the context.
Let me try out on the libusb windows side. It is possible that there is an issue there. Thanks.
So far I have not been able to reproduce the issues with libusb yet.
Ref: stress test codes have some simple tests with two contexts. https://github.com/libusb/libusb/blob/master/tests/stress.c
I have also adapted a few examples with non-default context (but single context) but again I am not able to reproduce the issue. But probably they are not good enough.
C:\work\libusb\libusb [master ≡ +2 ~3 -0 !]> git diff
diff --git a/examples/listdevs.c b/examples/listdevs.c
index b5b027c..5ae5895 100644
--- a/examples/listdevs.c
+++ b/examples/listdevs.c
@@ -54,20 +54,20 @@ int main(void)
libusb_device **devs;
int r;
ssize_t cnt;
-
- r = libusb_init(NULL);
+ libusb_context* ctx = NULL;
+ r = libusb_init(&ctx);
if (r < 0)
return r;
- cnt = libusb_get_device_list(NULL, &devs);
+ cnt = libusb_get_device_list(ctx, &devs);
if (cnt < 0){
- libusb_exit(NULL);
+ libusb_exit(ctx);
return (int) cnt;
}
print_devs(devs);
libusb_free_device_list(devs, 1);
- libusb_exit(NULL);
+ libusb_exit(ctx);
return 0;
}
diff --git a/examples/testlibusb.c b/examples/testlibusb.c
index ba00f90..c44c5d8 100644
--- a/examples/testlibusb.c
+++ b/examples/testlibusb.c
@@ -286,17 +286,17 @@ int main(int argc, char *argv[])
return 1;
}
}
-
- r = libusb_init(NULL);
+ libusb_context* ctx = NULL;
+ r = libusb_init(&ctx);
if (r < 0)
return r;
if (device_name) {
r = test_wrapped_device(device_name);
} else {
- cnt = libusb_get_device_list(NULL, &devs);
+ cnt = libusb_get_device_list(ctx, &devs);
if (cnt < 0) {
- libusb_exit(NULL);
+ libusb_exit(ctx);
return 1;
}
@@ -306,6 +306,6 @@ int main(int argc, char *argv[])
libusb_free_device_list(devs, 1);
}
- libusb_exit(NULL);
+ libusb_exit(ctx);
return r;
}
diff --git a/examples/xusb.c b/examples/xusb.c
index 61ce4dd..e23960a 100644
--- a/examples/xusb.c
+++ b/examples/xusb.c
@@ -1107,13 +1107,14 @@ int main(int argc, char** argv)
version = libusb_get_version();
printf("Using libusb v%d.%d.%d.%d\n\n", version->major, version->minor, version->micro, version->nano);
- r = libusb_init(NULL);
+ libusb_context *ctx = NULL;
+ r = libusb_init(&ctx);
if (r < 0)
return r;
// If not set externally, and no debug option was given, use info log level
if ((old_dbg_str == NULL) && (!debug_mode))
- libusb_set_option(NULL, LIBUSB_OPTION_LOG_LEVEL, LIBUSB_LOG_LEVEL_INFO);
+ libusb_set_option(ctx, LIBUSB_OPTION_LOG_LEVEL, LIBUSB_LOG_LEVEL_INFO);
if (error_lang != NULL) {
r = libusb_setlocale(error_lang);
if (r < 0)
@@ -1122,7 +1123,7 @@ int main(int argc, char** argv)
test_device(VID, PID);
- libusb_exit(NULL);
+ libusb_exit(ctx);
if (debug_mode) {
snprintf(str, sizeof(str), "LIBUSB_DEBUG=%s", (old_dbg_str == NULL)?"":old_dbg_str);
If we look at the debug log, one strange thing is like the following. There seems to be two times of libusb_get_device_list() and libusb_close() being called.
The following line is commented out here. There is only single libusb context here so context handling does not seem to be the issue.
#print(usb.is_connected())
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000344] [0000507c] libusb: debug [libusb_init] libusb v1.0.24.11650
[ 0.000499] [0000507c] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000654 events 0
[ 0.000668] [0000507c] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.000819] [0000507c] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000650 events 0
[ 0.001003] [0000507c] libusb: debug [get_windows_version] Windows 10 64-bit
[ 0.001156] [0000507c] libusb: debug [htab_create] using 1021 entries hash table
[ 0.004593] [0000507c] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.006318] [0000507c] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.012722] [0000507c] libusb: debug [windows_init] UsbDk backend is available
[ 0.013124] [0000507c] libusb: debug [libusb_get_device_list]
...
[ 0.057231] [0000507c] libusb: debug [libusb_release_interface] interface 0
[ 0.057314] [0000507c] libusb: debug [libusb_close]
write: True
[ 0.057621] [0000507c] libusb: debug [libusb_get_device_list]
...
...
[ 0.127214] [0000507c] libusb: debug [libusb_release_interface] interface 0
[ 0.127515] [0000507c] libusb: debug [libusb_close]
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
[ 0.128372] [0000507c] libusb: debug [libusb_exit]
[ 0.128646] [00000cbc] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 0.132787] [0000507c] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000650
[ 0.133041] [0000507c] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000654
[ 0.133276] [0000507c] libusb: warning [libusb_exit] device 1.8 still referenced
[ 0.133487] [0000507c] libusb: warning [libusb_exit] device 1.0 still referenced
[ 0.137786] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.8
Adding some debug print.
(py39venv) C:\work\libusb\python_usb [master ≡ +8 ~0 -0 !]> python .\cyusb_fx3_loopback_python_libusb1.py
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Closing USB
Close handle successfully
Exception ignored in: <function USBDevice.__del__ at 0x000001AF13268820>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1790, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
Calling closing method to delete self
Closing USB
Close handle successfully
import usb1
class USB:
"""USB class that handles IO operation with USB device
ENDPOINT_IN: device-to-host, ENDPOINT_OUT: host-to-device"""
# read size chunk
READ_CHUNK = 1024
def __init__(self, pid: hex, vid: hex, endpoint_in: hex, endpoint_out: hex) -> None:
self.endpoint_in = endpoint_in
self.endpoint_out = endpoint_out
self.pid = pid
self.vid = vid
self.context = usb1.USBContext()
def is_connected(self) -> bool:
"""Check if specified device is connected"""
with usb1.USBContext() as context:
for device in context.getDeviceIterator(skip_on_error=True):
if device.getVendorID() == self.vid and device.getProductID() == self.pid:
return True
def open(self) -> bool:
"""Open USB and initialize interface"""
try:
self.context.open()
return True
except Exception as err:
print("open device error:", err)
return False
def __get_handle(self):
"""return handle object"""
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
def close(self) -> bool:
"""Close USB"""
print("Closing USB")
try:
self.context.close()
print("Close handle successfully")
return True
except Exception as err:
print("Close handle error:", err)
return False
def write(self, msg: bytearray, timeout: int = 0) -> bool:
"""write an specific msg to device"""
handle = self.__get_handle()
if not handle:
return False
try:
with handle.claimInterface(0):
bytes_written = handle.bulkWrite(
self.endpoint_out, msg, timeout)
return bytes_written == len(msg)
except Exception as err:
print("write error", err)
handle.close()
return False
def read(self, timeout: int = 10) -> bytearray:
"""read data from the device"""
data = bytearray()
handle = self.__get_handle()
if not handle:
return False
try:
with handle.claimInterface(0):
while True:
try:
data += handle.bulkRead(self.endpoint_in,
self.READ_CHUNK, timeout)
except usb1.USBErrorTimeout:
break
except Exception as err:
print("read error", err)
return None
handle.close()
return data
def __del__(self):
print("Calling closing method to delete self")
self.close()
if __name__ == '__main__':
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
usb = USB(PRODUCT_ID, VENDOR_ID, ENDPOINT_IN, ENDPOINT_OUT)
#print(usb.is_connected())
msg = 100 * bytearray(b"B")
if usb.open():
print("write:", usb.write(msg))
print("read:", usb.read())
# error after adding this line
usb.close()
If we look at the debug log, one strange thing is like the following. There seems to be two times of libusb_get_device_list() and libusb_close() being called.
There is one special thing about libusb_get_device_list
: it is called in a generator method, getDeviceIterator
. I believe generators which are exhausted exit synchronously, but those which stop being used mid-sequence rely on garbage collection to close them, which then causes the pending (see EDIT below), which then (normally) causes the generator function to end.yield
statement to raise StopIteration
EDIT: This is apparently not actually the case, the code somehow jumps to any finally
block surrounding the active yield
statement without an exception being visible to the interpreter (sys.exc_info() == (None, None, None)
).
I do not see yet why libusb_get_device_list
would end up being called a second time, but I am getting the idea that there can be something wrong with context cleanup order while one such generator is stuck in limbo for the gc to clean it up.
One way to check this could be to call getDeviceList
instead of openByVendorIDAndProductID
, and basically duplicating the device matching logic: getDeviceList
exhausts the iterator.
...and I just noticed that your code calls __get_handle
twice (once in write
and once in read
). This should explain the duplicate libusb_get_device_list
call. It does not exclude an iterator lifetime issue, so I will poke a bit more at this.
Could you give a try to the following patch ? The context refcount wrapper (being patched here) can return before getDeviceIterator
does (because of collection order). This should force getDeviceIterator
to exit before the context refcount can be decremented. So I think this patch fixes a bug, I just do not know if it is related to this issue.
diff --git a/usb1/__init__.py b/usb1/__init__.py
index 1648124..6cd33cb 100644
--- a/usb1/__init__.py
+++ b/usb1/__init__.py
@@ -2085,9 +2085,13 @@ class USBContext(object):
with refcount(self):
if self.__context_p:
# pylint: disable=not-callable
- for value in func(self, *args, **kw):
- # pylint: enable=not-callable
- yield value
+ generator = func(self, *args, **kw)
+ # pylint: enable=not-callable
+ try:
+ for value in generator:
+ yield value
+ finally:
+ generator.close()
else:
def wrapper(self, *args, **kw):
with refcount(self):
...and I just noticed that your code calls
__get_handle
twice (once inwrite
and once inread
). This should explain the duplicatelibusb_get_device_list
call. It does not exclude an iterator lifetime issue, so I will poke a bit more at this.
Thanks. I think this is the root cause of the issue.
If I delete the read function, then there is no issue.
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~0 -0 !]> pip show libusb1
Name: libusb1
Version: 1.9.3
Summary: Pure-python wrapper for libusb-1.0
Home-page: http://github.com/vpelletier/python-libusb1
Author: Vincent Pelletier
Author-email: plr.vincent@gmail.com
License: LGPLv2.1+
Location: c:\work\python\py39venv\lib\site-packages
Requires:
Required-by:
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~0 -0 !]> cat .\cyusb_fx3_bulkloop_python_libusb1_write.py
# codes from https://github.com/vpelletier/python-libusb1/issues/72
import usb1
class USB:
"""USB class that handles IO operation with USB device
ENDPOINT_IN: device-to-host, ENDPOINT_OUT: host-to-device"""
# read size chunk
READ_CHUNK = 1024
def __init__(self, pid: hex, vid: hex, endpoint_in: hex, endpoint_out: hex) -> None:
self.endpoint_in = endpoint_in
self.endpoint_out = endpoint_out
self.pid = pid
self.vid = vid
self.context = usb1.USBContext()
def is_connected(self) -> bool:
"""Check if specified device is connected"""
with usb1.USBContext() as context:
for device in context.getDeviceIterator(skip_on_error=True):
if device.getVendorID() == self.vid and device.getProductID() == self.pid:
return True
def open(self) -> bool:
"""Open USB and initialize interface"""
try:
self.context.open()
return True
except Exception as err:
print("open device error:", err)
return False
def __get_handle(self):
"""return handle object"""
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
def close(self) -> bool:
"""Close USB"""
print("Closing USB")
try:
self.context.close()
print("Close handle successfully")
return True
except Exception as err:
print("Close handle error:", err)
return False
def write(self, msg: bytearray, timeout: int = 0) -> bool:
"""write an specific msg to device"""
handle = self.__get_handle()
if not handle:
return False
try:
with handle.claimInterface(0):
bytes_written = handle.bulkWrite(
self.endpoint_out, msg, timeout)
bytes_written == len(msg)
print("Number of bytes written: ", bytes_written)
return True
except Exception as err:
print("write error", err)
handle.close()
return False
def __del__(self):
print("Calling closing method to delete self")
self.close()
if __name__ == '__main__':
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
usb = USB(PRODUCT_ID, VENDOR_ID, ENDPOINT_IN, ENDPOINT_OUT)
#print(usb.is_connected())
msg = 1024 * bytearray(b"B")
if usb.open():
print("write:", usb.write(msg))
# error after adding this line
usb.close()
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~0 -0 !]> python .\cyusb_fx3_bulkloop_python_libusb1_write.py
Number of bytes written: 1024
write: True
Closing USB
Close handle successfully
Calling closing method to delete self
Closing USB
Close handle successfully
Could you give a try to the following patch ? The context refcount wrapper (being patched here) can return before
getDeviceIterator
does (because of collection order). This should forcegetDeviceIterator
to exit before the context refcount can be decremented. So I think this patch fixes a bug, I just do not know if it is related to this issue.
This does not seem to help.
(py39venv) C:\work\libusb\python-libusb1 [master ≡ +1 ~1 -0 !]> pip install .
Processing c:\work\libusb\python-libusb1
DEPRECATION: A future pip version will change local packages to be built in-place without first copying to a temporary directory. We recommend you use --use-feature=in-tree-build to test your packages with this new behavior before it becomes the default.
pip 21.3 will remove support for this functionality. You can find discussion regarding this at https://github.com/pypa/pip/issues/7555.
Building wheels for collected packages: libusb1
Building wheel for libusb1 (setup.py) ... done
Created wheel for libusb1: filename=libusb1-1.9.3+1.gae29a07.dirty-py3-none-any.whl size=60830 sha256=ba2cf9602c6bd831bbdd336387180292e1647ce41d0693201d469059093e9a0f
Stored in directory: c:\users\xfchen\appdata\local\pip\cache\wheels\b5\26\d7\725d45eae9e6667265a6409639f86f7f1b5bec0756a4c9f5e9
Successfully built libusb1
Installing collected packages: libusb1
Attempting uninstall: libusb1
Found existing installation: libusb1 1.9.3
Uninstalling libusb1-1.9.3:
Successfully uninstalled libusb1-1.9.3
Successfully installed libusb1-1.9.3+1.gae29a07.dirty
(py39venv) C:\work\libusb\python_usb [master ≡ +5 ~1 -0 !]> python .\cyusb_fx3_bulkloop_python_libusb1.py
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Closing USB
Close handle successfully
Exception ignored in: <function USBDevice.__del__ at 0x0000029F57258940>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1790, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
Calling closing method to delete self
Closing USB
Close handle successfully
Here is the quick hack but working codes with only single __get_handle call. Take note I remove the exception handlings to make it easy for me.
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~1 -0 !]> cat .\cyusb_fx3_bulkloop_python_libusb1_write_read.py
# codes from https://github.com/vpelletier/python-libusb1/issues/72
import usb1
class USB:
"""USB class that handles IO operation with USB device
ENDPOINT_IN: device-to-host, ENDPOINT_OUT: host-to-device"""
# read size chunk
READ_CHUNK = 1024
def __init__(self, pid: hex, vid: hex, endpoint_in: hex, endpoint_out: hex) -> None:
self.endpoint_in = endpoint_in
self.endpoint_out = endpoint_out
self.pid = pid
self.vid = vid
self.context = usb1.USBContext()
def is_connected(self) -> bool:
"""Check if specified device is connected"""
with usb1.USBContext() as context:
for device in context.getDeviceIterator(skip_on_error=True):
if device.getVendorID() == self.vid and device.getProductID() == self.pid:
return True
def open(self) -> bool:
"""Open USB and initialize interface"""
try:
self.context.open()
return True
except Exception as err:
print("open device error:", err)
return False
def __get_handle(self):
"""return handle object"""
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
def close(self) -> bool:
"""Close USB"""
print("Closing USB")
try:
self.context.close()
print("Close handle successfully")
return True
except Exception as err:
print("Close handle error:", err)
return False
def write_read(self, msg: bytearray, timeout: int = 0) -> bytearray:
"""write an specific msg to device and then read"""
data = bytearray()
handle = self.__get_handle()
with handle.claimInterface(0):
handle.bulkWrite(self.endpoint_out, msg, timeout)
bytes_written = len(msg)
print("Number of bytes written: ", bytes_written)
data += handle.bulkRead(self.endpoint_in,
self.READ_CHUNK, timeout)
handle.close()
return data
def __del__(self):
print("Calling closing method to delete self")
self.close()
if __name__ == '__main__':
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
usb = USB(PRODUCT_ID, VENDOR_ID, ENDPOINT_IN, ENDPOINT_OUT)
#print(usb.is_connected())
msg = 100 * bytearray(b"B")
if usb.open():
print("Reading back:", usb.write_read(msg))
# error after adding this line
usb.close()
(py39venv) C:\work\libusb\python_usb [master ≡ +7 ~1 -0 !]> python .\cyusb_fx3_bulkloop_python_libusb1_write_read.py
Number of bytes written: 100
Reading back: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Closing USB
Close handle successfully
Calling closing method to delete self
Closing USB
Close handle successfully
https://github.com/libusb/libusb/issues/974#issuecomment-909998431 https://github.com/libusb/libusb/issues/988
I have some simple codes to show device still referenced upon libusb_exit under Windows. Need to check if it is a libusb Windows issue or not. And I am not so sure if it is related to this issue or not.
Thanks. I think this is the root cause of the issue.
Well, it's definitely interesting to know it makes a difference, but I think it should not be the root cause. In the sense that it should be fine to list and open the device multiple times, at least as long as there is no overlap in the time both are opened. So while the pattern of list-open-read/write-close and then doing it all over again is not exactly typical (I would consider list-open-read/write-read/write-...-close to be more typical), at least I do not identify anything fundamentally wrong with it. So there has to be something actually wrong being triggered by this unusual pattern and causing the access violation.
I tend to believe there is an issue with libusb Windows as mentioned in libusb/libusb#974 and libusb/libusb/#988 with regard to device reference leak problem. It seems to me the issue has always been there under libusb Windows (tested back to libusb-1.0.21 release).
On the other hand, I tend to think the "access violation" may be related to how python-libusb1 works. Just wondering if python-libusb1 has some debug logging feature which I can use to debug further. Thanks.
Just wondering if python-libusb1 has some debug logging feature which I can use to debug further.
Unfortunately, no, there isn't. This said, I'm more and more convinced that you are somehow hitting a garbage collection issue, and these are quite sensitive to things like the timing in which things occur, and adding logs could push things over the edge into the "it's working again" order.
I've re-read more carefully the libusb debugging output, and here is how I would summarize and group it:
usb1.USBContext()
[ 0.000344] [0000507c] libusb: debug [libusb_init] libusb v1.0.24.11650
print("write:", usb.write(msg))
[ 0.013124] [0000507c] libusb: debug [libusb_get_device_list]
[ 0.053055] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.053428] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.053668] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.053980] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.054248] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.054456] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.054770] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.055084] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.055169] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.055247] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.055298] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.055345] [0000507c] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.055391] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.055531] [0000507c] libusb: debug [libusb_open] open 1.8
[ 0.055636] [0000507c] libusb: debug [libusb_claim_interface] interface 0
...
[ 0.057231] [0000507c] libusb: debug [libusb_release_interface] interface 0
[ 0.057314] [0000507c] libusb: debug [libusb_close]
write: True
print("read:", usb.read())
[ 0.057621] [0000507c] libusb: debug [libusb_get_device_list]
[ 0.095349] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.095506] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.095647] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.095973] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.096141] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.096268] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.096431] [0000507c] libusb: debug [libusb_get_device_descriptor]
[ 0.096641] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.096689] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.096733] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.096777] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.096821] [0000507c] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.096865] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.096940] [0000507c] libusb: debug [libusb_open] open 1.8
[ 0.097032] [0000507c] libusb: debug [libusb_claim_interface] interface 0
...
[ 0.127214] [0000507c] libusb: debug [libusb_release_interface] interface 0
[ 0.127515] [0000507c] libusb: debug [libusb_close]
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
usb.close()
[ 0.128372] [0000507c] libusb: debug [libusb_exit]
[ 0.133276] [0000507c] libusb: warning [libusb_exit] device 1.8 still referenced
[ 0.133487] [0000507c] libusb: warning [libusb_exit] device 1.0 still referenced
interpreter exit (?):
[ 0.137786] [0000507c] libusb: debug [libusb_unref_device] destroy device 1.8
Exception ignored in: <function USBDevice.__del__ at 0x000001BD8F7A8820>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1790, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
After libusb_close
calls, the 7th libusb_unref_device
does not happen, but nothing should be left referencing it. Could you try adding gc.collect()
after both the write()
and read()
calls ? Hopefully this should make these calls appear, and may resolve the access violation.
usb.close()
internal logic is as follows:
USBDevice.close
, whose logic is:
USBDeviceHandle
obtained from this devicelibusb_unref_device
libusb_exit
But in the above we can see that USBDevice.close
, called from .__del__
(so not by USBContext.close
but by the garbage collector) and after libusb_exit
. Also, because libusb_unref_device
is actually called it means mark the device as not to be closed again
did not happen.
So I believe what is happening here may be that python, seeing this USBDevice
being left with no reference left since write
returned, is removing it from USBContext.__close_set
(which is a weak set, so as to no prevent early garbage collection), but it somehow does no destroy it just yet: at this point, the USBDevice
instance is left in limbo, not reachable by the USBContext
instance, but not destroyed either. And eventually python's garbage collector runs (for example during interpreter shutdown), and bam, access violation.
So far I do not know how I will reliably fix this. Switching to a strong set
for USBContext.__close_set
would cause memory leaks for long-running applications which may open/close devices a lot (without closing the context). An alternative would be to trigger the garbage collector in USBContext._exit
to try to make it get rid of anything it may have pulled out of USBContext.__close_set
but not have destroyed yet, and it is not a nice solution and I have no idea how reliable it would be in practice.
Nice findings. I change the main function to include gc.collect() and indeed the issues go away.
if __name__ == '__main__':
import gc
#gc.enable()
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
usb = USB(PRODUCT_ID, VENDOR_ID, ENDPOINT_IN, ENDPOINT_OUT)
#print(usb.is_connected())
msg = 100 * bytearray(b"B")
if usb.open():
print("write:", usb.write(msg))
gc.collect()
print("read:", usb.read())
gc.collect()
# error after adding this line
usb.close()
(py39venv) C:\work\libusb\python_usb [master ≡ +8 ~1 -0 !]> python .\cyusb_fx3_bulkloop_python_libusb1_debug.py
Number of bytes written: 100
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Closing USB
Close handle successfully
Calling closing method to delete self
Closing USB
Close handle successfully
Debug log:
[ 0.053320] [000043c8] libusb: debug [libusb_close]
write: True
[ 0.055705] [000043c8] libusb: debug [libusb_unref_device] destroy device 1.37
[ 0.055832] [000043c8] libusb: debug [libusb_unref_device] destroy device 1.0
[...]
[ 0.121640] [000043c8] libusb: debug [libusb_close]
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
[ 0.125511] [000043c8] libusb: debug [libusb_unref_device] destroy device 1.37
[ 0.125672] [000043c8] libusb: debug [libusb_unref_device] destroy device 1.0
Closing USB
Excellent. And device 1.0 appears too, which I was not sure about. Here I feel we have touched the bottom of this issue.
I think I have found a cleaner way to fix this issue than explicit gc calls. I pushed the fix in a temporary branch, could you try this (at least without the gc.collect()
s, and ideally with the code you originally triggered the issue with) ?
The wip branch seems to help but there are a lot of warnings. And I think it still has some issues. Main issue is that the bahavior is not so consistent and sometimes the app will hang. And often there is this "usb1.USBErrorAccess: LIBUSB_ERROR_ACCESS [-3]" error message.
Code:
# codes from https://github.com/vpelletier/python-libusb1/issues/72
import usb1
class USB:
"""USB class that handles IO operation with USB device
ENDPOINT_IN: device-to-host, ENDPOINT_OUT: host-to-device"""
# read size chunk
READ_CHUNK = 1024
def __init__(self, pid: hex, vid: hex, endpoint_in: hex, endpoint_out: hex) -> None:
self.endpoint_in = endpoint_in
self.endpoint_out = endpoint_out
self.pid = pid
self.vid = vid
self.context = usb1.USBContext()
def is_connected(self) -> bool:
"""Check if specified device is connected"""
with usb1.USBContext() as context:
for device in context.getDeviceIterator(skip_on_error=True):
if device.getVendorID() == self.vid and device.getProductID() == self.pid:
return True
def open(self) -> bool:
"""Open USB and initialize interface"""
try:
self.context.open()
return True
except Exception as err:
print("open device error:", err)
return False
def __get_handle(self):
"""return handle object"""
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
def close(self) -> bool:
"""Close USB"""
print("Closing USB")
try:
self.context.close()
print("Close handle successfully")
return True
except Exception as err:
print("Close handle error:", err)
return False
def write(self, msg: bytearray, timeout: int = 0) -> bool:
"""write an specific msg to device"""
handle = self.__get_handle()
if not handle:
return False
try:
with handle.claimInterface(0):
bytes_written = handle.bulkWrite(
self.endpoint_out, msg, timeout)
bytes_written == len(msg)
print("Number of bytes written: ", bytes_written)
return True
except Exception as err:
print("write error", err)
#handle.close()
return False
def read(self, timeout: int = 10) -> bytearray:
"""read data from the device"""
data = bytearray()
handle = self.__get_handle()
if not handle:
return False
try:
with handle.claimInterface(0):
while True:
try:
data += handle.bulkRead(self.endpoint_in,
self.READ_CHUNK, timeout)
except usb1.USBErrorTimeout:
break
except Exception as err:
print("read error", err)
return None
handle.close()
return data
def __del__(self):
print("Calling closing method to delete self")
self.close()
if __name__ == '__main__':
VENDOR_ID = 0x04b4
PRODUCT_ID = 0x00f0
ENDPOINT_IN = 0x81
ENDPOINT_OUT = 0x01
usb = USB(PRODUCT_ID, VENDOR_ID, ENDPOINT_IN, ENDPOINT_OUT)
#print(usb.is_connected())
msg = 100 * bytearray(b"B")
if usb.open():
print("write:", usb.write(msg))
print("read:", usb.read())
# error after adding this line
usb.close()
Before the change (using release 1.9.3 version):
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> python ..\python_usb\cyusb_fx3_bulkloop_python_libusb1.py
Number of bytes written: 100
write: True
read: bytearray(b'BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB')
Closing USB
Close handle successfully
Exception ignored in: <function USBDevice.__del__ at 0x0000022811E0B940>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1778, in __del__
self.close()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1790, in close
self.__libusb_unref_device(self.device_p)
OSError: exception: access violation writing 0x0000000000000024
Calling closing method to delete self
Closing USB
Close handle successfully
After:
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> pip install .
Processing c:\work\libusb\python-libusb1_wip
DEPRECATION: A future pip version will change local packages to be built in-place without first copying to a temporary directory. We recommend you use --use-feature=in-tree-build to test your packages with this new behavior before it becomes the default.
pip 21.3 will remove support for this functionality. You can find discussion regarding this at https://github.com/pypa/pip/issues/7555.
Building wheels for collected packages: libusb1
Building wheel for libusb1 (setup.py) ... done
Created wheel for libusb1: filename=libusb1-1.9.3+4.gd88e2c0-py3-none-any.whl size=61334 sha256=e73a9f33af3b5da78cf58867e0232b5b45a88b31f7e9e20c3b6e8fd619f31cc5
Stored in directory: c:\users\xfchen\appdata\local\pip\cache\wheels\bf\01\cd\b543f3d47446fe65650c507543ffbc55d31914858eea76b1f1
Successfully built libusb1
Installing collected packages: libusb1
Attempting uninstall: libusb1
Found existing installation: libusb1 1.9.3
Uninstalling libusb1-1.9.3:
Successfully uninstalled libusb1-1.9.3
Successfully installed libusb1-1.9.3+4.gd88e2c0
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> $Env:LIBUSB_DEBUG=4
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> python ..\python_usb\cyusb_fx3_bulkloop_python_libusb1.py
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000271] [00001128] libusb: debug [libusb_init] libusb v1.0.24.11650
[ 0.000386] [00001128] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000608 events 0
[ 0.000600] [00001128] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.000689] [00001128] libusb: debug [usbi_add_event_source] add HANDLE 0000000000000680 events 0
[ 0.000782] [00001128] libusb: debug [get_windows_version] Windows 10 64-bit
[ 0.000890] [00001128] libusb: debug [htab_create] using 1021 entries hash table
[ 0.003879] [00001128] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.004970] [00001128] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.010338] [00001128] libusb: debug [windows_init] UsbDk backend is available
[ 0.010652] [00001128] libusb: debug [libusb_get_device_list]
[ 0.011915] [00000e50] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.031572] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [94]
[ 0.031808] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [95]
[ 0.032245] [00001128] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.032419] [00001128] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.032527] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [10]
[ 0.032816] [00001128] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.032951] [00001128] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.033053] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [1E]
[ 0.033528] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.033664] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.033761] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [71]
[ 0.034021] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.034152] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.034248] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [72]
[ 0.034490] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.034620] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.034720] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [73]
[ 0.035058] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.035210] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.035312] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [74]
[ 0.035616] [00001128] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_A36D&SUBSYS_091A1028&REV_10\3&11583659&0&A0' bus number 1
[ 0.035853] [00001128] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_15DB&SUBSYS_091A1028&REV_02\71D9F51854B3020000' bus number 2
[ 0.037821] [00001128] libusb: debug [winusb_get_device_list] extra GUID: {865C4DDE-10B6-6373-FAEE-1506B321A619}
[ 0.037962] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [71]
[ 0.038236] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.038362] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 59 bytes)
[ 0.038513] [00001128] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 3): 'USB\VID_046D&PID_C534\5&E9F3E45&0&3'
[ 0.038775] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [10]
[ 0.038978] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.039091] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.039245] [00001128] libusb: debug [init_device] (bus: 1, addr: 6, depth: 1, port: 14): 'USB\VID_8087&PID_0AAA\5&E9F3E45&0&14'
[ 0.039717] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [74]
[ 0.039910] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.039974] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 288 bytes)
[ 0.040121] [00001128] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 2): 'USB\VID_047F&PID_C056\D1CEC32927974D5F9BD6B2AEBF2EA8E3'
[ 0.040600] [00001128] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&36020D6F&0&0' reports 26 ports
[ 0.040781] [00001128] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&36020D6F&0&0'
[ 0.040980] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [73]
[ 0.041155] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.041243] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 269 bytes)
[ 0.041357] [00001128] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 10): 'USB\VID_0A5C&PID_5842\0123456789ABCD'
[ 0.041830] [00001128] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\7&2452366F&0&0' reports 4 ports
[ 0.041938] [00001128] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\7&2452366F&0&0'
[ 0.042260] [00001128] libusb: debug [winusb_get_device_list] extra GUID: {209D0288-9C4C-5B63-3A38-9EBE14E03F48}
[ 0.042346] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.042516] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.042601] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 44 bytes)
[ 0.042715] [00001128] libusb: debug [init_device] (bus: 1, addr: 16, depth: 1, port: 17): 'USB\VID_04B4&PID_00F0\5&E9F3E45&0&17'
[ 0.043248] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [72]
[ 0.043416] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.043503] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 1112 bytes)
[ 0.043618] [00001128] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 11): 'USB\VID_0BDA&PID_58FD\200901010001'
[ 0.044053] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\VID_044E&PID_1212&COL01&COL01\7&290AACAE&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.044183] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.044262] [00001128] libusb: debug [set_composite_interface] interface[1] = \\?\HID#VID_046D&PID_C534&MI_01&COL01#7&383A3A17&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.044409] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL01\5&99B72D3&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.044549] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.044621] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL03\7&383A3A17&0&0002
[ 0.044735] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&379854AA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.044833] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.044879] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL02\7&383A3A17&0&0001
[ 0.045038] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.045108] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL04\7&383A3A17&0&0003
[ 0.045267] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816&COL01\3&36A7043C&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.045411] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\VID_044E&PID_1212&COL01&COL02\7&290AACAE&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.045516] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.045562] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL05\7&383A3A17&0&0004
[ 0.045660] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816&COL02\3&36A7043C&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.045763] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL02\5&99B72D3&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.045856] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.045901] [00001128] libusb: debug [set_composite_interface] interface[3] = \\?\HID#VID_047F&PID_C056&MI_03&COL01#F&39E6F119&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.046019] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&379854AA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.046113] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.046157] [00001128] libusb: debug [set_composite_interface] interface[3] already set - ignoring HID collection: HID\VID_047F&PID_C056&MI_03&COL02\F&39E6F119&0&0001
[ 0.046249] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.046295] [00001128] libusb: debug [set_composite_interface] interface[3] already set - ignoring HID collection: HID\VID_047F&PID_C056&MI_03&COL03\F&39E6F119&0&0002
[ 0.046395] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL03\5&99B72D3&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.046490] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.046536] [00001128] libusb: debug [set_composite_interface] interface[0] = \\?\HID#VID_046D&PID_C534&MI_00#7&1C54B96&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}\KBD
[ 0.046637] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL04\5&99B72D3&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.046739] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL05\5&99B72D3&0&0004' (non USB HID, newly connected, etc.) - ignoring
[ 0.046925] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&379854AA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.048052] [00001128] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.048241] [00001128] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.049134] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.049221] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.049331] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.049385] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.052363] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.052489] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.052548] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x25
[ 0.052601] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x25
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.055215] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.055289] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.055337] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.057850] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.057918] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.060381] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.060437] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.060484] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.063124] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.063183] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.063230] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
[ 0.063275] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.065596] [00001128] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.065648] [00001128] libusb: debug [libusb_unref_device] destroy device 1.6
[ 0.065693] [00001128] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.065740] [00001128] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.065785] [00001128] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.065828] [00001128] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.065914] [00001128] libusb: debug [libusb_open] open 1.16
[ 0.066010] [00001128] libusb: debug [libusb_claim_interface] interface 0
[ 0.066143] [00001128] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 0.066192] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
[ 0.066235] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
[ 0.066280] [00001128] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 0.066326] [00001128] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 0.066496] [00001128] libusb: debug [libusb_submit_transfer] transfer 00000256A89FCF08
[ 0.066547] [00001128] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 01 with interface 0
[ 0.066592] [00001128] libusb: debug [winusbx_submit_bulk_transfer] writing 100 bytes
[ 0.066662] [00001128] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.066710] [00001128] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.066757] [00001128] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.066730] [00000e50] libusb: debug [windows_iocp_thread] transfer 00000256A89FCF08 completed, length 100
[ 0.066964] [00001128] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.067010] [00001128] libusb: debug [handle_event_trigger] event triggered
[ 0.067052] [00001128] libusb: debug [windows_handle_transfer_completion] handling transfer 00000256A89FCF08 completion with errcode 0, length 100
[ 0.067122] [00001128] libusb: debug [usbi_handle_transfer_completion] transfer 00000256A89FCF08 has callback 00007FF9CBBE9220
[ 0.067188] [00001128] libusb: debug [sync_transfer_cb] actual_length=100
[ 0.067267] [00001128] libusb: debug [libusb_free_transfer] transfer 00000256A89FCF08
[ 0.067380] [00001128] libusb: debug [libusb_release_interface] interface 0
Number of bytes written: 100
write: True
[ 0.067738] [00001128] libusb: debug [libusb_get_device_list]
[ 0.086850] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [94]
[ 0.087068] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [95]
[ 0.087457] [00001128] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.087622] [00001128] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.087729] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [10]
[ 0.088022] [00001128] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.088195] [00001128] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.088354] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.088900] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.089038] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.089135] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [71]
[ 0.089386] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.089517] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.089617] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [72]
[ 0.089862] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.089994] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.090099] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [73]
[ 0.090416] [00001128] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.090547] [00001128] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.090624] [00001128] libusb: debug [winusb_get_device_list] allocating new device for session [74]
[ 0.090941] [00001128] libusb: debug [enumerate_hcd_root_hub] assigning HCD 'PCI\VEN_8086&DEV_15DB&SUBSYS_091A1028&REV_02\71D9F51854B3020000' bus number 2
[ 0.092630] [00001128] libusb: debug [winusb_get_device_list] extra GUID: {865C4DDE-10B6-6373-FAEE-1506B321A619}
[ 0.092737] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [71]
[ 0.092903] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.092988] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 59 bytes)
[ 0.093103] [00001128] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 3): 'USB\VID_046D&PID_C534\5&E9F3E45&0&3'
[ 0.093319] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [10]
[ 0.093485] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.093566] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.093674] [00001128] libusb: debug [init_device] (bus: 1, addr: 6, depth: 1, port: 14): 'USB\VID_8087&PID_0AAA\5&E9F3E45&0&14'
[ 0.094077] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [74]
[ 0.094241] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.094322] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 288 bytes)
[ 0.094424] [00001128] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 2): 'USB\VID_047F&PID_C056\D1CEC32927974D5F9BD6B2AEBF2EA8E3'
[ 0.094955] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [73]
[ 0.095150] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.095259] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 269 bytes)
[ 0.095410] [00001128] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 10): 'USB\VID_0A5C&PID_5842\0123456789ABCD'
[ 0.095915] [00001128] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\7&2452366F&0&0' reports 4 ports
[ 0.096047] [00001128] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\7&2452366F&0&0'
[ 0.096376] [00001128] libusb: debug [winusb_get_device_list] extra GUID: {209D0288-9C4C-5B63-3A38-9EBE14E03F48}
[ 0.096467] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.097055] [00001128] libusb: debug [winusb_get_device_list] found existing device for session [72]
[ 0.097228] [00001128] libusb: debug [init_device] found 1 configurations (current config: 1)
[ 0.097320] [00001128] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 1112 bytes)
[ 0.097431] [00001128] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 11): 'USB\VID_0BDA&PID_58FD\200901010001'
[ 0.097843] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\VID_044E&PID_1212&COL01&COL01\7&290AACAE&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.097975] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.098093] [00001128] libusb: debug [set_composite_interface] interface[1] = \\?\HID#VID_046D&PID_C534&MI_01&COL01#7&383A3A17&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.098240] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL01\5&99B72D3&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.098416] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.098515] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL03\7&383A3A17&0&0002
[ 0.098646] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&379854AA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.098802] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.098898] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL02\7&383A3A17&0&0001
[ 0.099007] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.099080] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL04\7&383A3A17&0&0003
[ 0.099184] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816&COL01\3&36A7043C&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.099300] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\VID_044E&PID_1212&COL01&COL02\7&290AACAE&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.099428] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.099501] [00001128] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: HID\VID_046D&PID_C534&MI_01&COL05\7&383A3A17&0&0004
[ 0.099604] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816&COL02\3&36A7043C&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.099736] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL02\5&99B72D3&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.099858] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.099933] [00001128] libusb: debug [set_composite_interface] interface[3] = \\?\HID#VID_047F&PID_C056&MI_03&COL01#F&39E6F119&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.100076] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&379854AA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.100190] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.100237] [00001128] libusb: debug [set_composite_interface] interface[3] already set - ignoring HID collection: HID\VID_047F&PID_C056&MI_03&COL02\F&39E6F119&0&0001
[ 0.100336] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [74]:
[ 0.100383] [00001128] libusb: debug [set_composite_interface] interface[3] already set - ignoring HID collection: HID\VID_047F&PID_C056&MI_03&COL03\F&39E6F119&0&0002
[ 0.100487] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL03\5&99B72D3&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.100630] [00001128] libusb: debug [winusb_get_device_list] setting composite interface for [71]:
[ 0.100730] [00001128] libusb: debug [set_composite_interface] interface[0] = \\?\HID#VID_046D&PID_C534&MI_00#7&1C54B96&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}\KBD
[ 0.100887] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL04\5&99B72D3&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.101041] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\DELL091A&COL05\5&99B72D3&0&0004' (non USB HID, newly connected, etc.) - ignoring
[ 0.101202] [00001128] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&379854AA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.102328] [00001128] libusb: debug [get_api_type] driver(s): WinUSB
[ 0.102450] [00001128] libusb: debug [get_api_type] matched driver name against WinUSB
[ 0.103250] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.103315] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.103430] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.103484] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.106059] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.106116] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.106162] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x25
[ 0.106209] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x25
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.108789] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.108847] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.108894] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.111352] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.111467] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.114205] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.114313] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.114416] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.116859] [00001128] libusb: debug [libusb_get_device_descriptor]
[ 0.116919] [00001128] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.116965] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
[ 0.117010] [00001128] libusb: debug [parse_endpoint] skipping descriptor 0x30
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.119648] [00001128] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.119704] [00001128] libusb: debug [libusb_unref_device] destroy device 1.6
[ 0.119749] [00001128] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.119795] [00001128] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.119840] [00001128] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.119883] [00001128] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.119962] [00001128] libusb: debug [libusb_open] open 1.16
[ 0.120037] [00001128] libusb: error [winusbx_open] could not open device \\?\USB#VID_04B4&PID_00F0#5&E9F3E45&0&17#{A5DCBF10-6530-11D2-901F-00C04FB951ED} (interface 0): [5] Access is denied.
[ 0.120114] [00001128] libusb: debug [libusb_open] open 1.16 returns -3
Traceback (most recent call last):
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 102, in <module>
print("read:", usb.read())
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 70, in read
handle = self.__get_handle()
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 36, in __get_handle
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2325, in openByVendorIDAndProductID
return result.open()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2082, in open
mayRaiseUSBError(libusb1.libusb_open(self.device_p, byref(handle)))
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 127, in mayRaiseUSBError
__raiseUSBError(value)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 119, in raiseUSBError
raise __STATUS_TO_EXCEPTION_DICT.get(value, __USBError)(value)
usb1.USBErrorAccess: LIBUSB_ERROR_ACCESS [-3]
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x00000256A930B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
[ 0.132021] [00001128] libusb: debug [libusb_close]
[ 0.132232] [00001128] libusb: debug [libusb_unref_device] destroy device 1.16
Calling closing method to delete self
Closing USB
[ 0.134420] [00001128] libusb: debug [libusb_exit]
[ 0.134577] [00000e50] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 0.136633] [00001128] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000680
[ 0.136756] [00001128] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000608
[ 0.136870] [00001128] libusb: warning [libusb_exit] device 1.0 still referenced
Close handle successfully
In the case of hang:
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> python ..\python_usb\cyusb_fx3_bulkloop_python_libusb1.py
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x0000020531B1C5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2163, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x.close())
AttributeError: 'weakref' object has no attribute 'close'
... hang here and I have to hit reset of the device to recover ...
KeyboardInterrupt
Calling closing method to delete self
Closing USB
Close handle successfully
Exception ignored in: <function USBDeviceHandle.__del__ at 0x0000020531AF8670>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1077, in __del__
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1122, in close
OSError: exception: access violation writing 0x0000000000000024
BTW, I am not sure if this has anything to do with the topic here: https://github.com/rene-aguirre/pywinusb/issues/56 .
The issue is not related to libusb (pywinusb is only for HID device despite the name. It is Windows only). Interestingly, the pywinusb issue goes away with Python 3.9. So the issue is not exactly the same. Nevertheless it seems to me Windows Python is a bit different from other platforms.
AttributeError: 'weakref' object has no attribute 'close'
Woops, I did not notice it would receive the weakref and not the referent. I fixed this and pushed to wip branch.
But I also found something else in the weakref documentation which may make this solution impossible. If you get similar errors but with NoneType
instead of weakref
in the error, then this is not going to work and I have to find yet another way.
BTW, I am not sure if this has anything to do with the topic here: rene-aguirre/pywinusb#56 .
I am wary about making conclusions when there is another issue already going on (the weakref callback raising). Garbage collection is a very ticklish beast, small changes can make a large impact. Adding or removing __del__
methods can change the order in which objects get collected, and IIRC prevents python from breaking reference cycles. I started python-libusb1 before knowing this, and now getting rid of these __del__
requires more thinking. I am hoping that my pending change could make this easier... Except if it just does not work.
But I also found something else in the weakref documentation which may make this solution impossible. If you get similar errors but with
NoneType
instead ofweakref
in the error, then this is not going to work and I have to find yet another way.
Unfortunately this seems to be the case.
(py39venv) C:\work\libusb\python-libusb1-wip [wip ≡]> python ..\python_usb\cyusb_fx3_bulkloop_python_libusb1.py
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Number of bytes written: 100
write: True
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Traceback (most recent call last):
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 102, in <module>
print("read:", usb.read())
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 70, in read
handle = self.__get_handle()
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 36, in __get_handle
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2326, in openByVendorIDAndProductID
return result.open()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2083, in open
mayRaiseUSBError(libusb1.libusb_open(self.device_p, byref(handle)))
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 127, in mayRaiseUSBError
__raiseUSBError(value)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 119, in raiseUSBError
raise __STATUS_TO_EXCEPTION_DICT.get(value, __USBError)(value)
usb1.USBErrorAccess: LIBUSB_ERROR_ACCESS [-3]
Exception ignored in: <function _WeakSetCallback.__init__.<locals>._remove at 0x000002332FD0B5E0>
Traceback (most recent call last):
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 263, in _remove
callback(item)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2164, in <lambda>
self.__close_set = _WeakSetCallback(callback=lambda x: x().close())
AttributeError: 'NoneType' object has no attribute 'close'
Calling closing method to delete self
Closing USB
Close handle successfully
I think I have a better solution, just force-pushed in wip
branch. It turned out the be a lot more work, but it had some very nice payoffs as side-effects (almost no __del__
method left). Could you give it a try ?
This does not seem to work.
(py39venv) C:\work\libusb\python-libusb1_wip [wip ≡]> python ..\python_usb\cyusb_fx3_bulkloop_python_libusb1.py
Traceback (most recent call last):
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 101, in <module>
print("write:", usb.write(msg))
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 51, in write
handle = self.__get_handle()
File "C:\work\libusb\python_usb\cyusb_fx3_bulkloop_python_libusb1.py", line 36, in __get_handle
return self.context.openByVendorIDAndProductID(self.vid, self.pid)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2536, in openByVendorIDAndProductID
return result.open()
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 2254, in open
return USBDeviceHandle(
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1236, in __init__
registerFinalizer(handle, self.close)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1990, in __registerFinalizer
assert handle not in self.__finalizer_dict
TypeError: unhashable type
Traceback (most recent call last):
File "C:\Python39\lib\weakref.py", line 656, in _exitfunc
f()
File "C:\Python39\lib\weakref.py", line 580, in __call__
return info.func(*info.args, **(info.kwargs or {}))
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1290, in close
unregisterFinalizer(handle)
File "C:\work\python\py39venv\lib\site-packages\usb1\__init__.py", line 1994, in __unregisterFinalizer
self.__finalizer_dict.pop(handle)
KeyError: <usb1.libusb1.LP_libusb_device_handle object at 0x0000025FBCE3E3C0>
Calling closing method to delete self
Closing USB
Close handle successfully
TypeError: unhashable type
Woops, I had fixed one such occurrence, and forgot about the 2 others, sorry. I pushed a fix.
Now it hangs without any errors.
This error is a bit weird: visibly this happens in write()
before it returns, and the error is that handle_events
does not get any event to handle, and hence it blocks forever (just waking up every 60s). As you are not using any async transfers, I suspect these calls are the ones done internally to libusb (as synchronous transfers are actually based on async transfers + a blocking handle_events
call, internally to libusb). Maybe there was something wrong with the device at that point ?
Checking this, I did found a bug with my change, but it should be unrelated to this hang (it was not possible to open the same device more than once). I fixed it, and tested a minimally modified version of you test code (only changing vendor id and device id to match those used in python-functionfs/examples/usbcat/device.py) and it is working on both win10 (with WinUSB driver attached to my pizero running usbcat/device.py) and linux.
Note that usbcat is not a loopback test but a bidirectional pipe (like netcat). As I did not provide any input to it, read
s always return an empty string. I think this does not change how representative this test is.
EDIT: the linux output includes non-committed debug prints in finalizer {un,}register functions.
Yes libusb sync transfer is internally based on async plus a blocking handle_events call. https://github.com/libusb/libusb/blob/master/libusb/sync.c
I believe the device is okay as I tested with pyusb based code as well before using python-libusb1. https://github.com/mcuee/python_usb/blob/master/cyusb_fx3_loopback-test_python3.py https://github.com/pyusb/pyusb/issues/235
I will try another device, probably Linux Gadegt Zero.
Ah, I did not finish explaining my train of thought: As you do not create any async transfer and do not call handle_events
, this means that the infinite loop you are getting comes from the bulkWrite
itself. And it should not be affected by the changes I did...
So while I trust that your device is working, I was suspecting that for whatever reason (my previous bug having put it and/or windows in a weird state ?) it was not responding anymore. Maybe unplug/replug could have been enough (more if it was windows that was confused).
I think you are right. I tried it again (but with another Windows 10 laptop at home) and it works fine (tested with libusb-1.0.23, 1.0.24 and latest git 1.0.24.11650). So I think the fixes are good.
There is a warning in the end of the debug log though. But I am not sure if it is an issue with libusb Windows or python-libusb1.
[ 0.103928] [00004f70] libusb: warning [libusb_exit] device 1.0 still referenced
And your example works fine as well under my OrangePi Zero with old Python 3.5 and ARMBIAN 5.60 stable Debian GNU/Linux 9 (stretch) 4.14.70-sunxi.
OrangePi Zero Linux USB Gadget
mcuee@orangepizero:~/usbgadgests/python-functionfs$ sudo python3 examples/usbcat/device.py
epoll: fd 3 got event 1
onBind
epoll: fd 3 got event 1
onEnable
epoll: fd 3 got event 1
aio read completion received 100 bytes
epoll: fd 3 got event 1
aio read completion received 100 bytes
Windows 10 host
(mypy39x64) PS C:\work\pyusb> python .\test_functionfs.py
Number of bytes written: 100
write: True
read: bytearray(b'')
Closing USB
Close handle successfully
Calling closing method to delete self
Closing USB
Close handle successfully
[ 0.103928] [00004f70] libusb: warning [libusb_exit] device 1.0 still referenced
This is indeed a bit surprising. In a previous try (with explicit gc.collect()
calls) it did not happen, device 1.0 got somehow destroyed. No such device appear in my case (maybe running in a VM makes a difference ?). I'll try to see if I can reproduce this and identify what device this is.
I now consider my changes to be in the right direction, so I pushed them to master and dropped the wip
branch. Thanks a lot for your patient testing !
And your example works fine as well under my OrangePi Zero with old Python 3.5 and ARMBIAN 5.60 stable Debian GNU/Linux 9 (stretch) 4.14.70-sunxi.
Awesome. So far I personally have only run it on an intel edison (udc=DWC3 but without companion chip for USB3 support and some quirks - some endpoints do not work) and on a raspberry pi zero (udc=DWC2). Good to know that it is working on more gadget-able devices.
Hello, I've a created a sample class for libusb but when I call the
close
method I get access violation writing error. When theclose
method calls with destructor it works just fine. I'm not sure if I'm missing something in here.error: