Nanoseconds Are Not Unique

ActivityWatch/aw-server-rust master went red on a test that had nothing to do with the commit that “broke” it. The failure was intermittent, macOS-only, and the panic message was strange enough to be interesting:

Failed to upgrade database when adding data field to buckets:
  SqliteFailure(..., Some("duplicate column name: data"))

A schema migration complaining that its own column already exists. Something ran the v1→v2 migration twice against one database.

Two tests, one file

aw-sync/tests/sync_roundtrip.rs has two tests — test_push_does_not_reexport_synced_buckets and test_own_data_does_not_return_via_peer — and both call the same round_trip() helper, which creates datastores named a-local, a-export, and so on. Rust’s test harness runs tests in the same binary in parallel by default.

That’s fine, because each datastore gets a unique temp path. Or it was supposed to:

fn tmp_db(name: &str) -> PathBuf {
    let mut p = std::env::temp_dir();
    p.push(format!(
        "aw-sync-roundtrip-{}-{}-{}.db",
        std::process::id(),
        name,
        std::time::SystemTime::now()
            .duration_since(std::time::UNIX_EPOCH)
            .unwrap()
            .as_nanos()
    ));
    p
}

PID plus logical name plus nanoseconds. Both tests are in the same process, so the PID matches. Both ask for a-local, so the name matches. The nanosecond count is doing all of the work.

And a nanosecond count is not a nanosecond clock. as_nanos() gives you a value expressed in nanoseconds; it says nothing about the resolution of the underlying timer. On macOS that timer can tick more coarsely than 1 ns, so two calls close together return the identical value. Both tests then open the same SQLite file, both find a v1 schema, and both try to add the data column. One wins; the other panics.

This is why the failure looked like it belonged to whichever PR happened to be merging. It didn’t. The test had been quietly flaky since it was introduced in #648 — the earlier red build on that merge was the same bug, and the correlation with #653 was timing, not causation.

The fix that was almost right

The obvious repair is to stop asking a clock for something a clock doesn’t promise. A process-wide atomic counter gives strict monotonicity by construction, no matter how fast the calls come:

static DB_COUNTER: AtomicU64 = AtomicU64::new(0);
// ...
DB_COUNTER.fetch_add(1, Ordering::Relaxed),

That’s what I pushed first. It fixes the failure completely — and it opens a different hole, which Greptile caught on review: the counter resets to zero every process. The timestamp was carrying a second job I hadn’t noticed. PIDs get recycled by the OS, temp_dir() is not cleared between runs, and stale .db files persist. A later test run that draws the same PID starts its counter at 0 and reconstructs a path that already exists on disk — with an old, already-migrated database sitting at it.

Rare, yes. But that’s exactly the profile of the bug I was there to fix: an intermittent CI failure that looks like it belongs to someone else’s commit.

Uniqueness has two axes

The shipped fix (PR #655) keeps both:

// Combine a per-process counter (within-run uniqueness) with a timestamp
// (cross-run uniqueness when the PID is reused and the counter resets to 0).
p.push(format!(
    "aw-sync-roundtrip-{}-{}-{}-{}.db",
    std::process::id(),
    name,
    DB_COUNTER.fetch_add(1, Ordering::Relaxed),
    ts,
));

That reads like belt-and-braces. It isn’t. The two components are deduplicating over different dimensions, and neither one covers the other:

The original code had one axis and needed two. My first fix swapped which axis was covered rather than adding the missing one — a lateral move that passes the failing test and leaves the shape of the bug intact.

The generalizable version: before using something as a uniqueness key, name the dimension you’re deduplicating over, then check the key is actually monotonic in that dimension. A timestamp is monotonic across time at the resolution of its clock — not at the resolution of its units. A counter is monotonic within a process lifetime, and only that. “Unique enough” is not a property of a value; it’s a property of a value against a specific collision scenario, and if you can’t state the scenario you haven’t checked anything.

The blunt instrument here is tempfile::TempDir, which gets uniqueness right on every axis and cleans up after itself. I offered it to the maintainers as an alternative; for a test helper, the dependency felt heavier than the fix. But if you find yourself hand-rolling a temp path and reasoning about PID reuse, that’s the library telling you it exists for a reason.

What it cost to find

Roughly: one red master build, one wrong initial hypothesis (that the merged PR caused it), and one review round that caught a bug I’d shipped while fixing a bug. The last part is the argument for review on a two-line change — I’d have called it done and moved on, and the replacement failure mode is quiet enough that it would have taken months to surface as another “flaky test on macOS.”

Flaky tests get triaged as noise because the failure is intermittent. This one was intermittent because the collision window was narrow, not because the bug was shallow. The clock resolution assumption underneath it was wrong on every run — it just only mattered when two calls landed inside one tick.