LiveSplit / livesplit-core

livesplit-core is a library that provides a lot of functionality for creating a speedrun timer.
https://livesplit.org/
Apache License 2.0
212 stars 58 forks source link

HotkeySystem freeze during inputs #291

Closed Eein closed 2 years ago

Eein commented 4 years ago

Hello :wave:

I've been toying with HotkeySystem in the core and it works great with one exception. Occasionally a thread crashes (i think) when making inputs.

I first noticed this when I was skipping splits quickly when testing my timer UI implementation.

I've made a minimal reproduction case here: https://github.com/Eein/hotkey-reproduction

This app just prints out the current timestamp, timer state, and split index in a loop. You can start the timer using AltR, then press down to skip a split, and up to undo. I found you can trigger this issue quickly by starting the timer with AltR then holding down.

I've tried without using the timer.clone().read().x() calls and it doesn't seem to freeze at all.
Am I just accessing the timer too frequently while its trying to write changes in another thread?

using rust-gdb it going up the stack shows the following

#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x00005555556961b0 in parking_lot_core::thread_parker::ThreadParker::futex_wait (self=0x7ffff7c22480, ts=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/thread_parker/linux.rs:97
#2  0x000055555569652a in parking_lot_core::thread_parker::ThreadParker::park (self=0x7ffff7c22480) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/thread_parker/linux.rs:61
#3  0x0000555555694fed in parking_lot_core::parking_lot::park::{{closure}} (thread_data=0x7ffff7c22460) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:596
#4  0x000055555569429a in parking_lot_core::parking_lot::with_thread_data (f=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:174
#5  parking_lot_core::parking_lot::park (key=93824997521232, validate=..., before_sleep=..., timed_out=..., park_token=..., timeout=...)
    at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:563
#6  0x000055555568b865 in parking_lot::raw_rwlock::RawRwLock::lock_common (self=0x555555a5f750, timeout=..., token=..., try_lock=..., validate=...)
    at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:1092
#7  0x000055555568a93e in parking_lot::raw_rwlock::RawRwLock::lock_shared_slow (self=0x555555a5f750, recursive=false, timeout=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:669
#8  0x00005555555a7ad2 in <parking_lot::raw_rwlock::RawRwLock as lock_api::rwlock::RawRwLock>::lock_shared (self=0x555555a5f750) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:113
#9  0x00005555555a7c06 in lock_api::rwlock::RwLock<R,T>::read (self=0x555555a5f750) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/lock_api-0.2.0/src/rwlock.rs:328
#10 0x00005555555aa750 in hotkey_reproduction::main () at src/main.rs:44
(gdb) up
#1  0x00005555556961b0 in parking_lot_core::thread_parker::ThreadParker::futex_wait (self=0x7ffff7c22480, ts=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/thread_parker/linux.rs:97
97                  libc::syscall(
(gdb) up
#2  0x000055555569652a in parking_lot_core::thread_parker::ThreadParker::park (self=0x7ffff7c22480) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/thread_parker/linux.rs:61
61                  self.futex_wait(None);
(gdb) up
#3  0x0000555555694fed in parking_lot_core::parking_lot::park::{{closure}} (thread_data=0x7ffff7c22460) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:596
596                     thread_data.parker.park();
(gdb) up
#4  0x000055555569429a in parking_lot_core::parking_lot::with_thread_data (f=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:174
174         f(unsafe { &*thread_data_ptr })
(gdb) up
#5  parking_lot_core::parking_lot::park (key=93824997521232, validate=..., before_sleep=..., timed_out=..., park_token=..., timeout=...)
    at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot_core-0.5.0/src/parking_lot.rs:563
563         with_thread_data(|thread_data| {
(gdb) up
#6  0x000055555568b865 in parking_lot::raw_rwlock::RawRwLock::lock_common (self=0x555555a5f750, timeout=..., token=..., try_lock=..., validate=...)
    at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:1092
1092                    match parking_lot_core::park(
(gdb) up
#7  0x000055555568a93e in parking_lot::raw_rwlock::RawRwLock::lock_shared_slow (self=0x555555a5f750, recursive=false, timeout=...) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:669
669             self.lock_common(
(gdb) up
#8  0x00005555555a7ad2 in <parking_lot::raw_rwlock::RawRwLock as lock_api::rwlock::RawRwLock>::lock_shared (self=0x555555a5f750) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/parking_lot-0.8.0/src/raw_rwlock.rs:113
113                 let result = self.lock_shared_slow(false, None);
(gdb) up
#9  0x00005555555a7c06 in lock_api::rwlock::RwLock<R,T>::read (self=0x555555a5f750) at /home/will/.cargo/registry/src/github.com-1ecc6299db9ec823/lock_api-0.2.0/src/rwlock.rs:328
328             self.raw.lock_shared();
(gdb) up
#10 0x00005555555aa750 in hotkey_reproduction::main () at src/main.rs:44
44                  timer.clone().read().current_split_index(),
(gdb) up
Initial frame selected; you cannot go up.
(gdb)
^C
Thread 1 "hotkey-reproduc" received signal SIGINT, Interrupt.
syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
38      ../sysdeps/unix/sysv/linux/x86_64/syscall.S: No such file or directory.

If you need a more visual test, you can pull my timer at http://github.com/eein/glod and checkout the splits-refactor branch. (you'll need gtk)

Just a thought: While looking at the code I noticed the behavior for memory ordering here:

https://docs.rs/livesplit-core/0.11.0/src/livesplit_core/hotkey_system.rs.html#37

I don't have in depth knowledge but something to look at :) If I have some time in the next couple days i'll try SeqCst ordering for sanity.

Systems Tested PopOs 19.10 5.3.0 kernel - Gnome Manjaro 5.4 kernel - Gnome

CryZe commented 4 years ago

I'd say you may want to check the stacktrace of the other thread, but I'm definitely thinking the hotkey presses are basically queued up to the point where the main thread is not able to make any progress anymore.

Eein commented 4 years ago

Thanks! That's what I figured.

After snooping around, I'll probably stop my project and just wait until LiveSplitOne desktop comes out, looks great so far :) I'll be on the lookout for any trivial tasks and/or linux distribution testing once it's ready.

CryZe commented 4 years ago

Looks like this may be an actual bug. I'll reopen in the meantime: https://github.com/Amanieu/parking_lot/issues/212

CryZe commented 4 years ago

Okay, so it looks like they identified the problem and it's not really so much of a bug, but rather an intended design decision. Basically you are not allowed to have multiple readers on the same thread at the same time, which is what's happening here:

        println!("{:?} {:?} - Split {:?}",
            in_ms,
            timer.clone().read().current_phase(),
            timer.clone().read().current_split_index(),
        );

Those will only be unlocked again at the end of the print, so for a short time there's multiple.

CryZe commented 2 years ago

This is now essentially resolved as we don't use parking_lot anymore (when I merge the PR). Not sure if this applies to the locking primitives in std as well. But it's probably by design if std behaves like this too.