rmkit icon indicating copy to clipboard operation
rmkit copied to clipboard
verified publisher icon rmkit-dev

[remux] hang at 100% cpu after restarting keyd

Open plredmond opened this issue 1 year ago • 7 comments

Repro

(in type-folio, but "lying down"/disconnected) (in "flight mode")

  • via ssh (over usb)
    1. Boot up rm2
    2. ssh into rm2
    3. systemctl restart keyd
    4. open htop or top and observe that remux is at 100%
  • by hand
    1. Boot up rm2
    2. swipe to summon remux
    3. tap to choose yaft
    4. systemctl restart keyd
    5. open htop or top and observe that remux is at 100%

i have also observed remux getting into this 100% cpu state without restarting keyd, but i haven't figured out a repro for that yet

  • systemctl restart remux seems to fix the problem
  • avoiding certain specific triggers (e.g. not restarting keyd) seems to avoid the problem and allow extended use of yaft/keyd/remux/xochitl

Software versions

# toltecctl status 
Enabled: Yes
Supported: Yes
Branch: stable
Model: rm2
OS: 3.3.2.1666
# launcherctl status 
Launcher: remux
Status: running
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
find: ‘/etc/draft’: No such file or directory
Apps: 0 running find: ‘/etc/draft’: No such file or directory
3 installed

:open_mouth:

# opkg info remux 
Package: remux
Version: 0.3.0-4
Depends: procps-ng-ps, rm2fb-client
Status: install user installed
Section: launchers
Architecture: rmall
Maintainer: raisjn <[email protected]>
Size: 183523
Filename: remux_0.3.0-4_rmall.ipk
Description: Launcher that supports multi-tasking applications
Installed-Time: 1718998811
# opkg info keyd 
Package: keyd
Version: 2.4.3-1
Status: install user installed
Architecture: rmall
Installed-Time: 1719520983

I've tested a2ab078 (build 9670591399) on an rm2 at 3.3.2.1666.

https://github.com/toltec-dev/toltec/pull/744#issuecomment-2195698397 is me

# opkg info yaft 
Package: yaft
Version: 0.1.1-1
Depends: terminfo, display
Status: install user installed
Section: admin
Architecture: rmall
Maintainer: Mattéo Delabre <[email protected]>
Size: 208660
Filename: yaft_0.1.1-1_rmall.ipk
Description: Yet another framebuffer terminal
Installed-Time: 1718997339

plredmond avatar Jun 28 '24 18:06 plredmond

Does it handle the folio connecting and disconnecting properly when keyd isn't running?

Eeems avatar Jun 28 '24 18:06 Eeems

Yes, it handles the type folio properly when keyd isn't running.

To answer your question I did the following:

(in type-folio, but "lying down"/disconnected) (in "flight mode")

  • via ssh (over usb)
    1. systemctl disable keyd
    2. reboot
  • via ssh (over usb)
    1. htop (to monitor the behavior of remux)
  • by hand (after each step pausing 30s to observe htop in the ssh window on my laptop and confirm that remux is ok before continuing)
    1. xochitl onscreen: unlock xochitl
    2. xochitl onscreen: "stand up"/connect type folio :standing_man:
    3. xochitl onscreen: "lie down"/disconnect type folio :sleeping_bed:
    4. xochitl onscreen: remove rm2 from type folio :outbox_tray:
    5. xochitl onscreen: swipe to summon remux (remux appears)
    6. xochitl+remux onscreen: tap to select yaft from remux (yaft appears)
    7. yaft portrait-mode onscreen: place rm in type folio :inbox_tray:
    8. yaft portrait-mode onscreen: "stand up"/connect type folio :standing_man: (yaft changes to landscape-mode)
    9. yaft landscape-mode onscreen: "lie down"/disconnect type folio :sleeping_bed: (yaft changes to portrait-mode)

Throughout this sequence of actions, remux used negligible cpu and 1% of memory.

plredmond avatar Jun 28 '24 18:06 plredmond

Well that's good to know. I haven't looked closely at the code to see how it gets the key device(s) to work with. When keyd is not running, there will be a key input device for the power button, and one for the folio. The folio device will be removed and re-added every time it's disconnected and reconnected. With kyed running the same stuff happens, but there are now new virtual input devices provided by keyd, and it will grab all input on the other devices. Restarting keyd would remove and re-add these virtual devices, as well as ungrab, and then grab the other devices.

Depending on how the code is setup to handles these devices, it might not be happy with these input devices going away as they were the only ones not grabbed when remux started. And when keyd isn't running, it's just not an issue as it gets the power button input device and not the folio as the key input. So the folio device going away doesn't matter. @raisjn or someone else who has looked closer at the code would confirm.

Eeems avatar Jun 28 '24 19:06 Eeems

Ok, thanks for explaining that. I'll try looking at the code if I have time later to set up a build environment.

plredmond avatar Jun 28 '24 20:06 plredmond

Ok, thanks for explaining that. I'll try looking at the code if I have time later to set up a build environment.

If you aren't averse to using docker, using the docker version of the makefile targets does simplify setting up a build environment.

Eeems avatar Jun 28 '24 20:06 Eeems

@plredmond: thank you so much for reporting this and the reliable repro steps! it looks like a file descriptor was going away when keyd is restarted. i put in some hacky code to re-open the file descriptors in d2e0387983f4ade7f2a9fe9fa9b36066c74800c2 and it looks like the infinite loop + CPU usage goes away. please try it out - you can use the latest build on the build servers: build.rmkit.dev/ and verify it fixes it

raisjn avatar Jun 28 '24 21:06 raisjn

Thanks @raisjn!

  • I downloaded remux with sha256 36ecc8e0625d2794e4b3741150a5e44928bfe75f4fd7cf466c6968fd0c1c7707 and also remux.service and placed them respectively at /opt/bin/remux and lib/systemd/system/remux.service
  • reboot
  • Confirm that the remux which is running has the above sha256
  • systemctl restart keyd
Jul 01 20:22:01 reMarkable remux[193]: OPENING /dev/input/event1 AS WACOM
Jul 01 20:22:01 reMarkable remux[193]: OPENING /dev/input/event2 AS TOUCH
Jul 01 20:22:01 reMarkable remux[193]: OPENING /dev/input/event3 : UNKNOWN EVENT DEVICE
Jul 01 20:22:01 reMarkable remux[193]: ERROR OPENING INPUT DEVICE /dev/input/event4
Jul 01 20:22:01 reMarkable systemd[1]: keyd.service: Main process exited, code=exited, status=15/n/a
Jul 01 20:22:01 reMarkable systemd[1]: keyd.service: Failed with result 'exit-code'.
Jul 01 20:22:01 reMarkable systemd[1]: Stopped key remapping daemon.
Jul 01 20:22:01 reMarkable systemd[1]: Started key remapping daemon.
Jul 01 20:22:01 reMarkable kernel: input: keyd virtual keyboard as /devices/virtual/input/input7
Jul 01 20:22:01 reMarkable keyd[337]: CONFIG: parsing /opt/etc/keyd/default.conf
Jul 01 20:22:01 reMarkable kernel: input: keyd virtual pointer as /devices/virtual/input/input8
Jul 01 20:22:01 reMarkable keyd[337]: Starting keyd v2.4.3 ()
Jul 01 20:22:01 reMarkable systemd-logind[237]: Watching system buttons on /dev/input/event4 (keyd virtual keyboard)
Jul 01 20:22:01 reMarkable keyd[337]: DEVICE: ignoring 0fac:1ade  (keyd virtual pointer)
Jul 01 20:22:01 reMarkable keyd[337]: DEVICE: match    2edd:0001  /opt/etc/keyd/default.conf        (rM_Keyboard)
Jul 01 20:22:01 reMarkable keyd[337]: DEVICE: ignoring 056a:0000  (Wacom I2C Digitizer)
Jul 01 20:22:11 reMarkable systemd[1]: [email protected]: Succeeded.
Jul 01 20:22:11 reMarkable systemd[1]: [email protected]: Scheduled restart job, restart counter is at 1.
Jul 01 20:22:11 reMarkable systemd[1]: Stopped Getty on tty1.
Jul 01 20:22:11 reMarkable systemd[1]: Started Getty on tty1.

load average stays low and remux seems happy at 0.0% cpu usage! i guess this is fixed :slightly_smiling_face: thank you!

plredmond avatar Jul 01 '24 20:07 plredmond