Add production observability to zphp serve

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.

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
 

docs/src/server/observability.md

@@ -0,0 +1,138 @@
+# 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. IDs are for correlation, not secrets: generated ones are unique but predictable, so never use them as tokens.
+
+## 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. 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.

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.
 

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);
         }
     }
 };

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");