docs/components/stress_test/expected_state_trace.md
db_stress Expected-State Trace LogicThis note documents the trace/replay path used by db_stress crash-recovery
verification when it needs to tolerate lost buffered writes.
It is not a guide to RocksDB's generic tracing APIs in general. It is specifically about the code path centered on:
db_stress_tool/db_stress_driver.ccdb_stress_tool/db_stress_test_base.ccdb_stress_tool/expected_state.{h,cc}trace_replay/trace_replay.{h,cc}utilities/trace/replayer_impl.ccLATEST.state is the normal db_stress oracle: it stores the latest expected
value for each logical key. That is sufficient when recovery must preserve the
latest state exactly.
It is not sufficient when the test intentionally allows loss of buffered writes such as:
--sync_fault_injection--disable_wal--manual_wal_flush_one_in > 0In those modes, recovery is allowed to return an older prefix of recent writes. The important property is "no hole":
The trace logic makes this check possible by snapshotting the oracle at a known
DB sequence number N, tracing subsequent writes, then rebuilding the oracle
for the recovered DB sequence number M by replaying the first M - N traced
write operations.
History tracking only exists when db_stress uses the file-backed expected
state manager, which means --expected_values_dir is non-empty.
Tracing is started only when all of the following are true:
IsStateTracked())--expected_values_dir is non-emptyMightHaveUnsyncedDataLoss() is trueAs of the current code, MightHaveUnsyncedDataLoss() means:
FLAGS_sync_fault_injectionFLAGS_disable_walFLAGS_manual_wal_flush_one_in > 0This is broader than the older --expected_values_dir flag help text, which
still says historical values are tracked only with --sync_fault_injection.
The full flow for one db_stress process looks like this:
LATEST.state to match the
DB's recovered sequence number before any startup verification runs.LATEST.state.The important ordering in db_stress_driver.cc is:
FinishInitDb() runs before tracing is started for the new run.TrackExpectedState() runs after startup verification to avoid verification
reads contending on the DB-wide trace mutex.TrackExpectedState().That ordering ensures the sidecar oracle files are set up before the run starts creating potentially losable DB writes.
The file-backed manager (FileExpectedStateManager) uses these files inside
--expected_values_dir:
| File | Meaning |
|---|---|
LATEST.state | Current expected-value oracle used for normal verification |
PERSIST.seqno | Separate persisted-sequence-number oracle metadata |
<N>.state | Historical snapshot of expected values at DB sequence number N |
<N>.trace | Trace of writes that happened after sequence number N |
.<name>.tmp | Temporary file used for atomic replacement |
Only one historical generation matters at a time:
saved_seqno_ is the maximum sequence number found among *.state files
other than LATEST.state*.state and *.trace files are treated as stale and cleaned upOpen() also repairs one specific partial-save case:
<N>.state exists but <N>.trace does not, it creates an empty
<N>.traceThat models the intended semantics of crashing after the baseline snapshot was created but before tracing actually started.
The expected-state snapshot and trace are written through Env::Default(),
not through the DB's fault-injected filesystem wrapper.
That is intentional. These files are part of the test oracle, not part of the database state being validated. If they were subject to the same simulated data loss as the DB files, the oracle would become unreliable exactly when it is needed most.
SaveAtAndAfter() also disables WritableFileWriter buffering for the trace
file (writable_file_max_buffer_size = 0). This removes userspace buffering so
trace data is not stranded in an application buffer when the process is killed.
StressTest::TrackExpectedState() calls SharedState::SaveAtAndAfter(), which
dispatches to FileExpectedStateManager::SaveAtAndAfter(DB*).
The save path does this:
N = db->GetLatestSequenceNumber().LATEST.state to a temp file.<N>.state.<N>.trace as an empty file.<N>.trace.<old>.state and <old>.trace, if any.The state snapshot is created atomically via temp-file-plus-rename. The trace file is created directly because an empty trace already has the desired meaning.
The trace options are important:
kTraceFilterGet | kTraceFilterMultiGet | kTraceFilterIteratorSeek | kTraceFilterIteratorSeekForPrevpreserve_write_order = trueThe "filter" bits in TraceOptions are exclusion bits, so setting those bits
means "do not trace those read operations."
preserve_write_order = true is required because restore relies on prefix
semantics. It replays the first M - N traced write operations, so the trace
order must match the DB/WAL application order. Without preserved ordering, the
trace could contain the right writes in the wrong order and prefix replay would
be incorrect.
For expected-state recovery, the trace must satisfy this property:
Equivalently:
This follows directly from how Restore() consumes the trace:
Restore() chooses replay length from db->GetLatestSequenceNumber(), not
from trace metadata or explicit commit acknowledgementsAs a result, a later trace point can be strictly worse than an earlier one. If
a crash happens after WAL/sequence state is recoverable but before the sidecar
trace file gets the record, then Restore() will under-replay and validation
will fail.
By contrast, an earlier trace point can leave extra tail records for writes that do not survive recovery. That is acceptable as long as those records stay beyond the prefix implied by the recovered DB sequence number.
In short:
db_stress needs a prefix-preserving superset of recoverable writesThe semantics for this path are defined jointly by the trace producer and the expected-state consumer:
Generic producer API
The producer uses generic StartTrace() / Tracer / Replayer APIs, but the
active consumer in this path is FileExpectedStateManager::Restore(), not
generic query replay.
Replay progress from DB sequence space
Restore() does not replay "until the trace says commit." It replays
db->GetLatestSequenceNumber() - saved_seqno_ logical write operations.
Sidecar trace file
<N>.trace is written through Env::Default() and intentionally lives outside
the fault-injected DB path. There is no atomic coupling between WAL durability
and trace durability.
Ordered prefix semantics
For this path, preserve_write_order means the recovered trace prefix must
match DB/WAL application order. It does not by itself define whether the trace
contains an exact set of completed writes or a superset of recoverable writes;
that requirement comes from how Restore() interprets the trace.
<N>.trace<N>.trace is a normal RocksDB query trace file produced by Tracer.
In this db_stress path it contains:
kTraceBegin header record with trace magic and version metadatakTraceWrite recordskTraceEnd footer recordBecause the read trace types are filtered out, the practical payload is "header
plus write batches." Each kTraceWrite record stores:
WriteBatch::Data() bytesThe timestamp is recorded by the generic tracing library, but the expected-state
restore path does not use timing at all. It uses Replayer::Prepare() and
Replayer::Next() only as a parser for the trace stream.
db_stress does not explicitly call DB::EndTrace() during the normal
crash/reopen loop. That means:
kTraceEnd footerThis is not an accident. The restore logic is intentionally tolerant of it.
The generic TraceReader returns Status::Incomplete() at EOF. The generic
replay stack already recognizes this as the kind of condition caused by killing
a process without EndTrace(). FileExpectedStateManager::Restore() adds the
expected-state-specific rule that EOF or tail corruption is acceptable only
after enough writes have already been recovered:
This is the core reason the trace only needs to be good up to the recovered DB sequence number.
On the next run, FinishInitDb() checks shared->HasHistory(). If history is
present, it calls shared->Restore(db_) before normal verification and before
the compaction filter factory is attached to shared state.
Restore(DB*) does this:
M = db->GetLatestSequenceNumber().M >= saved_seqno_. Otherwise the DB rolled back further than the
oldest restorable baseline and restore fails.replay_write_ops = M - saved_seqno_.<saved_seqno_>.state to a temp LATEST.state.<saved_seqno_>.trace.Replayer, call Prepare(), and repeatedly call Next()
to decode trace records.TraceRecord into a custom handler that updates the temp
expected-state file.replay_write_ops logical write operations have been applied,
restore has enough information to succeed and becomes tolerant of EOF or tail
corruption.LATEST.state into place atomically.<saved_seqno_>.state.<saved_seqno_>.trace, but keep the replayed
trace itself for debugging.saved_seqno_.An important detail: the default Replayer is not used to execute traced
operations against the DB. It is only used to parse header and record formats.
Restore() pulls out TraceRecords with Next() and then calls
record->Accept(custom_handler, &result) on its own handler.
ExpectedStateTraceRecordHandler implements both:
TraceRecord::HandlerWriteBatch::HandlerThe generic trace layer gives it decoded TraceRecords. For write records, it
constructs a WriteBatch from the traced bytes and iterates the batch, letting
the handler process each individual batch entry.
Read trace types are ignored. In practice they should not appear because the trace options filtered them out, but the handler is still tolerant if they do.
The handler does not store raw RocksDB keys in the expected-state oracle. It
maps traced user keys back to db_stress logical integer keys.
The path is:
GetIntVal()This is why the debug logs track:
The roundtrip check compares the traced raw key against Key(parsed_id).
The handler replays only the logical effect needed by the oracle:
PutCF and TimedPutCF
value_base from the traced value bytesExpectedState::SyncPut()PutEntityCF
value_baseSyncPut()DeleteCF
SyncDelete()SingleDeleteCF
DeleteCFDeleteRangeCF
SyncDeleteRange(begin, end)MergeCF
PutCFdb_stress merge operator, whose merged value is derived
from the latest operand rather than from a more complex accumulation rulePutBlobIndexCF
BlobIndex, not the
original user value bytesvalue_base from the existing expected valuePrepared transactions need extra care because the trace may contain prepare and commit markers instead of immediately applied writes.
The handler buffers prepared writes in memory by transaction ID:
MarkBeginPrepare() starts buffering into a temporary WriteBatchMarkEndPrepare(xid) stores the buffered batch in a mapMarkCommit(xid) replays the stored batch through the same handlerMarkRollback(xid) drops the stored batch without applying itThat way the expected-state oracle reflects commit semantics rather than prepare-time visibility.
The trace stream is made of kTraceWrite records, but each one contains a
whole WriteBatch, and a batch can contain multiple individual write entries.
Restore therefore counts replay progress using the number of write operations applied by the handler, not the number of trace records read. The target count is:
db->GetLatestSequenceNumber() - saved_seqno_
Within a traced WriteBatch, the handler's Continue() method stops batch
iteration once enough write operations have been applied. The outer restore
loop still keeps reading trace records until Next() returns EOF, footer, or
corruption, at which point restore decides whether the trace prefix it already
consumed was sufficient.
<N>.trace uses RocksDB's generic binary query-trace format, so there is
already an offline printer for it: trace_analyzer.
Before adding any expected-state-specific debug logging, use this tool to dump the trace to a readable text file. This is the easiest path for both humans and agents to inspect replay inputs.
Build it with:
make -j128 trace_analyzer
Create an output directory first, then run:
mkdir -p /tmp/trace_dump
./trace_analyzer \
-trace_path=/path/to/<N>.trace \
-output_dir=/tmp/trace_dump \
-output_prefix=<N> \
-convert_to_human_readable_trace \
-try_process_corrupted_trace \
-no_print
This writes:
/tmp/trace_dump/<N>-human_readable_trace.txtThe line format is:
<hex_key> type_id cf_id value_size timestamp_us<begin_hex> <end_hex> type_id cf_id 0 timestamp_usUseful flags:
-no_key omits the hex key columns to reduce output size-try_process_corrupted_trace is recommended for db_stress crash traces,
since they can legitimately have a truncated or corrupt tail recordTwo important caveats:
trace_analyzer expects -output_dir to already existSeveral delete orders in the code are deliberate:
<N>.state is deleted before old traces
because deleting the trace first and then crashing would leave no way to
replay back up to NClean() also removes:
Open() or SaveAtAndAfter()saved_seqno_saved_seqno_Suppose a previous run saved a baseline at sequence number 100:
100.state contains the oracle snapshot at seqno 100100.trace contains writes after seqno 100Then the process crashes after issuing ten more write operations. The recovered
DB comes back with latest sequence number 107.
On the next startup:
Restore() copies 100.state to a temp LATEST.state.100.trace.107 - 100 = 7 replayed write operations to the temp
oracle.LATEST.state.The rebuilt oracle now matches the recovered DB and startup verification can check for logical holes.
The expected-state trace logic is a prefix-recovery oracle:
SaveAtAndAfter() snapshots the oracle at sequence number N and starts a
write-only, write-order-preserving traceRestore() learns the recovered sequence number M, replays the first
M - N traced write operations onto the snapshot, and rebuilds
LATEST.stateM is intactThat is the mechanism that lets db_stress validate "no hole in recovery"
instead of requiring exact preservation of the latest unsynced writes.