---
title: "Logging, Capture and Replay"
book: "Low-Latency Software"
subject: quant
language: en
chapter: 23
exercises: 8
source: https://one-course.com/books/quant/13/en/chapter/23-logging-capture-and-replay
---

# Chapter 23 — Logging, Capture and Replay

A regulator asks why one order left at 09:30:00.012345678 with that price and that size. There are two ways to answer. One is to search the logs for the lines around that time and reconstruct, from what the programmers chose to print, what the strategy probably saw. The other is to take the inputs the trading process received that morning, each with the time it received it, feed them to the same binary on a desk, and stop at the order: the book, the parameters in force and every value the decision used are there, exactly as they were, because the program is deterministic (chapter 20) and its inputs were kept. This chapter builds the second answer and the machinery it needs: a log that costs a few nanoseconds on the hot path because it writes raw numbers and formats them later, an [input journal](#def-ll-logging-capture-and-replay-journal) that records what arrived and when, and a replay driver that turns a production day into a reproducible experiment.

## 23.1 Why formatted logging is not for the hot path

A formatted log line does a surprising amount of work: it parses a format string, converts each number to decimal text, copies the result into a buffer, and, depending on the library, takes a lock and makes a system call. On the laptop, a line with four numbers costs about $100\,\mathrm{n}\mathrm{s}$ at the median through `snprintf` into a buffer, about as much through `fprintf` into a fully buffered file, and $210\,\mathrm{n}\mathrm{s}$ through a string stream ([Figure 23.2](#fig-ll-logging-capture-and-replay-calls)); and its tail is long, because the file’s buffer fills and is written, and because the stream allocates. A strategy engine that handles an event in $50\,\mathrm{n}\mathrm{s}$ (chapter 20) cannot afford one such line per event, and a system whose logging is switched off in production to save that time has nothing to look at when something goes wrong.

The answer is not to log less but to do less when logging. Everything in a log line is known when the program is compiled except the numbers: the text, the positions of the arguments and their types. So the hot path can write only the numbers, with an identifier for the statement, and leave the formatting to a program that runs later, elsewhere, when someone reads the log. The `C++` standard library of the compiler used here (g++ 11) does not even provide `std::format`; it would not change the conclusion, since formatting is the cost being removed.

## 23.2 Binary logging and deferred formatting

**Definition 23.1 (Binary log, deferred formatting).**

A *binary log* is a log whose records hold a statement identifier, a timestamp and the raw values of the statement’s arguments, not text; the statements’ format strings are stored once, in the log’s header or alongside the binary. *Deferred formatting* is the practice of turning such records into text only when the log is read, by a separate program, so that the program that writes the log never converts a number to text.

The idea is established: NanoLog, presented at the 2018 USENIX Annual Technical Conference, extracts the static parts of log statements at compile time, writes a compacted [binary log](#def-ll-logging-capture-and-replay-binlog) at run time and re-inflates it offline, and reports an invocation cost of 8 nanoseconds in [microbenchmarks](https://one-course.com/books/quant/13/en/chapter/2-cpu-microarchitecture#def-ll-cpu-microarchitecture-ubench) and 18 in applications. The build’s `firm.binlog` does the same with nothing but the language. A statement is written `log.log<"fill {} of {} at {}, position {}">(ts, id, qty, price, pos)`: the format string and the argument types are template arguments, so the statement’s identifier is computed at compile time, a hash of both ([Listing 23.1](#lst-ll-logging-capture-and-replay-id)), and the statement registers its format in a table during static initialisation, before `main` runs. At run time, a call writes the identifier, the timestamp and the arguments’ bytes into a slot of a single-producer ring (chapter 12), and returns ([Listing 23.2](#lst-ll-logging-capture-and-replay-log)). If the ring is full, the record is dropped and counted: the hot path never waits for the log.

```cpp
// The statement's identifier: FNV-1a over the format and the type codes, folded to 16 bits.
template <Fmt F, class... A>
constexpr std::uint16_t site_id() {
    std::uint32_t h = 2166136261u;
    for (std::size_t i = 0; i < F.size(); ++i) h = (h ^ static_cast<unsigned char>(F.s[i])) * 16777619u;
    h = (h ^ 0u) * 16777619u;
    ((h = (h ^ static_cast<unsigned char>(type_code<A>())) * 16777619u), ...);
    return static_cast<std::uint16_t>(h ^ (h >> 16));
}
```

***Listing 23.1.** A statement’s identifier, computed by the compiler from its format and the types of its arguments. code/firm/binlog/cpp/firm_binlog.hpp*

```cpp
    template <Fmt F, class... A>
    bool log(std::uint64_t ts, const A&... a) {
        static_assert((max_size<A>() + ... + 0) <= kMaxPayload, "binlog: arguments too large");
        constexpr std::uint16_t id = site_id<F, A...>();
        (void)Site<F, A...>::registered;
        std::uint8_t rec[kSlot - 4];
        std::uint8_t* p = rec + kHead;
        ((p = encode(p, a)), ...);
        const auto n = static_cast<std::uint16_t>(p - rec - kHead);
        std::memcpy(rec, &id, 2);
        std::memcpy(rec + 2, &n, 2);
        std::memset(rec + 4, 0, 4);
        std::memcpy(rec + 8, &ts, 8);
        if (ring_.try_write(rec, static_cast<std::uint32_t>(kHead + n))) return true;
        dropped_.fetch_add(1, std::memory_order_relaxed);
        return false;
    }
```

***Listing 23.2.** The hot path of a log call: encode the raw arguments behind a 16-byte header and write the record into the ring, or drop it. code/firm/binlog/cpp/firm_binlog.hpp*

A writer thread on another core drains the ring into a file. The file starts with a header that lists every statement (identifier, argument types, format), sorted by identifier, then the records as they came out of the ring; the Python decoder reads the header, decodes each record with its statement’s types and formats it. The format is simple enough to be written by three implementations: the Python reference encoder writes the fixture’s sample log, and the C++ logger, through its ring and through its writer thread, and the Rust logger each write the same statements to the same bytes. A test also counts heap allocations during logging and finds none, and fills a small ring on purpose to check that the overflow is dropped and counted.

![Logging, capture and replay. The hot path writes raw records into a ring and returns; a writer thread drains them to a file whose header holds every statement’s format; formatting happens offline. The inputs are journaled as they arrive, and a replay of the journal through the same binary produces the same log.](https://one-course.com/images/onecourse/chapters/quant-13/ll-logging-capture-and-replay/fig-13ebb7870057.svg)

***Figure 23.1.** Logging, capture and replay. The hot path writes raw records into a ring and returns; a writer thread drains them to a file whose header holds every statement’s format; formatting happens offline. The inputs are journaled as they arrive, and a replay of the journal through the same binary produces the same log.*

[Figure 23.2](#fig-ll-logging-capture-and-replay-calls) is the result: about $5\,\mathrm{n}\mathrm{s}$ per call at the median, twenty times less than `snprintf`, with a tail at the 99th percentile when the writer drains the ring and the [cache lines](https://one-course.com/books/quant/13/en/chapter/3-memory-hierarchy-and-caches#def-ll-memory-hierarchy-and-caches-line) it reads move between the cores. The writer’s manners matter. The first version polled the ring without pause, and every log call paid for the [cache lines](https://one-course.com/books/quant/13/en/chapter/3-memory-hierarchy-and-caches#def-ll-memory-hierarchy-and-caches-line) the writer kept pulling away; the build’s writer drains in batches and sleeps $100\,\text{µ}\mathrm{s}$ when there is little to drain ([Listing 23.3](#lst-ll-logging-capture-and-replay-writer)). The price is paid by nobody on the hot path: the log reaches the file a fraction of a millisecond later.

```cpp
    // Drain in batches and sleep in between: a writer that polls the ring without pause keeps
    // pulling its cache lines away from the producer, and every log call pays for it.
    void loop() {
        buf_.reserve(1 << 20);
        while (run_.load(std::memory_order_acquire))
            if (flush() < 1024) std::this_thread::sleep_for(std::chrono::microseconds(100));
    }
```

***Listing 23.3.** The writer’s loop: drain in batches, sleep when there is little to drain. code/firm/binlog/cpp/firm_binlog.hpp*

![The cost of one log call carrying four numbers, by method (TSC-timed, 200 000 calls each): the binary log with its writer thread draining the ring on another core, snprintf into a buffer, fprintf into a fully buffered file, and a string stream. Measured on a laptop (Intel Core Ultra 7 155H) under WSL2. Data: bench_log.py.](https://one-course.com/images/onecourse/chapters/quant-13/ll-logging-capture-and-replay/fig-15d052fa48c7.svg)

***Figure 23.2.** The cost of one log call carrying four numbers, by method (TSC-timed, 200 000 calls each): the [binary log](#def-ll-logging-capture-and-replay-binlog) with its writer thread draining the ring on another core, `snprintf` into a buffer, `fprintf` into a fully buffered file, and a string stream. Measured on a laptop (Intel Core Ultra 7 155H) under WSL2. Data: `bench_log.py`.*

## 23.3 Capture: inputs, outputs and time

**Definition 23.2 (Input journal).**

An *input journal* is the record, kept by a process, of every input it received, in the order it received them, each with the time of its reception: market events, order reports, timer firings that depend on the clock, parameter changes and control messages. Together with the program’s version, it is enough to reproduce everything the process computed.

A log of decisions says what the program did; only a journal of inputs says why, because it lets the decision be made again. The build’s journal is deliberately dull: a short header, then fixed records of 56 bytes, the reception time followed by the 48-byte event of the [feed handler](https://one-course.com/books/quant/13/en/chapter/18-the-feed-handler#def-ll-the-feed-handler-handler) (chapter 18). It is written by the thread that receives the inputs, at the point where they enter the engine, so that its order is the engine’s order. Two things are easy to get wrong. The journal must hold what the process received, not what the exchange sent: the exchange’s recording has no gaps, no retransmissions and no local arrival times, and a replay of it answers a different question. And the times must be the process’s own, taken once, at reception, with the clock of chapter 5, because they are inputs too: a strategy that ages its quotes reads them. The exchange’s time stamp and the receive time stamp of One Quant Book 1 (chapter 28) are both kept, one inside the event, the other in front of it.

**As of September 2026 — How long and how precisely records are kept.**

In the European Union (consulted September 2026), Commission Delegated Regulation (EU) 2017/589 requires firms engaged in high-frequency algorithmic trading to record their orders and keep the records for five years from the submission of each order (article 28). Commission Delegated Regulation (EU) 2017/574 requires members of a trading venue using a high-frequency algorithmic trading technique to keep their business clocks within 100 microseconds of UTC, with a time stamp granularity of 1 microsecond or better, and to review their traceability to UTC at least once a year.

Journals compress well, because consecutive events share most of their bytes: the same instrument, nearby prices and times, sequence numbers that count by one. [Table 23.1](#tab-ll-logging-capture-and-replay-journal) measures it on the two streams of the build: about 3.8 to 1 with the general-purpose compressor zlib at its default level, about 15 bytes per event.

| stream | events | recorded | journal | compressed | ratio |
| --- | --- | --- | --- | --- | --- |
| large tick (the simulator’s open) | 189 875 | $120\,\mathrm{s}$ | 10.6 MB | 2.8 MB | 3.76 |
| small tick (synthetic) | 6 000 | $6\,\mathrm{m}\mathrm{s}$ | 0.34 MB | 0.08 MB | 3.96 |

***Table 23.1.** The [input journal](#def-ll-logging-capture-and-replay-journal) of two event streams: 56 bytes per event raw, about 15 compressed with zlib at level 6. Data: `fig_journal.py` (deterministic).*

## 23.4 Deterministic replay of a production day

**Definition 23.3 (Deterministic replay).**

A *deterministic replay* runs a program on an [input journal](#def-ll-logging-capture-and-replay-journal), in the journal’s order, with time taken from the journal, and produces bit for bit the outputs that the program produced when the journal was recorded; it requires the program to be deterministic (chapter 20) and the journal to be complete.

The replay driver reads the journal, rebuilds the events and gives them to the strategy engine with the simulated clock: the build’s test journals the small-tick day, replays it, and obtains the committed output hash of chapter 20. A replay is also fast, because nothing waits for the market: on the laptop, the engine replays the simulator’s two busy minutes around the open, 189 875 events, journal reading included, in under $50\,\mathrm{m}\mathrm{s}$, about 2 800 times faster than they happened. A day replays in seconds, which changes what can be done with it: every change to the code can be replayed against last week, and every incident can be replayed as often as needed with a debugger attached.

When two runs that should agree do not, the logs find where. Each run logs its actions; the two logs are compared record by record ([Listing 23.4](#lst-ll-logging-capture-and-replay-diff)), and the first record that differs points at the first event whose handling differed. The build’s test plants a difference, a parameter change at event 3 000 that the second run receives and the first does not, as a value read from outside the journal would; the comparison finds the first differing action, number 540 of 1 084, just after the planted event, and nothing before it. This is the procedure of chapter 20’s weekend problem, mechanised: the log says where to look, and the replay lets one look as often as needed.

```python
def text(sites, records):
    return [f"{ts} {sites[i][0].format(*args)}" for ts, i, args in records]


def first_difference(a, b):
    for k, (x, y) in enumerate(zip(a, b, strict=False)):   # the shorter length decides below
        if x != y:
            return k
    return None if len(a) == len(b) else min(len(a), len(b))
```

***Listing 23.4.** Offline: format the records, and find the first record at which two logs differ. code/firm/binlog/firm_binlog.py*

## 23.5 What must be kept, and for how long

Three things are kept. The [input journal](#def-ll-logging-capture-and-replay-journal), because it is the only record from which everything else can be recomputed; the decision log, because it answers most questions without a replay and checks the replay when one is made; and the program: the exact binary, its configuration and the parameter snapshots, since a journal replayed through a different build answers nothing. The regulator’s clocks and retention periods (the dated box) set the minimum: time stamps traceable to UTC with the granularity required, and five years of order records. The storage is modest by the standards of the data a quantitative firm keeps anyway, as the weekend problem computes, and the cost of not keeping it is the first sentence of this chapter.

## 23.6 Tutorial: log, journal, replay, bisect

**Goal.** Log from the hot path at a few nanoseconds per call, journal a day’s inputs, replay them to the bit, and find a planted difference between two runs. **End state:** [Figure 23.2](#fig-ll-logging-capture-and-replay-calls), the journal table, the replay’s speed, and green tests in three languages.

1. **Log.** The C++ test logs the fixture’s statements through the ring and through the writer thread and compares the bytes with `data/sample.blog` , which the Python reference wrote; the Rust test writes the same bytes; the Python decoder’s `read` and `text` turn them into `data/sample.txt` .
2. **Measure.** `python bench_log.py` times a log call by each method and a replay of the open’s journal.
3. **Journal and replay.** The test journals the small-tick day, replays it through `firm.stratengine` , and checks the committed hash.
4. **Bisect.** `ll_bisect_test.cpp` runs the engine twice, plants a change in the second run, logs both, and finds the first differing record.

**What to change next.** Replace the planted parameter change by a wall-clock read (chapter 20’s defect) and watch the first difference move from run to run; compress the journal as it is written, in the writer thread.

## 23.7 Build: the binary log and the journal

**Purpose.** Every component of the trading path logs through it: the [feed handler](https://one-course.com/books/quant/13/en/chapter/18-the-feed-handler#def-ll-the-feed-handler-handler)’s gaps (chapter 18), the engine’s actions (chapter 20), the gateway’s messages (chapter 21), the [risk gate](https://one-course.com/books/quant/13/en/chapter/22-pre-trade-risk-and-kill-switches#def-ll-pre-trade-risk-and-kill-switches-gate)’s decisions (chapter 22); its journal is what the resilient architecture of chapter 24 replicates and what the tests of chapter 25 replay.

**Interface.** C++20 `firm::binlog`: `Logger(capacity)` with `log<"format">(ts, arguments)`, `drain`, `dropped`; `Writer(logger, path)`; `header()`; `Journal` with `add` and `records`. Python `firm_binlog`: `site_id`, `Writer`, `read`, `text`, `first_difference`, `journal_write`, `journal_read`. Rust `firm_binlog`: `Logger`, `read`, `text`, `site_id`.

**Rules.** No formatting, lock, system call or allocation on the hot path; a full ring drops and counts; statement identifiers from the format and the types; the journal written where the inputs enter the engine, with reception times; the same bytes from the three implementations.

**Acceptance tests.** `code/firm/binlog/`: the fixture written byte for byte by Python, C++ (ring and writer thread) and Rust, and decoded to its text; random statements round-tripped; identifiers that depend on the types, and collisions refused; zero allocations while logging, and overflow counted; a journal replayed through the strategy engine to the committed hash; the first difference between two logs found.

**Stretch.** Compression in the writer thread; a statement per component with a severity filtered at compile time; time stamps from the TSC with calibration records in the log, converted offline; a journal of the gateway’s reports next to the market data.

Sources and further reading

- S. Yang, S. J. Park and J. Ousterhout, “NanoLog: a nanosecond scale logging system”, *USENIX Annual Technical Conference* , 2018.
- Commission Delegated Regulation (EU) 2017/589 (RTS 6), article 28.
- Commission Delegated Regulation (EU) 2017/574 (RTS 25), article 4 and annex.

## 23.8 Exercises

**Exercise 23.1 ★.**

How many bytes does a record of the statement `"fill {} of {} at {}, position {}"` with four 64-bit arguments take, and how many does its formatted line take for the values 40, 100, 999 900 and $-200$ with a 14-digit time stamp? What, then, does the [binary log](#def-ll-logging-capture-and-replay-binlog) save?

**Solution of Exercise 23.1.**

$16 + 4 \times 8 = 48$ bytes. The line “34200000000010 fill 40 of 100 at 999900, position -200” is 54 characters, 55 with its newline: about the same. The [binary log](#def-ll-logging-capture-and-replay-binlog) saves the formatting (the conversions to decimal and the parsing of the format) on the hot path, not bytes.

**Exercise 23.2 ★.**

Why does the statement’s identifier depend on the types of its arguments and not only on its format?

**Solution of Exercise 23.2.**

The decoder reads the arguments with the types recorded for the identifier. Two calls with the same format and different types (an `int` and a `double`) encode different bytes; if they shared an identifier, one of them would be decoded wrongly.

**Exercise 23.3 ★.**

The open’s journal has 189 875 records of 56 bytes plus a 12-byte header. Check its size, and the bytes per event after compression, from [Table 23.1](#tab-ll-logging-capture-and-replay-journal).

**Solution of Exercise 23.3.**

$12 + 189\,875 \times 56 = 10\,633\,012$ bytes; compressed, $2\,831\,089 / 189\,875 \approx 14.9$ bytes per event.

**Exercise 23.4 ★★.**

A component logs 2 million records a second during a burst; the writer thread is blocked for $20\,\mathrm{m}\mathrm{s}$ by a slow disk. How many ring slots are needed so that nothing is dropped, and how much memory is that with 64-byte slots?

**Solution of Exercise 23.4.**

$2 \times 10^6 \times 0.02 = 40\,000$ records arrive while the writer is blocked; the ring’s capacity is a power of two, so 65 536 slots, 4 MiB with 64-byte slots.

**Exercise 23.5 ★★.**

The hot path stamps records with the TSC rather than with `clock_gettime`. What must the log also contain so that the time stamps can be converted to UTC offline with a granularity of a microsecond?

**Solution of Exercise 23.5.**

Calibration records written regularly by the writer (not the hot path): pairs of a TSC reading and a reading of a clock traceable to UTC (disciplined by PTP, chapter 5), close together in time. Offline, each record’s TSC value is converted by interpolating between the calibration pairs around it; the error is that of the reference clock plus the drift between pairs.

**Exercise 23.6 ★★.**

An engine handles an event in $50\,\mathrm{n}\mathrm{s}$ and logs five lines per event. What does logging cost per event with the [binary log](#def-ll-logging-capture-and-replay-binlog) and with `snprintf`, at the medians of [Figure 23.2](#fig-ll-logging-capture-and-replay-calls)?

**Solution of Exercise 23.6.**

With the [binary log](#def-ll-logging-capture-and-replay-binlog), about $5 \times 5\,\mathrm{n}\mathrm{s} = 25\,\mathrm{n}\mathrm{s}$ per event, half the event’s own work; with `snprintf`, about $5 \times 100\,\mathrm{n}\mathrm{s} = 500\,\mathrm{n}\mathrm{s}$, ten times the event.

**Exercise 23.7 ★★★.**

*Coding.* Log the [risk gate](https://one-course.com/books/quant/13/en/chapter/22-pre-trade-risk-and-kill-switches#def-ll-pre-trade-risk-and-kill-switches-gate)’s decisions (chapter 22) with a statement carrying the order’s identifier, the code and the mask; replay the gate’s fixture, and decode the log into a count of refusals by reason that matches `expected.txt`.

**Solution of Exercise 23.7.**

A statement `log<"order {} refused {} mask {}">(t, cl, code, mask)` in the gate’s refusal path (accepted orders can have their own); replaying `events.txt` through the gate with a logger, draining and decoding, the codes counted by reason give the counts on the first line of `expected.txt`.

**Exercise 23.8 ★★★.**

*Find the flaw.* “We do not need an [input journal](#def-ll-logging-capture-and-replay-journal). We log every decision with its reason, and to replay a day we run the strategy on the exchange’s own recording of the market data.”

**Solution of Exercise 23.8.**

A decision log says what was decided, not what it was decided from, and cannot be re-run under a debugger or after a fix. The exchange’s recording is not what the process received: it has no gaps, no retransmissions, no local reception times, no order reports, no parameter changes and no timer firings, and it is in the exchange’s order, not the process’s. A replay of it answers what the strategy would have done with perfect data, not what it did.

## 23.9 Problem: To the Nanosecond

**Problem 23.1.**

Weekend problem — what it costs to be able to answer

A firm journals the inputs of its trading processes and must be able to replay any order of the last five years. Use [Table 23.1](#tab-ll-logging-capture-and-replay-journal) and the measured replay speed.

**Part I — The rate.**

1. What is the average event rate of the open’s stream?
2. At that average rate, how many events does a trading day of 6.5 hours hold?
3. How many bytes is that journal raw, and compressed at the measured ratio?
4. Why is an average over a busy open a pessimistic estimate for a whole day, and why is it still the right one to plan with?

**Part II — Five years.**

5. With 252 trading days a year, how much does five years of such journals take, compressed?
6. The firm trades 200 instruments with similar streams. Scale the answer.
7. What else must be kept for a journal to be replayable five years later?
8. Why is the decision log, although smaller, not enough?

**Part III — Replay.**

9. At the measured speed, how long does a replay of one instrument’s day take?
10. And of the 200 instruments, one after the other, on one core?
11. What limits the replay speed, and what does not?
12. Why must the replay read time from the journal rather than from the machine?

**Part IV — The verdict.**

13. State the *named result* : journal storage per day at the measured rate and compression ratio, and replay speed against real time.
14. What does a log call cost with [deferred formatting](#def-ll-logging-capture-and-replay-binlog) , and with `snprintf` ?
15. What must the replay reproduce to answer the regulator’s question, and how do you check that it did?
16. What happens to replayability when a component reads the wall clock?
17. Where in the process must the journal be written, and why there?
18. What does the planted-difference test demonstrate, and what would it take to find a real one?
19. What time stamp precision does the dated box require, and does a TSC-stamped log meet it?
20. In one sentence: what makes an order explainable years later?

**Solution of Problem 23.1.**

1. $189\,875 / 120\,\mathrm{s} \approx 1\,582$ events a second.
2. $1\,582 \times 6.5 \times 3\,600 \approx 37.0$ million events.
3. $37.0 \times 10^6 \times 56 \approx 2.07$ GB raw, about 0.55 GB compressed at 3.76 to 1.
4. The open is among the busiest moments of the day, so the average over it overstates a quiet afternoon; but storage and replay must be sized for busy days, and event days are busier still.
5. $0.55~\text{GB} \times 252 \times 5 \approx 0.7$ TB.
6. About 139 TB for 200 instruments.
7. The exact binary and its build, its configuration, the parameter snapshots, the reference data (instrument definitions), the order reports it received, and the replay tools, all versioned with the journal.
8. It holds the outcomes but not their causes: it cannot be re-run, stopped at an event, or used to test a fix.
9. At about 2 800 times real time, $23\,400 / 2\,800 \approx 8.4\,\mathrm{s}$ : under ten seconds.
10. About half an hour, or less on several cores, since the instruments replay independently.
11. Reading and decoding the journal and the engine’s own work per event (memory and the processor); never the market’s timing, since nothing waits.
12. Every decision that depends on time would differ, and the replay would have to wait for real time to pass.
13. **Named result.** A journal costs 56 bytes per event raw and about 15 compressed (3.76 to 1): at the open’s average of 1 582 events a second, a 6.5-hour day is 37 million events, 2.1 GB raw and 0.55 GB compressed per instrument, about 0.7 TB over five years; and a replay runs about 2 800 times faster than real time, a day in under ten seconds.
14. About $5\,\mathrm{n}\mathrm{s}$ with [deferred formatting](#def-ll-logging-capture-and-replay-binlog) , about $100\,\mathrm{n}\mathrm{s}$ with `snprintf` .
15. The same actions, bit for bit, up to and including the order in question, with the state that produced it; checked by comparing the replayed decision log (or its hash) with the production log.
16. It is lost, unless the clock readings are themselves journaled as inputs and replayed.
17. On the engine’s thread, where the inputs enter it, in the order it handles them: anywhere earlier the order could differ, anywhere later something could be missing.
18. That the comparison of two logs finds the first divergence and that nothing before it differs; for a real one, the same comparison between a production log and its replay, then the journal’s event at that point, examined in the replay.
19. One microsecond or better, within 100 microseconds of UTC for high-frequency trading; the TSC’s resolution is far finer, and with calibration against a UTC-traceable clock the log meets both.
20. A complete journal of its inputs, a deterministic program, and the exact build that ran it.

## 23.10 Interview questions

**Interview question 23.1 ★ developer.**

Why is `printf`-style logging a problem on a hot path, and what do you do instead?

**Solution of Interview question 23.1.**

It formats text, parses a format, may lock, allocate or write to a file, and its tail is long: a hundred nanoseconds or more per line. Write a statement identifier, a time stamp and the raw arguments into a ring, let another thread write them out, and format offline.

*What the interviewer is looking for: binary records and [deferred formatting](#def-ll-logging-capture-and-replay-binlog).*

**Interview question 23.2 ★★ developer.**

Design a logger whose call costs under ten nanoseconds. What happens when its buffer is full?

**Solution of Interview question 23.2.**

Identifiers fixed at compile time, a fixed-size record encoded with a few copies into a preallocated single-producer ring per thread, a writer thread on another core that drains in batches. When the ring is full, drop the record and count it: the hot path never waits, and the count says what was lost.

*What the interviewer is looking for: no work beyond copying, and a drop policy.*

**Interview question 23.3 ★★ developer.**

What would you record to be able to replay a trading day exactly, and where in the process would you record it?

**Solution of Interview question 23.3.**

Every input as received (market data after the [feed handler](https://one-course.com/books/quant/13/en/chapter/18-the-feed-handler#def-ll-the-feed-handler-handler), order reports, timers that depend on time, parameter changes, control messages) with its reception time, plus the build and configuration; recorded on the engine’s thread where the inputs enter, in its order.

*What the interviewer is looking for: inputs as received, time included, at the engine’s boundary.*

**Interview question 23.4 ★★ developer.**

Two replays of the same day disagree. How do you find where?

**Solution of Interview question 23.4.**

Log the outputs of both with enough detail (actions, or hashes of the state per event), compare them record by record, and go to the first difference; then look for what differed at that event: time, iteration order, threads, inputs.

*What the interviewer is looking for: the first difference, then the cause.*

**Interview question 23.5 ★★ developer, risk.**

A regulator asks why an order was sent three years ago. What do you need to answer, and how long does it take?

**Solution of Interview question 23.5.**

The day’s journal, the exact build, its configuration and parameters, and the replay tools; replay to the order, check the replay against the production log, and read the state that produced the decision. With journals and tools kept, it takes minutes.

*What the interviewer is looking for: journal plus build, and a checked replay.*

**Interview question 23.6 ★★★ developer.**

Design capture and replay for a firm with dozens of trading processes on several venues. What is journaled, where, in what format, for how long, and how is replay tested?

**Solution of Interview question 23.6.**

Each process journals its own inputs in a common binary format with UTC-traceable time stamps, logs its decisions in binary, ships both to storage compressed; builds and configurations are versioned with them; replay drivers per component run in continuous integration against recent days and compare with production logs; retention follows the regulation.

*What the interviewer is looking for: per-process journals, a common format, versioning, and replay in CI.*
