Concurrency: usage.jsonl lost update — lock-free append races truncate rewrite (data loss)

[jeff-r2026]

Summary

usage.jsonl is a globally shared file that is read and written without any lock. appendUsageEvent() appends to it (fs.appendFile), while truncateUsageAfterReport() overwrites the whole file (readFile → writeFile). When an append lands between truncate's read and its write, the appended event is silently and permanently lost — it is neither on disk nor reported to the team.

This is a classic cross-process lost-update: a lock-free whole-file overwrite racing a lock-free append.

Where

src/usage-tracker.ts @ 48b3dcb

• appendUsageEvent() — line 205, fs.promises.appendFile(getUsagePath(), line) (line 209), no lock
• truncateUsageAfterReport() — line 246, readFile (line 248) → writeFile whole file (lines 252 / 256), no lock

Both operate on ~/.teamai/usage.jsonl, which is scope-independent (one file for the whole machine). The per-scope .sync-lock in pull() does not cover this path — it guards the team clone, a different directory.

Why it is reachable in practice

This is exactly the scenario of the tool's normal usage — multiple agent sessions on one machine plus session-hook auto-pull:

• appendUsageEvent fires from every Skill PostToolUse hook and every tracked slash command — a short-lived teamai track process, once per skill call, on every concurrent agent session.
• truncateUsageAfterReport runs at the end of pull()'s auto-report, which the SessionStart hook triggers as auto-pull.

So a high-frequency append races a frequently-running whole-file overwrite, across independent processes, with no shared lock.

Counterexample (TLA+ / TLC 2.19)

Modelled the two racing actions in TLA+. NoLostUpdate states every generated event is either still on disk or already reported. TLC finds a 5-state violation:

State 1: Init          — file = <<>>, reported = {}, nextId = 0
State 2: ReadReport    — auto-pull's report reads events, begins truncate (pc = "trunc")
State 3: TruncRead     — truncate's internal readFile snapshots the file (tSnap = <<>>, tLen = 0)
State 4: AppendEvent   — a concurrent `teamai track` appends event 0 (file = <<0>>, nextId = 1)
State 5: TruncWrite    — writeFile overwrites the whole file from the STALE snapshot
                         (rCount 0 >= tLen 0 -> clear branch) -> file = <<>>
                         event 0 is neither on disk nor in `reported`. LOST.

The two modelled actions:

\* A concurrent `teamai track` appends one usage event, lock-free, at any time.
AppendEvent ==
    /\ nextId < MaxEvents
    /\ file' = Append(file, nextId)
    /\ nextId' = nextId + 1

\* truncateUsageAfterReport: writeFile overwrites the WHOLE file from the stale
\* snapshot (tSnap/tLen), destroying anything appended since TruncRead.
TruncWrite ==
    /\ pc = "twrite"
    /\ file' = IF rCount >= tLen
               THEN << >>                              \* clear branch
               ELSE SubSeq(tSnap, rCount + 1, tLen)    \* keep-tail branch
    /\ pc' = "idle"

NoLostUpdate == Generated \subseteq (OnDisk \union reported)   \* VIOLATED

Confirmed against the real implementation

A Vitest repro drives the real appendUsageEvent + truncateUsageAfterReport and injects a real append between truncate's readFile and writeFile (the exact TruncRead → AppendEvent → TruncWrite interleaving). On main it fails with expected [] to include 'c' — the concurrently-appended event is overwritten and gone from disk.

it('loses a concurrently-appended event across truncate read->write', async () => {
  const usagePath = path.join(tmpDir, '.teamai', 'usage.jsonl');

  // A report cycle delivered events a,b; truncate(2) is about to remove them.
  await appendUsageEvent({ skill: 'a', timestamp: '2026-01-01T00:00:00Z', tool: 'claude' });
  await appendUsageEvent({ skill: 'b', timestamp: '2026-01-02T00:00:00Z', tool: 'claude' });

  // Right after truncate snapshots the file (but before it overwrites), a
  // concurrent `teamai track` appends event c.
  const realReadFile = fs.promises.readFile;
  let injected = false;
  vi.spyOn(fs.promises, 'readFile').mockImplementation(async (p, ...rest) => {
    const result = await realReadFile.call(fs.promises, p, ...rest);
    if (!injected && String(p) === usagePath) {
      injected = true;
      await appendUsageEvent({ skill: 'c', timestamp: '2026-01-03T00:00:00Z', tool: 'claude' });
    }
    return result;
  });

  await truncateUsageAfterReport(2);

  const skills = (await readUsageEvents()).map((e) => e.skill);
  expect(skills).toContain('c'); // FAILS on main: got []
});

The spyOn only controls timing; it does not change what either function does. It reproduces an interleaving that a lock-free append from another process reaches on its own between truncate's read and write syscalls.

Suggested fix (smallest correct)

Serialize appendUsageEvent and truncateUsageAfterReport under the same mutex — reuse the existing, already-hardened acquireLock/releaseLock (src/update.ts) on a usage.jsonl.lock sentinel, so truncate holds the lock across its whole read-modify-write and no append can interleave.

A fixed TLA+ model with this lock was model-checked exhaustively: 50 distinct states, no error — the lock removes the interleaving that produced the counterexample.

Severity

Critical — the lost data is real usage events destined for the team repo; once overwritten they are unrecoverable and never reported. This is the most easily triggered of the related lock-free-shared-file defects (see the sibling issues for events.jsonl and reported-*.json), because both sides fire at high frequency.

---

Found via TLA+/TLC concurrency audit of the sync/state layer. Related: lock-free whole-file rewrite in dashboard-collector.ts (events.jsonl) and lock-free read-merge-write in team-push.ts (reported-*.json).

[SaulMoro]

Fixed by #790 (head 42fa895).

every writer of <usage file> takes <usage file>.lock
  hook append      wait ≤ 250 ms, else write a side file; the next lock holder folds it in
  truncate / cap   read → temp file → rename, all under the lock

The repro in this issue, run with the scope argument added since #758:

build	result
origin/main 8cee7ab	fails: expected [ 'd' ] to deeply equal [ 'c', 'd' ] (event lost)
#790 42fa895	passes (event kept)

What remains: if a live holder keeps the lock more than 5 s, the truncate is skipped, so those events are reported again on the next pull. They are counted twice but not lost.