Python script takes long time to terminate

[apppie123]

When a simple python script(see below) is terminated in linux, it takes 11 seconds for the script to actually terminate when it's done.

In windows this is almost instantly. Why would this be?

import EasyMCP2221
from time import sleep

# Connect to the device
mcp = EasyMCP2221.Device()

# Reclaim GP0 for General Purpose Input Output, as an Output.
mcp.set_pin_function(gp0 = "GPIO_OUT")
mcp.GPIO_write(gp0 = False)
#mcp.save_config()

for x in range(0,4):
    mcp.GPIO_write(gp0 = True)
    sleep(0.5)
    mcp.GPIO_write(gp0 = False)
    sleep(2)

print("done")

[electronicayciencia]

Hello. I was able to reproduce the problem with a simpler script like this one:

import EasyMCP2221
mcp = EasyMCP2221.Device()
print("done")

It was fixed when I followed the instructions to run the script as non-root: Hidapi open failure I will investigate why. However, can you try that configuration and tell me if it works for you? Remember to unplug/plug the device to apply the new rules.

Thank you.

[apppie123]

The HIDapi error prevented me to run the script in Ubuntu 22.04. So I already applied those rules to be able to run this script.

So with this in place I get the ~11 seconds delay before the script terminates.

I've already done a reboot with no effect.

[electronicayciencia]

It seems to be related to HID module in Linux. Because the same delay happens just by running this code:

import hid
hidhandler = hid.device()
devs = hid.enumerate(0x04D8, 0x00DD)
hidhandler.open_path(devs[0]["path"])
print ("done")
exit

[electronicayciencia]

@apppie123 , are you running the code inside a virtual machine? I reproduced the problem with Ubuntu 20.04.3 LTS inside VMware Player 16. The issue solved when I switched the USB compatibility mode to USB 3:

I couldn't reproduce the problem in raspbian native nor in Ubuntu 18 (virtualized). Maybe it is some kind of incompatibility between the kernel version and the USB hardware.

[apppie123]

Thanks for looking into it! I'm running it native on a laptop with ubuntu 22.04, as far as I can see with lsusb -v, this laptop does not seem to have USB 3.1(just USB 2).

[apppie123]

Did you happen to test throughput of data as well with USB3 vs USB2? I don't know if it is related to the driver as well, but I don't see much difference between 100kHz and 400kHz communication speed using i2c. I can only get a max of 53 loops per second when exchanging 12 bytes of data over i2c. Which I think is far less than should be expected.

[electronicayciencia]

I've doing some tests with an old laptop. An HP-G62; it has only USB2 ports. I've installed Ubuntu 18.04 and all the examples run flawlessly. I wrote a small example to get DAC writing speed. With USB 2.0 I got 333 samples per second instead of 500 (it will become important later). Nothing weird until here.

Then, I installed Ubuntu 22.04 on the same laptop. Everything was fine, except at the end of the script; as you said.

According to strace, the delay seems to happen on USBDEVFS_RELEASEINTERFACE ioctl call.

This is the usbmon's trace. I still don't know what all this mean. But seems to repeat four times the same sequence at the end. Waiting about 5 second between calls.

ffff9622d1ffb6c0 3599904193 S Io:2:047:3 -115:1 1 = 51
ffff9622d1ffb6c0 3599908254 C Io:2:047:3 0:1 1 >
ffff9622d1ffb0c0 3599909357 C Ii:2:047:3 0:1 64 = 51000100 0100eeef eeef0000 00000000 00000000 00000101 0000f90d f3000008
ffff9622d1ffb0c0 3599909425 S Ii:2:047:3 -115:1 64 <
<delay>
ffff9622d1ffb6c0 3604072311 S Io:2:047:3 -115:1 1 = 51
ffff9622d1ffb6c0 3604959713 C Io:2:047:3 0:1 1 >
ffff9622d1ffb0c0 3604960556 C Ii:2:047:3 0:1 64 = 51000100 0100eeef eeef0000 00000000 00000000 00000101 0000f90d f3000008
ffff9622d1ffb0c0 3604960634 S Ii:2:047:3 -115:1 64 <
<delay>
ffff9622d1ffb6c0 3609191780 S Io:2:047:3 -115:1 1 = 51
ffff9622d1ffb6c0 3609952404 C Io:2:047:3 0:1 1 >
ffff9622d1ffb0c0 3609953154 C Ii:2:047:3 0:1 64 = 51000100 0100eeef eeef0000 00000000 00000000 00000101 0000f90d f3000008
ffff9622d1ffb0c0 3609953213 S Ii:2:047:3 -115:1 64 <
<delay>
ffff9622d1ffb600 3614055038 S Io:2:047:3 -115:1 1 = 51
ffff9622d1ffb600 3614962944 C Io:2:047:3 0:1 1 >
ffff9622d1ffb0c0 3614963999 C Ii:2:047:3 0:1 64 = 51000100 0100eeef eeef0000 00000000 00000000 00000101 0000f90d f3000008
ffff9622d1ffb0c0 3614964026 S Ii:2:047:3 -115:1 64 <
<end>

I will investigate further from here.

About the I2C speed. Your results are not unexpected. Each I2C interaction requires several USB request. See Internal details.

For write they're: setup, data, and one or more checking. For read: setup, busy check, and read buffer. Each of these requests requires a USB call. On USB 2.0 the DAC speed is 333 samples per second. It means 333 calls per second.

Supposing you need 6 I2C calls (3 for write, 3 for read) it gives us 333/6 = 55 loops per second. Very close to your 53.

The I2C speed 100kHz / 400kHz only matters when you are transmitting a lot of bytes. For 12 bytes interaction, speed is limited by the USB polling rate.

[electronicayciencia]

@apppie123 , I think I found the cause. The culprit is a kernel module called hid_mcp2221. It interferes with my library's raw commands. Can you try the following, please, and tell me if that works for you?

To blacklist the module, create a file named "/etc/modprobe.d/blacklist-mcp2221.conf" with this content:

blacklist hid_mcp2221

Then, remove the module from the kernel by running this command: rmmod hid_mcp2221.

After that, it should work without delays.