|
ravel
Deterministic simulation testing for C++. Seed a bug, replay it exact.
|
When a run fails, ravel tells you what failed, where, and gives you the means to replay it. This page shows what each kind of problem looks like, with real output, and what to do about it.
Every run produces a ravel::Result:
| Field | Meaning |
|---|---|
ok | true if nothing failed |
failure | what went wrong, in a sentence; empty if ok |
seed | the seed of the run |
steps | how many times the scheduler resumed a task |
trace_digest | a fingerprint of the whole run; equal digests mean identical runs |
trace_path | the trace file, if trace_dir was set and the run failed |
The failure sentence is the first thing to read. It always starts with what kind of thing happened, as the next section shows.
The system ran to the end and a property you stated was false. This is the failure you are looking for. The tutorial walks through one, including how to read the trace that explains it. Invariants are checked once, when the run ends (or at time_limit). To catch a violation as it happens, record it in shared state from the code that notices it, as the Raft example does, and check that state in the invariant.
A task let an exception escape, which stops the run at that step:
steps: 1 says it happened on the very first step. The message names the task and carries the exception's what(). If your task catches everything it will never show up here; let unexpected exceptions escape.
Tasks were still runnable after 200 steps (the limit was lowered here; the default is a million). That is a livelock: something that keeps running without making progress, like two tasks that keep yielding to each other, or a retry loop with no backoff and no limit. Look at the trace's last events to see who was running. The limit exists so a livelocked system fails the run instead of hanging your CI. If your system is legitimately busy for longer, raise max_steps.
If instead the system never goes quiet by design (heartbeats, election timers), that is not a livelock: set SimulationOptions::time_limit so the run stops at a virtual time instead, and check your invariants then.
A run completes when nothing is left to happen, and a task waiting for a message that will never arrive does not stop that. So a system that quietly deadlocks looks like a passing run, unless an invariant says what should have happened. Always include a liveness-flavored invariant such as "the client got its reply" or "the write was acknowledged", not only "nothing bad happened".
Shrinking works by replaying the failure over and over, so the failure has to replay. This message means it did not: the same seed and the same recorded choices failed the first time and not the second. Something outside ravel influences the code under test. Run ravel::check_determinism on your setup; it will name the step where two runs part ways. The usual culprits are a real clock, a static that survives between runs, or a container ordered by pointer. See the checklist.
That is check_determinism speaking. It shows two runs of the same seed and the first event where they differ (here, a task woke at different virtual times). The porting guide has the full example and the list of usual causes. There are three phrasings:
two runs of the same seed diverged at step N: ...: the code under test is not repeatable.replaying run 1's recorded choices diverged ...: something other than ravel's random choices steers the run, so a saved .choices file would not reproduce it.the runs made the same moves but ... ended with ...: the event sequence is identical but an invariant reads something that differs between runs.Set options.simulation.trace_dir = "ravel-traces" and every failed run leaves a file there: ravel-seed-<seed>.trace.jsonl. It has one line of JSON per event. Here is the whole trace of a tiny run (a message, then a disk write and sync):
| Field | Meaning |
|---|---|
step | position in the run, from 0 |
time | virtual time in ticks (never wall-clock time) |
kind | what happened; see the table below |
id | the task, channel or disk it concerns |
name | that thing's name: a task's name, from->to for a channel, a disk's name |
The events you will meet most:
| Kind | Reads as |
|---|---|
TaskSpawned | the task was created |
TaskResumed | the scheduler chose this task and ran it to its next co_await |
TaskFinished / TaskThrew | it returned, or an exception escaped (the run stops) |
MessageSent | someone called send() |
MessageDropped | the fault spec lost it |
MessageDelivered | it reached the receiver's inbox |
DiskWritten | a write, rename or removal completed |
DiskSynced | a sync or sync_dir completed |
DiskFailed | an injected disk error, or out of space |
DiskCrashed | crash() was called |
The full field reference is in formats.md.
Reading the example above: at t=0 the client sends a message and starts a disk write; the disk takes 3 ticks (DiskWritten at t=3) while the message is in flight for 4 (MessageDelivered at t=4); the server wakes up, finishes; the sync completes at t=5. Notice how the order of things is visible: the write finished before the message arrived. If a bug depends on that order, you can see it here.
A raw trace is easy for a program and tiring for a person. tools/ravel_trace.py (plain Python 3, no dependencies) turns it into something you can read at a glance. The examples use the tutorial's two traces for the failing deposit: the original failing run, and the minimal one ravel shrank it to.
**summary**: what is in the trace, and anything that deserves a look.
Four lost messages, and (from the tutorial) we know that one lost reply is the whole bug.
**timeline**: one column per task, channel and disk, one row per event, in time order. This is usually the fastest way to see a failure. Words in capitals mark what deserves a look (DROPPED, CRASH, FAILED, THREW):
Read it like a sequence diagram: the request goes out (send, then deliver), the server runs, its reply is DROPPED, and fifty ticks later the client runs again and sends the request a second time.
**show**: the events as a plain table, with filters --name (a task, channel or disk), --kind, --from and --to (virtual time). For example, only what was lost:
**diff**: where two traces part ways. Point it at the original failing run and the minimal one to see what shrinking threw away:
The runs part at step 2 (the original started the client first; the minimal run starts the server), and the table at the bottom is the summary of what shrinking removed: three of the four lost messages and the retries they caused. diff exits with status 1 when the traces differ and 0 when they are identical, so it also works in scripts, for instance to check that two runs of the same seed match.
Traces are plain JSON Lines, so ordinary tools work. With jq (the outputs below are from the tutorial's trace, ravel-seed-6.replay.trace.jsonl):
Only the lost messages:
One event per line, as a table:
Everything one task did:
What happened between two moments in time:
No jq? grep MessageDropped ravel-seed-6.replay.trace.jsonl does the first one.
A failing seed is a complete, repeatable description of the run, so you can watch it as many times as you like.
From a seed. Build the simulation yourself and run it in a debugger:
Every run of that code takes the same steps, so a breakpoint in a task hits at the same moment each time, and you can step through the exact interleaving that failed.
From a choices file (no seed needed, and it survives changes to ravel's random number generator). Use the shrunk one; it is the shortest run that fails:
Remember to pass the same SimulationOptions the failing run used (such as time_limit) as the third argument of replay if you set any.
Print the trace of a run that passed. Traces are only written for failures, but sim.write_trace(std::cout) works after any run.
sim.rng(). Fewer is simpler.1 in a fault position means "the fault happens". So the nonzero numbers in a minimal list are the ingredients the bug needs; everything else is irrelevant. The tutorial reads one out loud.ShrinkResult::budget_exhausted is true, shrinking stopped at max_attempts (20000 by default) before it finished. Raise it, or accept a result that is smaller but maybe not minimal.My invariant failed on some seeds. Is it a bug in my code or my invariant? Shrink it and read the trace: it is the shortest sequence of events that violates the property. If those events show a real problem, it is your code. If they show something legitimate (a fault your system is supposed to tolerate), your invariant is too strict.
A seed fails on my machine and not in CI. That should not happen: same seed, same run, everywhere. Run ravel::check_determinism. Different results on different machines means something outside ravel is leaking into the run, most often an uninitialized variable or a container ordered by pointer.
The trace is huge. Failures on long runs are long. Shrink first (the minimal run is usually short), or filter with jq. Tracing costs memory in proportion to the number of steps, so very long runs are better bounded with max_steps or time_limit.
How many seeds is enough? Bugs that need one unlucky moment show up on a fraction of seeds; the tutorial's showed up on 28%. Rarer ones need more: the Raft example's rarest bug is about 1 seed in 600. Run thousands in CI and more overnight, since seeds are cheap and each is a new chance.
1.9.8