loom

loom copied to clipboard

This change adds a new tracing facility that helps track down the source of nondeterministic execution. It records, for each branch point, the original (user) source code position leading to this branch, the operation being performed, and the reference that is involved in the branch. If this does not match on a later execution, we dump the mismatched operation, as well as a trace of recent operations, let the current execution run to completion, then panic.

A typical trace looks a bit like this:

===== NONDETERMINISTIC EXECUTION DETECTED =====
Previous execution:
    13: [tests/nondet.rs:55:28] loom::thread::JoinHandle<()>::join on Thread::2

Current execution:
    13: [tests/nondet.rs:55:28] loom::thread::JoinHandle<()>::join on Thread::3

Recent events:
       0: [tests/nondet.rs:17:26] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
       1: [tests/nondet.rs:18:19] loom::sync::arc::Arc<loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>>::clone on State::1
       2: [tests/nondet.rs:35:9] loom::thread::yield_now
     ...: THREAD SWITCH on Thread::1
       3: [tests/nondet.rs:21:30] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
     ...: THREAD SWITCH on Thread::0
     ...: loom::sync::mutex::MutexGuard<nondet::nondeterministic_execution_detected::State>::drop on Mutex::0
       4: [tests/nondet.rs:17:26] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
       5: [tests/nondet.rs:18:19] loom::sync::arc::Arc<loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>>::clone on State::1
       6: [tests/nondet.rs:35:9] loom::thread::yield_now
     ...: THREAD SWITCH on Thread::2
       7: [tests/nondet.rs:21:30] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
     ...: THREAD SWITCH on Thread::0
     ...: loom::sync::mutex::MutexGuard<nondet::nondeterministic_execution_detected::State>::drop on Mutex::0
       8: [tests/nondet.rs:17:26] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
       9: [tests/nondet.rs:18:19] loom::sync::arc::Arc<loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>>::clone on State::1
      10: [tests/nondet.rs:35:9] loom::thread::yield_now
     ...: THREAD SWITCH on Thread::3
      11: [tests/nondet.rs:21:30] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
     ...: THREAD SWITCH on Thread::0
     ...: loom::sync::mutex::MutexGuard<nondet::nondeterministic_execution_detected::State>::drop on Mutex::0
      12: [tests/nondet.rs:45:30] loom::sync::mutex::Mutex<nondet::nondeterministic_execution_detected::State>::lock on Mutex::0
     ...: loom::sync::mutex::MutexGuard<nondet::nondeterministic_execution_detected::State>::drop on Mutex::0

thread 'nondeterministic_execution_detected' panicked at 'Aborting due to non-deterministic execution', src/rt/execution.rs:262:13
stack backtrace:
   0: std::panicking::begin_panic
             at /local/home/bdonlan/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:497
   1: loom::rt::execution::Execution::check_consistency
             at ./src/rt/execution.rs:262
   2: loom::model::Builder::check
             at ./src/model.rs:208
   3: loom::model::model
             at ./src/model.rs:230
   4: nondet::nondeterministic_execution_detected
             at ./tests/nondet.rs:38
   5: nondet::nondeterministic_execution_detected::{{closure}}
             at ./tests/nondet.rs:9
   6: core::ops::function::FnOnce::call_once
             at /local/home/bdonlan/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:227
   7: core::ops::function::FnOnce::call_once
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/ops/function.rs:227
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
test nondeterministic_execution_detected ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

this is extremely cool!

wow this looks cool : )

random thought along this line: a "non-determinism checker" option that just executes each iteration twice with the same seed and reports if the traces diverge

:wave: hi @bdonlan, sorry this went so long without a review --- are you still interested in working on this? i'd love to give this branch a review if you're able to update it with the latest master branch!