search

eruption-project / eruption

Realtime RGB LED Driver for Linux
https://eruption-project.org/
GNU General Public License v3.0
270 stars 33 forks source link

Input Lag Spikes #160

Closed R1yuu closed 2 years ago

R1yuu commented 2 years ago

Introduction I play a rhythm game called osu (In particular osu-lazer) which requires constant perfectly timed input.

Please describe the bug With the eruption daemon enabled, I experience regular lag spikes in equal time intervals. When eruption is stopped using sudo systemctl stop eruption the lag completely disappears. I assume the lag spikes occur when eruption "pushes" new RGB instructions onto the keyboard.

To Reproduce Install and start eruption (via the AUR). Install osu-lazer (via the AUR). Start a beatmap and notice the input lag.

Expected behavior No noticeable input lag spikes.

Logs

Sep 18 19:37:42 andre-arch-pc systemd[1]: Starting Realtime RGB LED Driver for Linux...
Sep 18 19:37:42 andre-arch-pc systemd[1]: Started Realtime RGB LED Driver for Linux.
Sep 18 19:48:33 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 19:48:33 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 19:48:33 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 201 milliseconds, goal: 41
Sep 18 19:49:01 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 19:49:01 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 19:49:01 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 209 milliseconds, goal: 41
Sep 18 20:12:31 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 20:12:31 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 20:12:31 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 200 milliseconds, goal: 41
Sep 18 20:19:40 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 20:19:40 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 20:19:40 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 214 milliseconds, goal: 41
Sep 18 21:05:30 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 21:05:30 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 21:05:30 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 219 milliseconds, goal: 41
Sep 18 21:05:48 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 21:05:48 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 21:05:48 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 205 milliseconds, goal: 41
Sep 18 21:15:28 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 18 21:15:28 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 18 21:15:28 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 200 milliseconds, goal: 41
Sep 19 00:09:39 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Skipped rendering a frame to a device, because we could not acquire a lock
Sep 19 02:07:08 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 19 02:07:08 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 19 02:07:08 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 320 milliseconds, goal: 41
Sep 19 02:47:14 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 19 02:47:14 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 19 02:47:14 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 301 milliseconds, goal: 41
Sep 19 03:17:09 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: More than 82 milliseconds of jitter detected!
Sep 19 03:17:09 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: This means that we dropped at least one frame
Sep 19 03:17:09 andre-arch-pc eruption[351]: andre-arch-pc eruption[351]: Loop took: 301 milliseconds, goal: 41
Sep 19 03:20:48 andre-arch-pc systemd[1]: Stopping Realtime RGB LED Driver for Linux...
Sep 19 03:20:49 andre-arch-pc systemd[1]: eruption.service: Deactivated successfully.
Sep 19 03:20:49 andre-arch-pc systemd[1]: Stopped Realtime RGB LED Driver for Linux.
Sep 19 03:20:49 andre-arch-pc systemd[1]: eruption.service: Consumed 6min 38.361s CPU time.

Please complete the following information:

X3n0m0rph59 commented 2 years ago

Hi @R1yuu, thanks for reporting this issue!

Has this bug been introduced with the latest release 0.2.0 of Eruption?

Could you please provide the following information:

sudo lsusb

And please post the full log output of Eruption running in debug mode:

sudo systemctl mask eruption.service && sudo systemctl stop eruption.service
sudo RUST_LOG=debug RUST_BACKTRACE=full eruption

To re-enable Eruption afterwards please run:

sudo systemctl unmask eruption.service && sudo systemctl restart eruption.service
R1yuu commented 2 years ago

I tested (compiled and ran) the issue with eruption 0.1.23 and the problem seems to not be present on that version.
I believe to have noticed some minor lag spikes rarely at random times, but this could also have been paranoia. The log doesn't report any jitter anyway, so my hunch is that it was either not present at all in version 0.1.23 or at least to a much smaller degree. As for me, I would rate version 0.1.23 as working without problems.

Version 0.2.0 Output:

sudo lsusb:

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 1b1c:1b74 Corsair CORSAIR GLAIVE RGB PRO Gaming Mouse
Bus 001 Device 003: ID 046d:0ab7 Logitech, Inc. Blue Microphones
Bus 001 Device 002: ID 1e7d:3098 ROCCAT ROCCAT Vulcan AIMO
Bus 001 Device 005: ID 28bd:0094 XP-Pen STAR G640
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

sudo lsusb -v:

https://gist.github.com/R1yuu/a31fee683c00569cc047de7a88311a84

sudo systemctl mask eruption.service && sudo systemctl stop eruption.service
sudo RUST_LOG=debug RUST_BACKTRACE=full eruption 2>&1 | tee -a debug:

https://gist.github.com/R1yuu/a786c1238fc73c2fafa5cb13c7c5fd41

X3n0m0rph59 commented 2 years ago

Hi @R1yuu, the problem should now be fixed in the develop branch of Eruption!

I was able to reproduce the latency issue in a VM, and can confirm that it went away for me.

It seems that this issue was caused by a lock contention/dependency issue. The lock that guards the global key state map was held much longer than actually required.

Could you please build the develop branch from source, and give it a try?

R1yuu commented 2 years ago

The Lag Spikes are completely gone and everything is working as intended/expected.

Thank you for your commitment and good work!

Here the journalctl entries from my test run:

Okt 01 10:51:51 andre-arch-pc systemd[1]: Starting Realtime RGB LED Driver for Linux...
Okt 01 10:51:51 andre-arch-pc systemd[1]: Started Realtime RGB LED Driver for Linux.
Okt 01 10:55:37 andre-arch-pc eruption[16397]: andre-arch-pc eruption[16397]: Skipped rendering a frame to a device, because we could not acquire a lock
Okt 01 10:59:07 andre-arch-pc eruption[16397]: andre-arch-pc eruption[16397]: Skipped rendering a frame to a device, because we could not acquire a lock
Okt 01 10:59:35 andre-arch-pc eruption[16397]: andre-arch-pc eruption[16397]: Skipped rendering a frame to a device, because we could not acquire a lock

For me, this Issue is resolved. I will leave the closing of the thread to you.

X3n0m0rph59 commented 2 years ago

The Lag Spikes are completely gone and everything is working as intended/expected.

Excellent! Glad that it is working now...

Thank you for your commitment and good work!

You're welcome!