Outbox Pattern

In the previous lesson, each step called the next one directly: the catalog wrote to its own store and immediately notified membership of the loan. The code was one line, but there were two jobs — one inside the local transaction, the other outside it. A process that drops between the two has done the work but told no one.

M16/K04’s Distributed Transaction Problem lesson built the outbox arrangement and showed a single message being delivered twice. That measurement is not repeated here. The measurement here is over a load: how many messages get lost when the publisher crashes, how many get delivered a second time under the same crash sequence with the outbox, what the relay’s delay becomes, and how many rows accumulate in the table.

Mechanism

DC5. The publisher crashing is modeled not by actually killing the process, but by a decision drawn from a seeded generator at the point between committing and publishing. Seed 20260731, crash rate 0.10. Because the decision sequence is read by delivery attempt number, the k-th delivery attempt shares the same fate in both implementations.

DC6. The relay is not triggered, it polls the box. The measured delay is a direct consequence of this choice; in a triggered relay, the delay’s lower bound would not depend on the polling interval.

# setup.sh — catalog keeps its own state and outbox, membership records deliveries
rm -f catalog.db* membership.db*
sqlite3 catalog.db "PRAGMA journal_mode=WAL;
  CREATE TABLE entry (id INTEGER PRIMARY KEY, book_id INTEGER, member_id INTEGER);
  CREATE TABLE outbox (message_id INTEGER PRIMARY KEY, book_id INTEGER, member_id INTEGER,
                             written_at INTEGER NOT NULL, status TEXT NOT NULL DEFAULT 'pending');" >/dev/null
sqlite3 membership.db "PRAGMA journal_mode=WAL;
  CREATE TABLE delivery (seq INTEGER PRIMARY KEY, message_id INTEGER, arrived_at INTEGER);" >/dev/null

// generator.mjs — our own generator; the seed is visible, the sequence is the same on every run
export function generator(seed) {
  let d = seed >>> 0;
  return () => { d = (Math.imul(d, 1103515245) + 12345) >>> 0; return (d >>> 8) / 16777216; };
}

The membership side’s delivery table accumulates every delivery as a separate row; a duplicated delivery shows up a second time with the same message_id. Lost messages and duplicated messages are both counted from this one table.

Same Load, Two Implementations

Two hundred loan requests. The first implementation commits the state, then publishes. The second writes the state and the message in a single transaction, leaving the publish to a separate pass.

// publisher.mjs — same load, two implementations: --direct and --outbox
import { DatabaseSync } from "node:sqlite";
import { generator } from "./generator.mjs";

const mode = process.argv.includes("--direct") ? "direct" : "outbox";
const N = 200, SEED = 20260731, RATE = 0.10;
const roll = generator(SEED);
// fixed crash sequence keyed by attempt number: the k-th delivery attempt shares the same fate in both modes
const willCrash = Array.from({ length: N * 4 }, () => roll() < RATE);
let attempt = 0, crashed = 0;

const catalog = new DatabaseSync("catalog.db");
const membership = new DatabaseSync("membership.db");
const deliver = (messageId) =>
  membership.prepare("INSERT INTO delivery (message_id, arrived_at) VALUES (?,?)").run(messageId, Date.now());

if (mode === "direct") {
  for (let n = 1; n <= N; n++) {
    catalog.exec("BEGIN IMMEDIATE");
    const r = catalog.prepare("INSERT INTO entry (book_id, member_id) VALUES (?,4)").run(n);
    catalog.exec("COMMIT");
    if (willCrash[attempt++]) { crashed += 1; continue; }   // the process drops here: the message was never produced
    deliver(Number(r.lastInsertRowid));
  }
} else {
  for (let n = 1; n <= N; n++) {
    catalog.exec("BEGIN IMMEDIATE");                 // state and message in one transaction
    catalog.prepare("INSERT INTO entry (book_id, member_id) VALUES (?,4)").run(n);
    catalog.prepare("INSERT INTO outbox (book_id, member_id, written_at) VALUES (?,4,?)")
      .run(n, Date.now());
    catalog.exec("COMMIT");
  }
  for (let pass = 0; pass < 500; pass++) {           // relay passes
    const pending = catalog.prepare(
      "SELECT message_id FROM outbox WHERE status='pending' ORDER BY message_id").all();
    if (pending.length === 0) break;
    for (const i of pending) {
      deliver(i.message_id);
      if (willCrash[attempt++]) { crashed += 1; break; }    // drops before marking: will be redelivered
      catalog.prepare("UPDATE outbox SET status='sent' WHERE message_id=?").run(i.message_id);
    }
  }
}

const rows = membership.prepare("SELECT COUNT(*) c FROM delivery").get().c;
const unique = membership.prepare("SELECT COUNT(DISTINCT message_id) c FROM delivery").get().c;
const boxed = catalog.prepare("SELECT COUNT(*) c FROM outbox").get().c;
console.log(`${mode.padEnd(13)}| produced=${N} crashed=${crashed} | delivery rows=${rows}` +
  ` unique=${unique} lost=${N - unique} duplicated=${rows - unique}` +
  ` | rows in box=${boxed}`);

sh setup.sh
node publisher.mjs --direct
sh setup.sh
node publisher.mjs --outbox

direct       | produced=200 crashed=22 | delivery rows=178 unique=178 lost=22 duplicated=0 | rows in box=0
outbox       | produced=200 crashed=24 | delivery rows=224 unique=200 lost=0 duplicated=24 | rows in box=200

In direct publishing, no message was produced for 22 of the 200 state changes. These 22 books showed as on loan in the catalog, never appeared on the membership side, and no record of this state remains: the box has 0 rows, so there is no place in the system to look for “should have been sent but was not.” The loss is silent.

In the outbox, the lost count is zero. The crash count is 24, not 22, because this mode made more delivery attempts (224 versus 200), and although the first 200 attempts share the same fate as the direct mode, 2 more crashes turned up in the following 24 attempts. Each crash produced exactly one second delivery: 224 − 200 = 24 duplicates. The loss turned into duplication.

A third number should not be missed: the box has 200 rows. These are delivered rows whose job is done, and the table does not shrink on its own.

Relay Delay

The passes above ran back-to-back. In reality, the relay runs separately and polls the box at set intervals; the interval directly determines the time between a message being written and being delivered.

// writer.mjs — writes the state change and the message in one transaction, at regular intervals
import { DatabaseSync } from "node:sqlite";
const [count, interval] = process.argv.slice(2).map(Number);
const db = new DatabaseSync("catalog.db");
db.exec("PRAGMA busy_timeout = 500");
for (let n = 1; n <= count; n++) {
  db.exec("BEGIN IMMEDIATE");
  db.prepare("INSERT INTO entry (book_id, member_id) VALUES (?,4)").run(n);
  db.prepare("INSERT INTO outbox (book_id, member_id, written_at) VALUES (?,4,?)").run(n, Date.now());
  db.exec("COMMIT");
  await new Promise((r) => setTimeout(r, interval));
}
console.log(`writer: ${count} messages, written ${interval} ms apart`);

// relay.mjs — polls the box at set intervals; measures the delay and the empty polls
import { DatabaseSync } from "node:sqlite";
const [interval, duration] = process.argv.slice(2).map(Number);
const catalog = new DatabaseSync("catalog.db"); catalog.exec("PRAGMA busy_timeout = 500");
const membership = new DatabaseSync("membership.db");
const delays = [];
let polls = 0, emptyPolls = 0, mostPending = 0;
const end = Date.now() + duration;
while (Date.now() < end) {
  const pending = catalog.prepare(
    "SELECT message_id, written_at FROM outbox WHERE status='pending' ORDER BY message_id").all();
  polls += 1;
  if (pending.length === 0) emptyPolls += 1;
  mostPending = Math.max(mostPending, pending.length);
  for (const i of pending) {
    const now = Date.now();
    membership.prepare("INSERT INTO delivery (message_id, arrived_at) VALUES (?,?)").run(i.message_id, now);
    catalog.exec("BEGIN IMMEDIATE");
    catalog.prepare("UPDATE outbox SET status='sent' WHERE message_id=?").run(i.message_id);
    catalog.exec("COMMIT");
    delays.push(now - i.written_at);
  }
  await new Promise((r) => setTimeout(r, interval));
}
delays.sort((a, b) => a - b);
const median = delays[Math.floor(delays.length / 2)] ?? 0;
console.log(`relay(interval=${interval} ms): polls=${polls} empty polls=${emptyPolls}` +
  ` delivered=${delays.length} most pending rows=${mostPending}` +
  ` | delay median=${median} ms max=${delays.at(-1) ?? 0} ms (in this run)`);

# same write rate (60 messages, 50 ms apart), two different polling intervals
for INTERVAL in 20 250; do
  sh setup.sh
  node writer.mjs 60 50 &
  node relay.mjs $INTERVAL 4500
  wait
  sqlite3 catalog.db "SELECT status, COUNT(*) FROM outbox GROUP BY status;"
done

writer: 60 messages, written 50 ms apart
relay(interval=20 ms): polls=204 empty polls=144 delivered=60 most pending rows=1 | delay median=13 ms max=23 ms (in this run)
sent|60
writer: 60 messages, written 50 ms apart
relay(interval=250 ms): polls=18 empty polls=4 delivered=60 most pending rows=5 | delay median=131 ms max=252 ms (in this run)
sent|60

The part that does not depend on the run is clear: in both runs 60 messages were written, and 60 were delivered. What changes is how many queries and how much waiting the same work takes. At a twenty-millisecond interval, 144 of 204 polls are empty (in this run) — about 3.4 queries per delivery, two-thirds of them unrewarded. At a two-hundred-fifty-millisecond interval, polls drop to 18 and empty polls nearly vanish, but the median delay rises from 13 ms to 131 ms, and a single pass accumulates as many as 5 rows in the box instead of 1. The interval is a direct trade-off between empty queries and delay.

When the Relay Stops

Because the relay is a process independent of the publisher, it can go down on its own. This is the situation where the outbox’s gain is most visible and its cost is most concrete.

sh setup.sh
node writer.mjs 60 20
sqlite3 catalog.db "SELECT status, COUNT(*) FROM outbox GROUP BY status;"
node relay.mjs 20 1500
sqlite3 catalog.db "SELECT status, COUNT(*) FROM outbox GROUP BY status;"
sqlite3 catalog.db "DELETE FROM outbox WHERE status='sent';
                    SELECT 'rows after pruning: ' || COUNT(*) FROM outbox;"

writer: 60 messages, written 20 ms apart
pending|60
relay(interval=20 ms): polls=68 empty polls=67 delivered=60 most pending rows=60 | delay median=743 ms max=1382 ms (in this run)
sent|60
rows after pruning: 0

While the relay was down, 60 rows accumulated in the box, and none were lost. When the relay came back, it delivered all of them in a single pass; the cost is that the median delay rose from 13 ms to 743 ms, and the maximum delay to 1382 ms (in this run). The longer the relay stays down, the larger the accumulated rows and the catch-up delay grow — this is a quantity that has to be monitored, it is not bounded on its own.

The last line shows the table growing: the 60 delivered rows stay in the table and are only removed by an explicit pruning. The outbox adds to the write path a table that has nothing to do with the business rule; cleaning that table is a job in itself.

Three Columns

What it made cheaper: writing the state change and the message together eliminated the “done but not announced” state. Under the same crash sequence, direct publishing lost 22 messages while the outbox lost 0; and the loss is not silent, it shows up as a row waiting in the box.

What it made more expensive: every loan request now writes to two tables; there is also a new process (the relay) and a new setting (the polling interval). Empty polling, rising to as much as 3.4 queries per delivery, is the cost of shortening the delay. The box does not shrink on its own; pruning is a separate job.

Which new failure modes were born: two of them. The first is a second delivery: the relay dropping between delivering and marking caused 24 messages to arrive twice. The second is relay lag: when the relay stops, the system does not raise an error, it just falls behind; without measurement, the accumulating rows and growing delay go unnoticed.

Summary

• Under the same crash sequence, direct publishing produced no message for 22 of 200 state changes; the outbox lost no message at all.
• Duplication took the place of loss: the outbox made 224 deliveries, 24 of which are second deliveries; each crash produced exactly one duplicate.
• The polling interval is a trade-off between delay and empty queries: in this run, at 20 ms the median delay is 13 ms and 144 of 204 polls are empty; at 250 ms the delay rises to 131 ms and polls drop to 18.
• When the relay stopped, 60 rows accumulated in the box, and none were lost; during the catch-up, the median delay was 743 ms and the maximum was 1382 ms (in this run).
• Delivered rows stay in the table (200 and 60 rows); the outbox requires an explicit pruning job.

Next Step

The 24 second deliveries the outbox leaves behind cannot be solved on the publisher side: as long as the relay and the destination sit in separate stores, “I sent it” and “I processed it” cannot enter the same transaction. Only one path remains — moving the cost to the consumer. The next lesson delivers messages to the consumer both duplicated and out of order, counts the side effect produced by two consumer implementations, and measures how a version stamp discards a stale message.