diff --git a/CHANGELOG.md b/CHANGELOG.md index ecdad1a..e2aac5f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,20 @@ All notable changes to nxdns are recorded here. The format follows [Keep a Chang Sections are written by hand. Nothing here is generated from commit messages: the point of the file is to say what changed for an operator, which a commit subject rarely does. +## [Unreleased] + +### Fixed + +- **A blackhole route to an upstream no longer stops failover.** On a route like that, `connect()` fails with an errno the runtime has no name for, and nxdns took it for a fault of its own: the query got SERVFAIL at once, the next upstream was never tried, and nothing was charged to the unreachable one. A connect failure of that kind now counts against that upstream as `ConnectFailed (cause Unexpected)`, and the query fails over. + +### Added + +- **`nxdns_upstream_local_resource_total`** counts exchanges that ended on this process's own resources (memory, file descriptors, an unnamed system error) before any upstream answered. Until now, such a SERVFAIL left no record of its cause anywhere. + +### Changed + +- **A DoH upstream that answers with an error status says which.** The Diagnostics episode and `/api/health` read `HttpStatus (status 505 HTTP Version Not Supported)` instead of `HttpStatus (cause HttpStatus)`. A 505 is a server that requires HTTP/2, which nxdns does not speak. + ## [0.0.22] - 2026-10-19 ### Added diff --git a/docs/how-to/troubleshoot.md b/docs/how-to/troubleshoot.md index 16d90d3..9c6fb73 100644 --- a/docs/how-to/troubleshoot.md +++ b/docs/how-to/troubleshoot.md @@ -273,6 +273,28 @@ curl -s http://127.0.0.1:8080/metrics | grep nxdns_upstream_ **Fix.** Raise `upstream.total_timeout_ms` if the queue drains but drains too slowly for the budget. Otherwise the queue is telling you the upstream is slow: an upstream answering in a few milliseconds does not fill eight concurrent slots at household query rates, so sustained queueing points at the resolver you configured, and a faster one is the fix. Adding a second upstream helps only with saturation, not with latency: failover is strict priority, not load spreading. A query does take the next upstream when the first one's slots are all busy — priority orders the candidates that can be admitted right now — but once every eligible upstream is full it blocks on the highest-priority one, and it still sends one query to one upstream at a time. The per-upstream slot count is compiled, not configured, so there is no knob to widen one upstream either. +## SERVFAIL rows that name no upstream + +**Symptom.** The query log shows SERVFAIL rows whose `upstream` is empty, and `/api/health` shows every upstream healthy. + +**Diagnosis.** A failed exchange names no upstream only when no attributable attempt happened, and two pool-wide counters say why: + +```sh +curl -s http://127.0.0.1:8080/metrics | grep -E 'nxdns_upstream_(budget_exhausted|local_resource)_total' +``` + +`nxdns_upstream_budget_exhausted_total` is a query whose own budget ran out first; the previous section covers it. `nxdns_upstream_local_resource_total` is an exchange this process ended on its own resources: out of memory, out of file descriptors, or a system error the runtime has no name for. Neither is charged to an upstream, because no upstream caused it, and a local failure does not fail over, because the next upstream would hit the same wall. Both count exchanges, not rows without an upstream: when an earlier upstream had already failed in the same exchange, the row names that one. + +**Fix.** For `local_resource_total`, look at the process's limits: `grep -E 'Max open files' /proc/$(pidof nxdns)/limits` against `ls /proc/$(pidof nxdns)/fd | wc -l`, and `VmRSS` in `/proc/$(pidof nxdns)/status` against the memory the host has. A connect that fails for a reason the runtime cannot name — a blackhole route to the upstream is one — is not counted here: it is charged to that upstream as `ConnectFailed (cause Unexpected)`, and the query fails over. + +## A DoH upstream fails with `HttpStatus (status 505 HTTP Version Not Supported)` + +**Symptom.** Diagnostics shows the upstream failing with that cause, and no query ever succeeds against it. + +**Diagnosis.** The server refuses HTTP/1.1. nxdns speaks DoH over HTTP/1.1 only, and some public resolvers (Quad9's `https://dns.quad9.net/dns-query`, for one) require HTTP/2. Other statuses name themselves the same way: a 403 or 404 is usually a wrong URL path. + +**Fix.** Use that provider's DoT endpoint instead (for Quad9, `tls://9.9.9.9:853` with `tls_name = "dns.quad9.net"`), or a DoH upstream that accepts HTTP/1.1. + ## The disk is filling up **Symptom.** Writes stop but DNS keeps answering. The journal shows the transition: diff --git a/src/upstream/doh_client.zig b/src/upstream/doh_client.zig index 28cac46..29e960e 100644 --- a/src/upstream/doh_client.zig +++ b/src/upstream/doh_client.zig @@ -123,7 +123,11 @@ pub const DohClient = struct { // is an error before the location is ever read. var resp = req.receiveHead(&.{}) catch |err| return fault(headCause(&req, err), .receive); - if (resp.head.status != .ok) return peerFault(error.HttpStatus, error.HttpStatus); + if (resp.head.status != .ok) return .{ .fault = .{ + .kind = error.HttpStatus, + .cause = error.HttpStatus, + .http_status = resp.head.status, + } }; // `head.content_type` points into memory that `resp.reader` invalidates, // so the check happens before the body stream starts. if (!contentTypeOk(resp.head.content_type)) return peerFault(error.HttpContentType, error.HttpContentType); @@ -175,7 +179,19 @@ const Phase = enum { connect, send, receive }; /// arrive here as themselves. Without them a decode error or a bad record MAC /// would be reported as a plain receive failure. fn fault(err: anyerror, phase: Phase) transport.LeafError!transport.Outcome { - if (transport.mapLocal(err)) |local| return local; + // `.connect` is the whole of `http.request`: the name lookup, the TCP + // connect and the handshake. The handshake's only `error.Unexpected` is the + // errno the socket stream stored (std/http/Client.zig:1466; the TLS + // client's `InitError` has none), and a CA bundle scan fails as + // `CertificateBundleLoadFailure`. The lookup's resolver socket can fail + // locally, but that still leaves this upstream unreachable while a DoT + // upstream, always an IP literal, needs no lookup, so the fault belongs to + // this endpoint and the pool is right to move on. + const local = switch (phase) { + .connect => transport.mapLocalConnect(err), + .send, .receive => transport.mapLocal(err), + }; + if (local) |claimed| return claimed; return peerFault(kindOf(err, phase), err); } @@ -331,6 +347,12 @@ test "a local cause stays an error instead of becoming a fault" { try testing.expectError(error.Unexpected, fault(error.Unexpected, .send)); } +test "an unnamed connect errno is a connect fault, so the pool fails over" { + const outcome = try fault(error.Unexpected, .connect); + try testing.expectEqual(transport.PeerFault.ConnectFailed, outcome.fault.kind); + try testing.expectEqual(error.Unexpected, outcome.fault.cause); +} + test "kindOf maps the collapsed tls errors regardless of phase" { try testing.expectEqual(error.TlsFailed, kindOf(error.TlsInitializationFailed, .connect)); try testing.expectEqual(error.TlsFailed, kindOf(error.TlsInitializationFailed, .receive)); diff --git a/src/upstream/dot_client.zig b/src/upstream/dot_client.zig index 65c817a..9adcbed 100644 --- a/src/upstream/dot_client.zig +++ b/src/upstream/dot_client.zig @@ -279,7 +279,8 @@ pub const DotClient = struct { const stream = address.connect(io, .{ .mode = .stream }) catch |err| { log.debug("{f}", .{self.diagnose(.{ .connect_failed = err })}); - return try transport.faultOrLocal(err, error.ConnectFailed); + if (transport.mapLocalConnect(err)) |local| return local; + return .{ .kind = error.ConnectFailed, .cause = err }; }; // Emplaced before the handshake, never built beside it and copied in: diff --git a/src/upstream/health.zig b/src/upstream/health.zig index 0cb7ba3..6c67779 100644 --- a/src/upstream/health.zig +++ b/src/upstream/health.zig @@ -56,10 +56,10 @@ comptime { pub const window_len = 32; /// Bytes kept of a rendered `transport.Fault`, truncated to fit. Sized so the -/// widest classification and the widest concrete cause name fit whole; the -/// comptime-driven test below recomputes that worst case from the std error -/// sets, so a wider name std adds fails the test run rather than silently -/// truncating an operator's only diagnostic. +/// widest classification and the widest concrete cause name fit whole, and so +/// does the widest HTTP status with its phrase; the comptime-driven test below +/// recomputes that worst case from std, so a wider name std adds fails the test +/// run rather than silently truncating an operator's only diagnostic. pub const error_name_capacity = 64; /// The shift is capped so `base_backoff_ms << shift` cannot run away; by then @@ -552,7 +552,7 @@ test "lastError truncates a cause too wide for the buffer instead of overflowing try testing.expectEqualStrings(whole[0..error_name_capacity], state.lastError()); } -test "error_name_capacity holds the widest classification and cause whole" { +test "error_name_capacity holds the widest classification, cause and status whole" { // The widest concrete cause an upstream unwrap can produce. The three sets // are the ones `transport.zig`'s unwraps return a member of; a wider name // std adds fails here rather than truncating an operator's diagnostic. @@ -579,6 +579,18 @@ test "error_name_capacity holds the widest classification and cause whole" { try testing.expectEqualStrings("DetectingNetworkConfigurationFailed", widest_cause); try testing.expect(widest_kind.len + " (cause ".len + widest_cause.len + ")".len <= error_name_capacity); + + const widest_phrase = comptime blk: { + var widest: []const u8 = ""; + for (@typeInfo(std.http.Status).@"enum".fields) |field| { + const phrase = @as(std.http.Status, @enumFromInt(field.value)).phrase() orelse continue; + if (phrase.len > widest.len) widest = phrase; + } + break :blk widest; + }; + // `std.http.Status` is a u10, so a code has at most four digits. + const widest_status = "HttpStatus (status ".len + 4 + " ".len + widest_phrase.len + ")".len; + try testing.expect(widest_status <= error_name_capacity); } /// The fault of a `tripped` effect, or an error when the effect says `clear`. diff --git a/src/upstream/pool.zig b/src/upstream/pool.zig index 4bd79d7..dd8fb3c 100644 --- a/src/upstream/pool.zig +++ b/src/upstream/pool.zig @@ -382,6 +382,13 @@ pub const Pool = struct { /// removes. Read through `budgetExhaustedTotal`, since `Snapshot` is /// per-entry and has nowhere to put it. budget_exhausted_total: std.atomic.Value(u64) = .init(0), + /// Exchanges this process ended on its own resources (memory, descriptors, + /// an undersized buffer, an errno std does not name outside the connect + /// phase), counted once each by `exchange`. Pool-wide for the reason + /// `budget_exhausted_total` is: no endpoint caused it, so the pool records + /// it against none, and the SERVFAIL it becomes names no upstream. Read + /// through `localResourceTotal`. + local_resource_total: std.atomic.Value(u64) = .init(0), /// The failover loop tracks which entries it has already spent in a bitset /// on its stack, so the number of upstreams one pool may hold is bounded. @@ -461,11 +468,13 @@ pub const Pool = struct { ) transport.ExchangeError![]u8 { const deadline: std.Io.Clock.Timestamp = .fromNow(io, self.timeouts.total); return self.failover(io, query, response_buf, selected, deadline) catch |err| { - // Once per exhausted exchange, wherever the exhaustion was - // detected — the loop's own waits and attempts, or a leaf that - // reported one of its own. - if (err == error.BudgetExhausted) { - _ = self.budget_exhausted_total.fetchAdd(1, .monotonic); + // Once per failed exchange, wherever the failure was detected — + // the loop's own waits and attempts, or a leaf that reported one of + // its own. + switch (transport.group(err)) { + .budget_exhausted => _ = self.budget_exhausted_total.fetchAdd(1, .monotonic), + .local_resource => _ = self.local_resource_total.fetchAdd(1, .monotonic), + .peer_fault, .cancellation => {}, } return err; }; @@ -518,6 +527,11 @@ pub const Pool = struct { return self.budget_exhausted_total.load(.acquire); } + /// Exchanges that ended on this process's own resources, pool-wide. + pub fn localResourceTotal(self: *const Pool) u64 { + return self.local_resource_total.load(.acquire); + } + /// The two-pass failover loop. /// /// Pass one sweeps the entries health says are available, in priority @@ -1431,6 +1445,11 @@ test "a local resource error short-circuits and records nothing" { try testing.expectEqual(@as(usize, 0), good.calls.load(.acquire)); try testing.expectEqual(@as(u64, 0), entries[0].health.total_failures); try testing.expectEqual(@as(u32, 0), entries[0].health.consecutive_failures); + // Recorded against no endpoint, but still counted: the SERVFAIL it becomes + // names no upstream, and this is the only trace of why. + try testing.expectEqual(@as(u64, 1), pool.localResourceTotal()); + try testing.expectEqual(@as(u64, 0), pool.budgetExhaustedTotal()); + try testing.expect(selected == null); } test "a cancellation short-circuits and records nothing" { @@ -1453,6 +1472,7 @@ test "a cancellation short-circuits and records nothing" { try testing.expectEqual(@as(u64, 0), entries[0].health.total_failures); // A torn-down task is not a budget that ran out, and it names no endpoint. try testing.expectEqual(@as(u64, 0), pool.budgetExhaustedTotal()); + try testing.expectEqual(@as(u64, 0), pool.localResourceTotal()); try testing.expect(selected == null); } @@ -1722,6 +1742,7 @@ test "budget_exhausted_total counts exhausted exchanges once each" { stalling.behavior = .{ .reply = response_bytes }; _ = try pool.exchange(io, query_bytes, &buf, &selected); try testing.expectEqual(@as(u64, 3), pool.budgetExhaustedTotal()); + try testing.expectEqual(@as(u64, 0), pool.localResourceTotal()); } test "two stalling upstreams cost the total budget, not one budget each" { diff --git a/src/upstream/transport.zig b/src/upstream/transport.zig index 2f3d2ef..d551b7d 100644 --- a/src/upstream/transport.zig +++ b/src/upstream/transport.zig @@ -263,6 +263,20 @@ pub fn mapPhase(err: anyerror, phase: PeerFault) ExchangeError { return mapLocal(err) orelse phase; } +/// `mapLocal` for the connect phase, where `error.Unexpected` belongs to the +/// peer. +/// +/// zig 0.16.0's `connect()` names no `EINVAL` (std/Io/Threaded.zig:11909), and +/// `EINVAL` is what a blackhole route to the peer returns, so a route fault +/// arrives as `error.Unexpected`. Claimed as local, it would end the exchange +/// without failover and record nothing against the endpoint. In this phase an +/// errno std does not name is about the path to this peer, so it stays a peer +/// fault and the pool moves on to the next endpoint. +pub fn mapLocalConnect(err: anyerror) ?LeafError { + if (err == error.Unexpected) return null; + return mapLocal(err); +} + /// Closes `target` with cancellation blocked. /// /// A transport's close runs from a `defer` chain that a lost timeout race is @@ -458,10 +472,19 @@ pub const Client = struct { pub const Fault = struct { kind: PeerFault, cause: anyerror, + /// The status the peer answered with, when that is the fault. An error + /// name cannot carry it, and it is what says why the peer refused: a 505 + /// is a DoH server that will not speak HTTP/1.1. + http_status: ?std.http.Status = null, - /// The one text every surface prints. ` (cause )`. + /// The one text every surface prints: ` (cause )`, or + /// ` (status )` for a peer that answered with a status. pub fn format(self: Fault, w: *std.Io.Writer) std.Io.Writer.Error!void { - try w.print("{t} (cause {s})", .{ self.kind, @errorName(self.cause) }); + const status = self.http_status orelse + return w.print("{t} (cause {s})", .{ self.kind, @errorName(self.cause) }); + try w.print("{t} (status {d}", .{ self.kind, @intFromEnum(status) }); + if (status.phrase()) |phrase| try w.print(" {s}", .{phrase}); + try w.writeByte(')'); } }; @@ -776,6 +799,37 @@ test "mapPhase names the phase unless the error is this process's own" { ); } +test "mapLocalConnect leaves an unnamed connect errno to the peer" { + try testing.expectEqual(@as(?ExchangeError, null), mapLocalConnect(error.Unexpected)); + try testing.expectEqual(@as(?ExchangeError, error.OutOfMemory), mapLocalConnect(error.OutOfMemory)); + try testing.expectEqual( + @as(?ExchangeError, error.ProcessFdQuotaExceeded), + mapLocalConnect(error.ProcessFdQuotaExceeded), + ); + try testing.expectEqual(@as(?ExchangeError, error.Canceled), mapLocalConnect(error.Canceled)); + try testing.expectEqual(@as(?ExchangeError, null), mapLocalConnect(error.NetworkUnreachable)); +} + +test "a fault with a status prints the code and its phrase" { + var buf: [64]u8 = undefined; + const refused: Fault = .{ + .kind = error.HttpStatus, + .cause = error.HttpStatus, + .http_status = .http_version_not_supported, + }; + try testing.expectEqualStrings( + "HttpStatus (status 505 HTTP Version Not Supported)", + try std.fmt.bufPrint(&buf, "{f}", .{refused}), + ); + + // A code std has no name for still prints, without a phrase. + const unnamed: Fault = .{ .kind = error.HttpStatus, .cause = error.HttpStatus, .http_status = @enumFromInt(599) }; + try testing.expectEqualStrings("HttpStatus (status 599)", try std.fmt.bufPrint(&buf, "{f}", .{unnamed})); + + const plain: Fault = .{ .kind = error.ConnectFailed, .cause = error.Unexpected }; + try testing.expectEqualStrings("ConnectFailed (cause Unexpected)", try std.fmt.bufPrint(&buf, "{f}", .{plain})); +} + /// Stands in for whatever the pool or the forward client races. The variants /// are the three ways such a task ends: in time, too late, or with a failure of /// its own. diff --git a/src/web/metrics.zig b/src/web/metrics.zig index aa45529..f082e8f 100644 --- a/src/web/metrics.zig +++ b/src/web/metrics.zig @@ -186,6 +186,9 @@ pub const Sample = struct { /// label and cannot live in `UpstreamSample`. Absent while no pool is /// wired, like every other collaborator. upstream_budget_exhausted_total: ?u64 = null, + /// Exchanges the pool ended on this process's own resources. Pool-wide for + /// the same reason as `upstream_budget_exhausted_total`. + upstream_local_resource_total: ?u64 = null, peaks: PeakSample = .{}, }; @@ -300,6 +303,7 @@ pub fn collect(state: *server.WebState, io: std.Io, arena: Allocator) Allocator. if (generation.pool) |pool| { sample.upstreams = try upstreams(pool, io, arena); sample.upstream_budget_exhausted_total = pool.budgetExhaustedTotal(); + sample.upstream_local_resource_total = pool.localResourceTotal(); } } @@ -512,6 +516,15 @@ pub fn render(w: *std.Io.Writer, sample: Sample) std.Io.Writer.Error!void { ); try w.print("nxdns_upstream_budget_exhausted_total {d}\n", .{total}); } + if (sample.upstream_local_resource_total) |total| { + try labeledHead( + w, + "nxdns_upstream_local_resource_total", + "Exchanges this process ended on its own resources (memory, descriptors, an unnamed system error) before any upstream answered.", + "counter", + ); + try w.print("nxdns_upstream_local_resource_total {d}\n", .{total}); + } } fn renderPeaks(w: *std.Io.Writer, peaks: PeakSample) std.Io.Writer.Error!void { @@ -1788,3 +1801,20 @@ test "the budget-exhausted counter renders pool-wide, without a url label" { defer testing.allocator.free(absent); try testing.expect(!std.mem.containsAtLeast(u8, absent, 1, "nxdns_upstream_budget_exhausted_total")); } + +test "the local-resource counter renders pool-wide, without a url label" { + const text = try renderToString(testing.allocator, .{ .upstream_local_resource_total = 4 }); + defer testing.allocator.free(text); + + try testing.expect(std.mem.containsAtLeast( + u8, + text, + 1, + "# TYPE nxdns_upstream_local_resource_total counter\n", + )); + try testing.expect(std.mem.containsAtLeast(u8, text, 1, "nxdns_upstream_local_resource_total 4\n")); + + const absent = try renderToString(testing.allocator, .{}); + defer testing.allocator.free(absent); + try testing.expect(!std.mem.containsAtLeast(u8, absent, 1, "nxdns_upstream_local_resource_total")); +}