threads: log every wait and notify
#7220
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
When troubleshooting deadlocks in WebAssembly modules, it is important to understand which `wait` instructions are still pending a `notify`. It would be nice to have some kind of `--warn-deadlock-after=1s` flag available that would poll the parking lot for `wait`s hanging past the time limit, but I realized the real value would be to tie the `wait` instruction (through CLIF) to the original source code, if debug information were available. This did not seem to be entirely feasible, since CLIF loses the original Wasm source context (is this true?) and I was not confident that we would be able to use `addr2line` to map from Wasm instructions to source (e.g., see @cfallin's [issue](gimli-rs/addr2line#265)). Instead, this change simply logs each valid `wait` and `notify` execution, leaving it to the user to figure out which one is hanging (should not be too difficult) and how to map this back to their source code (more difficult).
pchickey
reviewed
Oct 11, 2023
| @@ -565,6 +565,7 @@ impl SharedMemory { | |||
| /// Implementation of `memory.atomic.notify` for this shared memory. | |||
| pub fn atomic_notify(&self, addr_index: u64, count: u32) -> Result<u32, Trap> { | |||
| validate_atomic_addr(&self.0.def.0, addr_index, 4, 4)?; | |||
| log::trace!("memory.atomic.notify(addr={addr_index}, count={count})"); | |||
There was a problem hiding this comment.
instead of using the format string, use log::trace!("memory.atomic.notify", addr=addr_index, count=count); to provide structured values.
There was a problem hiding this comment.
I tried that but it complains: I think to use the key-value syntax we need to set target: ..., up front and still provide a string at the end (see log::log!)?
There was a problem hiding this comment.
oh, my bad. I just realized this is log and the key value syntax only works with the tracing crate, and I forgot we use log in wasmtime-runtime in order to keep the dependencies as small as possible, but tracing in wasmtime-wit-bindgen, wasi, etc.
So, your PR is good to go as is. I don't think we need should using log vs tracing down in the runtime now, unless someone really wants to.
pchickey
approved these changes
Oct 11, 2023
abrown
added a commit
to abrown/wasmtime
that referenced
this pull request
Oct 13, 2023
In bytecodealliance#7220, we began logging the arguments of WebAssembly `wait` and `notify` as these instructions are executed. This change prints the addresses using hexadecimal, which is simply more convenient when dealing with addressing.
github-merge-queue bot
pushed a commit
that referenced
this pull request
Oct 14, 2023
In #7220, we began logging the arguments of WebAssembly `wait` and `notify` as these instructions are executed. This change prints the addresses using hexadecimal, which is simply more convenient when dealing with addressing.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
When troubleshooting deadlocks in WebAssembly modules, it is important to understand which
waitinstructions are still pending anotify. It would be nice to have some kind of--warn-deadlock-after=1sflag available that would poll the parking lot forwaits hanging past the time limit, but I realized the real value would be to tie thewaitinstruction (through CLIF) to the original source code, if debug information were available. This did not seem to be entirely feasible, since CLIF loses the original Wasm source context (is this true?) and I was not confident that we would be able to useaddr2lineto map from Wasm instructions to source (e.g., see @cfallin's issue).Instead, this change simply logs each valid
waitandnotifyexecution, leaving it to the user to figure out which one is hanging (should not be too difficult) and how to map this back to their source code (more difficult).