From 25ef13f945d542a0691263b096f8f29707de88b8 Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 13:13:53 -0500
Subject: [PATCH 01/11] Add request ids, JSON logs, metrics and an admin
 listener to serve

---
 src/h2.zig        |  13 +-
 src/main.zig      |  67 ++++-
 src/observe.zig   | 681 ++++++++++++++++++++++++++++++++++++++++++++++
 src/platform.zig  |  19 ++
 src/serve.zig     | 370 ++++++++++++++++++++-----
 src/websocket.zig |   7 +-
 6 files changed, 1076 insertions(+), 81 deletions(-)
 create mode 100644 src/observe.zig

diff --git a/src/h2.zig b/src/h2.zig
index a4b4f631..a4739bd7 100644
--- a/src/h2.zig
+++ b/src/h2.zig
@@ -197,21 +197,24 @@ pub const H2Session = struct {
         return null;
     }
 
-    pub fn submitResponse(self: *H2Session, stream_id: i32, status: u16, content_type: []const u8, body: []const u8) void {
+    // request_id, when not empty, is sent as x-request-id
+    pub fn submitResponse(self: *H2Session, stream_id: i32, status: u16, content_type: []const u8, body: []const u8, request_id: []const u8) void {
         // u16 max is 5 digits, valid http statuses are 3
         var status_buf: [5]u8 = undefined;
         const status_str = std.fmt.bufPrint(&status_buf, "{d}", .{status}) catch "500";
 
-        var nv = [_]c.nghttp2_nv{
+        var all_nv = [_]c.nghttp2_nv{
             makeNv(":status", status_str),
             makeNv("content-type", content_type),
+            makeNv("x-request-id", request_id),
         };
+        const nv = all_nv[0 .. if (request_id.len > 0) all_nv.len else all_nv.len - 1];
 
         if (body.len > 0) {
             // find the stream before allocating - if it's gone, body_source
             // would never get attached and onStreamClose would never free it
             const stream = self.findStream(stream_id) orelse {
-                _ = c.nghttp2_submit_response(self.session, stream_id, &nv, nv.len, null);
+                _ = c.nghttp2_submit_response(self.session, stream_id, nv.ptr, nv.len, null);
                 return;
             };
             const src = self.allocator.create(BodySource) catch return;
@@ -227,9 +230,9 @@ pub const H2Session = struct {
                 .source = .{ .ptr = @ptrCast(src) },
                 .read_callback = bodyReadCb,
             };
-            _ = c.nghttp2_submit_response(self.session, stream_id, &nv, nv.len, &prd);
+            _ = c.nghttp2_submit_response(self.session, stream_id, nv.ptr, nv.len, &prd);
         } else {
-            _ = c.nghttp2_submit_response(self.session, stream_id, &nv, nv.len, null);
+            _ = c.nghttp2_submit_response(self.session, stream_id, nv.ptr, nv.len, null);
         }
     }
 };
diff --git a/src/main.zig b/src/main.zig
index 602fb20d..93f5bacf 100644
--- a/src/main.zig
+++ b/src/main.zig
@@ -202,10 +202,39 @@ fn isScriptPath(arg: []const u8) bool {
 }
 
 fn serveCommand(allocator: std.mem.Allocator, args: []const []const u8) !void {
-    try requireArg(args, 3, "usage: zphp serve <file> [--port 8080] [--workers N] [--watch] [--tls-cert FILE --tls-key FILE]\n");
-    var config = @import("serve.zig").ServeConfig{ .file = args[2] };
+    const serve = @import("serve.zig");
+    try requireArg(args, 3, "usage: zphp serve <file> [--port 8080] [--workers N] [--watch] [--tls-cert FILE --tls-key FILE]\n" ++
+        "                  [--admin-port N [--admin-host IP]] [--access-log] [--log-format text|json] [--log-file FILE] [--request-id]\n");
+    var config = serve.ServeConfig{ .file = args[2] };
+    var admin_port: ?u16 = null;
+    var admin_host: ?[]const u8 = null;
+    var log_format: ?serve.LogFormat = null;
     var i: usize = 3;
     while (i < args.len) : (i += 1) {
+        if (std.mem.eql(u8, args[i], "--admin-port")) {
+            const port = std.fmt.parseInt(u16, try serveFlagValue(args, &i), 10) catch 0;
+            if (port == 0) serveConfigError("--admin-port needs a port between 1 and 65535");
+            admin_port = port;
+            continue;
+        } else if (std.mem.eql(u8, args[i], "--admin-host")) {
+            admin_host = try serveFlagValue(args, &i);
+            continue;
+        } else if (std.mem.eql(u8, args[i], "--log-format")) {
+            log_format = std.meta.stringToEnum(serve.LogFormat, try serveFlagValue(args, &i)) orelse
+                serveConfigError("--log-format must be text or json");
+            continue;
+        } else if (std.mem.eql(u8, args[i], "--log-file")) {
+            const path = try serveFlagValue(args, &i);
+            if (path.len == 0) serveConfigError("--log-file needs a path");
+            config.log_file = path;
+            continue;
+        } else if (std.mem.eql(u8, args[i], "--access-log")) {
+            config.access_log = true;
+            continue;
+        } else if (std.mem.eql(u8, args[i], "--request-id")) {
+            config.request_id = true;
+            continue;
+        }
         if (std.mem.eql(u8, args[i], "--port") and i + 1 < args.len) {
             config.port = std.fmt.parseInt(u16, args[i + 1], 10) catch 8080;
             i += 1;
@@ -225,7 +254,38 @@ fn serveCommand(allocator: std.mem.Allocator, args: []const []const u8) !void {
             config.watch = true;
         }
     }
-    try @import("serve.zig").serve(allocator, config);
+
+    if (admin_port) |port| {
+        if (port == config.port) serveConfigError("--admin-port must differ from --port");
+        config.admin_address = @import("net.zig").Address.parseIp(admin_host orelse "127.0.0.1", port) catch
+            serveConfigError("--admin-host must be an IPv4 or IPv6 address");
+    } else if (admin_host != null) {
+        serveConfigError("--admin-host requires --admin-port");
+    }
+    // access logs and log files are JSON Lines, which the text format is not
+    const wants_json = config.access_log or config.log_file != null;
+    if (log_format != null and log_format.? == .text and wants_json) serveConfigError("--access-log and --log-file write JSON lines; drop --log-format text");
+    config.log_format = log_format orelse if (wants_json) .json else .text;
+
+    try serve.serve(allocator, config);
+}
+
+fn serveFlagValue(args: []const []const u8, i: *usize) ![]const u8 {
+    if (i.* + 1 >= args.len) {
+        try writeStderr("error: ");
+        try writeStderr(args[i.*]);
+        try writeStderr(" needs a value\n");
+        std.process.exit(1);
+    }
+    i.* += 1;
+    return args[i.*];
+}
+
+fn serveConfigError(msg: []const u8) noreturn {
+    writeStderr("error: ") catch {};
+    writeStderr(msg) catch {};
+    writeStderr("\n") catch {};
+    std.process.exit(1);
 }
 
 fn requireArg(args: []const []const u8, min: usize, usage: []const u8) !void {
@@ -991,6 +1051,7 @@ test {
     _ = @import("stdlib/date_iso_interval.zig");
     _ = @import("stdlib/phar_path.zig");
     _ = @import("serve.zig");
+    _ = @import("observe.zig");
     _ = @import("stdlib/pcre.zig");
     _ = @import("pipeline/parser_tests.zig");
     _ = @import("integration_tests.zig");
diff --git a/src/observe.zig b/src/observe.zig
new file mode 100644
index 00000000..0b4830e8
--- /dev/null
+++ b/src/observe.zig
@@ -0,0 +1,681 @@
+// production observability for `zphp serve`: request ids, JSON Lines logs,
+// server-wide metrics and the admin listener that serves /health, /ready and
+// /metrics. everything here is configured once before any worker starts and
+// is read-only afterwards, so the request path never takes a lock
+const std = @import("std");
+const platform = @import("platform.zig");
+const sys = @import("sys.zig");
+const net = @import("net.zig");
+
+const posix = std.posix;
+
+// ---------------------------------------------------------------- request ids
+
+pub const max_request_id_len = 64;
+const id_header_prefix = "X-Request-Id: ";
+
+// an incoming id is echoed into a response header and the logs, so only a
+// short token of plain characters is accepted; anything else gets a fresh id
+pub fn validRequestId(id: []const u8) bool {
+    if (id.len == 0 or id.len > max_request_id_len) return false;
+    for (id) |ch| {
+        if (!std.ascii.isAlphanumeric(ch) and ch != '-' and ch != '_' and ch != '.' and ch != ':') return false;
+    }
+    return true;
+}
+
+// the effective id of the request a worker is running, kept with its
+// response header line so writing it costs a single copy
+pub const RequestId = struct {
+    buf: [id_header_prefix.len + max_request_id_len + 2]u8 = undefined,
+    len: usize = 0,
+
+    pub fn assign(self: *RequestId, incoming: ?[]const u8, prng: *std.Random.DefaultPrng) void {
+        @memcpy(self.buf[0..id_header_prefix.len], id_header_prefix);
+        var id_len: usize = 32;
+        const trimmed = if (incoming) |raw| std.mem.trim(u8, raw, " \t") else "";
+        if (validRequestId(trimmed)) {
+            id_len = trimmed.len;
+            @memcpy(self.buf[id_header_prefix.len..][0..id_len], trimmed);
+        } else {
+            const bytes = std.mem.toBytes(prng.next()) ++ std.mem.toBytes(prng.next());
+            const hex = std.fmt.bytesToHex(bytes, .lower);
+            @memcpy(self.buf[id_header_prefix.len..][0..id_len], &hex);
+        }
+        self.len = id_header_prefix.len + id_len + 2;
+        self.buf[self.len - 2] = '\r';
+        self.buf[self.len - 1] = '\n';
+    }
+
+    pub fn id(self: *const RequestId) []const u8 {
+        if (self.len == 0) return "";
+        return self.buf[id_header_prefix.len .. self.len - 2];
+    }
+
+    pub fn header(self: *const RequestId) []const u8 {
+        return self.buf[0..self.len];
+    }
+};
+
+pub fn seededPrng() std.Random.DefaultPrng {
+    var seed: u64 = undefined;
+    platform.random.bytes(std.mem.asBytes(&seed));
+    return .init(seed);
+}
+
+// ---------------------------------------------------------------- settings
+
+// set by serve() before any thread starts
+pub var log_json = false;
+pub var access_log = false;
+pub var request_ids = false;
+pub var metrics_enabled = false;
+
+var log_file: ?std.Io.File = null;
+var log_file_owned = false;
+
+pub fn openLog(path: ?[]const u8) !void {
+    if (path) |p| {
+        log_file = try platform.openAppend(p, false);
+        log_file_owned = true;
+    } else {
+        log_file = platform.stdout();
+    }
+}
+
+pub fn closeLog() void {
+    if (log_file_owned) if (log_file) |f| f.close(platform.io);
+    log_file = null;
+    log_file_owned = false;
+}
+
+// ---------------------------------------------------------------- JSON Lines
+
+// one log line, built on the stack and handed to the destination in a single
+// write. lines stay within the pipe atomicity limit, and the log file is
+// opened for append, so lines from concurrent workers never interleave.
+// fields that do not fit are dropped whole and strings are cut short, which
+// keeps every line valid JSON whatever the input
+pub const Record = struct {
+    buf: [4096]u8 = undefined,
+    len: usize = 0,
+
+    const tail = 2; // "}\n"
+
+    pub fn init(level: []const u8, component: []const u8, msg: []const u8) Record {
+        var r: Record = .{};
+        r.put("{\"ts\":\"");
+        r.timestamp(platform.milliTimestamp());
+        r.put("\"");
+        r.str("level", level);
+        r.str("component", component);
+        r.str("msg", msg);
+        return r;
+    }
+
+    fn room(r: *const Record) usize {
+        return r.buf.len - tail - r.len;
+    }
+
+    fn put(r: *Record, data: []const u8) void {
+        @memcpy(r.buf[r.len..][0..data.len], data);
+        r.len += data.len;
+    }
+
+    fn key(r: *Record, name: []const u8) void {
+        r.put(",\"");
+        r.put(name);
+        r.put("\":");
+    }
+
+    pub fn str(r: *Record, name: []const u8, value: []const u8) void {
+        if (r.room() < name.len + 8) return;
+        r.key(name);
+        r.put("\"");
+        r.escape(value);
+        r.put("\"");
+    }
+
+    pub fn int(r: *Record, name: []const u8, value: anytype) void {
+        if (r.room() < name.len + 24) return;
+        r.key(name);
+        r.len += (std.fmt.bufPrint(r.buf[r.len..], "{d}", .{value}) catch unreachable).len;
+    }
+
+    pub fn boolean(r: *Record, name: []const u8, value: bool) void {
+        if (r.room() < name.len + 8) return;
+        r.key(name);
+        r.put(if (value) "true" else "false");
+    }
+
+    // milliseconds with microsecond precision
+    pub fn millis(r: *Record, name: []const u8, ns: u64) void {
+        if (r.room() < name.len + 28) return;
+        r.key(name);
+        const us = ns / std.time.ns_per_us;
+        r.len += (std.fmt.bufPrint(r.buf[r.len..], "{d}.{d:0>3}", .{ us / 1000, us % 1000 }) catch unreachable).len;
+    }
+
+    // invalid UTF-8 becomes U+FFFD and control bytes are \u escaped, so
+    // request paths and exception messages cannot break or forge a line.
+    // one byte is always left for the closing quote
+    fn escape(r: *Record, s: []const u8) void {
+        var i: usize = 0;
+        while (i < s.len) {
+            if (r.room() < 7) return;
+            const ch = s[i];
+            if (ch < 0x80) {
+                switch (ch) {
+                    '"' => r.put("\\\""),
+                    '\\' => r.put("\\\\"),
+                    '\n' => r.put("\\n"),
+                    '\r' => r.put("\\r"),
+                    '\t' => r.put("\\t"),
+                    0...0x08, 0x0b, 0x0c, 0x0e...0x1f, 0x7f => {
+                        r.len += (std.fmt.bufPrint(r.buf[r.len..], "\\u{x:0>4}", .{ch}) catch unreachable).len;
+                    },
+                    else => r.put(&[_]u8{ch}),
+                }
+                i += 1;
+                continue;
+            }
+            const n = std.unicode.utf8ByteSequenceLength(ch) catch 0;
+            if (n == 0 or i + n > s.len or !std.unicode.utf8ValidateSlice(s[i .. i + n])) {
+                r.put("\\ufffd");
+                i += 1;
+                continue;
+            }
+            r.put(s[i .. i + n]);
+            i += n;
+        }
+    }
+
+    fn timestamp(r: *Record, ms: i64) void {
+        const total_ms: u64 = @intCast(@max(ms, 0));
+        const secs = std.time.epoch.EpochSeconds{ .secs = total_ms / 1000 };
+        const year_day = secs.getEpochDay().calculateYearDay();
+        const month_day = year_day.calculateMonthDay();
+        const day_secs = secs.getDaySeconds();
+        r.len += (std.fmt.bufPrint(r.buf[r.len..], "{d:0>4}-{d:0>2}-{d:0>2}T{d:0>2}:{d:0>2}:{d:0>2}.{d:0>3}Z", .{
+            year_day.year,
+            month_day.month.numeric(),
+            month_day.day_index + 1,
+            day_secs.getHoursIntoDay(),
+            day_secs.getMinutesIntoHour(),
+            day_secs.getSecondsIntoMinute(),
+            total_ms % 1000,
+        }) catch unreachable).len;
+    }
+
+    pub fn bytes(r: *Record) []const u8 {
+        r.put("}\n");
+        return r.buf[0..r.len];
+    }
+
+    // a failed write is counted and otherwise ignored: logging must never
+    // take down a request or the server
+    pub fn emit(r: *Record) void {
+        const line = r.bytes();
+        const file = log_file orelse return;
+        platform.writeAll(file, line) catch {
+            _ = global.log_errors.fetchAdd(1, .monotonic);
+        };
+    }
+};
+
+// ---------------------------------------------------------------- metrics
+
+// a value with a single writer: plain loads and stores, no read-modify-write,
+// so a worker never contends with anyone over its own counters
+const Cell = struct {
+    v: std.atomic.Value(u64) = .init(0),
+
+    pub inline fn add(c: *Cell, n: u64) void {
+        c.v.store(c.v.load(.monotonic) +% n, .monotonic);
+    }
+
+    pub inline fn set(c: *Cell, n: u64) void {
+        c.v.store(n, .monotonic);
+    }
+
+    pub inline fn get(c: *const Cell) u64 {
+        return c.v.load(.monotonic);
+    }
+};
+
+// request duration bucket bounds, in microseconds and as Prometheus labels
+const bucket_bounds_us = [_]u64{ 1_000, 2_500, 5_000, 10_000, 25_000, 50_000, 100_000, 250_000, 500_000, 1_000_000, 2_500_000, 5_000_000, 10_000_000 };
+const bucket_labels = [_][]const u8{ "0.001", "0.0025", "0.005", "0.01", "0.025", "0.05", "0.1", "0.25", "0.5", "1", "2.5", "5", "10" };
+const status_labels = [_][]const u8{ "1xx", "2xx", "3xx", "4xx", "5xx" };
+
+fn bucketIndex(ns: u64) usize {
+    for (bucket_bounds_us, 0..) |us, i| {
+        if (ns <= us * std.time.ns_per_us) return i;
+    }
+    return bucket_bounds_us.len;
+}
+
+// written only by the worker that owns it; the admin thread sums all of them.
+// each worker gets its own cache lines so no counter is ever shared
+pub const WorkerStats = struct {
+    requests: [status_labels.len]Cell align(std.atomic.cache_line) = @splat(.{}),
+    buckets: [bucket_bounds_us.len + 1]Cell = @splat(.{}),
+    duration_ns: Cell = .{},
+    busy: Cell = .{},
+    connections: Cell = .{},
+    connections_dropped: Cell = .{},
+    vm_memory: Cell = .{},
+
+    pub fn requestStarted(s: *WorkerStats) void {
+        s.busy.set(1);
+    }
+
+    pub fn requestFinished(s: *WorkerStats, status: i64, elapsed_ns: u64, vm_memory: usize) void {
+        const class: usize = @intCast(std.math.clamp(@divTrunc(status, 100), 1, 5) - 1);
+        s.buckets[bucketIndex(elapsed_ns)].add(1);
+        s.duration_ns.add(elapsed_ns);
+        s.requests[class].add(1);
+        s.vm_memory.set(vm_memory);
+        s.busy.set(0);
+    }
+
+    pub fn setConnections(s: *WorkerStats, n: usize) void {
+        s.connections.set(n);
+    }
+
+    pub fn connectionDropped(s: *WorkerStats) void {
+        s.connections_dropped.add(1);
+    }
+
+    // a stopped worker holds no connections and runs nothing; its totals stay
+    pub fn stopped(s: *WorkerStats) void {
+        s.busy.set(0);
+        s.connections.set(0);
+    }
+};
+
+// process-wide values. the main thread is the only writer of everything but
+// log_errors, which any thread may bump
+pub const Global = struct {
+    start_ms: i64 = 0,
+    ready: std.atomic.Value(bool) = .init(false),
+    workers_configured: Cell = .{},
+    workers_running: Cell = .{},
+    worker_start_failures: Cell = .{},
+    reloads: Cell = .{},
+    accepted: Cell = .{},
+    log_errors: std.atomic.Value(u64) = .init(0),
+
+    pub fn connectionAccepted(g: *Global) void {
+        g.accepted.add(1);
+    }
+
+    pub fn workerStartFailed(g: *Global) void {
+        g.worker_start_failures.add(1);
+    }
+
+    pub fn reloaded(g: *Global) void {
+        g.reloads.add(1);
+    }
+
+    pub fn setWorkers(g: *Global, running: usize, ready_now: bool) void {
+        g.workers_running.set(running);
+        g.ready.store(ready_now and running > 0, .release);
+    }
+};
+
+pub var global: Global = .{};
+
+// one slot per configured worker. allocated before the admin thread starts
+// and freed only after it has been joined
+pub var worker_stats: []WorkerStats = &.{};
+
+pub fn statsFor(slot: usize) ?*WorkerStats {
+    if (slot >= worker_stats.len) return null;
+    return &worker_stats[slot];
+}
+
+const Totals = struct {
+    requests: [status_labels.len]u64 = @splat(0),
+    buckets: [bucket_bounds_us.len + 1]u64 = @splat(0),
+    duration_ns: u64 = 0,
+    busy: u64 = 0,
+    connections: u64 = 0,
+    connections_dropped: u64 = 0,
+    vm_memory: u64 = 0,
+};
+
+fn sumWorkers() Totals {
+    var t: Totals = .{};
+    for (worker_stats) |*s| {
+        for (&t.requests, &s.requests) |*dst, *src| dst.* +%= src.get();
+        for (&t.buckets, &s.buckets) |*dst, *src| dst.* +%= src.get();
+        t.duration_ns +%= s.duration_ns.get();
+        t.busy += s.busy.get();
+        t.connections += s.connections.get();
+        t.connections_dropped +%= s.connections_dropped.get();
+        t.vm_memory += s.vm_memory.get();
+    }
+    return t;
+}
+
+fn seconds(w: *std.Io.Writer, ns: u64) !void {
+    try w.print("{d}.{d:0>9}", .{ ns / std.time.ns_per_s, ns % std.time.ns_per_s });
+}
+
+fn metric(w: *std.Io.Writer, name: []const u8, kind: []const u8, help: []const u8) !void {
+    try w.print("# HELP {s} {s}\n# TYPE {s} {s}\n", .{ name, help, name, kind });
+}
+
+// Prometheus text exposition format 0.0.4
+pub fn renderMetrics(w: *std.Io.Writer) !void {
+    const t = sumWorkers();
+
+    try metric(w, "zphp_http_requests_total", "counter", "HTTP requests answered, by status class.");
+    for (status_labels, t.requests) |label, n| try w.print("zphp_http_requests_total{{code=\"{s}\"}} {d}\n", .{ label, n });
+
+    // the count is the sum of the buckets read here, so +Inf always equals it
+    try metric(w, "zphp_http_request_duration_seconds", "histogram", "Time from a complete request to its response being written.");
+    var cumulative: u64 = 0;
+    for (bucket_labels, 0..) |label, i| {
+        cumulative += t.buckets[i];
+        try w.print("zphp_http_request_duration_seconds_bucket{{le=\"{s}\"}} {d}\n", .{ label, cumulative });
+    }
+    cumulative += t.buckets[bucket_labels.len];
+    try w.print("zphp_http_request_duration_seconds_bucket{{le=\"+Inf\"}} {d}\n", .{cumulative});
+    try w.writeAll("zphp_http_request_duration_seconds_sum ");
+    try seconds(w, t.duration_ns);
+    try w.print("\nzphp_http_request_duration_seconds_count {d}\n", .{cumulative});
+
+    try metric(w, "zphp_http_requests_active", "gauge", "Requests being handled right now.");
+    try w.print("zphp_http_requests_active {d}\n", .{t.busy});
+
+    try metric(w, "zphp_connections_active", "gauge", "Client connections held by workers.");
+    try w.print("zphp_connections_active {d}\n", .{t.connections});
+    try metric(w, "zphp_connections_accepted_total", "counter", "Client connections accepted.");
+    try w.print("zphp_connections_accepted_total {d}\n", .{global.accepted.get()});
+    try metric(w, "zphp_connections_dropped_total", "counter", "Connections closed on arrival because a worker's connection table was full.");
+    try w.print("zphp_connections_dropped_total {d}\n", .{t.connections_dropped});
+
+    try metric(w, "zphp_workers", "gauge", "Configured worker threads.");
+    try w.print("zphp_workers {d}\n", .{global.workers_configured.get()});
+    try metric(w, "zphp_workers_running", "gauge", "Worker threads currently running.");
+    try w.print("zphp_workers_running {d}\n", .{global.workers_running.get()});
+    try metric(w, "zphp_worker_busy_seconds_total", "counter", "Time workers spent handling requests; its rate over the worker count is utilization.");
+    try w.writeAll("zphp_worker_busy_seconds_total ");
+    try seconds(w, t.duration_ns);
+    try w.writeAll("\n");
+    try metric(w, "zphp_worker_start_failures_total", "counter", "Workers that failed to start.");
+    try w.print("zphp_worker_start_failures_total {d}\n", .{global.worker_start_failures.get()});
+    try metric(w, "zphp_reloads_total", "counter", "Worker restarts triggered by --watch.");
+    try w.print("zphp_reloads_total {d}\n", .{global.reloads.get()});
+
+    try metric(w, "zphp_vm_memory_bytes", "gauge", "PHP memory in use by the worker VMs at the end of their last request.");
+    try w.print("zphp_vm_memory_bytes {d}\n", .{t.vm_memory});
+    if (platform.currentRss()) |rss| {
+        try metric(w, "process_resident_memory_bytes", "gauge", "Resident memory size in bytes.");
+        try w.print("process_resident_memory_bytes {d}\n", .{rss});
+    }
+    try metric(w, "process_resident_memory_max_bytes", "gauge", "Peak resident memory size in bytes.");
+    try w.print("process_resident_memory_max_bytes {d}\n", .{platform.peakRss()});
+    try metric(w, "process_start_time_seconds", "gauge", "Start time of the process since the unix epoch in seconds.");
+    const start_ms: u64 = @intCast(@max(global.start_ms, 0));
+    try w.print("process_start_time_seconds {d}.{d:0>3}\n", .{ start_ms / 1000, start_ms % 1000 });
+    try metric(w, "zphp_uptime_seconds", "gauge", "Seconds since the server started.");
+    try w.print("zphp_uptime_seconds {d}\n", .{@divFloor(@max(platform.milliTimestamp() - global.start_ms, 0), 1000)});
+
+    try metric(w, "zphp_ready", "gauge", "1 when the server accepts application requests, as /ready reports.");
+    try w.print("zphp_ready {d}\n", .{@intFromBool(global.ready.load(.acquire))});
+    try metric(w, "zphp_log_write_errors_total", "counter", "Log lines that could not be written.");
+    try w.print("zphp_log_write_errors_total {d}\n", .{global.log_errors.load(.monotonic)});
+}
+
+// ---------------------------------------------------------------- admin listener
+
+// a separate loopback-by-default listener on its own thread, so probes and
+// scrapes never collide with application routes, never run PHP, and keep
+// answering while every worker is busy. clients are served one at a time
+// with a short deadline, which bounds what a stalled client can hold
+pub const Admin = struct {
+    server: net.Server,
+    wake: [2]posix.socket_t,
+    thread: std.Thread,
+
+    const io_deadline_ns: i128 = 2 * std.time.ns_per_s;
+
+    pub fn start(self: *Admin, addr: net.Address) !void {
+        self.server = try platform.tcpListen(addr, true);
+        errdefer self.server.deinit();
+        try platform.setNonBlocking(self.server.stream.handle, true);
+        self.wake = try platform.socketPair();
+        errdefer closePair(self.wake);
+        self.thread = try std.Thread.spawn(.{}, loop, .{self});
+    }
+
+    pub fn stop(self: *Admin) void {
+        _ = platform.send(self.wake[1], &[_]u8{1}) catch {};
+        self.thread.join();
+        closePair(self.wake);
+        self.server.deinit();
+    }
+
+    fn closePair(pair: [2]posix.socket_t) void {
+        platform.closeSocket(platform.socketToInt(pair[0]));
+        platform.closeSocket(platform.socketToInt(pair[1]));
+    }
+
+    fn loop(self: *Admin) void {
+        var fds = [2]sys.pollfd{
+            .{ .fd = self.server.stream.handle, .events = sys.POLL.IN, .revents = 0 },
+            .{ .fd = self.wake[0], .events = sys.POLL.IN, .revents = 0 },
+        };
+        while (true) {
+            _ = sys.poll(&fds, -1) catch {
+                platform.sleep(10 * std.time.ns_per_ms);
+                continue;
+            };
+            if (fds[1].revents != 0) return;
+            if (fds[0].revents & sys.POLL.IN == 0) continue;
+            const conn = self.server.accept() catch continue;
+            handle(conn.stream.handle);
+            conn.stream.close();
+        }
+    }
+
+    fn waitFor(sock: posix.socket_t, events: i16, deadline: i128) bool {
+        const left = deadline - platform.monotonicNanos();
+        if (left <= 0) return false;
+        var fds = [1]sys.pollfd{.{ .fd = sock, .events = events, .revents = 0 }};
+        const ms: i32 = @intCast(@min(@divTrunc(left, std.time.ns_per_ms) + 1, std.math.maxInt(i32)));
+        const ready = sys.poll(&fds, ms) catch return false;
+        return ready > 0;
+    }
+
+    fn sendAll(sock: posix.socket_t, data: []const u8, deadline: i128) bool {
+        var sent: usize = 0;
+        while (sent < data.len) {
+            const n = platform.send(sock, data[sent..]) catch |err| {
+                if (err == error.WouldBlock and waitFor(sock, sys.POLL.OUT, deadline)) continue;
+                return false;
+            };
+            sent += n;
+        }
+        return true;
+    }
+
+    fn handle(sock: posix.socket_t) void {
+        platform.setNonBlocking(sock, true) catch return;
+        const deadline = platform.monotonicNanos() + io_deadline_ns;
+        var buf: [2048]u8 = undefined;
+        var n: usize = 0;
+        while (std.mem.indexOf(u8, buf[0..n], "\r\n\r\n") == null) {
+            if (n == buf.len) return respond(sock, deadline, 431, "Request Header Fields Too Large", "text/plain; charset=utf-8", "request too large\n", false);
+            const got = platform.recv(sock, buf[n..]) catch |err| {
+                if (err == error.WouldBlock and waitFor(sock, sys.POLL.IN, deadline)) continue;
+                return;
+            };
+            if (got == 0) return;
+            n += got;
+        }
+        const line = buf[0 .. std.mem.indexOf(u8, buf[0..n], "\r\n") orelse n];
+        var parts = std.mem.tokenizeScalar(u8, line, ' ');
+        const method = parts.next() orelse "";
+        const target = parts.next() orelse "";
+        const path = target[0 .. std.mem.indexOfScalar(u8, target, '?') orelse target.len];
+        const head = std.mem.eql(u8, method, "HEAD");
+        if (!head and !std.mem.eql(u8, method, "GET")) {
+            return respond(sock, deadline, 405, "Method Not Allowed", "text/plain; charset=utf-8", "method not allowed\n", false);
+        }
+
+        if (std.mem.eql(u8, path, "/health")) {
+            respond(sock, deadline, 200, "OK", "text/plain; charset=utf-8", "ok\n", head);
+        } else if (std.mem.eql(u8, path, "/ready")) {
+            if (global.ready.load(.acquire)) {
+                respond(sock, deadline, 200, "OK", "text/plain; charset=utf-8", "ready\n", head);
+            } else {
+                respond(sock, deadline, 503, "Service Unavailable", "text/plain; charset=utf-8", "not ready\n", head);
+            }
+        } else if (std.mem.eql(u8, path, "/metrics")) {
+            var body: [16384]u8 = undefined;
+            var w: std.Io.Writer = .fixed(&body);
+            renderMetrics(&w) catch {};
+            respond(sock, deadline, 200, "OK", "text/plain; version=0.0.4; charset=utf-8", w.buffered(), head);
+        } else {
+            respond(sock, deadline, 404, "Not Found", "text/plain; charset=utf-8", "not found\n", head);
+        }
+    }
+
+    fn respond(sock: posix.socket_t, deadline: i128, code: u16, reason: []const u8, content_type: []const u8, body: []const u8, head: bool) void {
+        var hdr: [256]u8 = undefined;
+        const allow = if (code == 405) "Allow: GET, HEAD\r\n" else "";
+        const text = std.fmt.bufPrint(&hdr, "HTTP/1.1 {d} {s}\r\nContent-Type: {s}\r\nContent-Length: {d}\r\nCache-Control: no-store\r\n{s}Connection: close\r\n\r\n", .{ code, reason, content_type, body.len, allow }) catch return;
+        if (!sendAll(sock, text, deadline)) return;
+        if (!head) _ = sendAll(sock, body, deadline);
+    }
+};
+
+// ---------------------------------------------------------------- tests
+
+const testing = std.testing;
+
+test "request ids accept safe incoming tokens and replace anything else" {
+    var prng = std.Random.DefaultPrng.init(1);
+    var rid: RequestId = .{};
+
+    rid.assign("abc-123_x.y:z", &prng);
+    try testing.expectEqualStrings("abc-123_x.y:z", rid.id());
+    try testing.expectEqualStrings("X-Request-Id: abc-123_x.y:z\r\n", rid.header());
+
+    rid.assign("  padded  ", &prng);
+    try testing.expectEqualStrings("padded", rid.id());
+
+    const hostile = [_][]const u8{ "", "a\r\nSet-Cookie: x=1", "a b", "\"quoted\"", &@as([65]u8, @splat('x')), "caf\xc3\xa9", "a\x00b" };
+    for (hostile) |bad| {
+        rid.assign(bad, &prng);
+        try testing.expectEqual(@as(usize, 32), rid.id().len);
+        for (rid.id()) |ch| try testing.expect(std.ascii.isHex(ch));
+    }
+
+    rid.assign(&@as([64]u8, @splat('x')), &prng);
+    try testing.expectEqual(@as(usize, 64), rid.id().len);
+
+    rid.assign(null, &prng);
+    const first = rid.id()[0..32].*;
+    rid.assign(null, &prng);
+    try testing.expect(!std.mem.eql(u8, &first, rid.id()));
+}
+
+test "log records are valid JSON whatever the input" {
+    var r = Record.init("info", "access", "request");
+    r.str("path", "/a\"b\\c\n\r\t\x01\x7f\xff\xc3(caf\xc3\xa9");
+    r.int("status", @as(i64, 200));
+    r.boolean("tls", false);
+    r.millis("duration_ms", 1_234_567);
+    const line = r.bytes();
+    try testing.expect(std.mem.endsWith(u8, line, "}\n"));
+    try testing.expectEqual(@as(usize, 1), std.mem.count(u8, line, "\n"));
+
+    const parsed = try std.json.parseFromSlice(std.json.Value, testing.allocator, line, .{});
+    defer parsed.deinit();
+    const obj = parsed.value.object;
+    try testing.expectEqualStrings("/a\"b\\c\n\r\t\x01\x7f\u{fffd}\u{fffd}(café", obj.get("path").?.string);
+    try testing.expectEqual(@as(i64, 200), obj.get("status").?.integer);
+    try testing.expectEqualStrings("access", obj.get("component").?.string);
+    try testing.expectEqual(@as(f64, 1.234), obj.get("duration_ms").?.float);
+    try testing.expect(obj.get("ts").?.string.len == "2026-01-01T00:00:00.000Z".len);
+}
+
+test "oversized log fields are cut short and the line stays valid" {
+    var r = Record.init("error", "php", "uncaught exception");
+    const huge: [5000]u8 = @splat(1);
+    r.str("message", &huge);
+    r.str("exception", "RuntimeException");
+    r.int("line", @as(i64, 42));
+    const line = r.bytes();
+    try testing.expect(line.len <= 4096);
+    const parsed = try std.json.parseFromSlice(std.json.Value, testing.allocator, line, .{});
+    defer parsed.deinit();
+    try testing.expect(parsed.value.object.get("message") != null);
+}
+
+test "log timestamps are RFC 3339 UTC" {
+    var r: Record = .{};
+    r.timestamp(951_782_400_123); // 2000-02-29 00:00:00.123
+    try testing.expectEqualStrings("2000-02-29T00:00:00.123Z", r.buf[0..r.len]);
+}
+
+test "metrics aggregate every worker and keep the histogram consistent" {
+    var slots: [2]WorkerStats = .{ .{}, .{} };
+    const saved = worker_stats;
+    const saved_global = global;
+    worker_stats = &slots;
+    global.start_ms = 1_700_000_000_042;
+    defer {
+        worker_stats = saved;
+        global = saved_global;
+    }
+
+    slots[0].requestStarted();
+    slots[0].requestFinished(200, 500 * std.time.ns_per_us, 1000);
+    slots[1].requestFinished(404, 30 * std.time.ns_per_ms, 2000);
+    slots[1].requestFinished(503, 20 * std.time.ns_per_s, 2000);
+    slots[1].requestFinished(0, 0, 2000);
+    slots[1].requestStarted();
+    slots[0].setConnections(3);
+    slots[1].setConnections(4);
+
+    var buf: [16384]u8 = undefined;
+    var w: std.Io.Writer = .fixed(&buf);
+    try renderMetrics(&w);
+    const out = w.buffered();
+
+    const expect = [_][]const u8{
+        "zphp_http_requests_total{code=\"1xx\"} 1\n",
+        "zphp_http_requests_total{code=\"2xx\"} 1\n",
+        "zphp_http_requests_total{code=\"4xx\"} 1\n",
+        "zphp_http_requests_total{code=\"5xx\"} 1\n",
+        "zphp_http_request_duration_seconds_bucket{le=\"0.001\"} 2\n",
+        "zphp_http_request_duration_seconds_bucket{le=\"0.025\"} 2\n",
+        "zphp_http_request_duration_seconds_bucket{le=\"0.05\"} 3\n",
+        "zphp_http_request_duration_seconds_bucket{le=\"10\"} 3\n",
+        "zphp_http_request_duration_seconds_bucket{le=\"+Inf\"} 4\n",
+        "zphp_http_request_duration_seconds_count 4\n",
+        "zphp_http_request_duration_seconds_sum 20.030500000\n",
+        "zphp_http_requests_active 1\n",
+        "zphp_connections_active 7\n",
+        "zphp_vm_memory_bytes 3000\n",
+        "process_start_time_seconds 1700000000.042\n",
+    };
+    for (expect) |line| {
+        if (std.mem.indexOf(u8, out, line) == null) {
+            std.debug.print("missing: {s}\n{s}\n", .{ line, out });
+            return error.TestExpectedEqual;
+        }
+    }
+
+    slots[1].stopped();
+    w = .fixed(&buf);
+    try renderMetrics(&w);
+    try testing.expect(std.mem.indexOf(u8, w.buffered(), "zphp_connections_active 3\n") != null);
+    try testing.expect(std.mem.indexOf(u8, w.buffered(), "zphp_http_requests_active 0\n") != null);
+}
diff --git a/src/platform.zig b/src/platform.zig
index 5b78727c..bc55d389 100644
--- a/src/platform.zig
+++ b/src/platform.zig
@@ -526,6 +526,25 @@ pub fn peakRss() i64 {
     }
 }
 
+// the process's current resident size, where the os reports it cheaply
+pub fn currentRss() ?u64 {
+    if (is_windows) {
+        var counters: ProcessMemoryCounters = undefined;
+        counters.cb = @sizeOf(ProcessMemoryCounters);
+        if (K32GetProcessMemoryInfo(win32.GetCurrentProcess(), &counters, counters.cb) == 0) return null;
+        return counters.working_set_size;
+    }
+    if (builtin.os.tag != .linux) return null;
+    const file = std.Io.Dir.cwd().openFile(io, "/proc/self/statm", .{}) catch return null;
+    defer file.close(io);
+    var buf: [128]u8 = undefined;
+    const n = read(file, &buf) catch return null;
+    var fields = std.mem.tokenizeScalar(u8, buf[0..n], ' ');
+    _ = fields.next() orelse return null;
+    const pages = std.fmt.parseInt(u64, fields.next() orelse return null, 10) catch return null;
+    return pages * std.heap.pageSize();
+}
+
 // windows' read-only attribute is the only "not writable" a plain file has
 pub fn isReadOnly(path: []const u8) bool {
     if (!is_windows) return false;
diff --git a/src/serve.zig b/src/serve.zig
index 4277dc58..22ddfbd9 100644
--- a/src/serve.zig
+++ b/src/serve.zig
@@ -16,6 +16,7 @@ const platform = @import("platform.zig");
 const tls = @import("tls.zig");
 const h2 = @import("h2.zig");
 const env = @import("env.zig");
+const observe = @import("observe.zig");
 
 const Allocator = std.mem.Allocator;
 const posix = std.posix;
@@ -77,8 +78,17 @@ pub const ServeConfig = struct {
     // being read is closed; 0 disables. keeps stalled and slow-drip clients
     // from holding the per-worker connection table forever
     idle_timeout_seconds: u32 = 60,
+    // observability, all off by default. the admin listener serves /health,
+    // /ready and /metrics, and metrics are only collected while it is on
+    admin_address: ?net.Address = null,
+    log_format: LogFormat = .text,
+    log_file: ?[]const u8 = null,
+    access_log: bool = false,
+    request_id: bool = false,
 };
 
+pub const LogFormat = enum { text, json };
+
 const MAX_BODY_BYTES: usize = 64 * 1024 * 1024;
 
 const Request = struct {
@@ -117,6 +127,7 @@ const Connection = struct {
     ws_obj: ?*PhpObject,
     h2_session: ?*h2.H2Session,
     last_activity_ms: i64,
+    bytes_out: u64 = 0,
 
     fn init(allocator: Allocator, server_conn: net.Server.Connection, ssl_ptr: ?*tls.SSL) !Connection {
         return .{
@@ -140,8 +151,9 @@ const Connection = struct {
     }
 
     fn ioWrite(self: *Connection, data: []const u8) !usize {
-        if (self.ssl) |s| return tls.write(s, data);
-        return platform.send(self.fd, data);
+        const n = if (self.ssl) |s| try tls.write(s, data) else try platform.send(self.fd, data);
+        self.bytes_out +%= n;
+        return n;
     }
 
     pub fn write(self: *Connection, data: []const u8) !usize {
@@ -248,8 +260,105 @@ const Worker = struct {
     // the process umask a request may change with umask(); restored before
     // the next request runs, as php_request_shutdown does
     umask: Umask.Mask,
+    // observability: `tracing` is false unless some feature needs per-request
+    // timing or an id, so with everything off each hook is one branch
+    id: u16,
+    tracing: bool,
+    stats: ?*observe.WorkerStats,
+    prng: std.Random.DefaultPrng,
+    request_id: observe.RequestId,
+};
+
+// per-request observability state, inert when tracing is off
+const Trace = struct {
+    start_ns: i128 = 0,
+    bytes_before: u64 = 0,
+    id_header: []const u8 = "",
 };
 
+fn beginTrace(w: *Worker, req: *const Request, bytes_before: u64) Trace {
+    if (!w.tracing) return .{};
+    if (w.stats) |s| s.requestStarted();
+    var t: Trace = .{ .start_ns = platform.monotonicNanos(), .bytes_before = bytes_before };
+    if (observe.request_ids) {
+        w.request_id.assign(req.getHeader("X-Request-Id"), &w.prng);
+        t.id_header = w.request_id.header();
+    }
+    return t;
+}
+
+// every request that began a trace ends it exactly once, whatever the outcome
+fn endTrace(w: *Worker, t: *const Trace, req: *const Request, protocol: []const u8, addr_bytes: u32, status: i64, bytes_after: u64) void {
+    if (!w.tracing) return;
+    const elapsed: u64 = @intCast(@max(platform.monotonicNanos() - t.start_ns, 0));
+    if (w.stats) |s| s.requestFinished(status, elapsed, if (w.vm.memory) |m| m.usage() else 0);
+    if (!observe.access_log) return;
+    var r = observe.Record.init("info", "access", "request");
+    r.str("request_id", w.request_id.id());
+    r.int("worker", w.id);
+    r.str("method", req.method);
+    r.str("path", req.path);
+    r.str("protocol", protocol);
+    r.int("status", status);
+    r.int("bytes", bytes_after -% t.bytes_before);
+    r.millis("duration_ms", elapsed);
+    var addr_buf: [16]u8 = undefined;
+    r.str("remote_addr", formatIp4(addr_bytes, &addr_buf));
+    r.emit();
+}
+
+fn formatIp4(addr_bytes: u32, buf: *[16]u8) []const u8 {
+    return std.fmt.bufPrint(buf, "{d}.{d}.{d}.{d}", .{
+        @as(u8, @truncate(addr_bytes)),
+        @as(u8, @truncate(addr_bytes >> 8)),
+        @as(u8, @truncate(addr_bytes >> 16)),
+        @as(u8, @truncate(addr_bytes >> 24)),
+    }) catch "0.0.0.0";
+}
+
+// a request that failed inside the server rather than in PHP code; the
+// details stay in the log and never reach the client
+fn logRequestError(w: *Worker, msg: []const u8, err_name: []const u8) void {
+    if (!observe.log_json) return;
+    var r = observe.Record.init("error", "php", msg);
+    if (observe.request_ids) r.str("request_id", w.request_id.id());
+    r.int("worker", w.id);
+    r.str("error", err_name);
+    if (w.vm.error_msg) |m| r.str("detail", m[0..@min(m.len, 1024)]);
+    r.emit();
+}
+
+fn logUncaught(w: *Worker) void {
+    if (!observe.log_json) return;
+    const ex = w.vm.pending_exception orelse return;
+    var r = observe.Record.init("error", "php", "uncaught exception");
+    if (observe.request_ids) r.str("request_id", w.request_id.id());
+    r.int("worker", w.id);
+    if (ex == .object) {
+        r.str("exception", ex.object.class_name);
+        const message = ex.object.get("message");
+        if (message == .string) {
+            const text = message.string.bytes();
+            r.str("message", text[0..@min(text.len, 1024)]);
+        }
+        const file = ex.object.get("file");
+        if (file == .string) r.str("file", file.string.bytes());
+        const line = ex.object.get("line");
+        if (line == .int) r.int("line", line.int);
+    }
+    r.emit();
+}
+
+// a server lifecycle message: the existing text on stderr, or a JSON line
+fn logEvent(level: []const u8, msg: []const u8, text: []const u8) void {
+    if (observe.log_json) {
+        var r = observe.Record.init(level, "server", msg);
+        r.emit();
+    } else {
+        writeStderr(text) catch {};
+    }
+}
+
 // what to run for a request, and how to shape $_SERVER for it
 const Dispatch = struct {
     result: *const CompileResult,
@@ -312,7 +421,8 @@ fn loadFile(path: []const u8, allocator: Allocator, vm: *@import("runtime/vm.zig
     return heap_result;
 }
 
-fn initWorker(allocator: Allocator, result: *const CompileResult, doc_root: []const u8, port: u16, ws_enabled: bool, tls_ctx: ?*tls.SSL_CTX, idle_timeout_ms: i64) !Worker {
+fn initWorker(allocator: Allocator, slot: usize, result: *const CompileResult, doc_root: []const u8, port: u16, ws_enabled: bool, tls_ctx: ?*tls.SSL_CTX, idle_timeout_ms: i64) !Worker {
+    const stats = if (observe.metrics_enabled) observe.statsFor(slot) else null;
     var vm = try VM.init(allocator);
     errdefer vm.deinit();
     vm.file_loader = &loadFile;
@@ -336,6 +446,11 @@ fn initWorker(allocator: Allocator, result: *const CompileResult, doc_root: []co
         .n_fds = 1,
         .script_cache = .{},
         .umask = Umask.current(),
+        .id = @intCast(slot),
+        .tracing = stats != null or observe.access_log or observe.request_ids,
+        .stats = stats,
+        .prng = if (observe.request_ids) observe.seededPrng() else .init(0),
+        .request_id = .{},
     };
 }
 
@@ -363,7 +478,7 @@ fn startWorkers(allocator: Allocator, workers: []Worker, threads: []std.Thread,
     errdefer stopWorkers(workers[0..active], threads[0..active]);
     for (0..workers.len) |_| {
         const wd = &workers[active];
-        wd.* = initWorker(allocator, result, doc_root, port, ws_enabled, tls_ctx, idle_timeout_ms) catch |err| {
+        wd.* = initWorker(allocator, active, result, doc_root, port, ws_enabled, tls_ctx, idle_timeout_ms) catch |err| {
             reportWorkerFailure(err);
             continue;
         };
@@ -387,12 +502,20 @@ fn stopWorkers(workers: []Worker, threads: []std.Thread) void {
 }
 
 fn reportWorkerFailure(err: anyerror) void {
+    observe.global.workerStartFailed();
+    if (observe.log_json) {
+        var r = observe.Record.init("warn", "server", "worker failed to start");
+        r.str("error", @errorName(err));
+        r.emit();
+        return;
+    }
     writeStderr("warning: worker failed to start: ") catch {};
     writeStderr(@errorName(err)) catch {};
     writeStderr("\n") catch {};
 }
 
 fn deinitWorker(w: *Worker) void {
+    if (w.stats) |s| s.stopped();
     var i: usize = 1;
     while (i < w.n_fds) : (i += 1) {
         if (w.conns[i]) |*conn| {
@@ -481,6 +604,23 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
         break :blk @max(cpus, 1);
     };
 
+    observe.global = .{ .start_ms = platform.milliTimestamp() };
+    observe.log_json = config.log_format == .json;
+    observe.access_log = config.access_log;
+    observe.request_ids = config.request_id or config.access_log;
+    observe.metrics_enabled = config.admin_address != null;
+    if (observe.log_json) {
+        observe.openLog(config.log_file) catch |err| {
+            try writeStderr("error: could not open log file '");
+            try writeStderr(config.log_file orelse "");
+            try writeStderr("': ");
+            try writeStderr(@errorName(err));
+            try writeStderr("\n");
+            std.process.exit(1);
+        };
+    }
+    defer observe.closeLog();
+
     signal_socket = try platform.socketPair();
     defer closeWakePair(signal_socket);
     try platform.installShutdownHandler(requestShutdown);
@@ -511,6 +651,33 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
     var server = try platform.tcpListen(addr, true);
     defer server.deinit();
 
+    // the admin listener comes up before the application compiles, so /ready
+    // answers 503 until workers are actually serving
+    if (observe.metrics_enabled) {
+        observe.worker_stats = try allocator.alloc(observe.WorkerStats, worker_count);
+        @memset(observe.worker_stats, .{});
+        observe.global.workers_configured.set(worker_count);
+    }
+    defer if (observe.metrics_enabled) {
+        allocator.free(observe.worker_stats);
+        observe.worker_stats = &.{};
+    };
+    var admin: observe.Admin = undefined;
+    var admin_text: [64]u8 = undefined;
+    var admin_str: []const u8 = "";
+    if (config.admin_address) |admin_addr| {
+        admin_str = std.fmt.bufPrint(&admin_text, "{f}", .{admin_addr}) catch "?";
+        admin.start(admin_addr) catch |err| {
+            try writeStderr("error: could not start the admin listener on ");
+            try writeStderr(admin_str);
+            try writeStderr(": ");
+            try writeStderr(@errorName(err));
+            try writeStderr("\n");
+            std.process.exit(1);
+        };
+    }
+    defer if (config.admin_address != null) admin.stop();
+
     const abs_path = platform.realpathAlloc(allocator, config.file) catch
         try allocator.dupe(u8, config.file);
     defer allocator.free(abs_path);
@@ -585,7 +752,18 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
             break :blk false;
         };
 
-        if (first_run) {
+        if (first_run and observe.log_json) {
+            var r = observe.Record.init("info", "server", "server started");
+            r.str("file", config.file);
+            r.int("port", config.port);
+            r.boolean("tls", tls_ctx != null);
+            r.int("workers", worker_count);
+            r.boolean("watch", config.watch);
+            if (admin_str.len > 0) r.str("admin", admin_str);
+            r.int("pid", platform.getpid());
+            r.emit();
+            first_run = false;
+        } else if (first_run) {
             var port_buf: [8]u8 = undefined;
             const port_str = std.fmt.bufPrint(&port_buf, "{d}", .{config.port}) catch "?";
             try writeStderr("zphp serving ");
@@ -604,13 +782,19 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
 
         queue.reset();
         const active = startWorkers(allocator, workers_data, threads, &result, doc_root, config.port, ws_enabled, tls_ctx, @as(i64, config.idle_timeout_seconds) * 1000) catch |err| {
-            try writeStderr("error: no worker could start\n");
+            logEvent("error", "no worker could start", "error: no worker could start\n");
             result.deinit();
             ast.deinit();
             allocator.free(source);
             return err;
         };
-        if (active < worker_count) {
+        observe.global.setWorkers(active, true);
+        if (active < worker_count and observe.log_json) {
+            var r = observe.Record.init("warn", "server", "running with fewer workers than configured");
+            r.int("workers", active);
+            r.int("configured", worker_count);
+            r.emit();
+        } else if (active < worker_count) {
             var active_buf: [8]u8 = undefined;
             try writeStderr("warning: running with ");
             try writeStderr(std.fmt.bufPrint(&active_buf, "{d}", .{active}) catch "?");
@@ -629,12 +813,13 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
             _ = sys.poll(&main_poll, poll_timeout) catch continue;
 
             if (main_poll[1].revents & sys.POLL.IN != 0) {
-                try writeStderr("\nshutting down...\n");
+                logEvent("info", "shutting down", "\nshutting down...\n");
                 break;
             }
 
             if (main_poll[0].revents & sys.POLL.IN != 0) {
                 const conn = server.accept() catch continue;
+                if (observe.metrics_enabled) observe.global.connectionAccepted();
                 queue.push(.{ .conn = conn });
                 wake(workers_data[robin].wake_socket);
                 robin = (robin + 1) % active;
@@ -647,7 +832,7 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
                         tls_ctx = new_ctx;
                         tls_cert_mtime = new_mtime;
                         for (workers_data) |*wd| wd.tls_ctx = new_ctx;
-                        try writeStderr("tls: certificate reloaded\n");
+                        logEvent("info", "tls certificate reloaded", "tls: certificate reloaded\n");
                     }
                 }
             }
@@ -657,20 +842,25 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
                 if (new_mtime != watch_mtime and new_mtime != 0) {
                     watch_mtime = new_mtime;
                     needs_restart = true;
-                    try writeStderr("file change detected, reloading...\n");
+                    logEvent("info", "file change detected, reloading", "file change detected, reloading...\n");
                     break;
                 }
             }
         }
 
+        // not ready from the moment workers start draining
+        observe.global.setWorkers(active, false);
         stopWorkers(workers_data[0..active], threads[0..active]);
+        observe.global.setWorkers(0, false);
 
         result.deinit();
         ast.deinit();
         allocator.free(source);
 
         if (!needs_restart) break;
+        observe.global.reloaded();
     }
+    if (observe.log_json) logEvent("info", "server stopped", "");
 }
 
 // event loop (runs on each worker thread)
@@ -712,6 +902,7 @@ fn eventLoop(w: *Worker) void {
 
         closeIdleConnections(w);
         compactConnections(w);
+        if (w.stats) |s| s.setConnections(w.n_fds - 1);
     }
 }
 
@@ -732,6 +923,7 @@ fn closeIdleConnections(w: *Worker) void {
 
 fn registerConnection(w: *Worker, server_conn: net.Server.Connection) void {
     if (w.n_fds >= MAX_CONNS + 1) {
+        if (w.stats) |s| s.connectionDropped();
         server_conn.stream.close();
         return;
     }
@@ -872,8 +1064,10 @@ fn contentLengthOf(req: *const Request) ContentLength {
     return if (found) |n| .{ .value = n } else .none;
 }
 
-fn rejectRequest(w: *Worker, c: *Connection, code: i64, body: []const u8) void {
-    writeResponse(c, code, "text/plain", null, body, false, false, w.allocator) catch {};
+fn rejectRequest(w: *Worker, c: *Connection, req: *const Request, code: i64, body: []const u8) void {
+    const trace = beginTrace(w, req, c.bytes_out);
+    writeResponse(c, code, "text/plain", null, body, false, false, w.allocator, trace.id_header) catch {};
+    endTrace(w, &trace, req, "HTTP/1.1", c.addr_bytes, code, c.bytes_out);
     c.state = .closing;
 }
 
@@ -945,7 +1139,7 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
         const body_start = raw[header_end..c.buffered];
         const decoded_len = switch (decodeChunkedBody(body_start)) {
             .need_more => return,
-            .malformed => return rejectRequest(w, c, 400, "Malformed chunked body"),
+            .malformed => return rejectRequest(w, c, &req, 400, "Malformed chunked body"),
             .done => |d| d,
         };
         body_len = decoded_len.body_len;
@@ -954,10 +1148,10 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
     } else {
         switch (contentLengthOf(&req)) {
             .none => {},
-            .invalid => return rejectRequest(w, c, 400, "Invalid Content-Length"),
+            .invalid => return rejectRequest(w, c, &req, 400, "Invalid Content-Length"),
             .value => |declared| body_len = declared,
         }
-        if (body_len > MAX_BODY_BYTES) return rejectRequest(w, c, 413, "Request body too large");
+        if (body_len > MAX_BODY_BYTES) return rejectRequest(w, c, &req, 413, "Request body too large");
         consumed = header_end + body_len;
         if (c.buffered < consumed) return;
     }
@@ -973,14 +1167,19 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
                 c.state = .closing;
                 return;
             };
-            handleWsUpgrade(w, c, ws_key);
+            const ws_trace = beginTrace(w, &req, c.bytes_out);
+            handleWsUpgrade(w, c, ws_key, ws_trace.id_header);
+            endTrace(w, &ws_trace, &req, "HTTP/1.1", c.addr_bytes, if (c.state == .ws_idle) 101 else 500, c.bytes_out);
             shiftBuffer(c, consumed);
             return;
         }
     }
 
+    const trace = beginTrace(w, &req, c.bytes_out);
+
     // static file
-    if (tryServeStatic(w.allocator, c, w.doc_root, &req, c.keep_alive)) {
+    if (tryServeStatic(w.allocator, c, w.doc_root, &req, c.keep_alive, trace.id_header)) |status| {
+        endTrace(w, &trace, &req, "HTTP/1.1", c.addr_bytes, status, c.bytes_out);
         shiftBuffer(c, consumed);
         if (!c.keep_alive) c.state = .closing;
         return;
@@ -995,7 +1194,9 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
         .stream = c.stream,
         .address = net.Address{ .in = .{ .sa = .{ .port = 0, .addr = c.addr_bytes, .zero = @as([8]u8, @splat(0)) } } },
     };
-    populateSuperglobals(&w.vm, &req, mock_conn, w.port, if (w.env_snapshot) |*s| s else null, w.doc_root, dispatch.script_filename, dispatch.front_controller) catch {
+    populateSuperglobals(&w.vm, &req, mock_conn, w.port, if (w.env_snapshot) |*s| s else null, w.doc_root, dispatch.script_filename, dispatch.front_controller, w.request_id.id()) catch |err| {
+        logRequestError(w, "could not set up the request", @errorName(err));
+        endTrace(w, &trace, &req, "HTTP/1.1", c.addr_bytes, 500, c.bytes_out);
         c.state = .closing;
         return;
     };
@@ -1027,7 +1228,9 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
                 exc_class orelse "(none)",
                 exc_msg orelse "(none)",
             }) catch "500 Internal Server Error";
-            writeResponse(c, 500, "text/plain", null, body, c.keep_alive, false, w.allocator) catch {};
+            logRequestError(w, "request failed", @errorName(interp_err));
+            writeResponse(c, 500, "text/plain", null, body, c.keep_alive, false, w.allocator, trace.id_header) catch {};
+            endTrace(w, &trace, &req, "HTTP/1.1", c.addr_bytes, 500, c.bytes_out);
             shiftBuffer(c, consumed);
             if (!c.keep_alive) c.state = .closing;
             return;
@@ -1053,7 +1256,8 @@ fn processHttpRead(w: *Worker, c: *Connection) void {
     const code = w.vm.response_code;
     const extra_headers = w.vm.response_headers;
 
-    writeResponse(c, code, ct, extra_headers, w.vm.output.items, c.keep_alive, acceptsGzip(&req), w.allocator) catch {};
+    writeResponse(c, code, ct, extra_headers, w.vm.output.items, c.keep_alive, acceptsGzip(&req), w.allocator, trace.id_header) catch {};
+    endTrace(w, &trace, &req, "HTTP/1.1", c.addr_bytes, code, c.bytes_out);
     shiftBuffer(c, consumed);
     if (!c.keep_alive) c.state = .closing;
 }
@@ -1062,6 +1266,7 @@ fn reportUncaught(w: *Worker) void {
     const vm = &w.vm;
     vm.dispatchUncaught();
     if (vm.pending_exception == null) return;
+    logUncaught(w);
     if ((vm.error_reporting_level & 1) != 0) {
         const description = @import("stdlib/exceptions.zig").uncaughtDescription(vm, w.allocator);
         defer if (description) |text| w.allocator.free(text);
@@ -1151,10 +1356,16 @@ fn handleH2Request(w: *Worker, conn: *Connection, session: *h2.H2Session, stream
     req.header_count = stream.header_count;
     req.body = stream.body.items;
 
+    const trace = beginTrace(w, &req, 0);
+    const rid = w.request_id.id();
+
     // try static file
-    if (w.doc_root.len > 0 and tryServeStaticH2(w.allocator, session, stream_id, w.doc_root, &req)) {
-        stream.resetRequest(w.allocator);
-        return;
+    if (w.doc_root.len > 0) {
+        if (tryServeStaticH2(w.allocator, session, stream_id, w.doc_root, &req, rid)) |sent| {
+            endTrace(w, &trace, &req, "HTTP/2.0", conn.addr_bytes, 200, sent);
+            stream.resetRequest(w.allocator);
+            return;
+        }
     }
 
     // PHP execution - php-fpm dispatch (see HTTP/1.1 path)
@@ -1165,8 +1376,10 @@ fn handleH2Request(w: *Worker, conn: *Connection, session: *h2.H2Session, stream
         .stream = conn.stream,
         .address = net.Address{ .in = .{ .sa = .{ .port = 0, .addr = conn.addr_bytes, .zero = @as([8]u8, @splat(0)) } } },
     };
-    populateSuperglobals(&w.vm, &req, mock_conn, w.port, if (w.env_snapshot) |*s| s else null, w.doc_root, dispatch.script_filename, dispatch.front_controller) catch {
-        session.submitResponse(stream_id, 500, "text/plain", "Internal Server Error");
+    populateSuperglobals(&w.vm, &req, mock_conn, w.port, if (w.env_snapshot) |*s| s else null, w.doc_root, dispatch.script_filename, dispatch.front_controller, rid) catch |err| {
+        logRequestError(w, "could not set up the request", @errorName(err));
+        session.submitResponse(stream_id, 500, "text/plain", "Internal Server Error", rid);
+        endTrace(w, &trace, &req, "HTTP/2.0", conn.addr_bytes, 500, "Internal Server Error".len);
         stream.resetRequest(w.allocator);
         return;
     };
@@ -1181,11 +1394,13 @@ fn handleH2Request(w: *Worker, conn: *Connection, session: *h2.H2Session, stream
         }
     }
 
-    w.vm.interpret(dispatch.result) catch {
+    w.vm.interpret(dispatch.result) catch |interp_err| {
         if (w.vm.pending_exception != null) {
             reportUncaught(w);
         } else if (!w.vm.exit_requested) {
-            session.submitResponse(stream_id, 500, "text/plain", "Internal Server Error");
+            logRequestError(w, "request failed", @errorName(interp_err));
+            session.submitResponse(stream_id, 500, "text/plain", "Internal Server Error", rid);
+            endTrace(w, &trace, &req, "HTTP/2.0", conn.addr_bytes, 500, "Internal Server Error".len);
             stream.resetRequest(w.allocator);
             return;
         }
@@ -1198,43 +1413,45 @@ fn handleH2Request(w: *Worker, conn: *Connection, session: *h2.H2Session, stream
     const ct = http.responseContentType(&w.vm);
     const code: u16 = std.math.cast(u16, w.vm.response_code) orelse 200;
 
-    session.submitResponse(stream_id, code, ct, w.vm.output.items);
+    session.submitResponse(stream_id, code, ct, w.vm.output.items, rid);
+    endTrace(w, &trace, &req, "HTTP/2.0", conn.addr_bytes, code, w.vm.output.items.len);
     stream.resetRequest(w.allocator);
 }
 
-fn tryServeStaticH2(allocator: Allocator, session: *h2.H2Session, stream_id: i32, doc_root: []const u8, req: *const Request) bool {
+// the body size when the file was served, null when it is not a static file
+fn tryServeStaticH2(allocator: Allocator, session: *h2.H2Session, stream_id: i32, doc_root: []const u8, req: *const Request, request_id: []const u8) ?usize {
     const path = req.path;
-    if (std.mem.endsWith(u8, path, ".php")) return false;
-    if (path.len <= 1) return false;
+    if (std.mem.endsWith(u8, path, ".php")) return null;
+    if (path.len <= 1) return null;
     const rel = if (path[0] == '/') path[1..] else path;
-    if (rel.len == 0) return false;
-    if (std.mem.indexOf(u8, rel, "..") != null) return false;
+    if (rel.len == 0) return null;
+    if (std.mem.indexOf(u8, rel, "..") != null) return null;
 
-    const file_path = std.fs.path.join(allocator, &.{ doc_root, rel }) catch return false;
+    const file_path = std.fs.path.join(allocator, &.{ doc_root, rel }) catch return null;
     defer allocator.free(file_path);
-    const file = std.Io.Dir.cwd().openFile(platform.io, file_path, .{}) catch return false;
+    const file = std.Io.Dir.cwd().openFile(platform.io, file_path, .{}) catch return null;
     defer file.close(platform.io);
-    const stat = file.stat(platform.io) catch return false;
-    if (stat.kind != .file) return false;
+    const stat = file.stat(platform.io) catch return null;
+    if (stat.kind != .file) return null;
 
     const size: usize = @intCast(stat.size);
-    if (size > 10 * 1024 * 1024) return false;
+    if (size > 10 * 1024 * 1024) return null;
 
-    const body = allocator.alloc(u8, size) catch return false;
+    const body = allocator.alloc(u8, size) catch return null;
     defer allocator.free(body);
-    const bytes_read = platform.readAll(file, body) catch return false;
+    const bytes_read = platform.readAll(file, body) catch return null;
 
     const mime = mimeType(rel);
-    session.submitResponse(stream_id, 200, mime, body[0..bytes_read]);
-    return true;
+    session.submitResponse(stream_id, 200, mime, body[0..bytes_read], request_id);
+    return bytes_read;
 }
 
 // WebSocket processing
 
-fn handleWsUpgrade(w: *Worker, c: *Connection, ws_key: []const u8) void {
+fn handleWsUpgrade(w: *Worker, c: *Connection, ws_key: []const u8, id_header: []const u8) void {
     var accept_buf: [28]u8 = undefined;
     const accept = ws_proto.computeAcceptKey(ws_key, &accept_buf);
-    ws_proto.writeHandshakeResponse(c, accept) catch {
+    ws_proto.writeHandshakeResponse(c, accept, id_header) catch {
         c.state = .closing;
         return;
     };
@@ -1371,7 +1588,7 @@ fn parseRequest(raw: []const u8) Request {
     return req;
 }
 
-fn populateSuperglobals(vm: *VM, req: *const Request, conn: net.Server.Connection, port: u16, env_snapshot: ?*const env.EnvSnapshot, doc_root: []const u8, script_filename: []const u8, front_controller: bool) !void {
+fn populateSuperglobals(vm: *VM, req: *const Request, conn: net.Server.Connection, port: u16, env_snapshot: ?*const env.EnvSnapshot, doc_root: []const u8, script_filename: []const u8, front_controller: bool, request_id: []const u8) !void {
     const a = vm.allocator;
     const server_arr = try vm.allocArray();
 
@@ -1441,6 +1658,9 @@ fn populateSuperglobals(vm: *VM, req: *const Request, conn: net.Server.Connectio
     const addr_owned = try a.dupe(u8, addr_str);
     try vm.strings.append(a, addr_owned);
     try server_arr.set(a, .{ .string = Value.String.borrowed("REMOTE_ADDR") }, .{ .string = Value.String.borrowed(addr_owned) });
+    // the worker owns the id's bytes until its next request, like the
+    // connection buffer the other borrowed values point into
+    if (request_id.len > 0) try server_arr.set(a, .{ .string = Value.String.borrowed("REQUEST_ID") }, .{ .string = Value.String.borrowed(request_id) });
 
     try vm.putRequestVar("$_SERVER", .{ .array = server_arr });
 
@@ -1683,35 +1903,36 @@ fn urlDecode(a: Allocator, input: []const u8) ![]const u8 {
     return buf.toOwnedSlice(a);
 }
 
-fn tryServeStatic(allocator: Allocator, conn: *Connection, doc_root: []const u8, req: *const Request, keep_alive: bool) bool {
+// the status sent when the path was a static file, null when it was not
+fn tryServeStatic(allocator: Allocator, conn: *Connection, doc_root: []const u8, req: *const Request, keep_alive: bool, id_header: []const u8) ?u16 {
     const path = req.path;
-    if (std.mem.endsWith(u8, path, ".php")) return false;
-    if (path.len <= 1) return false;
+    if (std.mem.endsWith(u8, path, ".php")) return null;
+    if (path.len <= 1) return null;
     const rel = if (path.len > 0 and path[0] == '/') path[1..] else path;
-    if (rel.len == 0) return false;
-    if (std.mem.indexOf(u8, rel, "..") != null) return false;
+    if (rel.len == 0) return null;
+    if (std.mem.indexOf(u8, rel, "..") != null) return null;
 
-    const file_path = std.fs.path.join(allocator, &.{ doc_root, rel }) catch return false;
+    const file_path = std.fs.path.join(allocator, &.{ doc_root, rel }) catch return null;
     defer allocator.free(file_path);
-    const file = std.Io.Dir.cwd().openFile(platform.io, file_path, .{}) catch return false;
+    const file = std.Io.Dir.cwd().openFile(platform.io, file_path, .{}) catch return null;
     defer file.close(platform.io);
-    const stat = file.stat(platform.io) catch return false;
-    if (stat.kind != .file) return false;
+    const stat = file.stat(platform.io) catch return null;
+    if (stat.kind != .file) return null;
 
     const size = stat.size;
     const mime = mimeType(rel);
 
     var etag_buf: [64]u8 = undefined;
     const mtime_s: u64 = @intCast(@divFloor(stat.mtime.nanoseconds, 1_000_000_000));
-    const etag = std.fmt.bufPrint(&etag_buf, "\"{x}-{x}\"", .{ size, mtime_s }) catch return false;
+    const etag = std.fmt.bufPrint(&etag_buf, "\"{x}-{x}\"", .{ size, mtime_s }) catch return null;
 
     if (req.getHeader("If-None-Match")) |inm| {
         if (std.mem.eql(u8, inm, etag)) {
             const conn_val = if (keep_alive) "keep-alive" else "close";
             var hdr_buf: [512]u8 = undefined;
-            const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 304 Not Modified\r\nETag: {s}\r\nConnection: {s}\r\n\r\n", .{ etag, conn_val }) catch return false;
-            _ = conn.ioWrite(hdr) catch return false;
-            return true;
+            const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 304 Not Modified\r\nETag: {s}\r\n{s}Connection: {s}\r\n\r\n", .{ etag, id_header, conn_val }) catch return null;
+            _ = conn.ioWrite(hdr) catch return null;
+            return 304;
         }
     }
 
@@ -1719,33 +1940,33 @@ fn tryServeStatic(allocator: Allocator, conn: *Connection, doc_root: []const u8,
     const use_gzip = acceptsGzip(req) and isCompressible(mime) and size <= 1024 * 1024;
 
     if (use_gzip) {
-        const raw = allocator.alloc(u8, size) catch return false;
+        const raw = allocator.alloc(u8, size) catch return null;
         defer allocator.free(raw);
-        const bytes_read = platform.readAll(file, raw) catch return false;
+        const bytes_read = platform.readAll(file, raw) catch return null;
         if (gzipCompress(allocator, raw[0..bytes_read])) |compressed| {
             defer allocator.free(compressed);
             var hdr_buf: [512]u8 = undefined;
-            const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 200 OK\r\nContent-Type: {s}\r\nContent-Length: {d}\r\nContent-Encoding: gzip\r\nETag: {s}\r\nCache-Control: public, max-age=3600\r\nVary: Accept-Encoding\r\nConnection: {s}\r\n\r\n", .{ mime, compressed.len, etag, conn_val }) catch return false;
-            _ = conn.ioWrite(hdr) catch return false;
-            _ = conn.ioWrite(compressed) catch return true;
-            return true;
+            const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 200 OK\r\nContent-Type: {s}\r\nContent-Length: {d}\r\nContent-Encoding: gzip\r\nETag: {s}\r\nCache-Control: public, max-age=3600\r\nVary: Accept-Encoding\r\n{s}Connection: {s}\r\n\r\n", .{ mime, compressed.len, etag, id_header, conn_val }) catch return null;
+            _ = conn.ioWrite(hdr) catch return null;
+            _ = conn.ioWrite(compressed) catch return 200;
+            return 200;
         }
     }
 
     var hdr_buf: [512]u8 = undefined;
-    const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 200 OK\r\nContent-Type: {s}\r\nContent-Length: {d}\r\nETag: {s}\r\nCache-Control: public, max-age=3600\r\nConnection: {s}\r\n\r\n", .{ mime, size, etag, conn_val }) catch return false;
-    _ = conn.ioWrite(hdr) catch return false;
+    const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 200 OK\r\nContent-Type: {s}\r\nContent-Length: {d}\r\nETag: {s}\r\nCache-Control: public, max-age=3600\r\n{s}Connection: {s}\r\n\r\n", .{ mime, size, etag, id_header, conn_val }) catch return null;
+    _ = conn.ioWrite(hdr) catch return null;
 
     var fbuf: [32768]u8 = undefined;
     var remaining: u64 = size;
     while (remaining > 0) {
         const to_read = @min(remaining, fbuf.len);
-        const nr = platform.read(file, fbuf[0..to_read]) catch return true;
+        const nr = platform.read(file, fbuf[0..to_read]) catch return 200;
         if (nr == 0) break;
-        _ = conn.ioWrite(fbuf[0..nr]) catch return true;
+        _ = conn.ioWrite(fbuf[0..nr]) catch return 200;
         remaining -= nr;
     }
-    return true;
+    return 200;
 }
 
 fn mimeType(path: []const u8) []const u8 {
@@ -1805,7 +2026,10 @@ fn statusText(code: i64, buf: *[32]u8) []const u8 {
     };
 }
 
-fn writeResponse(conn: *Connection, code: i64, content_type: []const u8, extra_headers: ?*PhpArray, body: []const u8, keep_alive: bool, use_gzip: bool, allocator: Allocator) !void {
+// id_header is the server's X-Request-Id line, or empty; a request id the
+// application sets with header() takes its place
+fn writeResponse(conn: *Connection, code: i64, content_type: []const u8, extra_headers: ?*PhpArray, body: []const u8, keep_alive: bool, use_gzip: bool, allocator: Allocator, id_header: []const u8) !void {
+    var app_set_id = false;
     var status_buf: [32]u8 = undefined;
     const status_text = statusText(code, &status_buf);
 
@@ -1841,6 +2065,7 @@ fn writeResponse(conn: *Connection, code: i64, content_type: []const u8, extra_h
                 // (curl truncates the rest of the headers at that point)
                 if (std.mem.startsWith(u8, hdr, "HTTP/")) continue;
                 if (std.mem.indexOfScalar(u8, hdr, '\r') != null or std.mem.indexOfScalar(u8, hdr, '\n') != null) continue;
+                if (id_header.len > 0 and std.ascii.startsWithIgnoreCase(hdr, "x-request-id:")) app_set_id = true;
                 if (pos + hdr.len + 2 < hdr_buf.len) {
                     @memcpy(hdr_buf[pos .. pos + hdr.len], hdr);
                     pos += hdr.len;
@@ -1852,6 +2077,11 @@ fn writeResponse(conn: *Connection, code: i64, content_type: []const u8, extra_h
         }
     }
 
+    if (id_header.len > 0 and !app_set_id and pos + id_header.len < hdr_buf.len) {
+        @memcpy(hdr_buf[pos .. pos + id_header.len], id_header);
+        pos += id_header.len;
+    }
+
     if (pos + 2 <= hdr_buf.len) {
         hdr_buf[pos] = '\r';
         hdr_buf[pos + 1] = '\n';
diff --git a/src/websocket.zig b/src/websocket.zig
index 08ba95d1..bde69085 100644
--- a/src/websocket.zig
+++ b/src/websocket.zig
@@ -44,9 +44,10 @@ fn writeAllTo(writer: anytype, data: []const u8) !void {
     }
 }
 
-pub fn writeHandshakeResponse(writer: anytype, accept_key: []const u8) !void {
-    var hdr_buf: [256]u8 = undefined;
-    const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 101 Switching Protocols\r\nUpgrade: websocket\r\nConnection: Upgrade\r\nSec-WebSocket-Accept: {s}\r\n\r\n", .{accept_key}) catch return error.IoError;
+// extra_headers is zero or more complete "Name: value\r\n" lines
+pub fn writeHandshakeResponse(writer: anytype, accept_key: []const u8, extra_headers: []const u8) !void {
+    var hdr_buf: [384]u8 = undefined;
+    const hdr = std.fmt.bufPrint(&hdr_buf, "HTTP/1.1 101 Switching Protocols\r\nUpgrade: websocket\r\nConnection: Upgrade\r\nSec-WebSocket-Accept: {s}\r\n{s}\r\n", .{ accept_key, extra_headers }) catch return error.IoError;
     try writeAllTo(writer, hdr);
 }
 

From 7b2af672086a61f671147daa171a44cf0071848a Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 13:13:54 -0500
Subject: [PATCH 02/11] Test serve observability across workers, logs and
 shutdown

---
 tests/serve/app.php |   5 +
 tests/serve_test    | 229 +++++++++++++++++++++++++++++++++++++++++++-
 2 files changed, 233 insertions(+), 1 deletion(-)

diff --git a/tests/serve/app.php b/tests/serve/app.php
index b64ba1e0..1b4ce90d 100644
--- a/tests/serve/app.php
+++ b/tests/serve/app.php
@@ -168,6 +168,11 @@ function isolation_counter() { static $n = 0; return ++$n; }
         "atom" => DateTime::ATOM,
         "enum_case" => RoundingMode::HalfEven->name,
     ]);
+} elseif ($path === "/request-id") {
+    echo $_SERVER["REQUEST_ID"] ?? "none";
+} elseif ($path === "/slow") {
+    usleep(((int) ($_GET["ms"] ?? 500)) * 1000);
+    echo "slow";
 } elseif ($path === "/header-trailing-space") {
     header("X-Trailing-Space: hello    ");
     header("X-Tab-Space: world\t  ");
diff --git a/tests/serve_test b/tests/serve_test
index 751d965f..d8254bf4 100755
--- a/tests/serve_test
+++ b/tests/serve_test
@@ -29,6 +29,11 @@ cleanup() {
         wait "$FAIL_PID" 2>/dev/null || true
     fi
     if [ -n "${READY_FILE:-}" ]; then rm -f "$READY_FILE"; fi
+    if [ -n "${OBS_PID:-}" ]; then
+        kill "$OBS_PID" 2>/dev/null || true
+        wait "$OBS_PID" 2>/dev/null || true
+    fi
+    if [ -n "${OBS_DIR:-}" ]; then rm -rf "$OBS_DIR"; fi
     exit "$status"
 }
 trap cleanup EXIT
@@ -313,7 +318,7 @@ kill $TLS_PID 2>/dev/null; wait $TLS_PID 2>/dev/null || true
 # --- HTTP/2 tests ---
 H2_PORT=19880
 
-"$ZPHP" serve "$APP" --port $H2_PORT --workers 2 --tls-cert /tmp/zphp_test.crt --tls-key /tmp/zphp_test.key &
+"$ZPHP" serve "$APP" --port $H2_PORT --workers 2 --tls-cert /tmp/zphp_test.crt --tls-key /tmp/zphp_test.key --request-id &
 H2_PID=$!
 for i in $(seq 1 20); do
     if curl -sk -o /dev/null "https://localhost:$H2_PORT/health" 2>/dev/null; then break; fi
@@ -338,6 +343,10 @@ check "h2 status 201" "201" "$h2_status"
 h1_fallback=$(curl -sk --http1.1 https://localhost:$H2_PORT/health)
 check "h1 fallback" '{"status":"ok"}' "$h1_fallback"
 
+h2_rid=$(curl -sk --http2 -D - -o /dev/null -H "X-Request-Id: h2-rid-1" https://localhost:$H2_PORT/request-id | tr -d '\r')
+check_contains "h2 echoes the request id" "x-request-id: h2-rid-1" "$h2_rid"
+check "h2 request id reaches php" "h2-rid-2" "$(curl -sk --http2 -H "X-Request-Id: h2-rid-2" https://localhost:$H2_PORT/request-id)"
+
 h2_multi=$(curl -sk --http2 https://localhost:$H2_PORT/health https://localhost:$H2_PORT/health https://localhost:$H2_PORT/health 2>&1)
 h2_count=$(echo "$h2_multi" | grep -o '"status":"ok"' | wc -l | tr -d ' ')
 check "h2 multiplexing" "3" "$h2_count"
@@ -576,6 +585,224 @@ PY
 check "stalled connection closed by idle timeout" "closed" "$idle_result"
 kill $IDLE_PID 2>/dev/null; wait $IDLE_PID 2>/dev/null || true
 
+# --- observability: admin listener, metrics, access logs, request ids ---
+OBS_PORT=$((PORT + 40))
+OBS_ADMIN=$((PORT + 41))
+OBS_DIR=$(mktemp -d /tmp/zphp_obs.XXXXXX)
+is_windows=0
+case "$(uname -s)" in MINGW*|MSYS*|CYGWIN*) is_windows=1 ;; esac
+# zphp is a native program under msys2 and needs the windows spelling
+native_path() { if command -v cygpath >/dev/null 2>&1; then cygpath -m "$1"; else echo "$1"; fi; }
+limited() { if command -v timeout >/dev/null 2>&1; then timeout 20 "$@"; else "$@"; fi; }
+pass() { passed=$((passed + 1)); echo "  pass  $1"; }
+fail() { failed=$((failed + 1)); echo "  FAIL  $1"; errors="$errors${nl}--- $1 ---${nl}$2${nl}"; }
+check_absent() {
+    if echo "$3" | grep -qi -- "$2"; then fail "$1" "expected no: $2${nl}got: $3"; else pass "$1"; fi
+}
+wait_ready() {
+    for i in $(seq 1 100); do
+        [ "$(curl -s -o /dev/null -w '%{http_code}' "http://127.0.0.1:$1/ready")" = "200" ] && return 0
+        sleep 0.1
+    done
+    return 1
+}
+metric_value() { curl -s "http://127.0.0.1:$OBS_ADMIN/metrics" | awk -v m="$1" '$1 == m {print $2}'; }
+# counters update right after the response is written, so poll briefly
+wait_metric() {
+    local v=""
+    for i in $(seq 1 50); do
+        v=$(metric_value "$1")
+        [ "$v" = "$2" ] && break
+        sleep 0.05
+    done
+    echo "$v"
+}
+
+# defaults: nothing observable changes without the flags
+check_absent "no request id header by default" "^X-Request-Id:" "$(curl -si http://localhost:$PORT/health | tr -d '\r')"
+check "no REQUEST_ID by default" "none" "$(curl -s http://localhost:$PORT/request-id)"
+
+# --request-id with a text-logging admin listener: ids, but no log lines
+"$ZPHP" serve "$APP" --port $OBS_PORT --workers 2 --request-id --admin-port $OBS_ADMIN > "$OBS_DIR/plain.out" 2> "$OBS_DIR/plain.err" &
+OBS_PID=$!
+if wait_ready $OBS_ADMIN; then pass "admin ready with text logs"; else fail "admin ready with text logs" "/ready never answered 200"; fi
+check "request id reaches php" "plain-1" "$(curl -s -H 'X-Request-Id: plain-1' http://localhost:$OBS_PORT/request-id)"
+check_contains "request id echoed" "X-Request-Id: plain-1" "$(curl -si -H 'X-Request-Id: plain-1' http://localhost:$OBS_PORT/health | tr -d '\r')"
+kill $OBS_PID 2>/dev/null; wait $OBS_PID 2>/dev/null || true
+OBS_PID=
+check "text mode writes nothing to stdout" "" "$(cat "$OBS_DIR/plain.out")"
+check_contains "text mode keeps the startup line" "zphp serving" "$(cat "$OBS_DIR/plain.err")"
+
+# configuration is validated before anything binds
+config_error() {
+    local name="$1" needle="$2" out st=0
+    shift 2
+    out=$(limited "$ZPHP" serve "$APP" --port $OBS_PORT "$@" 2>&1 >/dev/null) || st=$?
+    if [ "$st" -eq 1 ] && echo "$out" | grep -q -- "$needle"; then pass "$name"; else fail "$name" "exit $st, got: $out"; fi
+}
+config_error "admin port zero rejected" "needs a port" --admin-port 0
+config_error "admin port text rejected" "needs a port" --admin-port nope
+config_error "admin port needs a value" "needs a value" --admin-port
+config_error "admin host needs a port" "requires --admin-port" --admin-host 127.0.0.1
+config_error "admin port must differ" "must differ" --admin-port $OBS_PORT
+config_error "admin host must be an address" "IPv4 or IPv6" --admin-port $OBS_ADMIN --admin-host localhost.invalid
+config_error "unknown log format rejected" "text or json" --log-format xml
+config_error "access log needs json" "drop --log-format text" --log-format text --access-log
+config_error "unwritable log file rejected" "could not open log file" --log-file "$(native_path "$OBS_DIR")/missing/dir/x.log"
+
+# everything on, four workers, logging to a file
+OBS_LOG="$OBS_DIR/access.log"
+"$ZPHP" serve "$APP" --port $OBS_PORT --workers 4 --admin-port $OBS_ADMIN --access-log --log-file "$(native_path "$OBS_LOG")" > "$OBS_DIR/obs.out" 2> "$OBS_DIR/obs.err" &
+OBS_PID=$!
+if wait_ready $OBS_ADMIN; then pass "admin ready"; else fail "admin ready" "/ready never answered 200"; fi
+
+check "admin health" "ok" "$(curl -s http://127.0.0.1:$OBS_ADMIN/health)"
+check "admin ready body" "ready" "$(curl -s http://127.0.0.1:$OBS_ADMIN/ready)"
+check "metrics content type" "text/plain; version=0.0.4; charset=utf-8" "$(curl -s -o /dev/null -w '%{content_type}' http://127.0.0.1:$OBS_ADMIN/metrics)"
+check_contains "metrics histogram" "# TYPE zphp_http_request_duration_seconds histogram" "$(curl -s http://127.0.0.1:$OBS_ADMIN/metrics)"
+check "metrics worker count" "4" "$(metric_value zphp_workers_running)"
+check "metrics head" "200" "$(curl -s -I -o /dev/null -w '%{http_code}' http://127.0.0.1:$OBS_ADMIN/metrics)"
+check "admin unknown path" "404" "$(curl -s -o /dev/null -w '%{http_code}' http://127.0.0.1:$OBS_ADMIN/index.php)"
+check "admin rejects post" "405" "$(curl -s -o /dev/null -w '%{http_code}' -X POST http://127.0.0.1:$OBS_ADMIN/health)"
+check_contains "admin paths on the app port run php" '"error":"not found"' "$(curl -s http://localhost:$OBS_PORT/metrics)"
+check "app health still the application's" '{"status":"ok"}' "$(curl -s http://localhost:$OBS_PORT/health)"
+
+# request ids on one keep-alive connection: each request gets its own
+rid_result=$(python3 - "$OBS_PORT" <<'PY'
+import re, socket, sys
+s = socket.create_connection(("127.0.0.1", int(sys.argv[1])), timeout=10)
+def request(rid):
+    head = "GET /request-id HTTP/1.1\r\nHost: x\r\n" + ("" if rid is None else "X-Request-Id: " + rid + "\r\n") + "\r\n"
+    s.sendall(head.encode("latin-1"))
+    data = b""
+    while b"\r\n\r\n" not in data:
+        data += s.recv(65536)
+    hdr, body = data.split(b"\r\n\r\n", 1)
+    n = int(re.search(rb"(?im)^content-length:\s*(\d+)", hdr).group(1))
+    while len(body) < n:
+        body += s.recv(65536)
+    m = re.search(rb"(?im)^x-request-id: ([^\r]*)", hdr)
+    return (m.group(1).decode() if m else "-"), body[:n].decode()
+ids = [request("client-1"), request(None), request("x" * 65), request("bad id\x01"), request("client-2")]
+hexid = re.compile(r"^[0-9a-f]{32}$")
+print("given=" + ("ok" if ids[0] == ("client-1", "client-1") and ids[4] == ("client-2", "client-2") else repr(ids)))
+gen = ids[1:4]
+print("generated=" + ("ok" if all(h == b and hexid.match(h) for h, b in gen) else repr(gen)))
+print("unique=" + ("ok" if len({h for h, _ in gen}) == 3 else repr(gen)))
+PY
+)
+check_contains "incoming request ids kept per request" "given=ok" "$rid_result"
+check_contains "missing and invalid ids replaced" "generated=ok" "$rid_result"
+check_contains "generated ids unique on keep-alive" "unique=ok" "$rid_result"
+check_contains "static files carry the id" "X-Request-Id: static-1" "$(curl -si -H 'X-Request-Id: static-1' http://localhost:$OBS_PORT/style.css | tr -d '\r')"
+check "uncaught exception still 500" "500" "$(curl -s -o /dev/null -w '%{http_code}' -H 'X-Request-Id: boom-1' http://localhost:$OBS_PORT/uncaught)"
+check "malformed request still 400" "HTTP/1.1 400 Bad Request" "$(PORT=$OBS_PORT hostile 'POST /reject HTTP/1.1\r\nHost: x\r\nX-Request-Id: reject-1\r\nContent-Length: -1\r\n\r\n')"
+PORT=$OBS_PORT hostile 'GET /esc"\x01\\\xff HTTP/1.1\r\nHost: x\r\nConnection: close\r\n\r\n' > /dev/null || true
+curl -s -o /dev/null -H "Authorization: Bearer topsecret-auth" -H "Cookie: session=topsecret-cookie" "http://localhost:$OBS_PORT/echo?token=topsecret-query"
+
+# admin keeps answering while workers are busy, and active requests show
+slow_pids=""
+for i in 1 2; do curl -s -o /dev/null "http://localhost:$OBS_PORT/slow?ms=1500" & slow_pids="$slow_pids $!"; done
+sleep 0.5
+check "admin health while workers are busy" "ok" "$(curl -s -m 1 http://127.0.0.1:$OBS_ADMIN/health)"
+active=$(metric_value zphp_http_requests_active)
+if [ "${active:-0}" -ge 1 ]; then pass "active requests visible"; else fail "active requests visible" "got: $active"; fi
+wait $slow_pids
+
+# requests spread over workers are counted exactly once
+seq 1 200 | xargs -P 16 -I{} curl -s -o /dev/null "http://localhost:$OBS_PORT/echo?n={}" || true
+# since startup: /health, /request-id x5, /style.css, /echo with secrets, /slow x2 and the 200
+check "2xx requests counted across workers" "210" "$(wait_metric 'zphp_http_requests_total{code="2xx"}' 210)"
+check "4xx requests counted" "3" "$(wait_metric 'zphp_http_requests_total{code="4xx"}' 3)"
+check "5xx requests counted" "1" "$(wait_metric 'zphp_http_requests_total{code="5xx"}' 1)"
+check "no request left active" "0" "$(wait_metric zphp_http_requests_active 0)"
+hist=$(curl -s http://127.0.0.1:$OBS_ADMIN/metrics | awk '
+    /^zphp_http_requests_total/ {sum += $2}
+    /^zphp_http_request_duration_seconds_count/ {count = $2}
+    /^zphp_http_request_duration_seconds_bucket\{le="\+Inf"\}/ {inf = $2}
+    END {print (sum == count && count == inf) ? "ok" : sum " " count " " inf}')
+check "histogram matches the request counters" "ok" "$hist"
+check "connections all closed" "0" "$(wait_metric zphp_connections_active 0)"
+
+kill -TERM $OBS_PID 2>/dev/null
+obs_exit=0
+wait $OBS_PID 2>/dev/null || obs_exit=$?
+OBS_PID=
+if [ $obs_exit -eq 0 ] || [ $obs_exit -eq 143 ]; then pass "observability server shuts down"; else fail "observability server shuts down" "exit $obs_exit"; fi
+check "admin listener closed on shutdown" "000" "$(curl -s -o /dev/null -w '%{http_code}' -m 2 http://127.0.0.1:$OBS_ADMIN/health || true)"
+check "log file mode leaves stdout empty" "" "$(cat "$OBS_DIR/obs.out")"
+
+log_result=$(python3 - "$(native_path "$OBS_LOG")" "$OBS_ADMIN" "$is_windows" <<'PY'
+import json, sys
+path, admin, windows = sys.argv[1], sys.argv[2], sys.argv[3] == "1"
+raw = open(path, "rb").read()
+out = []
+try:
+    lines = [json.loads(l) for l in raw.decode("utf-8").splitlines()]
+    out.append("json=ok")
+except Exception as e:
+    print("json=" + repr(e)); sys.exit()
+access = [l for l in lines if l.get("component") == "access"]
+fields = {"ts", "level", "component", "msg", "request_id", "worker", "method", "path", "protocol", "status", "bytes", "duration_ms", "remote_addr"}
+out.append("fields=" + ("ok" if access and all(fields <= set(l) for l in access) else "missing"))
+out.append("count=%d" % len(access))
+out.append("workers=%d" % len({l["worker"] for l in access}))
+start = [l for l in lines if l.get("msg") == "server started"]
+out.append("startup=" + ("ok" if start and start[0].get("admin") == "127.0.0.1:" + admin and start[0].get("workers") == 4 else repr(start)))
+err = [l for l in lines if l.get("component") == "php" and l.get("request_id") == "boom-1"]
+out.append("exception=" + ("ok" if err and err[0].get("exception") == "RuntimeException" and err[0].get("message") == "boom" else repr(err)))
+boom = [l for l in access if l["request_id"] == "boom-1"]
+out.append("exception_access=" + ("ok" if boom and boom[0]["status"] == 500 else repr(boom)))
+rej = [l for l in access if l["request_id"] == "reject-1"]
+out.append("rejected=" + ("ok" if rej and rej[0]["status"] == 400 and rej[0]["path"] == "/reject" else repr(rej)))
+esc = [l for l in access if l["path"].startswith("/esc")]
+out.append("escaped=" + ("ok" if esc and esc[0]["path"] == '/esc"\x01\\�' else repr(esc)))
+out.append("secrets=" + ("leaked" if b"topsecret" in raw else "ok"))
+stops = [l["msg"] for l in lines if l.get("component") == "server"]
+out.append("shutdown=" + ("ok" if windows or stops[-2:] == ["shutting down", "server stopped"] else repr(stops)))
+print(" ".join(out))
+PY
+)
+for k in json=ok fields=ok startup=ok exception=ok exception_access=ok rejected=ok escaped=ok secrets=ok shutdown=ok; do
+    check_contains "log ${k%%=*}" "$k" "$log_result"
+done
+check_contains "every request logged once" "count=214" "$log_result"
+if echo "$log_result" | grep -q "workers=[2-4]"; then pass "log shows several workers"; else fail "log shows several workers" "$log_result"; fi
+
+# repeated start and stop with everything on leaves nothing behind
+cycle_ok=1
+for i in 1 2 3; do
+    "$ZPHP" serve "$APP" --port $OBS_PORT --workers 2 --admin-port $OBS_ADMIN --access-log --log-file "$(native_path "$OBS_DIR/cycle.log")" > /dev/null 2> "$OBS_DIR/cycle.err" &
+    OBS_PID=$!
+    wait_ready $OBS_ADMIN || { cycle_ok=0; echo "cycle $i: never ready"; }
+    [ "$(curl -s http://localhost:$OBS_PORT/health)" = '{"status":"ok"}' ] || { cycle_ok=0; echo "cycle $i: request failed"; }
+    kill -TERM $OBS_PID 2>/dev/null
+    st=0; wait $OBS_PID 2>/dev/null || st=$?
+    OBS_PID=
+    [ $st -eq 0 ] || [ $st -eq 143 ] || { cycle_ok=0; echo "cycle $i: exit $st"; }
+    if grep -q "leaked" "$OBS_DIR/cycle.err"; then cycle_ok=0; echo "cycle $i: leak"; head -5 "$OBS_DIR/cycle.err"; fi
+done
+check "repeated start and stop" "1" "$cycle_ok"
+if [ $is_windows -eq 0 ]; then
+    check "every cycle logged its shutdown" "3" "$(grep -c '"server stopped"' "$OBS_DIR/cycle.log")"
+fi
+
+# a second server cannot take an admin port that is in use. windows lets
+# SO_REUSEADDR bind over a listener, so the check only holds elsewhere
+[ $is_windows -eq 0 ] && python3 -c "
+import socket, time
+s = socket.socket(); s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
+s.bind(('127.0.0.1', $OBS_ADMIN)); s.listen(1); time.sleep(8)
+" &
+HOLD_PID=$!
+if [ $is_windows -eq 0 ]; then
+    sleep 0.5
+    config_error "admin port conflict reported" "could not start the admin listener" --admin-port $OBS_ADMIN
+fi
+kill $HOLD_PID 2>/dev/null; wait $HOLD_PID 2>/dev/null || true
+rm -rf "$OBS_DIR"
+OBS_DIR=
+
 # test: graceful shutdown
 kill -TERM $SERVER_PID
 exit_code=0

From b094beddf9f398b0ef43b1baeac95a04ba3d8ab2 Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 13:13:55 -0500
Subject: [PATCH 03/11] Document serve observability options and metrics

---
 README.md                        |   2 +
 docs/src/SUMMARY.md              |   1 +
 docs/src/server/observability.md | 136 +++++++++++++++++++++++++++++++
 docs/src/server/serving.md       |   4 +
 4 files changed, 143 insertions(+)
 create mode 100644 docs/src/server/observability.md

diff --git a/README.md b/README.md
index 85176ffc..ddbac6f6 100644
--- a/README.md
+++ b/README.md
@@ -79,6 +79,8 @@ $rates = json_decode($response->await(), true);
 zphp serve public/index.php --workers 8 --tls-cert cert.pem --tls-key key.pem
 ```
 
+For production, `--admin-port 9090` adds `/health`, `/ready` and Prometheus `/metrics` on a separate loopback listener, and `--access-log` writes JSON Lines with request IDs. See [Observability](https://nvms.github.io/zphp/server/observability.html).
+
 ## Standalone executables
 
 `zphp build --compile app.php` turns an application into an executable that runs on machines without PHP installed. It packs every file under the project root, so the scripts the entry point requires and the assets it reads travel with it.
diff --git a/docs/src/SUMMARY.md b/docs/src/SUMMARY.md
index 701607fe..4f4947a0 100644
--- a/docs/src/SUMMARY.md
+++ b/docs/src/SUMMARY.md
@@ -13,6 +13,7 @@
 - [TLS and HTTP/2](./server/tls.md)
 - [Static Files](./server/static-files.md)
 - [WebSockets](./server/websockets.md)
+- [Observability](./server/observability.md)
 
 # Parallelism
 
diff --git a/docs/src/server/observability.md b/docs/src/server/observability.md
new file mode 100644
index 00000000..16adf97c
--- /dev/null
+++ b/docs/src/server/observability.md
@@ -0,0 +1,136 @@
+# Observability
+
+`zphp serve` can report its health, export Prometheus metrics, write structured access logs, and tag every request with an ID. Every feature is opt-in. With none of the flags below, the server behaves and performs exactly as it does without them.
+
+```sh
+zphp serve app.php --workers 8 --admin-port 9090 --access-log
+```
+
+## Options
+
+| Flag | Default | Description |
+|---|---|---|
+| `--admin-port <N>` | Off | Start the admin listener on port N. It serves `/health`, `/ready` and `/metrics`, and metrics are collected only while it is on. |
+| `--admin-host <IP>` | `127.0.0.1` | Address the admin listener binds to. Requires `--admin-port`. |
+| `--access-log` | Off | Write one JSON line per request. Implies `--log-format json` and `--request-id`. |
+| `--log-format <text\|json>` | `text` | `text` keeps the human-readable messages on stderr. `json` writes server events as JSON Lines to stdout. |
+| `--log-file <path>` | stdout | Append JSON lines to this file instead of stdout. Implies `--log-format json`. |
+| `--request-id` | Off | Assign request IDs without enabling access logs. |
+
+The server checks these options before it binds anything. An invalid port, a missing value, `--admin-port` equal to `--port`, an admin host that is not an IP address, `--log-format text` combined with `--access-log` or `--log-file`, or a log file that cannot be opened stops startup with an error and exit status 1. So does an admin port that is already in use.
+
+## Admin listener
+
+The admin listener is a separate socket served by its own thread. Probes and scrapes never reach application routes or run PHP, and they keep working while every worker is busy. `/health` on the application port is still your application's route.
+
+| Path | Status | Body |
+|---|---|---|
+| `/health` | 200 while the process is running and its admin thread is responsive | `ok` |
+| `/ready` | 200 once workers are serving, 503 during startup, `--watch` reloads and shutdown | `ready` or `not ready` |
+| `/metrics` | 200 | Prometheus text format 0.0.4 |
+
+Only `GET` and `HEAD` are accepted (`405` otherwise), and other paths answer `404`. Each response closes its connection. The listener comes up before the application compiles, so orchestrators see `/ready` return 503 until the server can accept application requests. Readiness drops to 503 as soon as a shutdown or reload starts.
+
+A Kubernetes probe setup:
+
+```yaml
+livenessProbe:
+  httpGet: { path: /health, port: 9090 }
+readinessProbe:
+  httpGet: { path: /ready, port: 9090 }
+```
+
+### Security
+
+The admin listener binds to `127.0.0.1` by default and has no authentication. Metrics reveal traffic volume, error rates and memory use. Expose it beyond loopback only on a trusted network, for example `--admin-host 0.0.0.0` inside a container whose port is reachable only by the scraper, and keep it out of public load balancers. Clients are served one at a time with a two-second deadline, so a stalled admin client cannot hold the listener for long, and it never affects application workers.
+
+## Prometheus metrics
+
+```yaml
+scrape_configs:
+  - job_name: zphp
+    static_configs:
+      - targets: ['127.0.0.1:9090']
+```
+
+Every value covers the whole server. Each worker records into its own counters without locks or shared cache lines, and `/metrics` sums them when scraped. Labels are fixed: no URL, request ID or other client-supplied value ever becomes a label.
+
+| Metric | Type | Meaning |
+|---|---|---|
+| `zphp_http_requests_total{code}` | counter | Requests answered, by status class `1xx` to `5xx`. Includes responses the server produced itself, such as 400 for a malformed body. |
+| `zphp_http_request_duration_seconds` | histogram | Time from a complete request to its response being written. Buckets from 1 ms to 10 s. |
+| `zphp_http_requests_active` | gauge | Requests being handled right now. A worker runs one request at a time, so this is also the number of busy workers. |
+| `zphp_connections_active` | gauge | Client connections held by workers, including keep-alive, HTTP/2 and WebSocket connections. |
+| `zphp_connections_accepted_total` | counter | Connections accepted. |
+| `zphp_connections_dropped_total` | counter | Connections closed on arrival because a worker's connection table was full. |
+| `zphp_workers` | gauge | Configured workers. |
+| `zphp_workers_running` | gauge | Workers currently running. Lower than `zphp_workers` when some failed to start. |
+| `zphp_worker_busy_seconds_total` | counter | Time spent handling requests. `rate(zphp_worker_busy_seconds_total[1m]) / zphp_workers_running` is worker utilization. |
+| `zphp_worker_start_failures_total` | counter | Workers that failed to start. |
+| `zphp_reloads_total` | counter | Restarts triggered by `--watch`. |
+| `zphp_vm_memory_bytes` | gauge | PHP memory in use by the worker VMs at the end of their last request, before per-request state is reset. A rising floor points at memory retained across requests. |
+| `process_resident_memory_bytes` | gauge | Current resident memory (Linux and Windows). |
+| `process_resident_memory_max_bytes` | gauge | Peak resident memory. |
+| `process_start_time_seconds` | gauge | Process start time, seconds since the Unix epoch. |
+| `zphp_uptime_seconds` | gauge | Seconds since the server started. |
+| `zphp_ready` | gauge | 1 when `/ready` answers 200. |
+| `zphp_log_write_errors_total` | counter | Log lines that could not be written. |
+
+Counters persist across `--watch` reloads and reset only when the process restarts. Requests are counted when their response is written, including requests that end in an uncaught exception. A connection that closes before sending a complete request is not counted as a request. WebSocket messages are not requests; the upgrade itself is counted with status 101.
+
+Useful queries:
+
+```promql
+sum(rate(zphp_http_requests_total{code="5xx"}[5m])) / sum(rate(zphp_http_requests_total[5m]))
+histogram_quantile(0.99, sum by (le) (rate(zphp_http_request_duration_seconds_bucket[5m])))
+```
+
+## Request IDs
+
+With `--request-id` or `--access-log`, every request gets an ID:
+
+- A valid incoming `X-Request-Id` header is kept. Valid means 1 to 64 characters from `A-Z a-z 0-9 - _ . :`.
+- Anything else, including a missing header, gets a new random 32-character hex ID. A rejected header is never echoed back.
+- The ID is sent back in the `X-Request-Id` response header on HTTP/1.1, HTTP/2, static files, server error responses and WebSocket upgrades.
+- PHP sees it as `$_SERVER['REQUEST_ID']`.
+
+```php
+<?php
+error_log("charging card, request " . $_SERVER['REQUEST_ID']);
+```
+
+If the application sets its own `X-Request-Id` header with `header()`, the application's value is sent instead. Each request on a keep-alive or HTTP/2 connection gets its own ID.
+
+## JSON logs
+
+`--log-format json` writes one JSON object per line. Every line has `ts` (UTC, RFC 3339 with milliseconds), `level`, `component` and `msg`. The `server` component reports startup, shutdown, worker start failures, TLS certificate reloads and `--watch` reloads.
+
+```json
+{"ts":"2026-11-14T17:45:56.803Z","level":"info","component":"server","msg":"server started","file":"app.php","port":8080,"tls":false,"workers":8,"watch":false,"admin":"127.0.0.1:9090","pid":4242}
+```
+
+`--access-log` adds a line per request:
+
+```json
+{"ts":"2026-11-14T17:45:56.917Z","level":"info","component":"access","msg":"request","request_id":"8c879700cf5676eda6f59cb811b470c2","worker":1,"method":"GET","path":"/orders","protocol":"HTTP/1.1","status":200,"bytes":2310,"duration_ms":4.213,"remote_addr":"10.0.0.7"}
+```
+
+`bytes` counts what was written to the connection for HTTP/1.1, headers included, and the response body for HTTP/2. `path` excludes the query string, and no header, cookie or body is ever logged, so credentials in query parameters or headers stay out of the logs.
+
+Requests that fail with an uncaught exception, or fail inside the server, also produce an `error` line carrying the same `request_id`:
+
+```json
+{"ts":"2026-11-14T17:45:56.941Z","level":"error","component":"php","msg":"uncaught exception","request_id":"1f8735e29b84c7011c14a7b9436348e6","worker":2,"exception":"RuntimeException","message":"boom","file":"/srv/app.php","line":16}
+```
+
+These lines are for operators and leave PHP's error handling as it is. `display_errors`, `log_errors` and `error_log` behave as before, and clients still see only what the application and `display_errors` allow.
+
+User-controlled values are escaped. Control characters are written as `\u` escapes, and invalid UTF-8 becomes U+FFFD, so a request cannot break or forge a log line. A line is at most 4 KiB; longer values are cut short.
+
+### Delivery
+
+Each line is formatted on the worker's stack and handed to the destination in a single write, with no lock. Lines up to 4 KiB are written atomically to pipes, and the log file is opened for append, so lines from concurrent workers never interleave. A write that fails is counted in `zphp_log_write_errors_total` and dropped. It never affects the response. Writes are blocking, so a log reader that stops consuming stdout eventually slows the workers down. Point `--log-file` at local disk, or make sure the stdout collector keeps up.
+
+## Crashes
+
+zphp does not install crash handlers that log from signal context, because that is not safe. A crash ends the process. Run zphp under a supervisor (systemd, a container runtime, Kubernetes) that restarts it, and use the exit status and `process_start_time_seconds` to spot restarts.
diff --git a/docs/src/server/serving.md b/docs/src/server/serving.md
index ba0b7b42..190c15e9 100644
--- a/docs/src/server/serving.md
+++ b/docs/src/server/serving.md
@@ -17,6 +17,10 @@ The entry point is compiled at startup. Each worker keeps a persistent VM, with
 | `--tls-cert <file>` | None | TLS certificate |
 | `--tls-key <file>` | None | TLS private key |
 | `--watch` | Off | Restart workers when PHP file changes are detected under the document root |
+| `--admin-port <N>` | Off | Serve `/health`, `/ready` and `/metrics` on a separate loopback listener |
+| `--access-log` | Off | Write a JSON line per request |
+
+Logging, request IDs and metrics have more options; see [Observability](./observability.md).
 
 The server binds to all IPv4 interfaces. Use firewall rules or a reverse proxy to control access. Provide both TLS flags to enable HTTPS.
 

From 697aa0ac9e3ebb844ce3f06e1619b5111adac50a Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 13:32:26 -0500
Subject: [PATCH 04/11] Keep the observability tests running when windows skips
 a check

---
 tests/serve_test | 15 ++++++++-------
 1 file changed, 8 insertions(+), 7 deletions(-)

diff --git a/tests/serve_test b/tests/serve_test
index d8254bf4..0236f706 100755
--- a/tests/serve_test
+++ b/tests/serve_test
@@ -628,7 +628,7 @@ OBS_PID=$!
 if wait_ready $OBS_ADMIN; then pass "admin ready with text logs"; else fail "admin ready with text logs" "/ready never answered 200"; fi
 check "request id reaches php" "plain-1" "$(curl -s -H 'X-Request-Id: plain-1' http://localhost:$OBS_PORT/request-id)"
 check_contains "request id echoed" "X-Request-Id: plain-1" "$(curl -si -H 'X-Request-Id: plain-1' http://localhost:$OBS_PORT/health | tr -d '\r')"
-kill $OBS_PID 2>/dev/null; wait $OBS_PID 2>/dev/null || true
+kill $OBS_PID 2>/dev/null || true; wait $OBS_PID 2>/dev/null || true
 OBS_PID=
 check "text mode writes nothing to stdout" "" "$(cat "$OBS_DIR/plain.out")"
 check_contains "text mode keeps the startup line" "zphp serving" "$(cat "$OBS_DIR/plain.err")"
@@ -724,7 +724,7 @@ hist=$(curl -s http://127.0.0.1:$OBS_ADMIN/metrics | awk '
 check "histogram matches the request counters" "ok" "$hist"
 check "connections all closed" "0" "$(wait_metric zphp_connections_active 0)"
 
-kill -TERM $OBS_PID 2>/dev/null
+kill -TERM $OBS_PID 2>/dev/null || true
 obs_exit=0
 wait $OBS_PID 2>/dev/null || obs_exit=$?
 OBS_PID=
@@ -776,7 +776,7 @@ for i in 1 2 3; do
     OBS_PID=$!
     wait_ready $OBS_ADMIN || { cycle_ok=0; echo "cycle $i: never ready"; }
     [ "$(curl -s http://localhost:$OBS_PORT/health)" = '{"status":"ok"}' ] || { cycle_ok=0; echo "cycle $i: request failed"; }
-    kill -TERM $OBS_PID 2>/dev/null
+    kill -TERM $OBS_PID 2>/dev/null || true
     st=0; wait $OBS_PID 2>/dev/null || st=$?
     OBS_PID=
     [ $st -eq 0 ] || [ $st -eq 143 ] || { cycle_ok=0; echo "cycle $i: exit $st"; }
@@ -789,17 +789,18 @@ fi
 
 # a second server cannot take an admin port that is in use. windows lets
 # SO_REUSEADDR bind over a listener, so the check only holds elsewhere
-[ $is_windows -eq 0 ] && python3 -c "
+if [ $is_windows -eq 0 ]; then
+    python3 -c "
 import socket, time
 s = socket.socket(); s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
 s.bind(('127.0.0.1', $OBS_ADMIN)); s.listen(1); time.sleep(8)
 " &
-HOLD_PID=$!
-if [ $is_windows -eq 0 ]; then
+    HOLD_PID=$!
     sleep 0.5
     config_error "admin port conflict reported" "could not start the admin listener" --admin-port $OBS_ADMIN
+    kill $HOLD_PID 2>/dev/null || true
+    wait $HOLD_PID 2>/dev/null || true
 fi
-kill $HOLD_PID 2>/dev/null; wait $HOLD_PID 2>/dev/null || true
 rm -rf "$OBS_DIR"
 OBS_DIR=
 

From c9f8986bf47420eceac40ddcb5c9fec58346feaa Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 15:32:08 -0500
Subject: [PATCH 05/11] Cut access log formatting cost with a cached timestamp
 and bulk escaping

---
 src/observe.zig | 75 +++++++++++++++++++++++++++++++++++++------------
 1 file changed, 57 insertions(+), 18 deletions(-)

diff --git a/src/observe.zig b/src/observe.zig
index 0b4830e8..88a4776a 100644
--- a/src/observe.zig
+++ b/src/observe.zig
@@ -92,8 +92,8 @@ pub fn closeLog() void {
 // ---------------------------------------------------------------- JSON Lines
 
 // one log line, built on the stack and handed to the destination in a single
-// write. lines stay within the pipe atomicity limit, and the log file is
-// opened for append, so lines from concurrent workers never interleave.
+// write. the log file is opened for append and a pipe keeps writes up to
+// PIPE_BUF whole, so lines from concurrent workers do not interleave.
 // fields that do not fit are dropped whole and strings are cut short, which
 // keeps every line valid JSON whatever the input
 pub const Record = struct {
@@ -162,6 +162,16 @@ pub const Record = struct {
     fn escape(r: *Record, s: []const u8) void {
         var i: usize = 0;
         while (i < s.len) {
+            // runs of printable ascii, the common case, are copied whole
+            var end = i;
+            while (end < s.len and s[end] >= 0x20 and s[end] < 0x7f and s[end] != '"' and s[end] != '\\') end += 1;
+            if (end > i) {
+                const n = @min(end - i, r.room() -| 1);
+                r.put(s[i..][0..n]);
+                if (n < end - i) return;
+                i = end;
+                continue;
+            }
             if (r.room() < 7) return;
             const ch = s[i];
             if (ch < 0x80) {
@@ -190,21 +200,32 @@ pub const Record = struct {
         }
     }
 
+    // the calendar part changes once a second, so each thread keeps the last
+    // one it formatted
+    threadlocal var ts_second: u64 = std.math.maxInt(u64);
+    threadlocal var ts_text: [19]u8 = undefined;
+
     fn timestamp(r: *Record, ms: i64) void {
         const total_ms: u64 = @intCast(@max(ms, 0));
-        const secs = std.time.epoch.EpochSeconds{ .secs = total_ms / 1000 };
-        const year_day = secs.getEpochDay().calculateYearDay();
-        const month_day = year_day.calculateMonthDay();
-        const day_secs = secs.getDaySeconds();
-        r.len += (std.fmt.bufPrint(r.buf[r.len..], "{d:0>4}-{d:0>2}-{d:0>2}T{d:0>2}:{d:0>2}:{d:0>2}.{d:0>3}Z", .{
-            year_day.year,
-            month_day.month.numeric(),
-            month_day.day_index + 1,
-            day_secs.getHoursIntoDay(),
-            day_secs.getMinutesIntoHour(),
-            day_secs.getSecondsIntoMinute(),
-            total_ms % 1000,
-        }) catch unreachable).len;
+        const second = total_ms / 1000;
+        if (second != ts_second) {
+            const secs = std.time.epoch.EpochSeconds{ .secs = second };
+            const year_day = secs.getEpochDay().calculateYearDay();
+            const month_day = year_day.calculateMonthDay();
+            const day_secs = secs.getDaySeconds();
+            _ = std.fmt.bufPrint(&ts_text, "{d:0>4}-{d:0>2}-{d:0>2}T{d:0>2}:{d:0>2}:{d:0>2}", .{
+                year_day.year,
+                month_day.month.numeric(),
+                month_day.day_index + 1,
+                day_secs.getHoursIntoDay(),
+                day_secs.getMinutesIntoHour(),
+                day_secs.getSecondsIntoMinute(),
+            }) catch @memcpy(&ts_text, "9999-12-31T23:59:59");
+            ts_second = second;
+        }
+        r.put(&ts_text);
+        const frac: u16 = @intCast(total_ms % 1000);
+        r.put(&.{ '.', @intCast('0' + frac / 100), @intCast('0' + frac / 10 % 10), @intCast('0' + frac % 10), 'Z' });
     }
 
     pub fn bytes(r: *Record) []const u8 {
@@ -616,12 +637,30 @@ test "oversized log fields are cut short and the line stays valid" {
     const parsed = try std.json.parseFromSlice(std.json.Value, testing.allocator, line, .{});
     defer parsed.deinit();
     try testing.expect(parsed.value.object.get("message") != null);
+
+    var plain = Record.init("info", "access", "request");
+    const long: [5000]u8 = @splat('a');
+    plain.str("path", &long);
+    plain.int("status", @as(i64, 200));
+    const plain_line = plain.bytes();
+    try testing.expectEqual(@as(usize, 4096), plain_line.len);
+    const plain_parsed = try std.json.parseFromSlice(std.json.Value, testing.allocator, plain_line, .{});
+    defer plain_parsed.deinit();
+    try testing.expect(plain_parsed.value.object.get("path").?.string.len > 3900);
 }
 
 test "log timestamps are RFC 3339 UTC" {
-    var r: Record = .{};
-    r.timestamp(951_782_400_123); // 2000-02-29 00:00:00.123
-    try testing.expectEqualStrings("2000-02-29T00:00:00.123Z", r.buf[0..r.len]);
+    const cases = [_]struct { ms: i64, text: []const u8 }{
+        .{ .ms = 951_782_400_123, .text = "2000-02-29T00:00:00.123Z" },
+        .{ .ms = 951_782_400_004, .text = "2000-02-29T00:00:00.004Z" },
+        .{ .ms = 951_782_399_999, .text = "2000-02-28T23:59:59.999Z" },
+        .{ .ms = 0, .text = "1970-01-01T00:00:00.000Z" },
+    };
+    for (cases) |case| {
+        var r: Record = .{};
+        r.timestamp(case.ms);
+        try testing.expectEqualStrings(case.text, r.buf[0..r.len]);
+    }
 }
 
 test "metrics aggregate every worker and keep the histogram consistent" {

From 1c0086060b90f22be7b1e298c72cc90603d6b2a2 Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 15:32:08 -0500
Subject: [PATCH 06/11] Describe log line atomicity per destination

---
 docs/src/server/observability.md | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/docs/src/server/observability.md b/docs/src/server/observability.md
index 16adf97c..2971eee7 100644
--- a/docs/src/server/observability.md
+++ b/docs/src/server/observability.md
@@ -129,7 +129,7 @@ User-controlled values are escaped. Control characters are written as `\u` escap
 
 ### Delivery
 
-Each line is formatted on the worker's stack and handed to the destination in a single write, with no lock. Lines up to 4 KiB are written atomically to pipes, and the log file is opened for append, so lines from concurrent workers never interleave. A write that fails is counted in `zphp_log_write_errors_total` and dropped. It never affects the response. Writes are blocking, so a log reader that stops consuming stdout eventually slows the workers down. Point `--log-file` at local disk, or make sure the stdout collector keeps up.
+Each line is formatted on the worker's stack and handed to the destination in a single write, with no lock. The log file is opened for append, so lines from concurrent workers never interleave in it. On stdout, a pipe keeps each write whole up to `PIPE_BUF` (4 KiB on Linux, 512 bytes on macOS); typical access lines are around 300 bytes. A write that fails is counted in `zphp_log_write_errors_total` and dropped. It never affects the response. Writes are blocking, so a log reader that stops consuming stdout eventually slows the workers down. Point `--log-file` at local disk, or make sure the stdout collector keeps up.
 
 ## Crashes
 

From b77a4e614be2c3bbbe4eb1e03be14149e9be1fc7 Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 15:49:22 -0500
Subject: [PATCH 07/11] Append to existing log files on windows

---
 src/observe.zig  | 6 +++++-
 tests/serve_test | 1 +
 2 files changed, 6 insertions(+), 1 deletion(-)

diff --git a/src/observe.zig b/src/observe.zig
index 88a4776a..a7766824 100644
--- a/src/observe.zig
+++ b/src/observe.zig
@@ -76,7 +76,11 @@ var log_file_owned = false;
 
 pub fn openLog(path: ?[]const u8) !void {
     if (path) |p| {
-        log_file = try platform.openAppend(p, false);
+        const file = try platform.openAppend(p, false);
+        // windows' crt emulates O_APPEND by seeking inside its own write,
+        // which these direct handle writes bypass, so start at the end
+        if (platform.is_windows) platform.seekFromEnd(file, 0) catch {};
+        log_file = file;
         log_file_owned = true;
     } else {
         log_file = platform.stdout();
diff --git a/tests/serve_test b/tests/serve_test
index 0236f706..9e5dca71 100755
--- a/tests/serve_test
+++ b/tests/serve_test
@@ -783,6 +783,7 @@ for i in 1 2 3; do
     if grep -q "leaked" "$OBS_DIR/cycle.err"; then cycle_ok=0; echo "cycle $i: leak"; head -5 "$OBS_DIR/cycle.err"; fi
 done
 check "repeated start and stop" "1" "$cycle_ok"
+check "a reopened log file is appended to" "3" "$(grep -c '"server started"' "$OBS_DIR/cycle.log")"
 if [ $is_windows -eq 0 ]; then
     check "every cycle logged its shutdown" "3" "$(grep -c '"server stopped"' "$OBS_DIR/cycle.log")"
 fi

From e42999aa469a91d45680137dce798f0e3c87c6ff Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 15:49:23 -0500
Subject: [PATCH 08/11] Keep workers stopped on warning failures and ids on
 oversized app headers

---
 src/serve.zig | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/src/serve.zig b/src/serve.zig
index 22ddfbd9..069e031e 100644
--- a/src/serve.zig
+++ b/src/serve.zig
@@ -796,9 +796,11 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
             r.emit();
         } else if (active < worker_count) {
             var active_buf: [8]u8 = undefined;
-            try writeStderr("warning: running with ");
-            try writeStderr(std.fmt.bufPrint(&active_buf, "{d}", .{active}) catch "?");
-            try writeStderr(" workers\n");
+            // workers are running: a failed stderr write must not return
+            // past the code that stops them
+            writeStderr("warning: running with ") catch {};
+            writeStderr(std.fmt.bufPrint(&active_buf, "{d}", .{active}) catch "?") catch {};
+            writeStderr(" workers\n") catch {};
         }
 
         var main_poll: [2]sys.pollfd = .{
@@ -2065,13 +2067,13 @@ fn writeResponse(conn: *Connection, code: i64, content_type: []const u8, extra_h
                 // (curl truncates the rest of the headers at that point)
                 if (std.mem.startsWith(u8, hdr, "HTTP/")) continue;
                 if (std.mem.indexOfScalar(u8, hdr, '\r') != null or std.mem.indexOfScalar(u8, hdr, '\n') != null) continue;
-                if (id_header.len > 0 and std.ascii.startsWithIgnoreCase(hdr, "x-request-id:")) app_set_id = true;
                 if (pos + hdr.len + 2 < hdr_buf.len) {
                     @memcpy(hdr_buf[pos .. pos + hdr.len], hdr);
                     pos += hdr.len;
                     hdr_buf[pos] = '\r';
                     hdr_buf[pos + 1] = '\n';
                     pos += 2;
+                    if (id_header.len > 0 and std.ascii.startsWithIgnoreCase(hdr, "x-request-id:")) app_set_id = true;
                 }
             }
         }

From 5c1ff0b0c488bc1e3f9de5c72f14e77d4872099c Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 16:26:44 -0500
Subject: [PATCH 09/11] Harden the admin listener against accept failures and
 port sharing

---
 src/observe.zig | 37 ++++++++++++-------------------------
 src/serve.zig   | 12 ++++++------
 2 files changed, 18 insertions(+), 31 deletions(-)

diff --git a/src/observe.zig b/src/observe.zig
index a7766824..57c515d8 100644
--- a/src/observe.zig
+++ b/src/observe.zig
@@ -252,7 +252,7 @@ pub const Record = struct {
 
 // a value with a single writer: plain loads and stores, no read-modify-write,
 // so a worker never contends with anyone over its own counters
-const Cell = struct {
+pub const Cell = struct {
     v: std.atomic.Value(u64) = .init(0),
 
     pub inline fn add(c: *Cell, n: u64) void {
@@ -304,14 +304,6 @@ pub const WorkerStats = struct {
         s.busy.set(0);
     }
 
-    pub fn setConnections(s: *WorkerStats, n: usize) void {
-        s.connections.set(n);
-    }
-
-    pub fn connectionDropped(s: *WorkerStats) void {
-        s.connections_dropped.add(1);
-    }
-
     // a stopped worker holds no connections and runs nothing; its totals stay
     pub fn stopped(s: *WorkerStats) void {
         s.busy.set(0);
@@ -331,18 +323,6 @@ pub const Global = struct {
     accepted: Cell = .{},
     log_errors: std.atomic.Value(u64) = .init(0),
 
-    pub fn connectionAccepted(g: *Global) void {
-        g.accepted.add(1);
-    }
-
-    pub fn workerStartFailed(g: *Global) void {
-        g.worker_start_failures.add(1);
-    }
-
-    pub fn reloaded(g: *Global) void {
-        g.reloads.add(1);
-    }
-
     pub fn setWorkers(g: *Global, running: usize, ready_now: bool) void {
         g.workers_running.set(running);
         g.ready.store(ready_now and running > 0, .release);
@@ -469,7 +449,9 @@ pub const Admin = struct {
     const io_deadline_ns: i128 = 2 * std.time.ns_per_s;
 
     pub fn start(self: *Admin, addr: net.Address) !void {
-        self.server = try platform.tcpListen(addr, true);
+        // windows' SO_REUSEADDR would let another process bind the same port
+        // and take over the endpoint
+        self.server = try platform.tcpListen(addr, !platform.is_windows);
         errdefer self.server.deinit();
         try platform.setNonBlocking(self.server.stream.handle, true);
         self.wake = try platform.socketPair();
@@ -501,7 +483,12 @@ pub const Admin = struct {
             };
             if (fds[1].revents != 0) return;
             if (fds[0].revents & sys.POLL.IN == 0) continue;
-            const conn = self.server.accept() catch continue;
+            // a failed accept leaves the listener readable, so back off
+            // rather than spin, e.g. while the process is out of descriptors
+            const conn = self.server.accept() catch {
+                platform.sleep(10 * std.time.ns_per_ms);
+                continue;
+            };
             handle(conn.stream.handle);
             conn.stream.close();
         }
@@ -684,8 +671,8 @@ test "metrics aggregate every worker and keep the histogram consistent" {
     slots[1].requestFinished(503, 20 * std.time.ns_per_s, 2000);
     slots[1].requestFinished(0, 0, 2000);
     slots[1].requestStarted();
-    slots[0].setConnections(3);
-    slots[1].setConnections(4);
+    slots[0].connections.set(3);
+    slots[1].connections.set(4);
 
     var buf: [16384]u8 = undefined;
     var w: std.Io.Writer = .fixed(&buf);
diff --git a/src/serve.zig b/src/serve.zig
index 069e031e..7ef5033e 100644
--- a/src/serve.zig
+++ b/src/serve.zig
@@ -422,7 +422,7 @@ fn loadFile(path: []const u8, allocator: Allocator, vm: *@import("runtime/vm.zig
 }
 
 fn initWorker(allocator: Allocator, slot: usize, result: *const CompileResult, doc_root: []const u8, port: u16, ws_enabled: bool, tls_ctx: ?*tls.SSL_CTX, idle_timeout_ms: i64) !Worker {
-    const stats = if (observe.metrics_enabled) observe.statsFor(slot) else null;
+    const stats = observe.statsFor(slot);
     var vm = try VM.init(allocator);
     errdefer vm.deinit();
     vm.file_loader = &loadFile;
@@ -502,7 +502,7 @@ fn stopWorkers(workers: []Worker, threads: []std.Thread) void {
 }
 
 fn reportWorkerFailure(err: anyerror) void {
-    observe.global.workerStartFailed();
+    observe.global.worker_start_failures.add(1);
     if (observe.log_json) {
         var r = observe.Record.init("warn", "server", "worker failed to start");
         r.str("error", @errorName(err));
@@ -821,7 +821,7 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
 
             if (main_poll[0].revents & sys.POLL.IN != 0) {
                 const conn = server.accept() catch continue;
-                if (observe.metrics_enabled) observe.global.connectionAccepted();
+                if (observe.metrics_enabled) observe.global.accepted.add(1);
                 queue.push(.{ .conn = conn });
                 wake(workers_data[robin].wake_socket);
                 robin = (robin + 1) % active;
@@ -860,7 +860,7 @@ pub fn serve(allocator: Allocator, config: ServeConfig) !void {
         allocator.free(source);
 
         if (!needs_restart) break;
-        observe.global.reloaded();
+        observe.global.reloads.add(1);
     }
     if (observe.log_json) logEvent("info", "server stopped", "");
 }
@@ -904,7 +904,7 @@ fn eventLoop(w: *Worker) void {
 
         closeIdleConnections(w);
         compactConnections(w);
-        if (w.stats) |s| s.setConnections(w.n_fds - 1);
+        if (w.stats) |s| s.connections.set(w.n_fds - 1);
     }
 }
 
@@ -925,7 +925,7 @@ fn closeIdleConnections(w: *Worker) void {
 
 fn registerConnection(w: *Worker, server_conn: net.Server.Connection) void {
     if (w.n_fds >= MAX_CONNS + 1) {
-        if (w.stats) |s| s.connectionDropped();
+        if (w.stats) |s| s.connections_dropped.add(1);
         server_conn.stream.close();
         return;
     }

From 1287ae491aa20b84e6b8eeb2a3670f97e11ade9b Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 16:26:44 -0500
Subject: [PATCH 10/11] Test json logs on stdout and admin port conflicts on
 every platform

---
 tests/serve_test | 43 +++++++++++++++++++++++++++++++------------
 1 file changed, 31 insertions(+), 12 deletions(-)

diff --git a/tests/serve_test b/tests/serve_test
index 9e5dca71..f4917064 100755
--- a/tests/serve_test
+++ b/tests/serve_test
@@ -650,6 +650,26 @@ config_error "unknown log format rejected" "text or json" --log-format xml
 config_error "access log needs json" "drop --log-format text" --log-format text --access-log
 config_error "unwritable log file rejected" "could not open log file" --log-file "$(native_path "$OBS_DIR")/missing/dir/x.log"
 
+# --log-format json alone: server and error lines on stdout, no access lines
+"$ZPHP" serve "$APP" --port $OBS_PORT --workers 1 --log-format json > "$OBS_DIR/json.out" 2> "$OBS_DIR/json.err" &
+OBS_PID=$!
+for i in $(seq 1 50); do curl -s -o /dev/null "http://localhost:$OBS_PORT/health" && break; sleep 0.1; done
+check "json mode keeps php errors" "500" "$(curl -s -o /dev/null -w '%{http_code}' http://localhost:$OBS_PORT/uncaught)"
+check_absent "json mode alone sends no request id" "^X-Request-Id:" "$(curl -si http://localhost:$OBS_PORT/health | tr -d '\r')"
+sleep 0.2
+kill $OBS_PID 2>/dev/null || true; wait $OBS_PID 2>/dev/null || true
+OBS_PID=
+json_out=$(python3 - "$(native_path "$OBS_DIR/json.out")" <<'PY'
+import json, sys
+lines = [json.loads(l) for l in open(sys.argv[1], encoding="utf-8")]
+comps = [l["component"] for l in lines]
+ok = bool(lines) and lines[0]["msg"] == "server started" and "php" in comps and "access" not in comps
+print("ok" if ok else repr(lines))
+PY
+)
+check "json mode writes server and error lines to stdout" "ok" "$json_out"
+check_absent "json mode drops the text banner" "zphp serving" "$(cat "$OBS_DIR/json.err")"
+
 # everything on, four workers, logging to a file
 OBS_LOG="$OBS_DIR/access.log"
 "$ZPHP" serve "$APP" --port $OBS_PORT --workers 4 --admin-port $OBS_ADMIN --access-log --log-file "$(native_path "$OBS_LOG")" > "$OBS_DIR/obs.out" 2> "$OBS_DIR/obs.err" &
@@ -788,20 +808,19 @@ if [ $is_windows -eq 0 ]; then
     check "every cycle logged its shutdown" "3" "$(grep -c '"server stopped"' "$OBS_DIR/cycle.log")"
 fi
 
-# a second server cannot take an admin port that is in use. windows lets
-# SO_REUSEADDR bind over a listener, so the check only holds elsewhere
-if [ $is_windows -eq 0 ]; then
-    python3 -c "
-import socket, time
-s = socket.socket(); s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
+# a second server cannot take an admin port that is in use. the holder needs
+# SO_REUSEADDR past earlier TIME_WAITs, but on windows that would let zphp share
+python3 -c "
+import os, socket, time
+s = socket.socket()
+if os.name != 'nt': s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
 s.bind(('127.0.0.1', $OBS_ADMIN)); s.listen(1); time.sleep(8)
 " &
-    HOLD_PID=$!
-    sleep 0.5
-    config_error "admin port conflict reported" "could not start the admin listener" --admin-port $OBS_ADMIN
-    kill $HOLD_PID 2>/dev/null || true
-    wait $HOLD_PID 2>/dev/null || true
-fi
+HOLD_PID=$!
+sleep 0.5
+config_error "admin port conflict reported" "could not start the admin listener" --admin-port $OBS_ADMIN
+kill $HOLD_PID 2>/dev/null || true
+wait $HOLD_PID 2>/dev/null || true
 rm -rf "$OBS_DIR"
 OBS_DIR=
 

From efe35e2b53c4875d37193eb1f37251b007d5e3b3 Mon Sep 17 00:00:00 2001
From: TrixNEW <cooldinothunder@gmail.com>
Date: Sat, 14 Nov 2026 16:26:45 -0500
Subject: [PATCH 11/11] Document stdout sharing, log rotation and request id
 limits

---
 docs/src/server/observability.md | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/docs/src/server/observability.md b/docs/src/server/observability.md
index 2971eee7..f35d19bc 100644
--- a/docs/src/server/observability.md
+++ b/docs/src/server/observability.md
@@ -99,7 +99,7 @@ With `--request-id` or `--access-log`, every request gets an ID:
 error_log("charging card, request " . $_SERVER['REQUEST_ID']);
 ```
 
-If the application sets its own `X-Request-Id` header with `header()`, the application's value is sent instead. Each request on a keep-alive or HTTP/2 connection gets its own ID.
+If the application sets its own `X-Request-Id` header with `header()`, the application's value is sent instead. Each request on a keep-alive or HTTP/2 connection gets its own ID. IDs are for correlation, not secrets: generated ones are unique but predictable, so never use them as tokens.
 
 ## JSON logs
 
@@ -131,6 +131,8 @@ User-controlled values are escaped. Control characters are written as `\u` escap
 
 Each line is formatted on the worker's stack and handed to the destination in a single write, with no lock. The log file is opened for append, so lines from concurrent workers never interleave in it. On stdout, a pipe keeps each write whole up to `PIPE_BUF` (4 KiB on Linux, 512 bytes on macOS); typical access lines are around 300 bytes. A write that fails is counted in `zphp_log_write_errors_total` and dropped. It never affects the response. Writes are blocking, so a log reader that stops consuming stdout eventually slows the workers down. Point `--log-file` at local disk, or make sure the stdout collector keeps up.
 
+With JSON logs on stdout, anything the application writes to the process's `STDOUT` lands in the same stream; use `--log-file` if it does. The log file stays open for the life of the process, so rotate it with `copytruncate` rather than by renaming it.
+
 ## Crashes
 
 zphp does not install crash handlers that log from signal context, because that is not safe. A crash ends the process. Run zphp under a supervisor (systemd, a container runtime, Kubernetes) that restarts it, and use the exit status and `process_start_time_seconds` to spot restarts.