Here is something to think about: bugs are not rare, but rather the ordering of events that triggers them are. What do I mean by this?
Let’s start with a simple story. When I worked at AWS on RDS (Relational Database Service), we built the control-plane for the service using workflows, of course using SWF (Simple Workflow). The workflows would execute a series of steps to create, modify or delete a database instance. Every so often we’d see something that looked impossible: a workflow that seemed to run its steps out of order.
What we actually observed was a pause. A worker would pick up a step and then stop for an unexpectedly long time. While it was stopped it stopped heartbeating, so SWF decided it was dead, and reassigned it to another worker. The new worker finished the step and the workflow moved on. Then the first worker woke up. As far as it could tell no time had passed, so it carried on with the step it was holding, causing havoc in it’s wake.
We suddenly realized that we were not adequately testing all the possible schedules of events. The workflow code was correct, but the schedule that triggered the bug was not one we had ever seen in our tests. It was a rare schedule, but it was not a rare bug. Thus began adding idempotency tokens to every step and making sure that every step could be run multiple times without breaking anything. It was a lot of work, but it made the system much more robust.
What’s the purpose of this story?
I am building Rewind VM, a deterministic VM. It helps finds bugs in software primarily by running the same code under many different schedules.11I say schedule rather than thread interleaving on purpose. Most of the bugs on that page are races between processes, or between a process and a signal. Only a few are between two threads of one program.. That mere act of shuffling the schedule has found many bugs thus far.
The software under test is not even a distributed system, such as the workflow example above, and yet many of the bugs are still schedule-dependent. No crazy Jepsen test-suite needed. How can this be ? All these projects have tests that validate the code on every change. Why does shuffling the schedule find so many bugs that all those tests never did?
The bugs aren’t rare, the schedules your tests run are. An idle, fast machine runs the same handful of orderings nearly every time. A test passes because the order never changes, and the code may only ever have handled that one order.
Aside: New to Rewind? Start with a flaky build you only catch once and dafuq is a deterministic VM?
It takes different schedules or unforseen long pauses, similar to the workflow story above, trigger these bugs. The bugs are not rare, but the schedules that trigger them are. How rare are they?
The smallest race I know is counter++ from two threads.
long counter;
void increment(void) {
counter++;
}
increment:
mov rax, [counter] ; load
add rax, 1 ; add
mov [counter], rax ; store
ret
Two threads run increment once each. Each thread’s three steps execute in order, but the two threads can interleave. An ordering is a choice of which 3 of the 6 slots belong to thread A, so there are of them.
We can visualize the 20 choices as paths on a grid. A step right is a step of thread A, a step down is a step of thread B, and every path from the top-left corner to the bottom-right one is one ordering.
The shaded square holds the four points where both threads have loaded the counter and neither has stored it. Any path that enters it ends with the counter with a value of 1, with the second writer storing the stale original value.
Only the two paths along the edges provide the “correct result” of 2, A entirely before B or B entirely before A. That is 18 of 20 orderings that lose an update. If every ordering were equally likely, this race would fire in 9 runs out of 10. 😱
What does this look like on a real machine?
Let’s build a small program that runs the two threads and records the order of their steps. The program is a bit more complicated than the simple counter++ above, because it has to record the order of the steps. It also has to be careful not to introduce any new races in the recording itself. The program leverages Rewind’s rewind_point() to give Rewind VM a place to switch threads.22The program also has a version that uses a barrier to make the threads collide on purpose to make the race even more likely.
race.c
/*
* Two threads each add one to a shared counter in three steps: load the
* counter, add one, store it back. No lock, so a thread that runs between
* the other's load and store writes a stale value over it.
*
* Each step first takes the next slot of a shared atomic sequence and
* writes its thread's letter there, so the program prints the order the
* six steps ran in, such as AABABB, and the final counter.
*
* rewind_point() between the steps gives Rewind VM a place to switch
* threads. main() calls it once before the threads start, so the one
* failed open it makes outside Rewind happens there; on the host the
* points inside the threads are a load and a branch.
*
* Built with -DSTART_BARRIER, both threads wait on a barrier before the
* first step, so they start as close together as the host allows.
*
* The exit status encodes the outcome so `rewind check` reports it
* without reading output: ordering index (0..19) * 2 + (1 if an update
* was lost).
*/
#include <pthread.h>
#include <stdatomic.h>
#include <stdio.h>
#include <string.h>
#include "rewind.h"
enum { THREADS = 2, STEPS = 3, MARKS = THREADS * STEPS };
static volatile long counter;
static atomic_int next_mark;
static char order[MARKS + 1];
#ifdef START_BARRIER
static pthread_barrier_t start;
#endif
/* Record that thread `who` is taking its next step. */
static void mark(char who)
{
order[atomic_fetch_add(&next_mark, 1)] = who;
}
static void *increment(void *arg)
{
char who = *(const char *)arg;
#ifdef START_BARRIER
pthread_barrier_wait(&start);
#endif
mark(who);
long seen = counter; /* load */
rewind_point();
mark(who);
seen = seen + 1; /* add */
rewind_point();
mark(who);
counter = seen; /* store */
return NULL;
}
/* The index of `s` among the 20 orderings of AAABBB, in sorted order. */
static int ordering_index(const char *s)
{
int index = 0;
for (int a = 0; a < 64; a++) {
char candidate[MARKS + 1];
int as = 0;
for (int i = 0; i < MARKS; i++) {
candidate[i] = (a >> (MARKS - 1 - i)) & 1 ? 'B' : 'A';
as += candidate[i] == 'A';
}
candidate[MARKS] = '\0';
if (as != STEPS) {
continue;
}
if (strcmp(candidate, s) == 0) {
return index;
}
index++;
}
return -1;
}
int main(void)
{
static const char names[THREADS] = { 'A', 'B' };
pthread_t threads[THREADS];
/* Open /dev/rewind, or find it missing, before any thread runs. */
rewind_point();
#ifdef START_BARRIER
pthread_barrier_init(&start, NULL, THREADS);
#endif
for (int i = 0; i < THREADS; i++) {
pthread_create(&threads[i], NULL, increment, (void *)&names[i]);
}
for (int i = 0; i < THREADS; i++) {
pthread_join(threads[i], NULL);
}
int lost = counter != THREADS;
printf("%s %ld\n", order, counter);
return ordering_index(order) * 2 + lost;
}
I ran each one 10,000 times on my laptop, a Ryzen 7 7840U with 16 idle hardware threads.
$ for i in $(seq 10000); do ./race; done | sort | uniq -c | sort -rn
9985 AAABBB 2
15 BBBAAA 2
$ for i in $(seq 10000); do ./race-barrier; done | sort | uniq -c | sort -rn
9957 BBBAAA 2
39 AAABBB 2
2 BBAAAB 1
1 BAAABB 1
1 BAABAB 1
Across 20,000 runs the idle laptop ran 5 of the 20 orderings and lost an update 4 times.
Interestingly, the barrier was supposed to make them collide. Instead it flipped the order such that 9,957 runs were BBBAAA.
A busy machine is a little different. With stress-ng --cpu 16 keeping every hardware thread busy, the same two binaries ran 13 and 16 of the orderings, and lost an update in 32 and 66 of 10,000 runs. That’s still fewer than 1 run in 100 lost an update.
Rewind runs the guest on one virtual CPU and only switches threads at an exit, such as a system call (see dafuq is a deterministic VM?) or a rewind_point SDK call. This gives Rewind a chance to modify the schedule.
We can then run the same binary with Rewind to see how many of the 20 orderings it can reach.
$ rewind check --epoch 1790985600 --root root --schedules 9999 \
--all --no-narrow -- /bin/race
...
schedule 9999: exited:0 354 steps run 9b248f72f742b07f
1492 of 9999 other schedules ended differently
Across 10,000 runs Rewind reached 15 of the 20 orderings and lost an update in 1,371 of them. With a barrier it reached all 20 orderings and lost an update in 2,997 of them.
We can observe that Rewind’s perturbations reach more orderings than the host, and that it loses an update more often which helps us find the bug. The table below summarizes the results:
| Where | Start | Orderings seen | Runs that lost an update |
|---|---|---|---|
| idle laptop | create | 2 of 20 | 0 of 10,000 |
| idle laptop | barrier | 5 of 20 | 4 of 10,000 |
| busy laptop | create | 13 of 20 | 32 of 10,000 |
| busy laptop | barrier | 16 of 20 | 66 of 10,000 |
| Rewind | create | 15 of 20 | 1,371 of 10,000 |
| Rewind | barrier | 20 of 20 | 2,997 of 10,000 |
Interleavings though are not the only way to trigger bugs. Long pauses are orderings too, and they can be even rarer than interleavings.
A long pause sits at the far edge of the lattice. Thread A stops, and everything else takes hundreds of steps before A takes its next one. A path like that runs along one edge of the grid for a long time. A short perturbation hands the other side a few steps, so it rarely walks that far.
Rewind has knobs to make long pauses more likely. The --stall-max knob raises the maximum stall time, and the --stall-min knob lowers the minimum stall time. These settings can help explore even more unlikely schedules to discover bugs that only appear under extreme conditions.
It’s kind of surprising that with all the hype of property based testing, fuzzing, and Jepsen, that a simple deterministic VM that shuffles the schedule finds so many bugs. Our hardware is so fast that we’ve become accustomed to thinking that the order of events is always the same. Adding a little randomness to the schedule can expose bugs that have been hiding in plain sight.
Bugs aren’t rare, but the schedules that trigger them are.