raspberrypi/linux

official 7-inch touchscreen polling rate too low

ardera opened this issue · 14 comments

Describe the bug
The rate of input events arriving at userspace when using the Official 7inch touchscreen is too low. Input events arrive at user space at about 33Hz, resulting in perceived lagginess of touch applications, even though the application is running at 60fps.

This bug was present once before, see #3227, so this is kinda a regression. I'm not sure exactly what commit/update caused it to go back down to 33Hz though.

To reproduce
See #3227

Expected behaviour
Expected is at least 60Hz, possibly even higher (since touchscreen controller seems to support 100Hz, and higher polling rates result in less input lag. All iPhones past iPhone X for example poll at 120Hz, some android gaming phones at 240Hz)

Actual behaviour
The frequency of input events arriving at userspace is 33Hz.

System

System Information
------------------

Raspberry Pi 4 Model B Rev 1.1
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2019-09-26
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 80d486687ea77d31fc3fc13cf3a2f8b464e129be, stage2

Linux hpi4 5.4.51-v7l+ #1327 SMP Thu Jul 23 11:04:39 BST 2020 armv7l GNU/Linux
Revision        : b03111
Serial          : 100000001afe70ee
Model           : Raspberry Pi 4 Model B Rev 1.1
Throttled flag  : throttled=0x0
Camera          : supported=0 detected=0

Videocore information
---------------------

Jul 17 2020 10:59:17
Copyright (c) 2012 Broadcom
version 21a15cb094f41c7506ad65d2cb9b29c550693057 (clean) (release) (start)

alloc failures:     0
compactions:        0
legacy block fails: 0

Filesystem information
----------------------
Filesystem     1K-blocks    Used Available Use% Mounted on
/dev/root       30391116 8174312  20946604  29% /
devtmpfs          732824       0    732824   0% /dev
tmpfs             864920       0    864920   0% /dev/shm
tmpfs             864920    8960    855960   2% /run
tmpfs               5120       4      5116   1% /run/lock
tmpfs             864920       0    864920   0% /sys/fs/cgroup
/dev/mmcblk0p1    258095   54461    203634  22% /boot
tmpfs             172984       0    172984   0% /run/user/1000

Filename                                Type            Size    Used    Priority
/var/swap                               file            102396  0       -2

Package version information
---------------------------
raspberrypi-ui-mods:
  Installed: 1.20200611
raspberrypi-sys-mods:
  Installed: 20200729
openbox:
  Installed: 3.6.1-8+rpt4
lxpanel:
  Installed: 0.10.0-2+rpt12
pcmanfm:
  Installed: 1.3.1-1+rpt22
rpd-plym-splash:
  Installed: 0.23

Networking Information
----------------------

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        inet6 y.y.y.y.y.y.y.y  prefixlen 64  scopeid 0x0<global>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 3980  bytes 322796 (315.2 KiB)
        RX errors 0  dropped 4  overruns 0  frame 0
        TX packets 3454  bytes 460022 (449.2 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet x.x.x.x  netmask x.x.x.x
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y.y.y.y.y.y.y.y  prefixlen 64  scopeid 0x0<global>
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 2520  bytes 227289 (221.9 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 40  bytes 5580 (5.4 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0


USB Information
---------------

/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M

config.txt
----------

arm_freq=1500
audio_pwm_mode=514
config_hdmi_boost=5
core_freq=500
core_freq_min=200
disable_commandline_tags=2
disable_l2cache=1
disable_overscan=1
display_default_lcd=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
enable_gic=1
enable_uart=1
force_eeprom_read=1
force_pwm_open=1
framebuffer_ignore_alpha=1
framebuffer_swap=1
gpu_freq=500
gpu_freq_min=250
init_uart_clock=0x2dc6c00
lcd_framerate=60
mask_gpu_interrupt0=1024
mask_gpu_interrupt1=0x10000
max_framebuffers=2
over_voltage_avs=-30000
pause_burst_frames=1
program_serial_random=1
total_mem=2048
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x11e1a300
hdmi_pixel_freq_limit:1=0x11e1a300
device_tree=-
overlay_prefix=overlays/
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt
-----------
coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1  smsc95xx.macaddr=DC:A6:32:2C:42:1A vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait

raspi-gpio settings
-------------------

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT pull=UP
GPIO 1: level=1 fsel=0 func=INPUT pull=UP
GPIO 2: level=1 fsel=0 func=INPUT pull=UP
GPIO 3: level=1 fsel=0 func=INPUT pull=UP
GPIO 4: level=1 fsel=0 func=INPUT pull=UP
GPIO 5: level=1 fsel=0 func=INPUT pull=UP
GPIO 6: level=1 fsel=0 func=INPUT pull=UP
GPIO 7: level=1 fsel=1 func=OUTPUT pull=UP
GPIO 8: level=1 fsel=1 func=OUTPUT pull=UP
GPIO 9: level=0 fsel=4 alt=0 func=SPI0_MISO pull=DOWN
GPIO 10: level=0 fsel=4 alt=0 func=SPI0_MOSI pull=DOWN
GPIO 11: level=0 fsel=4 alt=0 func=SPI0_SCLK pull=DOWN
GPIO 12: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 13: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 14: level=1 fsel=2 alt=5 func=TXD1 pull=NONE
GPIO 15: level=1 fsel=2 alt=5 func=RXD1 pull=UP
GPIO 16: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 17: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 18: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 19: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 20: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 21: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 22: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 23: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 24: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 25: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 26: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 27: level=0 fsel=0 func=INPUT pull=DOWN
BANK1 (GPIO 28 to 45):
GPIO 28: level=1 fsel=2 alt=5 func=RGMII_MDIO pull=UP
GPIO 29: level=0 fsel=2 alt=5 func=RGMII_MDC pull=DOWN
GPIO 30: level=0 fsel=7 alt=3 func=CTS0 pull=UP
GPIO 31: level=0 fsel=7 alt=3 func=RTS0 pull=NONE
GPIO 32: level=1 fsel=7 alt=3 func=TXD0 pull=NONE
GPIO 33: level=1 fsel=7 alt=3 func=RXD0 pull=UP
GPIO 34: level=1 fsel=7 alt=3 func=SD1_CLK pull=NONE
GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD pull=UP
GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0 pull=UP
GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1 pull=UP
GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2 pull=UP
GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3 pull=UP
GPIO 40: level=0 fsel=4 alt=0 func=PWM1_0 pull=NONE
GPIO 41: level=0 fsel=4 alt=0 func=PWM1_1 pull=NONE
GPIO 42: level=0 fsel=1 func=OUTPUT pull=UP
GPIO 43: level=1 fsel=0 func=INPUT pull=UP
GPIO 44: level=1 fsel=5 alt=1 func=SDA0 pull=UP
GPIO 45: level=1 fsel=5 alt=1 func=SCL0 pull=UP
BANK2 (GPIO 46 to 53):
GPIO 46: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 47: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 48: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 49: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 50: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 51: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 52: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 53: level=0 fsel=0 func=INPUT pull=DOWN

vcdbg log messages
------------------

006622.276: arasan: arasan_emmc_open
007055.809: brfs: File read: /mfs/sd/config.txt
007056.618: brfs: File read: 1807 bytes
007082.456: brfs: File read: /mfs/sd/config.txt
007089.239: brfs: File read: 1807 bytes
007535.723: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
007838.303: *** Restart logging
007842.476: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
007845.841: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
007845.853: HDMI0: hdmi_pixel_encoding: 300000000
007845.867: HDMI1: hdmi_pixel_encoding: 300000000
007850.775: dtb_file 'bcm2711-rpi-4-b.dtb'
007857.519: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
007857.536: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xb935
007934.172: brfs: File read: 47413 bytes
007944.543: brfs: File read: /mfs/sd/overlays/overlay_map.dtb
008289.610: brfs: File read: 1371 bytes
008298.958: brfs: File read: /mfs/sd/overlays/rpi-ft5406.dtbo
008299.766: Loaded overlay 'rpi-ft5406'
008334.252: brfs: File read: 842 bytes
008343.123: brfs: File read: /mfs/sd/overlays/rpi-backlight.dtbo
008378.109: Loaded overlay 'rpi-backlight'
008467.985: brfs: File read: 489 bytes
008471.908: brfs: File read: /mfs/sd/config.txt
008472.350: dtparam: spi=on
008522.388: dtparam: audio=on
008580.871: brfs: File read: 1807 bytes
008592.982: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo
008692.513: Loaded overlay 'vc4-fkms-v3d'
008893.470: brfs: File read: 1238 bytes
008895.824: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo
008995.330: Loaded overlay 'vc4-fkms-v3d'
009232.200: brfs: File read: 1238 bytes
009235.631: brfs: File read: /mfs/sd/cmdline.txt
009235.669: Read command line from file 'cmdline.txt':
009235.683: 'console=serial0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait'
010961.431: brfs: File read: 121 bytes
011448.138: brfs: File read: /mfs/sd/kernel7l.img
011448.154: Loading 'kernel7l.img' to 0x8000 size 0x5b8528
011448.173: Device tree loaded to 0x2eff4000 (size 0xbf55)
011451.695: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
013668.581: vchiq_core: vchiq_init_state: slot_zero = 0xded80000, is_master = 1

dmesg log
---------

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.4.51-v7l+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1327 SMP Thu Jul 23 11:04:39 BST 2020
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] On node 0 totalpages: 458752
[    0.000000]   DMA zone: 2304 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 262144 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s49856 r8192 d23872 u81920
[    0.000000] pcpu-alloc: s49856 r8192 d23872 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 456448
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1  smsc95xx.macaddr=m.m.m.m vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x19400000-0x1d400000] (64MB)
[    0.000000] Memory: 1465652K/1835008K available (10240K kernel code, 725K rwdata, 2740K rodata, 2048K init, 853K bss, 107212K reserved, 262144K cma-reserved, 1048576K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 30051 entries in 59 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] random: get_random_bytes called from start_kernel+0x340/0x518 with crng_init=0
[    0.000007] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000030] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000110] bcm2835: system timer (irq = 17)
[    0.000782] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000801] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000822] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000838] Switching to timer-based delay loop, resolution 18ns
[    0.001074] Console: colour dummy device 80x30
[    0.001569] printk: console [tty1] enabled
[    0.001632] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.001674] pid_max: default: 32768 minimum: 301
[    0.001996] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002035] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003199] Disabling memory control group subsystem
[    0.003313] CPU: Testing write buffer coherency: ok
[    0.003788] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.004614] Setting up static identity map for 0x200000 - 0x20003c
[    0.004813] rcu: Hierarchical SRCU implementation.
[    0.005436] smp: Bringing up secondary CPUs ...
[    0.006543] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.007767] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.008938] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.009081] smp: Brought up 1 node, 4 CPUs
[    0.009151] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.009176] CPU: All CPU(s) started in HYP mode.
[    0.009199] CPU: Virtualization extensions available.
[    0.009932] devtmpfs: initialized
[    0.022897] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.023160] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.023207] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.030928] pinctrl core: initialized pinctrl subsystem
[    0.031949] NET: Registered protocol family 16
[    0.035319] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.036982] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.037018] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.037355] Serial: AMBA PL011 UART driver
[    0.041001] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.060844] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-07-17 10:59, variant start
[    0.070860] raspberrypi-firmware soc:firmware: Firmware hash is 21a15cb094f41c7506ad65d2cb9b29c550693057
[    0.124717] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.129211] vgaarb: loaded
[    0.129674] SCSI subsystem initialized
[    0.129905] usbcore: registered new interface driver usbfs
[    0.129976] usbcore: registered new interface driver hub
[    0.130114] usbcore: registered new device driver usb
[    0.131643] clocksource: Switched to clocksource arch_sys_counter
[    0.881621] VFS: Disk quotas dquot_6.6.0
[    0.881779] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.881945] FS-Cache: Loaded
[    0.882133] CacheFiles: Loaded
[    0.882966] simple-framebuffer 3ea50000.framebuffer: framebuffer at 0x3ea50000, 0x177000 bytes, mapped to 0x(ptrval)
[    0.883008] simple-framebuffer 3ea50000.framebuffer: format=a8r8g8b8, mode=800x480x32, linelength=3200
[    0.885347] Console: switching to colour frame buffer device 100x30
[    0.888316] simple-framebuffer 3ea50000.framebuffer: fb0: simplefb registered!
[    0.899282] thermal_sys: Registered thermal governor 'step_wise'
[    0.899620] NET: Registered protocol family 2
[    0.902507] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.903647] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.904827] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.905994] TCP: Hash tables configured (established 8192 bind 8192)
[    0.907205] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.908312] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.909622] NET: Registered protocol family 1
[    0.911353] RPC: Registered named UNIX socket transport module.
[    0.912478] RPC: Registered udp transport module.
[    0.913548] RPC: Registered tcp transport module.
[    0.914611] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.915705] PCI: CLS 0 bytes, default 64
[    0.918576] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    0.921837] Initialise system trusted keyrings
[    0.923143] workingset: timestamp_bits=14 max_order=19 bucket_order=5
[    0.934775] FS-Cache: Netfs 'nfs' registered for caching
[    0.936612] NFS: Registering the id_resolver key type
[    0.937750] Key type id_resolver registered
[    0.938837] Key type id_legacy registered
[    0.939895] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.942031] Key type asymmetric registered
[    0.943077] Asymmetric key parser 'x509' registered
[    0.944263] bounce: pool size: 64 pages
[    0.945309] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    0.946553] io scheduler mq-deadline registered
[    0.947572] io scheduler kyber registered
[    0.952211] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    0.953228] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    0.955229] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
[    0.956316] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x007fffffff -> 0x0000000000
[    1.013755] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
[    1.015043] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    1.016047] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.017077] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[    1.019168] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    1.020440] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.024868] PCI: bus0: Fast back to back transfers disabled
[    1.025888] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    1.027164] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    1.028329] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    1.029736] pci 0000:01:00.0: PME# supported from D0 D3cold
[    1.034155] PCI: bus1: Fast back to back transfers disabled
[    1.035200] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    1.036267] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    1.037335] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    1.038451] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.039478] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    1.040801] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    1.042065] pcieport 0000:00:00.0: PME: Signaling with IRQ 57
[    1.043429] pcieport 0000:00:00.0: AER: enabled with IRQ 57
[    1.044730] pci 0000:01:00.0: enabling device (0140 -> 0142)
[    1.050231] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    1.054161] iproc-rng200 fe104000.rng: hwrng registered
[    1.055461] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.057114] vc-sm: Videocore shared memory driver
[    1.058656] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.071085] brd: module loaded
[    1.083851] loop: module loaded
[    1.086146] Loading iSCSI transport class v2.0-870.
[    1.089053] libphy: Fixed MDIO Bus: probed
[    1.090602] bcmgenet fd580000.ethernet: failed to get enet clock
[    1.091599] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.092646] bcmgenet fd580000.ethernet: failed to get enet-wol clock
[    1.093595] bcmgenet fd580000.ethernet: failed to get enet-eee clock
[    1.094523] bcmgenet: Skipping UMAC reset
[    1.121759] libphy: bcmgenet MII bus: probed
[    1.201749] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.203643] usbcore: registered new interface driver r8152
[    1.204599] usbcore: registered new interface driver lan78xx
[    1.205541] usbcore: registered new interface driver smsc95xx
[    1.206804] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.207692] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.210749] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890
[    1.213791] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.214771] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.215733] usb usb1: Product: xHCI Host Controller
[    1.216675] usb usb1: Manufacturer: Linux 5.4.51-v7l+ xhci-hcd
[    1.217603] usb usb1: SerialNumber: 0000:01:00.0
[    1.219069] hub 1-0:1.0: USB hub found
[    1.220018] hub 1-0:1.0: 1 port detected
[    1.221370] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.222276] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.223166] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.224526] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
[    1.225433] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.226345] usb usb2: Product: xHCI Host Controller
[    1.227255] usb usb2: Manufacturer: Linux 5.4.51-v7l+ xhci-hcd
[    1.228193] usb usb2: SerialNumber: 0000:01:00.0
[    1.229669] hub 2-0:1.0: USB hub found
[    1.230651] hub 2-0:1.0: 4 ports detected
[    1.233027] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.234220] dwc_otg: FIQ enabled
[    1.234231] dwc_otg: NAK holdoff enabled
[    1.234243] dwc_otg: FIQ split-transaction FSM enabled
[    1.234257] Module dwc_common_port init
[    1.234677] usbcore: registered new interface driver uas
[    1.235724] usbcore: registered new interface driver usb-storage
[    1.236837] mousedev: PS/2 mouse device common for all mice
[    1.239880] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.243324] sdhci: Secure Digital Host Controller Interface driver
[    1.244275] sdhci: Copyright(c) Pierre Ossman
[    1.245752] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[    1.247270] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.251806] ledtrig-cpu: registered to indicate activity on CPUs
[    1.253005] hidraw: raw HID events driver (C) Jiri Kosina
[    1.254075] usbcore: registered new interface driver usbhid
[    1.254988] usbhid: USB HID core driver
[    1.256831] vchiq: vchiq_init_state: slot_zero = (ptrval)
[    1.259243] [vc_sm_connected_init]: start
[    1.265577] [vc_sm_connected_init]: end - returning 0
[    1.268497] Initializing XFRM netlink socket
[    1.269435] NET: Registered protocol family 17
[    1.270397] Key type dns_resolver registered
[    1.271694] Registering SWP/SWPB emulation handler
[    1.272867] registered taskstats version 1
[    1.273732] Loading compiled-in X.509 certificates
[    1.275058] Key type ._fscrypt registered
[    1.275918] Key type .fscrypt registered
[    1.286867] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.287817] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 29, base_baud = 0) is a PL011 rev2
[    1.295036] printk: console [ttyS0] disabled
[    1.296036] fe215040.serial: ttyS0 at MMIO 0x0 (irq = 31, base_baud = 62500000) is a 16550
[    2.537242] printk: console [ttyS0] enabled
[    2.544331] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    2.553569] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    2.560648] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    2.616596] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    2.624802] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    2.632919] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    2.639410] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    2.650626] of_cfs_init
[    2.650650] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    2.654279] of_cfs_init: OK
[    2.662241] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    2.671301] Waiting for root device PARTUUID=6c586e13-02...
[    2.715500] random: fast init done
[    2.763804] mmc1: new high speed SDIO card at address 0001
[    2.787115] mmc0: new ultra high speed DDR50 SDHC card at address e624
[    2.795564] mmcblk0: mmc0:e624 SP32G 29.7 GiB
[    2.804599]  mmcblk0: p1 p2
[    2.811708] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    2.832880] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.842264] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    2.856779] devtmpfs: mounted
[    2.868650] Freeing unused kernel memory: 2048K
[    2.874536] Run /sbin/init as init process
[    2.994359] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    3.003725] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    3.011966] usb 1-1: Product: USB2.0 Hub
[    3.018775] hub 1-1:1.0: USB hub found
[    3.024080] hub 1-1:1.0: 4 ports detected
[    3.325665] systemd[1]: System time before build time, advancing clock.
[    3.351693] usb 1-1.3: new full-speed USB device number 3 using xhci_hcd
[    3.441186] NET: Registered protocol family 10
[    3.448008] Segment Routing with IPv6
[    3.483003] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    3.498110] usb 1-1.3: New USB device found, idVendor=1e7d, idProduct=2dbe, bcdDevice= 1.01
[    3.509040] systemd[1]: Detected architecture arm.
[    3.517438] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.536698] usb 1-1.3: Product: ROCCAT Kone Pure
[    3.542534] usb 1-1.3: Manufacturer: ROCCAT
[    3.625476] systemd[1]: Set hostname to <hpi4>.
[    4.369181] random: systemd: uninitialized urandom read (16 bytes read)
[    4.414037] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[    4.423718] random: systemd: uninitialized urandom read (16 bytes read)
[    4.432030] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    4.442788] random: systemd: uninitialized urandom read (16 bytes read)
[    4.451399] systemd[1]: Listening on Journal Socket.
[    4.466505] systemd[1]: Mounting Kernel Debug File System...
[    4.481107] systemd[1]: Mounting POSIX Message Queue File System...
[    4.490962] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped.
[    4.508537] systemd[1]: Starting Set the console keyboard layout...
[    5.143511] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    5.246230] systemd-journald[125]: Received request to flush runtime journal from PID 1
[    5.853715] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    5.854743] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    5.859171] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    5.862956] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    5.946669] mc: Linux media interface: v0.10
[    5.950152] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.952205] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.952226] [vc_sm_connected_init]: start
[    5.970845] videodev: Linux video capture interface: v2.00
[    5.992488] [vc_sm_connected_init]: installed successfully
[    6.000295] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    6.019148] bcm2835_audio bcm2835_audio: card created with 8 channels
[    6.037338] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    6.037492] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    6.038198] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    6.055836] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    6.057384] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    6.059129] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    6.075695] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    6.075755] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    6.091144] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    6.091182] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    6.092345] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    6.092746] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    6.093089] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    6.093424] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    6.093448] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    6.093472] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    6.093497] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    6.093521] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    6.093712] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    6.103990] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    6.104029] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    6.152221] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
[    6.152243] checking generic (3ea50000 177000) vs hw (0 ffffffffffffffff)
[    6.152257] fb0: switching to vc4drmfb from simple
[    6.152791] Console: switching to colour dummy device 80x30
[    6.153020] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    6.153033] [drm] No driver support for vblank timestamp query.
[    6.153045] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL
[    6.153609] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0
[    6.157455] Console: switching to colour frame buffer device 100x30
[    6.174256] vc4-drm gpu: fb0: vc4drmfb frame buffer device
[    6.231501] input: raspberrypi-ts as /devices/platform/soc/soc:firmware/soc:firmware:touchscreen/input/input0
[    6.389172] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1
[    6.398546] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    6.523878] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    6.621972] brcmfmac: F1 signature read @0x18000000=0x15264345
[    6.631573] input: ROCCAT ROCCAT Kone Pure as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:1E7D:2DBE.0001/input/input1
[    6.634637] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.635437] usbcore: registered new interface driver brcmfmac
[    6.658066] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2
[    6.693637] konepure 0003:1E7D:2DBE.0001: input,hiddev96,hidraw0: USB HID v1.00 Mouse [ROCCAT ROCCAT Kone Pure] on usb-0000:01:00.0-1.3/input0
[    6.695163] input: ROCCAT ROCCAT Kone Pure as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:1E7D:2DBE.0002/input/input2
[    6.762653] konepure 0003:1E7D:2DBE.0002: input,hidraw1: USB HID v1.11 Keyboard [ROCCAT ROCCAT Kone Pure] on usb-0000:01:00.0-1.3/input1
[    6.889675] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.907976] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar  2 2020 23:30:41 version 7.45.202 (r724630 CY) FWID 01-72f6ece2
[    8.493851] random: crng init done
[    8.493868] random: 7 urandom warning(s) missed due to ratelimiting
[    8.510331] uart-pl011 fe201000.serial: no DMA platform data
[    8.751129] 8021q: 802.1Q VLAN Support v1.8
[    8.981754] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    9.214163] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    9.537238] bcmgenet: Skipping UMAC reset
[    9.539535] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[    9.539899] bcmgenet fd580000.ethernet eth0: Link is Down
[   14.706907] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   14.711988] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   14.712032] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   15.350968] Bluetooth: Core ver 2.22
[   15.351050] NET: Registered protocol family 31
[   15.351063] Bluetooth: HCI device and connection manager initialized
[   15.351087] Bluetooth: HCI socket layer initialized
[   15.351106] Bluetooth: L2CAP socket layer initialized
[   15.351135] Bluetooth: SCO socket layer initialized
[   15.360492] Bluetooth: HCI UART driver ver 2.3
[   15.360510] Bluetooth: HCI UART protocol H4 registered
[   15.360588] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   15.360885] Bluetooth: HCI UART protocol Broadcom registered
[   15.522770] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   15.522780] Bluetooth: BNEP filters: protocol multicast
[   15.522798] Bluetooth: BNEP socket layer initialized
[   15.557597] Bluetooth: RFCOMM TTY layer initialized
[   15.557616] Bluetooth: RFCOMM socket layer initialized
[   15.557631] Bluetooth: RFCOMM ver 1.11
[   15.900428] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.wlan0.retrans_time - use net.ipv6.neigh.wlan0.retrans_time_ms instead
[  453.623917] usb 1-1.3: USB disconnect, device number 3

Logs
evhz output:

Press CTRL-C to exit.

event0: raspberrypi-ts
0
raspberrypi-ts: Latest    25Hz, Average     0Hz
raspberrypi-ts: Latest    33Hz, Average    12Hz
raspberrypi-ts: Latest    33Hz, Average    19Hz
raspberrypi-ts: Latest    33Hz, Average    22Hz
raspberrypi-ts: Latest    33Hz, Average    24Hz
raspberrypi-ts: Latest    16Hz, Average    26Hz
raspberrypi-ts: Latest    33Hz, Average    24Hz
raspberrypi-ts: Latest    33Hz, Average    25Hz
raspberrypi-ts: Latest    33Hz, Average    26Hz
raspberrypi-ts: Latest    33Hz, Average    27Hz
raspberrypi-ts: Latest    33Hz, Average    27Hz
raspberrypi-ts: Latest    33Hz, Average    28Hz
raspberrypi-ts: Latest    33Hz, Average    28Hz
raspberrypi-ts: Latest    33Hz, Average    28Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    16Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    28Hz
raspberrypi-ts: Latest    33Hz, Average    28Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    30Hz
raspberrypi-ts: Latest    16Hz, Average    30Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    29Hz
raspberrypi-ts: Latest    33Hz, Average    30Hz
raspberrypi-ts: Latest    33Hz, Average    30Hz
raspberrypi-ts: Latest    33Hz, Average    30Hz
raspberrypi-ts: Latest    16Hz, Average    30Hz

kinda offtopic
Is there any way the (actual) touchscreen driver can be moved out of the firmware into the linux kernel, and be modified to use interrupts if the user wants so? The delay is pretty bad to be honest, less input lag would make the Raspberry Pi actually very usable for modern UI (using flutter and my flutter-pi project).

Any news on this? Basically every other generic touchscreen is working better right now (both in terms of polling rate and latency) than this officially supported one.

6by9 commented

5.4 has adopted the mainline driver from drivers/input/touchscreen/raspberrypi-ts.c rather than the downstream drivers/input/touchscreen/rpi-ft5406.c

It appears to have defined 60fps polling, but it offloads the poll process to the framework by the looks of it.

There is one commit in later kernels (>=5.5) that changes this driver, but I haven't looked to see if the required framework change are in 5.4 or not.
bd88ce2

I can confirm it seems like its the linux-side again, the firmware-side is polling the TS at approx 57Hz according to my i2c sniffer.

The intervals between events are most commonly 30ms, sometimes 60ms and very rarely 40ms. It's kinda strange. The HZ is 100 so one kernel jiffy is 10ms. The polled_dev is configured with an interval of 17ms, so you'd expect to see either 10ms or 20ms in userspace, maybe 30ms. But that's not the case at all.

There is one commit in later kernels (>=5.5) that changes this driver, but I haven't looked to see if the required framework change are in 5.4 or not.
bd88ce2

I did a little bit of research and it seems the actual implementation didn't change much. input_dev_poller looks basically exactly the same as input_polled_device (/ input_polldev). They still use the same mechanism for the delaying the work / polling, and they have exactly the same delay calculation.

While the driver is different, the cause of the slow polling may be the same as #3227 (comment)

6by9 commented

I've had a very brief look at the framework for input_poller and it looks plausible. It's using queue_delayed_work to retrigger every poll period.
AFAIK that is accurate at <20ms, although it does appear to be using timers (not hrtimers) for sleeping, so it may well be the same issue. That ought to be reported upstream as it surely affects all input devices using that input-poller mechanism.

That ought to be reported upstream as it surely affects all input devices using that input-poller mechanism.

Do you want to do that? I can do it, if you want me to. I kinda have the feeling though they'll say we should just increase the HZ.

6by9 commented

@pelwell Do you have a feel for the delay accuracy on queue_delayed_work?
HZ appears to be set to 100 for our configs, so a 10ms tick. That would give a moderate level of inaccuracy on the polling, but I wouldn't expect so close to 30Hz.
I find it odd that upstream have switched to this polling mechanism on a number of drivers if the accuracy isn't there on the poll rate.

Is there any way the (actual) touchscreen driver can be moved out of the firmware into the linux kernel, and be modified to use interrupts if the user wants so? The delay is pretty bad to be honest, less input lag would make the Raspberry Pi actually very usable for modern UI (using flutter and my flutter-pi project).

There is some work in mainline to write drivers for the Toshiba TC358752 DSI to DPI bridge and the touchscreen controller. One issue is that they share an I2C controller with the camera module, so if you shift the touchscreen to the kernel then you can not use the firmware camera stack (you can use libcamera which is all ARM side).

I'd be tempted to create a delayed_work item that just requeues itself 1 jiffy later for 100 iterations, and log the times.

So, according to this doc on linux work queues, queue_delayed_work waits for at least delay jiffies. That means queue_delayed_work alone is introducing 20-30ms of latency. The polling work is executed right after a kernel tick ocurred, and then queue_delayed_work with the polling work is executed.
The 17ms is probably rounded up to 2 kernel jiffies as well, and queue_delayed_work is invoked with a delay of 2 jiffies.
queue_delayed_work then needs to wait for 3 kernel ticks, since the dt between the invocation of queue_delayed_work and the 2nd kernel tick is not at least 2 kernel jiffies (= 20ms) (it's probably 19.99ms). That means the delay introduced by queue_delayed_work alone is most likely closer to 30ms.

I don't know where the other 10ms come from. Maybe the worker thread is not directly woken up by the work being queued after these 20ms, but woken up by the scheduler on the next kernel tick?

Either way, I'm amazed by how inaccurate input_polled_dev is. I mean not only the problem we have right now, but generally, using relative timing/delays to implement reocurring work is a bad idea. If the actual poll would be a bit more time consuming, the timing would be off. Absolute timing works better in most cases. Or did I miss something?

EDIT: I somehow though queue_delayed_work was invoked with a delay of 1 jiffy. It's actually 2 jiffies, since the 17ms get rounded up as well. That explains the 30ms delay. I corrected the numbers in the text above.

The kernel devs have been introducing sleep ranges and other "inaccuracies", allowing power savings by batching up activity to increase the length of the low power states. This could be a consequence of those changes.

The kernel devs have been introducing sleep ranges and other "inaccuracies", allowing power savings by batching up activity to increase the length of the low power states. This could be a consequence of those changes.

Could be. Though I just looked it up and input-polldev was introduced in 2007 in 2.6.22 and hasn't changed much since. I don't know how concerned people were with power management back then.

just for completeness: with the new edt-ft5x06 driver the polling rate is still pretty low, about 33Hz at max:

pi@hpi4:~/devel/evhz $ sudo ./evhz 
Press CTRL-C to exit.

event0: Razer Razer Viper
event1: Razer Razer Viper Keyboard
event2: Razer Razer Viper Consumer Control
event3: Razer Razer Viper System Control
event4: Razer Razer Viper
event5: Razer Razer Viper
event6: vc4
event7: vc4
event8: generic ft5x06 (00)

generic ft5x06 (00): Latest    33Hz, Average     0Hz
generic ft5x06 (00): Latest    33Hz, Average    16Hz
generic ft5x06 (00): Latest    33Hz, Average    22Hz
generic ft5x06 (00): Latest    33Hz, Average    24Hz
generic ft5x06 (00): Latest    33Hz, Average    26Hz
generic ft5x06 (00): Latest    33Hz, Average    27Hz
generic ft5x06 (00): Latest    33Hz, Average    28Hz
generic ft5x06 (00): Latest    33Hz, Average    28Hz
generic ft5x06 (00): Latest    16Hz, Average    29Hz
generic ft5x06 (00): Latest     1Hz, Average    28Hz
generic ft5x06 (00): Latest    16Hz, Average    25Hz
generic ft5x06 (00): Latest    33Hz, Average    24Hz
generic ft5x06 (00): Latest    33Hz, Average    25Hz
generic ft5x06 (00): Latest    33Hz, Average    25Hz
generic ft5x06 (00): Latest    33Hz, Average    26Hz
generic ft5x06 (00): Latest    33Hz, Average    26Hz
generic ft5x06 (00): Latest    33Hz, Average    27Hz
generic ft5x06 (00): Latest    33Hz, Average    27Hz

Any updates on this issue? This issue is making it hard to use the pi display for our product. Even button click events cause a lag that is hard to not notice

lbt commented

based on @ardera's comment about rounding up the jiffies I changed
RPI_TS_POLL_INTERVAL to 7 in raspberrypi-ts.c for 5.15.32 and got:

raspberrypi-ts: Latest 50Hz, Average 47Hz
raspberrypi-ts: Latest 50Hz, Average 47Hz
raspberrypi-ts: Latest 25Hz, Average 46Hz
raspberrypi-ts: Latest 50Hz, Average 46Hz
raspberrypi-ts: Latest 50Hz, Average 47Hz

Then setting HZ to 250 in the config:

raspberrypi-ts: Latest 50Hz, Average 56Hz
raspberrypi-ts: Latest 62Hz, Average 56Hz
raspberrypi-ts: Latest 62Hz, Average 56Hz
raspberrypi-ts: Latest 50Hz, Average 56Hz
raspberrypi-ts: Latest 41Hz, Average 56Hz
raspberrypi-ts: Latest 83Hz, Average 56Hz
raspberrypi-ts: Latest 35Hz, Average 56Hz
raspberrypi-ts: Latest 125Hz, Average 57Hz
raspberrypi-ts: Latest 50Hz, Average 57Hz

This led to VASTLY improved gesture support on the screen with Qt/QML code

Of course the correct solution is to have the input-poller code get the timing correct but this solution may help others