Buggy cec-mini-kb service causes framerate hiccups on some displays

vanfanel commented 5 months ago

In Lakka 5.0 and nightly 6.x builds, I see this spawn on dmesg repeatedly and infinitely: [ 1667.419435] input: cec-mini-kb as /devices/virtual/input/input376 This means that cec-mini-kb is (wringly) creating a new input device perodically.

It causes framerate hiccups each time it's executed, which is also observable on vsync rate detection, which shows a very high deviance (~10%) when this buggy service is active. This totally destroys framerate stability in low-latency scenarios (threaded video disabled, max_swapchain = 2) so it's a major problem.

I can luckily stop this misbehaving service with systemctl mask cec-mini-kb, but for not tech-saavy people trying Lakka, having high vsync rate deviances like this will cause that "emulation is not the same as real hardware" feeling that an optimal solution like Lakka should avoid.

Only some displays are affected: namely I have this happening on the PiCade display, where Lakka is a widespread operating system.

The idea behind this is good, but the implementation is buggy. Please consider having it disabled by default.

ShigeakiAsai commented 5 months ago

Hello vanfanel

I also happened same problem on my Picade maybe. Did "journalctl | grep cec" showing the following message?

Jun 06 19:02:18 Lakka systemd[1]: Started cec-mini-kb.service. Jun 06 19:02:18 Lakka kernel: input: cec-mini-kb as /devices/virtual/input/input397 Jun 06 19:02:22 Lakka cec-mini-kb[3262]: Failed to become active Jun 06 19:02:23 Lakka systemd[1]: cec-mini-kb.service: Main process exited, code=killed, status=11/SEGV Jun 06 19:02:23 Lakka systemd[1]: cec-mini-kb.service: Failed with result 'signal'. Jun 06 19:02:25 Lakka systemd[1]: cec-mini-kb.service: Scheduled restart job, restart counter is at 397. Jun 06 19:02:25 Lakka systemd[1]: Stopped cec-mini-kb.service.

If it is so, same problem.

ASAI, Shigeaki

vanfanel commented 5 months ago

@ShigeakiAsai Yes. It seems to be the same problem.

ShigeakiAsai commented 5 months ago

@vanfanel Thank you for your reply.

In this case, "Segmentation fault" was happened in cec-mini-kb. The cec-mini-kb.service repeats to restart each 2 sec if cec-mini-kb is failed. In these each repeat, a new input device is created.

I will investigate it a little bit more. I'd like to use your workaround until I can figure something out.

ASAI, Shigeaki

vanfanel commented 5 months ago

@ShigeakiAsai Then simply do systemctl mask cec-mini-kb and you will be free of this broken service.

ShigeakiAsai commented 5 months ago

The following is my investigation report.

I'm considering to fix now. Please give me several time.

(edit start) ~~### 1. The cec-mini-kb service starts too early.~~ ~~In RPi4+HDMI display(NOT Picade), the cec-mini-kb service success after vc4-drm is configured.~~ ~~10 times and more failed before vc4-drm is configured.~~ I'm sorry, this was my environment issue. If HDMI display was detected at boot time, this appeared 1 time only. (edit end)

2. If cec-mini-kb service fails, it will loop infinitely.

packages/lakka/lakka_tools/cec_minikb/system.d/cec-mini-kb.service [Service] ExecStart=/usr/bin/cec-mini-kb --poweroff "shutdown -P now" Restart=always RestartSec=2_

3. The bad response reason is cec_adapter->Open(), not uinput_dev_init().

2024-06-07T23:14:38.037580+0900 Lakka systemd[1]: Started cec-mini-kb.service. 2024-06-07T23:14:38.041836+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec-minikb is Start! 2024-06-07T23:14:38.041891+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : uinput_dev_init() Start! 2024-06-07T23:14:38.042373+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : uinput_dev_init() End! _->uinput_dev_init() needs 0.002sec. 2024-06-07T23:14:38.044555+0900 Lakka kernel: input: cec-mini-kb as /devices/virtual/input/input5 2024-06-07T23:14:38.105713+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : devices_found is 1 2024-06-07T23:14:38.105751+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : adapter_number is 0 2024-06-07T23:14:38.105768+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec_adapter->Open() Start! 2024-06-07T23:14:39.541207+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec_adapter->Open() End! _-> cec_adapter->Open() needs 1.436sec. 2024-06-07T23:14:39.541222+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec_adapter->SetActiveSource() Start! 2024-06-07T23:14:39.827240+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec_adapter->SetActiveSource() is failed! 2024-06-07T23:14:39.827468+0900 Lakka cec-mini-kb[651]: Failed to become active 2024-06-07T23:14:40.668169+0900 Lakka cec-mini-kb[651]: cec-mini-kb : DEBUG : cec-minikb is End! 2024-06-07T23:14:40.669027+0900 Lakka systemd[1]: cec-mini-kb.service: Main process exited, code=exited, status=6/NOTCONFIGURED 2024-06-07T23:14:40.669294+0900 Lakka systemd[1]: cec-mini-kb.service: Failed with result 'exit-code'. 2024-06-07T23:14:42.865498+0900 Lakka systemd[1]: cec-mini-kb.service: Scheduled restart job, restart counter is at 5. 2024-06-07T23:14:42.865888+0900 Lakka systemd[1]: Stopped cec-mini-kb.service. 2024-06-07T23:14:42.865947+0900 Lakka systemd[1]: cec-mini-kb.service: Start request repeated too quickly. 2024-06-07T23:14:42.865957+0900 Lakka systemd[1]: cec-mini-kb.service: Failed with result 'exit-code'. 2024-06-07T23:14:42.866196+0900 Lakka systemd[1]: Failed to start cec-mini-kb.service.`

Note:

"Segmentation fault" problem is fixed latest cec-mini-kb. This "Segmentation fault" was no relationship for this problem.

Thanks ASAI, Shigeaki

synthic commented 5 months ago

I wonder if this issue explains why they decided to base the new composite builds on the older Lakka branch.

Due to issues (hiccups and stutters) on the current release (Lakka-v5.x) and development (devel) branches, this community version is based on the Lakka-v4.x branch, where these issues are not present.

ShigeakiAsai commented 5 months ago

@synthic Lakka-v4.x branch : CEC function is not included. Lakka-v5.x or later : CEC function is included. The new composite builds : I don't know CEC function is installed or not. If the new composite builds only supports composite device, CEC function is able to disable. @ToKe79 how is it?

BTW, this issue is for "There is framerate hiccups when CEC function support HDMI display is not connected" I think. It includes the case of composite CRT is only connected.

ShigeakiAsai commented 5 months ago

I consider to fix this issue by changing cec-mini-kb.service. packages/lakka/lakka_tools/cec_mini_kb/system.d/cec-mini-kb.service

Current: If cec-mini-kb.service is failed, cec-mini-kb.service is always restarted endless.

My fixing idea: If cec-mini-kb.service is failed 5 times during 30sec, cec-mini-kb.service stops to restart.

[Unit]
...
StartLimitInterval=30s
StartLimitBurst=5

My fixing idea will effective for following case of 2 and 3. But it does not effective for following case of 4.

CEC supported HDMI display is connected
CEC un-supported HDMI display is connected
CEC supported HDMI display is NOT connected ( Also composite CRT is only connected. )
CEC supported HDMI display is connected, but KMS/DRM does not recognize HDMI display connection in booting time

I want someone's help about above case of 4 please.

Thanks ASAI, Shigeaki

gouchi commented 5 months ago

@spleen1981 Do you have some feedback for this issue ?

Thank you.

spleen1981 commented 5 months ago

My understanding is that there is no issue with cec-mini-kb itself (though it's not clear to me if there is a SEGFAULT at latest commit or not), but it's just a matter of setting up of the relevant service. If that is the case, I guess the service should be relaxed similarly to how suggested above. Or just we could avoid to restart the service at all to be safe; I guess CEC adapter should be available or not with a given hardware configuration and in case one changes the hardware configuration (e.g. screen), lakka should be rebooted. Not sure what is the scenario 4 above, where CEC adapter is recognized at a later stage. but if it's needed cec service can be called after another one at a stage where it is sure CEC adapter is identified (or not). It would be great if we had a setting in retroarch showing CEC status and the possibility to manually start or stop the service, but most probably it's overkill. The only thing I would not do is disabling the service by default, as for the platforms where it's working it's very convenient to control the GUI by the remote control, especially when no keyboard is available and no gamepad is configured yet.

ShigeakiAsai commented 5 months ago

@gouchi Thank you for your follow.

@spleen1981 Thank you for your comment.

I want to change my idea as following.

My fixing idea (replace):

When the systemd detects "retroarch.service" was normally started, it starts "cec-mini-kb.service". The "cec-mini-kb.service" is tried to (re)start during 20 sec 3 times. If this 3 times failed, the systemd stops "cec-mini-kb.service" (re)start.

Changing detail:

retroarch.service Change service type to "notify".
retroarch Notifies "Ready" to systemd via sd_notify() when initialize is done.
cec-mini-kb package Update package revision.
cec-mini-kb.service (a) Give "After=retroarch.service" and "Requires=retroarch.service" dependencies in [Unit] section. (b) Change to "WantedBy=retroarch.service" from "WantedBy=multi-user.target" in [Install] section. (c) Add "StartLimitInterval=20s" and "StartLimitBurst=3" in [Service] section. By (a) and (b), the systemd starts "cec-mini-kb.service" after "retroarch.service" is activated. By (c), the systemd (re)starts "cec-mini-kb.service" 3 times only during 20 sec.

About this changing, I'm confirming now. https://github.com/ShigeakiAsai/Lakka-LibreELEC/commits/ForIssue1981-cec-mini-kb-service-is-repeated-when-it-failed/ https://github.com/ShigeakiAsai/Lakka-LibreELEC/commit/1af2ab8cf6887fbae7603d41fad1cd750c64184a and https://github.com/ShigeakiAsai/Lakka-LibreELEC/commit/f4d2136a8548cfd5d8698e6106f5d5e4dea1bf6e

Thanks ASAI, Shigeaki

vanfanel commented 5 months ago

@ShigeakiAsai If you let it retry for 20 seconds, the vsync rate detection will be altered (and games will still show hiccups during that time, which is a very bad thing IMHO). Please consider trying 1 time only while Lakka boots, and that's all.

ShigeakiAsai commented 5 months ago

@vanfanel I made 1 time only version. About this result, please refer attached log files. no-repeat-CEC-log.zip

HDMI display connected boot time. HDMI display connected boot time and execute createlog
HDMI display disconnected boot time, 1min after connected.
Picade display connected boot time. Picade display connected boot time and execute createlog

This version has a small problem in the following situation.

When HDMI display is not recognized or not connected in Lakka booting, "cec-mini-kb.service" is failed after reconnect HDMI display.

But, this may unusual case. So, I will talk lakka team with this version via pull request.

Thanks ASAI, Shigeaki

ShigeakiAsai commented 4 months ago

@vanfanel Pull request #1984 is merged and this can confirm with 22th June or later build. Could you please check it on your PiCade?

Thanks ASAI, Shigeaki

vanfanel commented 4 months ago

@ShigeakiAsai Works good on my PiCade, no more framarate hiccups caused by the service! Many thanks for fixing this :)

libretro / Lakka-LibreELEC