Files
nxdns/src/storage/querylog_schema.zig
T
mokhtar 0fd6bbd312
Gates / frontend (push) Successful in 1m36s
Gates / test (push) Successful in 1m56s
Gates / test-aarch64 (push) Successful in 7m37s
Gates / package (push) Successful in 9m12s
Gates / container (push) Successful in 13s
CI / gates (push) Successful in 19m4s
milestone 28: query provenance — every logged query is exactly explainable
query rows gain qclass, rcode, group, policy action and reason, the
matched rule or list entry with its source, cname and safe-search
targets, route kind, forward zone, and the resolver that actually
answered — the pool and local markers die. servfails are logged and
name the resolver that lost; post-parse protocol refusals become rows.
a detail page at /queries/:id renders the ordered explanation, and
coverage watermarks distinguish an empty history from a missing one.

the schema fingerprint changes: existing query history is recreated
with the old file kept aside and the reset filed as a resolved
diagnostic. fixes an oversized udp reply being rebuilt as noerror,
which handed clients a truncated nxdomain as success.
2026-08-22 09:16:40 +02:00

564 lines
24 KiB
Zig

//! The `querylog.db` schema and its open-or-recreate policy.
//!
//! `querylog.db` is never migrated (PLAN §3.7). It holds expendable log rows,
//! so a schema change replaces the file instead of upgrading it. The
//! replacement trigger is a fingerprint derived from the DDL text itself, so
//! editing the schema below automatically invalidates every existing file — the
//! policy cannot drift out of sync with the SQL.
//!
//! **Recreating is destructive, so the predicate is a positive whitelist.** Only
//! a missing file, `error.Corrupt`, `error.NotADb`, a failed `PRAGMA
//! quick_check` and a fingerprint mismatch recreate. Every other error
//! propagates and the file on disk is not touched. `error.Busy` / `error.Locked`
//! mean another process holds the write lock — waiting is right, deleting is
//! catastrophic. `error.OutOfMemory` is this process's problem. `error.CantOpen`
//! is usually a permission or missing-directory problem that recreating would
//! mask rather than fix. Same for `error.ReadOnly`, `error.IoErr`, `error.Full`,
//! `error.Perm`, `error.Auth` and `error.Canceled`.
const std = @import("std");
const db = @import("db.zig");
const log = std.log.scoped(.querylog_schema);
/// PLAN §11.3, plus the coverage watermark of milestone 28. Multi-statement
/// text — it goes through `db.Db.exec`, never through `prepare`.
///
/// The trailing INSERT seeds `querylog_meta`, which is part of the schema
/// rather than a later step: a `query_log` with no watermark beside it cannot
/// answer whether an empty result means "no queries" or "no history", and every
/// database this program reads from is created by executing this string.
/// `unixepoch()` is SQLite's own UTC clock, which is the clock every
/// `timestamp` in the file is measured against.
///
/// `available_since` starts one second *after* `created_at` on purpose. A row
/// logged in the same second the file was created is not evidence that the
/// second is completely covered, and the watermark's whole job is to be
/// conservative. From there it only ever advances, in `queries_repo.pruneOlderThan`.
pub const ddl: [:0]const u8 =
\\CREATE TABLE domains (
\\ id INTEGER PRIMARY KEY,
\\ domain TEXT NOT NULL UNIQUE
\\);
\\
\\CREATE TABLE query_log (
\\ id INTEGER PRIMARY KEY,
\\ timestamp INTEGER NOT NULL,
\\ domain_id INTEGER NOT NULL REFERENCES domains(id),
\\ client_ip TEXT NOT NULL, -- text, not a FK: log rows are immutable facts
\\ qtype INTEGER,
\\ blocked INTEGER NOT NULL,
\\ response_time_us INTEGER,
\\ cache_hit INTEGER,
\\ upstream TEXT,
\\ qclass INTEGER NOT NULL,
\\ rcode INTEGER NOT NULL,
\\ group_id INTEGER, -- text/id pairs, not FKs: a renamed
\\ group_name TEXT, -- group must not rewrite history
\\ policy_action TEXT NOT NULL,
\\ policy_reason TEXT NOT NULL,
\\ matched TEXT,
\\ source_id INTEGER,
\\ source_name TEXT,
\\ cname_target TEXT,
\\ safe_search_target TEXT,
\\ route_kind TEXT NOT NULL,
\\ forward_zone TEXT,
\\ CHECK (rcode BETWEEN 0 AND 4095) -- twelve bits (RFC 6891 6.1.3)
\\);
\\CREATE INDEX idx_query_log_ts ON query_log(timestamp);
\\CREATE INDEX idx_query_log_client ON query_log(client_ip);
\\CREATE INDEX idx_query_log_domain ON query_log(domain_id);
\\
\\CREATE TABLE upstream_targets (
\\ id INTEGER PRIMARY KEY,
\\ url TEXT NOT NULL UNIQUE -- the historical identity: config.db ids cannot cross database files
\\);
\\
\\CREATE TABLE upstream_minute (
\\ upstream_id INTEGER NOT NULL REFERENCES upstream_targets(id),
\\ minute_ts INTEGER NOT NULL,
\\ successes INTEGER NOT NULL,
\\ failures INTEGER NOT NULL,
\\ last_failure_ts INTEGER,
\\ last_error TEXT,
\\ PRIMARY KEY (upstream_id, minute_ts),
\\ CHECK (successes >= 0),
\\ CHECK (failures >= 0)
\\) WITHOUT ROWID;
\\CREATE INDEX idx_upstream_minute_ts ON upstream_minute(minute_ts);
\\
\\CREATE TABLE querylog_meta (
\\ id INTEGER PRIMARY KEY CHECK (id = 1), -- one row, enforced by the schema
\\ created_at INTEGER NOT NULL,
\\ available_since INTEGER NOT NULL
\\);
\\INSERT INTO querylog_meta (id, created_at, available_since)
\\VALUES (1, unixepoch(), unixepoch() + 1);
;
/// `PRAGMA user_version` is a signed 32-bit field. Deriving the fingerprint from
/// the DDL means editing the schema automatically invalidates every existing
/// file — which is exactly the policy.
pub const fingerprint: i32 = blk: {
// Covers the CRC lookup-table generation in std.hash.crc, which evaluates
// under this scope's quota and overflows the 1000 default (and 100k).
@setEvalBranchQuota(2_000_000);
break :blk @bitCast(std.hash.Crc32.hash(ddl));
};
const set_user_version = std.fmt.comptimePrint("PRAGMA user_version = {d};", .{fingerprint});
/// The WAL checkpoint threshold for every read-write `querylog.db` connection,
/// in pages (32 MiB at the 4096-byte page size). SQLite's 1000-page default
/// trips every ~40 min under this workload and rewrites the same hot index and
/// interior pages into the main database each time; 8192 stretches that to ~5 h
/// and cuts those in-place rewrites ~8x, which is SD-card write wear this
/// household appliance does not need to spend.
///
/// The durability consequence, stated precisely:
///
/// - Commit never fsyncs at `synchronous = NORMAL`; the checkpoint's fsync is
/// the only guaranteed durability boundary. This moves that boundary from
/// ~40 min to ~5 h of querylog data (query rows plus upstream-history
/// minutes) under power loss or kernel panic. Typical loss stays far smaller
/// because of kernel writeback, but that is not a guarantee.
/// - Process crash or clean stop loses nothing committed, at any threshold.
/// Consistency is never at risk: recovery replays the longest valid WAL
/// prefix atomically.
/// - 32 MiB is an expectation, not a cap: a pinned reader snapshot stops a
/// passive checkpoint partway and the WAL overshoots until that reader
/// finishes. The daily retention `wal_checkpoint(TRUNCATE)` is the backstop
/// that shrinks the file.
///
/// `config.db` keeps the SQLite default: it holds configuration, not a log.
pub const wal_autocheckpoint_pages: i32 = 8192;
/// Long enough for any path this program will be handed, plus the aside suffix.
/// A longer path is `error.NameTooLong`, which is what the filesystem calls
/// would have returned anyway.
const path_buf_len = 4096 + 64;
pub const RecreateReason = enum { missing, corrupt, not_a_database, quick_check_failed, fingerprint_mismatch };
pub const OpenResult = struct {
database: db.Db,
/// Non-null feeds a counter and the `/api/health` rollup.
recreated: ?RecreateReason,
/// The path the previous file was kept as, by value. It existed only in a
/// stack buffer inside `open` before the diagnostics event needed it, and a
/// slice of that buffer would dangle the moment `open` returned.
///
/// Empty when nothing was renamed aside, which `.missing` and a clean open
/// both are.
aside_buf: [path_buf_len]u8 = undefined,
aside_len: u16 = 0,
pub fn aside(self: *const OpenResult) []const u8 {
return self.aside_buf[0..self.aside_len];
}
};
pub const Error = db.Error || error{AsideNameCollision} ||
std.Io.Dir.RenamePreserveError || std.Io.Dir.DeleteFileError || std.Io.Dir.AccessError;
/// Opens `path`, recreating it if and only if it is genuinely unusable.
///
/// `path` is resolved twice by two different mechanisms: `dir`-relative for the
/// filesystem calls, and process-cwd-relative by SQLite's VFS, which knows
/// nothing about `dir`. The caller must therefore pass either an absolute path
/// with `dir` open on its parent, or `std.Io.Dir.cwd()` with a cwd-relative
/// path.
pub fn open(io: std.Io, dir: std.Io.Dir, path: [:0]const u8) Error!OpenResult {
var handle: ?db.Db = null;
errdefer if (handle) |*h| h.close();
const reason: ?RecreateReason = probe: {
dir.access(io, path, .{}) catch |e| switch (e) {
error.FileNotFound => break :probe .missing,
else => |other| return other,
};
handle = db.Db.open(path, .{ .mode = .read_write_existing }) catch |e|
break :probe recreatable(e) orelse return e;
const opened = &handle.?;
db.applyPragmas(opened, .{ .wal_autocheckpoint_pages = wal_autocheckpoint_pages }) catch |e|
break :probe recreatable(e) orelse return e;
const healthy = quickCheck(opened) catch |e|
break :probe recreatable(e) orelse return e;
if (!healthy) break :probe .quick_check_failed;
const stamped = opened.queryInt("PRAGMA user_version") catch |e|
break :probe recreatable(e) orelse return e;
if (stamped != fingerprint) break :probe .fingerprint_mismatch;
break :probe null;
};
const cause = reason orelse return .{ .database = handle.?, .recreated = null };
// Close first, so SQLite checkpoints and drops `-wal`/`-shm` where it can.
if (handle) |*h| h.close();
handle = null;
var aside_buf: [path_buf_len]u8 = undefined;
const aside: ?[]const u8 = if (cause == .missing)
null
else
try renameAside(io, dir, path, cause, &aside_buf);
// Not optional: a stale WAL left beside the renamed database would be
// replayed into the freshly created file and corrupt it immediately. Any
// failure other than "already gone" propagates rather than building the new
// database on a half-cleaned state.
try deleteSidecars(io, dir, path);
const fresh = try createFresh(path);
if (cause == .missing) {
log.info("created querylog database '{s}'", .{path});
} else {
log.warn("recreated querylog database '{s}': {s}; previous file kept as '{s}'", .{
path,
@tagName(cause),
aside.?,
});
}
var result: OpenResult = .{ .database = fresh, .recreated = cause };
if (aside) |name| {
result.aside_len = @intCast(name.len);
@memcpy(result.aside_buf[0..name.len], name);
}
return result;
}
/// The whitelist. `null` means "propagate, do not touch the file".
fn recreatable(e: db.Error) ?RecreateReason {
return switch (e) {
error.Corrupt => .corrupt,
error.NotADb => .not_a_database,
else => null,
};
}
/// `PRAGMA quick_check` rather than `integrity_check`: it skips the expensive
/// index-vs-table cross-check while still catching structural damage, and a
/// damaged index on an expendable log is not worth a multi-second startup scan.
fn quickCheck(database: *db.Db) db.Error!bool {
var stmt = try database.prepare("PRAGMA quick_check");
defer stmt.deinit();
if (!try stmt.step()) return false;
return std.ascii.eqlIgnoreCase(stmt.columnText(0), "ok");
}
/// What the aside file's name calls the reason it was set aside.
///
/// The name is the only account of the reason an operator gets: the log line
/// naming it scrolls away, the file stays for months. `fingerprint_mismatch` is
/// a database with nothing wrong with it — this build's DDL moved — so calling
/// its file "corrupt" invites the operator to delete evidence of a healthy file.
fn asideTag(reason: RecreateReason) []const u8 {
return switch (reason) {
.missing => unreachable, // there is no file to rename
.corrupt => "corrupt",
.not_a_database => "not-a-database",
.quick_check_failed => "quick-check-failed",
.fingerprint_mismatch => "schema-changed",
};
}
/// Renames the unusable file out of the way and returns the name it now has.
///
/// `renamePreserve` is `RENAME_NOREPLACE`: it returns `error.PathAlreadyExists`
/// instead of overwriting. A previously saved file must never be destroyed by
/// the next recreate, and two recreates in the same second are not hypothetical
/// on a boot loop — hence the uniquifying retries.
fn renameAside(io: std.Io, dir: std.Io.Dir, path: []const u8, reason: RecreateReason, buf: []u8) Error![]const u8 {
const tag = asideTag(reason);
const seconds = std.Io.Clock.real.now(io).toSeconds();
var attempt: u32 = 0;
while (attempt < 100) : (attempt += 1) {
const aside = if (attempt == 0)
std.fmt.bufPrint(buf, "{s}.{s}-{d}", .{ path, tag, seconds }) catch return error.NameTooLong
else
std.fmt.bufPrint(buf, "{s}.{s}-{d}-{d}", .{ path, tag, seconds, attempt }) catch return error.NameTooLong;
dir.renamePreserve(path, dir, aside, io) catch |e| switch (e) {
error.PathAlreadyExists => continue,
else => |other| return other,
};
return aside;
}
return error.AsideNameCollision;
}
fn deleteSidecars(io: std.Io, dir: std.Io.Dir, path: []const u8) Error!void {
var buf: [path_buf_len]u8 = undefined;
for ([_][]const u8{ "-wal", "-shm" }) |suffix| {
const sidecar = std.fmt.bufPrint(&buf, "{s}{s}", .{ path, suffix }) catch return error.NameTooLong;
dir.deleteFile(io, sidecar) catch |e| switch (e) {
error.FileNotFound => {},
else => |other| return other,
};
}
}
fn createFresh(path: [:0]const u8) db.Error!db.Db {
var database = try db.Db.open(path, .{ .mode = .read_write_create });
errdefer database.close();
try db.applyPragmas(&database, .{ .wal_autocheckpoint_pages = wal_autocheckpoint_pages });
var tx = try db.Tx.begin(&database);
errdefer tx.rollback();
try database.exec(ddl);
try database.exec(set_user_version);
try tx.commit();
return database;
}
const testing = std.testing;
test "fingerprint matches a fresh hash of the DDL" {
try testing.expectEqual(fingerprint, @as(i32, @bitCast(std.hash.Crc32.hash(ddl))));
}
test "ddl creates the query-log tables, the upstream-history tables and every index" {
var database = try db.Db.open(":memory:", .{ .mode = .memory });
defer database.close();
try db.applyPragmas(&database, .{});
try database.exec(ddl);
try testing.expectEqual(
@as(i64, 5),
try database.queryInt("SELECT count(*) FROM sqlite_schema WHERE type='table'"),
);
const objects = [_][]const u8{
"domains", "query_log",
"idx_query_log_ts", "idx_query_log_client",
"idx_query_log_domain", "upstream_targets",
"upstream_minute", "idx_upstream_minute_ts",
"querylog_meta",
};
for (objects) |name| {
var stmt = try database.prepare("SELECT count(*) FROM sqlite_schema WHERE name = ?1");
defer stmt.deinit();
try stmt.bindText(1, name);
try testing.expect(try stmt.step());
try testing.expectEqual(@as(i64, 1), stmt.columnInt(0));
}
}
test "the schema refuses an rcode outside twelve bits" {
var database = try db.Db.open(":memory:", .{ .mode = .memory });
defer database.close();
try db.applyPragmas(&database, .{});
try database.exec(ddl);
try database.exec("INSERT INTO domains (id, domain) VALUES (1, 'a.example');");
var stmt = try database.prepare(
\\INSERT INTO query_log
\\ (timestamp, domain_id, client_ip, blocked, qclass, rcode,
\\ policy_action, policy_reason, route_kind)
\\VALUES (1, 1, '10.0.0.1', 0, 1, ?1, 'not_evaluated', 'no_match', 'upstream')
);
defer stmt.deinit();
// The whole range an EDNS extended RCODE can express, and nothing wider:
// the producers are `u12`, and this is what stops any other writer — a
// hand-run UPDATE included — from putting a value in the column that the
// read path would have to reject.
for ([_]i64{ 0, 4095 }) |accepted| {
try stmt.reset();
try stmt.bindInt(1, accepted);
try stmt.exec();
}
for ([_]i64{ -1, 4096, 65535 }) |refused| {
// `sqlite3_reset` repeats the error of the statement it is resetting,
// which for every iteration after the first is the constraint failure
// this loop just asserted — the same reason `BatchWriter.resetAll`
// discards it.
stmt.reset() catch {};
try stmt.bindInt(1, refused);
try testing.expectError(error.Constraint, stmt.exec());
}
try testing.expectEqual(@as(i64, 2), try database.queryInt("SELECT count(*) FROM query_log"));
}
test "querylog_meta is seeded with one row the schema will not let a second join" {
var database = try db.Db.open(":memory:", .{ .mode = .memory });
defer database.close();
try db.applyPragmas(&database, .{});
try database.exec(ddl);
try testing.expectEqual(@as(i64, 1), try database.queryInt("SELECT count(*) FROM querylog_meta"));
const created = try database.queryInt("SELECT created_at FROM querylog_meta");
const since = try database.queryInt("SELECT available_since FROM querylog_meta");
// Conservative by exactly one second: a row logged in the creating second
// must not let a query claim that second is completely covered.
try testing.expectEqual(created + 1, since);
try testing.expect(created > 1_700_000_000);
// `CHECK (id = 1)` is what makes "the singleton row" a schema fact rather
// than a convention the read path has to defend against.
try testing.expectError(error.Constraint, database.exec(
"INSERT INTO querylog_meta (id, created_at, available_since) VALUES (2, 1, 1);",
));
try testing.expectError(error.Constraint, database.exec(
"INSERT INTO querylog_meta (id, created_at, available_since) VALUES (1, 1, 1);",
));
try testing.expectEqual(@as(i64, 1), try database.queryInt("SELECT count(*) FROM querylog_meta"));
}
test "the user_version statement stamps the fingerprint" {
var database = try db.Db.open(":memory:", .{ .mode = .memory });
defer database.close();
try database.exec(set_user_version);
try testing.expectEqual(@as(i64, fingerprint), try database.queryInt("PRAGMA user_version"));
}
// The behaviour these two cases describe — a resource error leaves the file on
// disk alone — is proven against a real file by "S7 case 23" in
// `storage_integration_test.zig`, which locks a healthy `querylog.db` from a
// second connection and asserts `open` returns `error.Busy` with the bytes, the
// file and the absence of an aside all intact. `error.OutOfMemory` has no such
// case: `open` takes no allocator, and SQLite allocates through its own global
// allocator, so there is no seam to inject a failure through. The two tests
// below are what covers it.
test "recreatable is a whitelist and never selects a resource error" {
try testing.expectEqual(RecreateReason.corrupt, recreatable(error.Corrupt).?);
try testing.expectEqual(RecreateReason.not_a_database, recreatable(error.NotADb).?);
const propagating = [_]db.Error{
error.Busy, error.Locked, error.OutOfMemory, error.CantOpen,
error.ReadOnly, error.IoErr, error.Full, error.Perm,
error.Auth, error.Misuse, error.Constraint, error.SqliteError,
error.Unexpected,
};
for (propagating) |e| {
try testing.expect(recreatable(e) == null);
}
}
test "the aside name says why, and a healthy file is never called corrupt" {
try testing.expectEqualStrings("corrupt", asideTag(.corrupt));
try testing.expectEqualStrings("not-a-database", asideTag(.not_a_database));
try testing.expectEqualStrings("quick-check-failed", asideTag(.quick_check_failed));
try testing.expectEqualStrings("schema-changed", asideTag(.fingerprint_mismatch));
}
test "recreatable selects exactly two of db.Error's members" {
// Exhaustive over the whole set, so a variant added to `db.Error` later
// defaults to propagate. The list above only proves the named errors are
// safe today; this proves nothing else can join the whitelist unnoticed.
var whitelisted: usize = 0;
inline for (@typeInfo(db.Error).error_set.?) |member| {
if (recreatable(@field(db.Error, member.name)) != null) whitelisted += 1;
}
try testing.expectEqual(@as(usize, 2), whitelisted);
}
test "a recreate returns the aside name by value and a fresh create returns none" {
var threaded: std.Io.Threaded = .init(testing.allocator, .{});
defer threaded.deinit();
const io = threaded.io();
var tmp = testing.tmpDir(.{ .iterate = true });
defer tmp.cleanup();
var path_buf: [path_buf_len]u8 = undefined;
const path = try std.fmt.bufPrintZ(&path_buf, ".zig-cache/tmp/{s}/querylog.db", .{tmp.sub_path});
// First open: the file is missing, so nothing is renamed aside. The
// one-shot event is deliberately not emitted for this case.
var created = try open(io, std.Io.Dir.cwd(), path);
created.database.close();
try testing.expectEqual(RecreateReason.missing, created.recreated.?);
try testing.expectEqualStrings("", created.aside());
try tmp.dir.writeFile(io, .{ .sub_path = "querylog.db", .data = "not a database at all" });
var recreated = try open(io, std.Io.Dir.cwd(), path);
recreated.database.close();
try testing.expectEqual(RecreateReason.not_a_database, recreated.recreated.?);
try testing.expect(recreated.aside().len != 0);
// The name is a real file, which is the whole reason it travels out.
const kept = std.fs.path.basename(recreated.aside());
try tmp.dir.access(io, kept, .{});
}
test "a recreate resets coverage to the new file and keeps the old one aside" {
var threaded: std.Io.Threaded = .init(testing.allocator, .{});
defer threaded.deinit();
const io = threaded.io();
var tmp = testing.tmpDir(.{ .iterate = true });
defer tmp.cleanup();
var path_buf: [path_buf_len]u8 = undefined;
const path = try std.fmt.bufPrintZ(&path_buf, ".zig-cache/tmp/{s}/querylog.db", .{tmp.sub_path});
var created = try open(io, std.Io.Dir.cwd(), path);
const first_coverage = try created.database.queryInt("SELECT available_since FROM querylog_meta");
// A row in the file the operator is about to lose.
try created.database.exec("INSERT INTO domains (domain) VALUES ('old.example');");
created.database.close();
// A healthy file this build's DDL no longer matches — the case milestone
// 28's own schema edit produces on every upgrade.
{
var stamped = try db.Db.open(path, .{ .mode = .read_write_existing });
defer stamped.close();
var sql_buf: [64]u8 = undefined;
try stamped.exec(try std.fmt.bufPrintZ(&sql_buf, "PRAGMA user_version = {d};", .{fingerprint +% 1}));
}
var recreated = try open(io, std.Io.Dir.cwd(), path);
defer recreated.database.close();
try testing.expectEqual(RecreateReason.fingerprint_mismatch, recreated.recreated.?);
// The name says the file was healthy and this build moved, not that it rotted.
try testing.expect(std.mem.indexOf(u8, recreated.aside(), ".schema-changed-") != null);
try tmp.dir.access(io, std.fs.path.basename(recreated.aside()), .{});
// Exactly one meta row, and coverage starts at the recreate rather than
// carrying the replaced file's promise forward.
try testing.expectEqual(
@as(i64, 1),
try recreated.database.queryInt("SELECT count(*) FROM querylog_meta"),
);
const new_coverage = try recreated.database.queryInt("SELECT available_since FROM querylog_meta");
try testing.expect(new_coverage >= first_coverage);
// Nothing of the old file came across: the history is genuinely gone, which
// is what the coverage start has to tell the operator.
try testing.expectEqual(
@as(i64, 0),
try recreated.database.queryInt("SELECT count(*) FROM domains"),
);
}
test "a clean reopen reports no recreate and no aside" {
var threaded: std.Io.Threaded = .init(testing.allocator, .{});
defer threaded.deinit();
const io = threaded.io();
var tmp = testing.tmpDir(.{ .iterate = true });
defer tmp.cleanup();
var path_buf: [path_buf_len]u8 = undefined;
const path = try std.fmt.bufPrintZ(&path_buf, ".zig-cache/tmp/{s}/querylog.db", .{tmp.sub_path});
var first = try open(io, std.Io.Dir.cwd(), path);
first.database.close();
var second = try open(io, std.Io.Dir.cwd(), path);
second.database.close();
try testing.expectEqual(@as(?RecreateReason, null), second.recreated);
try testing.expectEqualStrings("", second.aside());
}