Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Add a timeout message #809

Merged
merged 2 commits into from
Nov 17, 2024
Merged

Add a timeout message #809

merged 2 commits into from
Nov 17, 2024

Conversation

AlexKnauth
Copy link
Contributor

To distinguish between errors where an auto-splitter update took too long, from other errors, such as panics, running out of stack space, etc.

@AlexKnauth
Copy link
Contributor Author

When testing with an auto-splitter that loops forever printing looping without calling next_tick().await, the logs look like this:

[2024-05-31 20:08:11][Auto Splitter][INFO] looping
[2024-05-31 20:08:11][Auto Splitter][INFO] looping
[2024-05-31 20:08:11][Auto Splitter][INFO] looping
[2024-05-31 20:08:11][Auto Splitter][ERROR] timeout, no update in 5 seconds
[2024-05-31 20:08:11][Auto Splitter][INFO] looping
[2024-05-31 20:08:11][Auto Splitter][ERROR] Unloaded, because the script trapped: error while executing at wasm backtrace:
    0:  0xb6f - <unknown>!<wasm function 17>
    1: 0x79c9 - <unknown>!<wasm function 106>

Caused by:
    wasm trap: interrupt

@AlexKnauth AlexKnauth marked this pull request as draft November 16, 2024 13:42
@AlexKnauth AlexKnauth marked this pull request as ready for review November 16, 2024 14:35
@AlexKnauth
Copy link
Contributor Author

Tested again after a rebase on the new watchdog implementation, logs look like this:

[2024-11-16 09:33:24][Auto Splitter][INFO] looping
[2024-11-16 09:33:24][Auto Splitter][INFO] looping
[2024-11-16 09:33:24][Auto Splitter][INFO] looping
[2024-11-16 09:33:24][Auto Splitter][ERROR] timeout, no update in 5 seconds
[2024-11-16 09:33:24][Auto Splitter][INFO] looping
[2024-11-16 09:33:24][Auto Splitter][ERROR] Unloaded, because the script trapped: error while executing at wasm backtrace:
    0: 0x647c6 - hollowknight_autosplit_wasm.wasm!free
    1: 0x49f79 - hollowknight_autosplit_wasm.wasm!hollowknight_autosplit_wasm::main::{{closure}}::haf64fc4596a16a8a
    2: 0x4e2e6 - hollowknight_autosplit_wasm.wasm!update
    3: 0x66def - hollowknight_autosplit_wasm.wasm!update.command_export

Caused by:
    wasm trap: interrupt

For an auto-splitter that loops forever printing looping without calling next_tick().await. Printing an error log message saying timeout, no update in 5 seconds is more helpful in this situation, rather than leaving it ambiguous about the possible causes of the error.

CryZe
CryZe reviewed Nov 16, 2024
View reviewed changes
src/auto_splitting/mod.rs
@@ -944,6 +945,10 @@ fn watchdog<T: event::CommandSink + TimerQuery + Send>(shared_state: Arc<SharedS
};

if result.timed_out() {
if !has_timed_out {
log::error!(target: "Auto Splitter", "timeout, no update in {} seconds", TIMEOUT.as_secs_f32());
has_timed_out = true;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This never gets reset to false again. The rest looks good.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Btw, long term I think we want the watchdog to be more configurable (the timeout) and with a custom callback where the UI could then for example ask the user if they want to shut down the auto splitter.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the catch, fixed in timeout: reset to false again.

CryZe
CryZe reviewed Nov 16, 2024
View reviewed changes
src/auto_splitting/mod.rs
if let Some(auto_splitter) = &*shared_state.auto_splitter.load() {
auto_splitter.interrupt_handle().interrupt();
}
} else {
has_timed_out = false;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure this is the right place. I think this should be set in the Unloaded case, so it doesn't get set all the time.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nvm, the reload case in the other thread never puts the watchdog into the unloaded state, so I guess this is fine.

@AlexKnauth
Copy link
Contributor Author

So is this good to merge?

@CryZe CryZe merged commit d35ff05 into LiveSplit:master Nov 17, 2024
70 checks passed
@CryZe CryZe added enhancement An improvement for livesplit-core. code quality Affects the quality of the code. auto splitting This is about the auto splitting implementation. labels Nov 17, 2024
@CryZe CryZe added this to the v0.14 milestone Nov 17, 2024
@AlexKnauth AlexKnauth deleted the timeout branch November 17, 2024 16:59
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@CryZe CryZe CryZe left review comments

Assignees
No one assigned
Labels
auto splitting This is about the auto splitting implementation. code quality Affects the quality of the code. enhancement An improvement for livesplit-core.
Projects
None yet
Milestone
v0.14
Development

Successfully merging this pull request may close these issues.
2 participants
@AlexKnauth @CryZe