OnDiskBitmap TileGrid delays USB communication

[dhalbert]

Observed in 7.0.0.

Setting the grid for an OnDiskBitmap TileGrid can cause USB communication to be delayed long enough that a keypress can start repeating. I noticed this while working on the Kitty_Paw_Keypad example. I was converting it to use keypad, and saw repeated keypresses. However, the program was only sending one keypress, and then, noticeably delayed (about half a second), the corresponding key release. The delay was long enough to cause auto-repeat (typematic) to be invoked for the keyboard. Just before this occurrence, a TileGrid subscript was set.

I reproduced this on both Qt Py RP2040 and Metro M4, so it's not port-specific. The auto-repeat does not always happen, but happens often enough to be quite noticeable.

Example program (simplified from original):

import board
import displayio
import digitalio
import keypad
import usb_hid

from adafruit_st7789 import ST7789
from adafruit_hid.keyboard import Keyboard
from adafruit_hid.keycode import Keycode

keyboard = Keyboard(usb_hid.devices)

displayio.release_displays()

spi = board.SPI()
tft_cs = board.D7
tft_dc = board.D5

display_bus = displayio.FourWire(
    spi, command=tft_dc, chip_select=tft_cs, reset=board.D6
)

display = ST7789(display_bus, width=240, height=240, rowstart=80)
bitmap = displayio.OnDiskBitmap("/parrot-240-sheet.bmp")
parrot0_grid = displayio.TileGrid(bitmap, pixel_shader=bitmap.pixel_shader,
                                  tile_height=240, tile_width=240)

group = displayio.Group()
group.append(parrot0_grid)
display.show(group)

keys = keypad.Keys((board.A0, board.A1, board.A2, board.A3), value_when_pressed=False, pull=True)

parrot0_grid[0] = 0

while True:
    key_event = keys.events.get()
    if key_event:
        key_number = key_event.key_number
        if key_event.pressed:
            parrot0_grid[0] = 0

            keycode = Keycode.A + key_number
            keyboard.send(Keycode.SHIFT, Keycode.A + key_number)
            print("sent SHIFT and", keycode)

Here is an example when auto-repeat start up. Here are the HID reports received by the host, sending Shift-B and then releasing both. The actual keypress was much quicker.

# ReportID: 1 / LeftControl: 0 | LeftShift: 1 | LeftAlt: 0 | Left GUI: 0 | RightControl: 0 | RightShift: 0 | RightAlt: 0 | Right GUI: 0 | # |Keyboard ['b and B', '00', '00', '00', '00', '00'] 
E: 000006.896132 9 01 02 00 05 00 00 00 00 00
B# ReportID: 1 / LeftControl: 0 | LeftShift: 0 | LeftAlt: 0 | Left GUI: 0 | RightControl: 0 | RightShift: 0 | RightAlt: 0 | Right GUI: 0 | # |Keyboard ['00', '00', '00', '00', '00', '00'] 
E: 000007.368036 9 01 00 00 00 00 00 00 00 00

Notice that the timestamps are about 0.47 seconds apart.

Here are the input events, with auto-repeat happening (the repeated B key):

Event: time 1633208136.039088, type 4 (EV_MSC), code 4 (MSC_SCAN), value 700e1
Event: time 1633208136.039088, type 1 (EV_KEY), code 42 (KEY_LEFTSHIFT), value 1
Event: time 1633208136.039088, type 4 (EV_MSC), code 4 (MSC_SCAN), value 70005
Event: time 1633208136.039088, type 1 (EV_KEY), code 48 (KEY_B), value 1
Event: time 1633208136.039088, -------------- SYN_REPORT ------------
Event: time 1633208136.306471, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.306471, -------------- SYN_REPORT ------------
Event: time 1633208136.346218, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.346218, -------------- SYN_REPORT ------------
Event: time 1633208136.386246, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.386246, -------------- SYN_REPORT ------------
Event: time 1633208136.426233, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.426233, -------------- SYN_REPORT ------------
Event: time 1633208136.466224, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.466224, -------------- SYN_REPORT ------------
Event: time 1633208136.510239, type 1 (EV_KEY), code 48 (KEY_B), value 2
Event: time 1633208136.510239, -------------- SYN_REPORT ------------
Event: time 1633208136.510239, type 4 (EV_MSC), code 4 (MSC_SCAN), value 700e1
Event: time 1633208136.510239, type 1 (EV_KEY), code 42 (KEY_LEFTSHIFT), value 0
Event: time 1633208136.510239, type 4 (EV_MSC), code 4 (MSC_SCAN), value 70005
Event: time 1633208136.510239, type 1 (EV_KEY), code 48 (KEY_B), value 0
Event: time 1633208136.510239, -------------- SYN_REPORT ------------

[dhalbert]

I did a little more experimentation on this. Commenting out the actual pixel reading of the OnDiskBitmap in the C code helps. The display redisplay can be slow, as noted below, especially for this case.

circuitpython/shared-module/displayio/Display.c

Lines 323 to 327 in fd9c3d1

	// TODO(tannewt): Make refresh displays faster so we don't starve other
	// background tasks.
	#if CIRCUITPY_USB
	usb_background();
	#endif

[tannewt]

I'd assume this is due to the time needed to refresh the 240x240 pixels in the first tile.

[dhalbert]

displayio_tilegrid_fill_area() gets called, which calls common_hal_displayio_ondiskbitmap_get_pixel() for each pixel. A pixel read does a seek and a read of the OnDiskBitmap file. If the file sector is cached, it's fast, but otherwise it could take a long time.

Somewhere, the code should notice that it took a long time, and do usb_background() or the equivalent. There may be other high-priority background tasks to do as well.

I don't see an easy general solution to this. common_hal_displayio_ondiskbitmap_get_pixel() could notice when it took a long time by looking at ticks. There's nothing returned from f_read() that says the cache was or was not used. Or displayio_tilegrid_fill_area() could notice in its inner loop that a lot of time had passed, by something it called, and do the high-priority background tasks.

@tannewt Do you think this is worth fixing for 7.x.x or is it Long Term? I am willing to make it Long Term.

[tannewt]

It might be simplest for OnDiskBitmap to run background tasks for every pixel. The check for having no background tasks to do is pretty cheap and would hopefully be inlined.

[FoamyGuy]

I was able to recreate the extra key presses issue with a slightly modified version of the code on CLUE:

import board
import displayio
import digitalio
import keypad
import usb_hid

from adafruit_hid.keyboard import Keyboard
from adafruit_hid.keycode import Keycode

keyboard = Keyboard(usb_hid.devices)
display = board.DISPLAY
bitmap = displayio.OnDiskBitmap("/parrot-240-sheet.bmp")
parrot0_grid = displayio.TileGrid(bitmap, pixel_shader=bitmap.pixel_shader,
                                  tile_height=240, tile_width=240)

group = displayio.Group()
group.append(parrot0_grid)
display.show(group)

keys = keypad.Keys((board.BUTTON_A, board.BUTTON_B), value_when_pressed=False, pull=True)

parrot0_grid[0] = 0
p = 1
while True:
    key_event = keys.events.get()
    if key_event:
        key_number = key_event.key_number
        if key_event.pressed:
            parrot0_grid[0] = p
            p += 1
            if p > 9:
                p = 0
            keycode = Keycode.A + key_number
            keyboard.send(Keycode.SHIFT, Keycode.A + key_number)
            print("sent SHIFT and", keycode)

I tried what I understand to be the proposal above: adding the usb_background() call inside of ODB get pixel function here: https://github.com/FoamyGuy/circuitpython/blob/a9e1acff09cba12ce03e18dbb23d528e2366ce63/shared-module/displayio/OnDiskBitmap.c#L155-L157

But this did not seem to resolve the extra key press issue. I still get long strings of A's and B's somewhat frequently when pressing the buttons.

[tannewt]

Are we missing the release events from the keypad queue? I think I've heard of this problem as "sticky keys". press/release APIs have this problem if events get lost. Instead, folks use an API that always provides pressed state so that any dropped events don't result in missed presses.

[dhalbert]

Are we missing the release events from the keypad queue?

I am not sure that is the problem. Adding usb_background() doesn't do anything for delayed key presses, if it's the scanning that's being delayed as opposed to the transmission.

It would be easy to test this by giving a longer queue length for the Keys object.