search for standard sites pub-search.waow.tech
search zig blog atproto

add http.request span + slow receive logging for latency diagnosis

server-side search is 0-2.5ms but TTFB is 1-2.5s for some requests.
the new http.request span wraps the full request lifecycle including
receiveHead(), and logs a warning when receive takes >100ms. this
will reveal whether the delay is in Fly proxy, connection queueing,
or request reading.

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>

+17
+17
backend/src/server.zig
··· 26 var server = http.Server.init(reader.interface(), &writer.interface); 27 28 while (true) { 29 var request = server.receiveHead() catch |err| { 30 if (err != error.HttpConnectionClosing and err != error.EndOfStream) { 31 logfire.debug("http receive error: {}", .{err}); 32 } 33 return; 34 }; 35 handleRequest(&server, &request) catch |err| { 36 logfire.err("request error: {}", .{err}); 37 return; 38 }; 39 if (!request.head.keep_alive) return; 40 } 41 }
··· 26 var server = http.Server.init(reader.interface(), &writer.interface); 27 28 while (true) { 29 + const recv_start = std.time.microTimestamp(); 30 var request = server.receiveHead() catch |err| { 31 if (err != error.HttpConnectionClosing and err != error.EndOfStream) { 32 logfire.debug("http receive error: {}", .{err}); 33 } 34 return; 35 }; 36 + const recv_us = std.time.microTimestamp() - recv_start; 37 + const target = request.head.target; 38 + 39 + // log slow receives — this captures time waiting for the request to arrive 40 + if (recv_us > 100_000) { // > 100ms 41 + logfire.warn("http.receive slow: {d}ms | {s}", .{ @divTrunc(recv_us, 1000), target }); 42 + } 43 + 44 + const req_span = logfire.span("http.request", .{ 45 + .target = target, 46 + .receive_ms = @divTrunc(recv_us, 1000), 47 + }); 48 + 49 handleRequest(&server, &request) catch |err| { 50 logfire.err("request error: {}", .{err}); 51 + req_span.end(); 52 return; 53 }; 54 + req_span.end(); 55 + 56 if (!request.head.keep_alive) return; 57 } 58 }