High CPU using FT232H, CircuitPython and Pillow

[mckenziec]

Hiya.

I've been playing with an FT232H and ili3941 display as per this guide: https://learn.adafruit.com/tft-sidekick-with-ft232h/overview

I'm finding on my Ubuntu 18.04 LTS server writing an Image to the display is resulting is high CPU. My server is an Atom J4105, it's a pretty nice low power x86 server (https://ark.intel.com/content/www/us/en/ark/products/128989/intel-celeron-j4105-processor-4m-cache-up-to-2-50-ghz.html)

import board
import digitalio
import adafruit_rgb_display.ili9341 as ili9341
from PIL import Image, ImageDraw
import time

cs_pin = digitalio.DigitalInOut(board.C0)
dc_pin = digitalio.DigitalInOut(board.C1)
disp = ili9341.ILI9341(board.SPI(), cs=cs_pin, dc=dc_pin, baudrate=64000000, width=240, height=320)

image = Image.new('RGB', (disp.width, disp.height))
draw = ImageDraw.Draw(image)
while True:
    disp.image(image, 0)
    time.sleep(1)

All it does is draw the same image to the display every 1 second. it doesn't recreate the image or anything, just display it.

When I watch htop the python ./test.py is just running with 25% cpu consistently.

So I ran profile with the above program, only with 1 iteration (draw the image once), here's the top results:

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    149/1    0.024    0.000    3.230    3.230 {built-in method builtins.exec}
        1    0.000    0.000    3.230    3.230 stats.py:1(<module>)
      206    0.004    0.000    1.457    0.007 usbtools.py:54(find_all)
       24    0.000    0.000    1.446    0.060 rgb.py:261(write)
      204    0.002    0.000    1.426    0.007 chip.py:29(id)
       46    0.000    0.000    1.273    0.028 spi_device.py:79(__enter__)
       46    0.001    0.000    1.235    0.027 busio.py:102(configure)
        1    0.000    0.000    1.181    1.181 ili9341.py:92(__init__)
        1    0.000    0.000    1.181    1.181 rgb.py:237(__init__)
        1    0.000    0.000    1.178    1.178 rgb.py:120(__init__)
        1    0.000    0.000    1.178    1.178 rgb.py:128(init)
      216    0.002    0.000    1.004    0.005 usbtools.py:203(_find_devices)
        1    1.001    1.001    1.001    1.001 {built-in method time.sleep}
      146    0.001    0.000    0.969    0.007 board.py:291(id)

There's 206 calls to usbtools.py and chip.py. I think that's the device setup, and there is an initial delay before image processing.

However when I add cProfile to just the disp.image() call, I timed 0.5 seconds to display the image! Here's the code:

import board
import digitalio
import adafruit_rgb_display.ili9341 as ili9341
from PIL import Image, ImageDraw
import time
import cProfile

cs_pin = digitalio.DigitalInOut(board.C0)
dc_pin = digitalio.DigitalInOut(board.C1)
disp = ili9341.ILI9341(board.SPI(), cs=cs_pin, dc=dc_pin, baudrate=64000000, width=240, height=320)

image = Image.new('RGB', (disp.width, disp.height))
draw = ImageDraw.Draw(image)

def do_cprofile(func):
    def profiled_func(*args, **kwargs):
        profile = cProfile.Profile()
        try:
            profile.enable()
            result = func(*args, **kwargs)
            profile.disable()
            return result
        finally:
            profile.print_stats(sort='cumtime')
    return profiled_func

@do_cprofile
def displayimage(disp, image):
    disp.image(image, 0)

displayimage(disp, image)

And the results:

$ python3 test1.py 
         408521 function calls (407051 primitive calls) in 0.547 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.547    0.547 test1.py:30(displayimage)
        1    0.102    0.102    0.547    0.547 rgb.py:167(image)
        1    0.000    0.000    0.269    0.269 rgb.py:134(_block)
        3    0.000    0.000    0.269    0.090 rgb.py:261(write)
        6    0.000    0.000    0.167    0.028 spi_device.py:79(__enter__)
        6    0.000    0.000    0.162    0.027 busio.py:102(configure)
       24    0.000    0.000    0.162    0.007 chip.py:29(id)
       24    0.001    0.000    0.161    0.007 usbtools.py:54(find_all)
    76800    0.054    0.000    0.137    0.000 Image.py:1270(getpixel)
       18    0.000    0.000    0.118    0.007 board.py:291(id)
       24    0.000    0.000    0.109    0.005 usbtools.py:203(_find_devices)
       24    0.000    0.000    0.103    0.004 libusb1.py:939(get_backend)
       24    0.102    0.004    0.102    0.004 libusb1.py:703(__init__)
        6    0.000    0.000    0.064    0.011 busio.py:169(write)
...

Notice that the call to basically disp.image() is take 0.54 seconds, and what looks like write operations is slow?

In all the FT232H and CircuitPython guides and samples, the performance is not discussed, and you include samples that sleep for 0.1 seconds between iterations.

Is this expected performance? The high CPU makes stat display not a good application for this hardware.

Thanks.

[ladyada]

@caternuson hiya did you see the same?

[tannewt]

FYI, I moved this to the Blinka repo since CircuitPython itself isn't run on Linux (just its libraries are.)

[mckenziec]

FYI, this pretty much limits the FT232H and at least the ILI3941 display to some narrow uses. Stats on performance is not one of them unless its averages that update infrequently. You wouldn't want to write to the display and skew your average idle CPU by 25% just displaying the average.

[caternuson]

I didn't see loads that high. But I will investigate. @mckenziec You are also Duhmojo on discord? This looks the same as what was brought up there.

[mckenziec]

Yes that's me. cater was helping earlier this week but I don't think he was able to find the time to reproduce it. So I decided to try and just log the issue against CircuitPython. Let me know if you need any more details from me.

[mckenziec]

Oh caternuson = cater :D

[caternuson]

OK, just checking. I haven't had a chance to look into this yet. But when I do, I'll report back here.

[caternuson]

@mckenziec Finally getting around to testing this. I'm generally seeing the same thing you are seeing. I think I didn't notice this originally because it's not really slowing my system down noticeably. But I do see a fairly high CPU load on the running Python process. It's a high CPU load, but not a huge memory load.

I did some further testing, a little less sophisticated than yours, by simply commenting out parts of the basic example from the guide. Simply looping on Matplotlib and PIL rendering (no FT232H coms) causes a high CPU load, even with a decent sleep in the loop. Similarly, simply writing out the same static image (no PIL rendering) over the FT232H in a loop causes a high CPU load, again even with a sleep. Guess PIL just isn't super efficient. And the libusb layer for talking to the FT232H is also expensive.

Not sure what can be done to buy back performance since a lot of this is buried in other libs we are using. I'm open to suggestions.

[mckenziec]

I noticed that adafruit_rgb_display.rgb.py can use numpy. The comments mention speeding up an operation related to converting the image data to a PIL image to rgb bytes.

I installed numpy (I've done work with it in the past) but after stepping into rgb.py, it's clear the current source code isn't the latest that's in GitHub.

Here's my pip3 modules:

$ pip3 freeze | grep ada
adafruit-circuitpython-busdevice==4.0.0
adafruit-circuitpython-lis3dh==5.0.1
adafruit-circuitpython-rgb-display==3.5.6

Trying to upgrade adafruit-blinka didn't get me anything, so I directly upgraded rgb:

$ sudo pip3 install adafruit-circuitpython-rgb-display --upgrade
Collecting adafruit-circuitpython-rgb-display
  Downloading https://files.pythonhosted.org/packages/1c/9e/8a816ef39fee9ee9764631c87c72626c1349219e08af9f5fdb057063bd13/adafruit-circuitpython-rgb-display-3.7.0.tar.gz
...
Installing collected packages: adafruit-circuitpython-busdevice, adafruit-circuitpython-rgb-display
  Found existing installation: adafruit-circuitpython-busdevice 4.0.0
    Uninstalling adafruit-circuitpython-busdevice-4.0.0:
      Successfully uninstalled adafruit-circuitpython-busdevice-4.0.0
  Running setup.py install for adafruit-circuitpython-busdevice ... done
  Found existing installation: adafruit-circuitpython-rgb-display 3.5.6
    Uninstalling adafruit-circuitpython-rgb-display-3.5.6:
      Successfully uninstalled adafruit-circuitpython-rgb-display-3.5.6
  Running setup.py install for adafruit-circuitpython-rgb-display ... done
Successfully installed adafruit-circuitpython-busdevice-4.0.1 adafruit-circuitpython-rgb-display-3.7.0

With numpy and rgb.py upgraded the tables turn a bit. We go from display image() taking 0.547 seconds to 0.260. CPU observed in top goes from 25% to 12%.

$ python3  test1.py
         24484 function calls (23021 primitive calls) in 0.260 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.001    0.001    0.260    0.260 test1.py:30(displayimage)
        1    0.002    0.002    0.259    0.259 rgb.py:178(image)
        1    0.000    0.000    0.251    0.251 rgb.py:145(_block)
        3    0.000    0.000    0.251    0.084 rgb.py:274(write)
        6    0.000    0.000    0.164    0.027 spi_device.py:79(__enter__)
        6    0.000    0.000    0.159    0.027 busio.py:121(configure)
       24    0.000    0.000    0.158    0.007 chip.py:31(id)
       24    0.000    0.000    0.158    0.007 usbtools.py:54(find_all)
       18    0.000    0.000    0.118    0.007 board.py:297(id)
       24    0.000    0.000    0.106    0.004 usbtools.py:203(_find_devices)
       24    0.000    0.000    0.099    0.004 libusb1.py:939(get_backend)
       24    0.099    0.004    0.099    0.004 libusb1.py:703(__init__)
        6    0.000    0.000    0.065    0.011 busio.py:191(write)

Still not ideal, but a major improvement. If I reduce the length of the interval sleep the average CPU observed of course drops.

I already had some optimizations in my project to dial back updating the display (I literally wired up a PIR and implemented a kind of screen saver if motion wasn't detected so the CPU wasn't gobbled up while I wasn't around), and maybe switching to summary information that needs less real time updates that aren't affected by the 12% load that an every second interval image update would cause.

You should update the FTF232H guide and explain what it would be appropriate for. 0.5 second image draws of CPU utilization wouldn't be a good application.

https://learn.adafruit.com/circuitpython-on-any-computer-with-ft232h/tft-display

[makermelissa]

Yeah, that was a PR submitted by a community contributor that was only merged in a couple weeks ago: adafruit/Adafruit_CircuitPython_RGB_Display#47

[mckenziec]

I would suggest if writing images to be CPU heavy, add more draw functionality to rgb.py. The numpy approach is much better, but its not light weight on the CPU. If I have time tonight I'll test performance with direct pixel writes with resets in between, and if it seems to perform well I might write my own little library for writing text via pixels instead of rendering a complete image.

I considered working on an alternative to image() that buffered the last image and only updated changed pixels. e.g. only write changes between the images via pixel calls. There are a couple of approaches using PIL to figure it out, but there's no guarantee it'll speed things up. (https://stackoverflow.com/questions/1927660/compare-two-images-the-python-linux-way)

[ladyada]

windowed writes would def be faster but...more computation is required :) FT232H to display is a bit of a hack, probably best thing to do for now is add some time.sleep's and not try to get 30 FPS

[mckenziec]

Hi ladyada. I totally agree, and I was not intending to let the loop run away with the cpu. :) If this is a current limitation, then I'm suggesting the guides (https://learn.adafruit.com/tft-sidekick-with-ft232h specifically, which has Image writes on a 0.5 sleep loop, and a full CPU plot example) should include a bit of expectation management, because I wouldn't be able to display CPU or updates that frequently without a noticeable performance load. The reason I opened this issue was because those guides seem to perform much better than I've experienced.

I'll play around with my setup further this weekend, and if I make any progress I'll share it back. I can adjust my own project to display information on a slower basis, and it doesn't need to be pretty. e.g. basic white text and/or some bars would be fine. Thanks.