From 95b9ec6fe0ff87b9f3fb2bc8f51a6f2c8a1922c9 Mon Sep 17 00:00:00 2001 From: zzstoatzz Date: Thu, 13 Aug 2026 15:37:23 -0500 Subject: [PATCH] authority checks: bound the network phase, unconflate the metrics MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Follow-up to the 2026-08-13 authority stall (see relay docs/incidents/2026-08-13-zlay-authority-stall): checks wedged because the HTTP head phase had no deadline, and diagnosis was misdirected because relay_host_authority_network_time_us_total started its timer before pool acquisition — ~118s/check was mostly queueing behind the 4-slot resolver pool, not network. - bump zat v0.3.20 → v0.3.30: HttpTransport.head_deadline_ns (10s) bounds connect/TLS/send/receiveHead, so a peer that accepts and never answers can no longer pin a resolver slot indefinitely - network_time_us now starts after pool acquire; pool wait is its own counter, relay_host_authority_pool_wait_us_total Co-Authored-By: Claude Fable 5 --- build.zig.zon | 4 ++-- src/internal/broadcaster.zig | 8 ++++++++ src/internal/validator.zig | 13 ++++++++++--- 3 files changed, 20 insertions(+), 5 deletions(-) diff --git a/build.zig.zon b/build.zig.zon index 4caee11..4da78c0 100644 --- a/build.zig.zon +++ b/build.zig.zon @@ -5,8 +5,8 @@ .minimum_zig_version = "0.16.0", .dependencies = .{ .zat = .{ - .url = "https://tangled.org/zat.dev/zat/archive/v0.3.20.tar.gz", - .hash = "zat-0.3.20-5PuC7jptCwAJeTe-h5Np-5d4Tssg2F451f3-Mwe3HkIn", + .url = "https://tangled.org/zat.dev/zat/archive/v0.3.30.tar.gz", + .hash = "zat-0.3.30-5PuC7qcjDQC_lmJUYVMA_YiVlNQhfLo0WLf_lQrF3t6v", }, .websocket = .{ .url = "https://tangled.org/zzstoatzz.io/websocket.zig/archive/v0.1.11.tar.gz", diff --git a/src/internal/broadcaster.zig b/src/internal/broadcaster.zig index f8c6e01..894fd60 100644 --- a/src/internal/broadcaster.zig +++ b/src/internal/broadcaster.zig @@ -72,6 +72,7 @@ pub const Stats = struct { host_authority_cache_hits: std.atomic.Value(u64) = .{ .raw = 0 }, host_authority_network_checks: std.atomic.Value(u64) = .{ .raw = 0 }, host_authority_network_time_us: std.atomic.Value(u64) = .{ .raw = 0 }, + host_authority_pool_wait_us: std.atomic.Value(u64) = .{ .raw = 0 }, // per-branch reject breakdown (subsets of failed_host_authority). // lets us tell whether rejects come from stale cached forgeries // (host_mismatch), genuinely forged DIDs (resolve/no_endpoint), @@ -1129,6 +1130,10 @@ pub fn formatPrometheusMetrics(stats: *const Stats, cache_entries: usize, attrib \\# HELP relay_host_authority_network_time_us_total worker microseconds spent waiting on host authority network decisions \\relay_host_authority_network_time_us_total {d} \\ + \\# TYPE relay_host_authority_pool_wait_us_total counter + \\# HELP relay_host_authority_pool_wait_us_total worker microseconds spent waiting for a host resolver pool slot + \\relay_host_authority_pool_wait_us_total {d} + \\ \\# TYPE relay_host_authority_cache_entries gauge \\# HELP relay_host_authority_cache_entries confirmed DID and incoming host mismatches cached \\relay_host_authority_cache_entries {d} @@ -1137,6 +1142,7 @@ pub fn formatPrometheusMetrics(stats: *const Stats, cache_entries: usize, attrib stats.host_authority_cache_hits.load(.acquire), stats.host_authority_network_checks.load(.acquire), stats.host_authority_network_time_us.load(.acquire), + stats.host_authority_pool_wait_us.load(.acquire), attribution.host_authority_cache_entries, }) catch return w.buffered(); @@ -1673,6 +1679,7 @@ test "formatPrometheusMetrics produces valid output" { stats.host_authority_cache_hits.store(321, .release); stats.host_authority_network_checks.store(12, .release); stats.host_authority_network_time_us.store(456_000, .release); + stats.host_authority_pool_wait_us.store(789_000, .release); var buf: [65536]u8 = undefined; const output = formatPrometheusMetrics(&stats, 42, .{ @@ -1693,6 +1700,7 @@ test "formatPrometheusMetrics produces valid output" { try std.testing.expect(std.mem.indexOf(u8, output, "relay_host_authority_cache_hits_total 321") != null); try std.testing.expect(std.mem.indexOf(u8, output, "relay_host_authority_network_checks_total 12") != null); try std.testing.expect(std.mem.indexOf(u8, output, "relay_host_authority_network_time_us_total 456000") != null); + try std.testing.expect(std.mem.indexOf(u8, output, "relay_host_authority_pool_wait_us_total 789000") != null); try std.testing.expect(std.mem.indexOf(u8, output, "relay_host_authority_cache_entries 9") != null); } diff --git a/src/internal/validator.zig b/src/internal/validator.zig index 6e798b1..348ba8f 100644 --- a/src/internal/validator.zig +++ b/src/internal/validator.zig @@ -860,15 +860,22 @@ pub const Validator = struct { } _ = self.stats.host_authority_network_checks.fetchAdd(1, .monotonic); + + const wait_t0 = microTimestamp(self.io); + const idx = self.acquireHostResolver(); + defer self.releaseHostResolver(idx); + + // pool wait and network time are separate metrics: during the + // 2026-08-13 stall the combined timer read ~118s/check when the + // network itself was ~4s — queueing behind the 4-slot pool was the + // rest, and the conflation misdirected the diagnosis. const network_t0 = microTimestamp(self.io); + _ = self.stats.host_authority_pool_wait_us.fetchAdd(@intCast(@max(0, network_t0 - wait_t0)), .monotonic); defer { const elapsed: u64 = @intCast(@max(0, microTimestamp(self.io) - network_t0)); _ = self.stats.host_authority_network_time_us.fetchAdd(elapsed, .monotonic); } - const idx = self.acquireHostResolver(); - defer self.releaseHostResolver(idx); - var resolver = &self.host_resolvers[idx]; // first resolve attempt -- 2.51.2