Linux: read() timeout not respected: high CPU usage

Issue #16 open
David Fokkema
created an issue

On linux (I tested a laptop and a raspberry pi) read() returns immediately if there is no data. It does not wait for a timeout to occur. The timeout should be about 16 ms, per the FTDI documentation. Polling for data thus results in high CPU usage on linux systems. On the Pi (running raspbian), I recompiled libusb (1.0.19) and libftdi (1.1) and reinstalled pylibftdi (0.14.1) and got the same results.

I used the following code:

import time
import pylibftdi

dev = pylibftdi.Device()
N = 0
t0 = time.time()
while True:
    dev.read(62)
    N += 1
    if time.time() - t0 > 1:
        print "Read frequency (approx.): %.1f Hz" % N
        t0 = time.time()
        N = 0

On my Mac, I get a read frequency of 63 Hz (16 ms timeout) and about 2 % CPU usage. On the Pi, I get a frequency varying from 700 - 900 Hz and 30 - 40 % CPU usage.

Comments (12)

  1. Ben Bass repo owner

    Hi David,

    I've tested your program on a Linux machine running 64 bit Ubuntu 14.04 with FT232R, FT232H and FT245RL devices; all report 63.0 Hz from your program. I have a Raspberry Pi, but won't be able to check that for a couple of days.

    I'm using libusb from the Ubuntu package libusb-1.0-0, I think I compiled libftdi myself though some time ago:

    >>> from pylibftdi import driver                                                                                                                                                               
    >>> driver.Driver().libftdi_version()
    (1, 0, 0, '1.0', 'v1.0-37-g048eb72')
    >>> 
    

    Which FTDI device(s) are you using?

    Honestly I wasn't aware of the 16ms timeout, and in my user-code I've typically assumed that read() could return immediately and taken that into account when polling, but I can see that a small timeout is a good thing if it works!

    -- edit: just rebuilt latest libftdi1 from git ('v1.1-12-g2ecba57') and I get the same 63Hz results.

    Ben

  2. David Fokkema reporter

    This is what I get:

    >>> from pylibftdi import driver
    >>> driver.Driver().libftdi_version()
    (1, 1, 0, '1.1', 'unknown')
    

    I'm using a device I believe to be a FT2232H, with vendor/product id 0x403, 0x6010. On my laptop, I used a 32-bit Ubuntu 14.04, without compiling new libraries. I can try that.

    I'm not sure if it is a pylibftdi or libftdi or libusb bug. I really hope you can reproduce the bug on your Pi, ;-). Maybe the bug only surfaces using a FT2232H.

  3. Ben Bass repo owner

    I've replicated the problem on my Raspberry Pi (model B); got approx 980Hz and 45% CPU usage running your test code.

    At this point I'm suspecting something Pi-specific here; there's no shortage of Pi related USB issues doing searches on this sort of thing. I'm fairly sure this isn't specific to pylibftdi since it works on Mac and (non-Pi) Linux, and the code path when read() returns an empty string only performs a single call to libftdi's ftdi_read_data; there's no time-related code in that pylibftdi code.

    I'll take a more detailed look at some point, but can't promise a quick solution; I'm keen to avoid workarounds in the pylibftdi code which could equally well be done in user code (e.g. either a 1ms delay following an empty read, or perhaps checking the duration of a read() which returns an empty string and adding a short delay if it is less than some threshold to avoid additional latency if 'correct' timeout is happening).

  4. David Fokkema reporter

    Unfortunately, I can also reproduce the error on an Eee PC 1000H with a 32-bit linux kernel. I run Ubuntu 14.04 on that machine, and I tried recompiling libusb and libftdi (above-mentioned versions).

    Do I understand correctly that you think the problem lies not in pylibftdi? Then it must be libftdi or libusb? If so, I'll brush up on my C and try to write a minimal script that reads out my device, first using libftdi.

  5. Ben Bass repo owner

    OK, I can reproduce the problem on my Eee PC701 running Ubuntu 12.04 (but not on a modern-ish laptop).

    strace of the process shows continual 1ms sleeps (using select) following EAGAIN responses to an ioctl.

    I'm not a USB expert by a long way, and certainly EAGAIN gets processed well below the level of pylibftdi. I may be able to dig further at some point, but yes, I suspect the problem is not directly in pylibftdi. There may be some way I can mitigate / avoid the issue in pylibftdi though, but can't promise anything quick.

  6. David Fokkema reporter

    I can not not reproduce the problem. I tried a Macbook Pro (mid 2010) using Ubuntu 14.04, fully upgraded, and also after recompiling the above-mentioned libraries and versions. Still, the problem occurs. Maybe the MBP is not modern-ish enough? I've compiled libftdi from the git repository, but that does not help. Maybe it is deep down, in libusb.

    I can use a workaround to limit the CPU usage, but it is ugly, and during the sleep it is not possible to receive data.

  7. Tom Kooij

    This is probably caused by the linux kernel setting the latency to 1ms upon autodiscovery and/or setup of the USB connection. (Or it might be libusb, or latency is 1ms by default and the windows ftdi driver sets it to 16ms...).

    On my laptop (Ubuntu 14.04 LTS in virtualbox) latency is set to 1ms on an FT232RL immediately after USB plugin, with the above described high CPU usage when polling for data.

    To fix this, manually set the latency timer using a call to libftdi:

    dev = pylibftdi.Device()
    dev.ftdi_fn.ftdi_set_latency_timer(16)
    

    As 16ms latency is the datasheet standard, you might want to include this in the Device() class and/or add a warning in documentation.

  8. Ben Bass repo owner

    Thanks Tom; I'll add this to the next version; various parameters are already defaulted on startup (e.g. bitmode, flow control and baud rate); setting this in addition seems sensible and can always be overridden if particular applications need it..

  9. Log in to comment