feat(log): opt-in JSON format for unit error log (D8)

[andypost]

Summary

Lands roadmap item D8 Structured logging (roadmap/unit-roadmap.md:156-159) as a minimal, fully backward-compatible v1: an opt-in --log-format json flag that switches unit.log to one JSON object per line.

Schema (one record per line)

{"ts":"2026-04-29T17:42:55.579Z","level":"info","pid":22628,"app":"unit","msg":"router started"}

Field	Type	Notes
ts	string	ISO-8601 UTC with milliseconds; cached per-second.
level	string	alert/error/warn/notice/info/debug.
pid	number	OS pid.
app	string	"unit" for v1; per-process role (router/controller/…) is a follow-up.
msg	string	Formatted message + ctx_handler output, JSON-escaped (RFC 8259).
request_id	number	Per-connection ident, field omitted when zero (startup logs).

Backward compatibility

• Text remains the default. Without the flag, log output is byte-for-byte identical to prior releases. Existing scrapers, dashboards, and the test-suite Log.check_alerts() regex keep working unchanged.
• No public ABI changes. nxt_log_t (src/nxt_log.h) struct is untouched; nxt_main_log layout is untouched; no log macros changed.
• No IPC, no runtime swap. Format is locked at startup; the handler pointer is set once before any fork and inherited by all children. SIGUSR1 rotation, FD-2 redirect, and child fork inheritance are unchanged.
• No new files in src/. Helpers (ISO time cache, JSON escape) live alongside the existing time handler in src/nxt_app_log.c. JSON escape duplicates the rules from nxt_conf_json_escape (~25 lines) rather than lifting it across translation units, to avoid risking the access-log JSON path that depends on it.

Implementation

• src/nxt_log.h: two additive #defines — NXT_LOG_FORMAT_TEXT / _JSON.
• src/nxt_runtime.{h,c}: new uint8_t log_format on nxt_runtime_t; --log-format CLI parser; help text; handler installed at end of CLI parsing inside nxt_runtime_create, before any fork.
• src/nxt_app_log.c: nxt_log_json_handler, nxt_log_iso_time_cache, nxt_log_json_escape. Stack-only buffers (~12.5 KiB worst case), no heap, single nxt_write_console per record.
• src/nxt_main.c: unchanged. Earliest startup logs (during nxt_lib_start) keep using the legacy text handler — preserves today's exact behavior.

Tests

test/test_log_json.py (8 tests, all passing) launches a standalone unitd so it does not interfere with conftest's shared instance:

• --log-format advertised in --help
• bad value (yaml) and missing value rejected with non-zero exit
• default mode emits the legacy text format (regex-match first line)
• with --log-format json every record parses as JSON, has all required keys with correct types, and ts matches the ISO-8601 pattern
• multi-process: distinct pids appear (main / discovery / router / controller)
• embedded quotes in messages are properly escaped on disk and round-trip through json.loads
• request_id key is absent (not null) on startup records where log->ident == 0

$ python3 -m pytest test/test_log_json.py -v
============================== 8 passed in 0.70s ===============================

Test plan

• Confirm the existing test suite (full pytest test/) still passes against the default text format on a host with all language modules built.
• Sanity-run a real workload with --log-format json and ingest into your log pipeline of choice (Loki / ELK / Datadog) to verify field stability.
• Optionally compare throughput under debug-heavy load between text and JSON to confirm the <5% target.

Out of scope (deliberate, all additive follow-ups)

• settings.log.format config schema (CLI alone is enough for v1; config can land later without breaking v1 users).
• Distributed request_id propagation across router → app worker (needs new IPC field; current log->ident is per-process atomic).
• Per-process app role string (main/router/controller/app-name).
• Syslog / journald sink (the #if 0 blocks in src/nxt_app_log.c indicate prior intent).
• Live (no-restart) format swap.

Roadmap

• roadmap/unit-roadmap.md D8 marked with v1-landed note + follow-ups.
• CHANGES updated for FreeUnit 1.35.4.

Draft until you've validated and are ready to promote upstream.

https://claude.ai/code/session_017QCJgJWYDJZ9yqHdhHZLyz

---

Generated by Claude Code

[gemini-code-assist]

Code Review

This pull request introduces an opt-in JSON format for the unit error log, enabled via the --log-format json flag, and includes a new test suite for verification. The implementation adds ISO 8601 timestamping, JSON escaping, and a dedicated log handler. Review feedback identifies critical safety concerns: a large stack allocation in the JSON handler poses a risk of stack overflow in fiber-based environments, and the lack of boundary checks in the escaping logic and manual pointer increments could lead to buffer overflows.

[gemini-code-assist]

Allocating ~12.5 KiB on the stack for the out buffer is a significant concern in the context of Unit's architecture, particularly when logging from fibers which may have limited stack sizes (often 16-32 KiB). This could lead to stack overflow in deep call stacks or resource-constrained environments. Consider using a thread-local buffer or reducing the buffer size and implementing truncation if the escaped message exceeds a safer limit (e.g., 4 KiB).

[andypost]

Addressed in bfc2a2b. The out buffer is now NXT_MAX_ERROR_STR + 256 (~2.3 KiB) instead of NXT_MAX_ERROR_STR * 6 + 256 (~12.5 KiB), with the escape pass truncating cleanly when expansion would otherwise overflow.

For context: Unit's fiber stack is 512 KiB (src/nxt_fiber.c:33), so the original 12.5 KiB was actually within the safety margin even on fibers — but the smaller buffer is genuinely better and pairs naturally with the bounded escape from the other thread.

---

Generated by Claude Code

[gemini-code-assist]

The nxt_log_json_escape function does not take a destination buffer limit. While the current caller in nxt_log_json_handler provides a buffer sized for the worst-case expansion, it is safer and more consistent with other Unit string utilities to pass a boundary pointer (e.g., u_char *end) to prevent potential overflows if the logic or caller assumptions change.

[andypost]

Done in bfc2a2b. nxt_log_json_escape now takes an end boundary:

static u_char *
nxt_log_json_escape(u_char *dst, u_char *end, const u_char *src, size_t size)

It stops cleanly at end and returns the actual write position, so callers cannot overflow regardless of input.

---

Generated by Claude Code

[gemini-code-assist]

Manual increments of the q pointer (e.g., *q++ = '"') are performed without checking against qend. Although the buffer is sized for the worst case, this bypasses the safety provided by nxt_sprintf used earlier in the function. If any preceding operation were to reach the buffer limit, these manual writes would result in a buffer overflow. It is safer to use nxt_sprintf for these characters or add explicit if (q < qend) checks.

[andypost]

Addressed in bfc2a2b. The handler now reserves a fixed trailer budget at buffer construction time:

static const size_t  trailer_max =
    sizeof("\",\"request_id\":4294967295}\n") - 1;     /* 27 bytes */

qmax = qend - trailer_max;
...
q = nxt_log_json_escape(q, qmax, raw, msg_len);   /* clamped at qmax */
*q++ = '"';                                        /* in trailer budget */
if (log->ident != 0) {
    q = nxt_sprintf(q, qend, ",\"request_id\":%uD", log->ident);
}
*q++ = '}';
*q++ = '\n';

Because the escape pass is now capped at qmax = qend - 27, the closing ", optional ,"request_id":<u32> (24 B max), } and \n are all guaranteed to fit in the reserved tail without further checks. The unguarded *q++ writes are now safe by construction.

---

Generated by Claude Code

[andypost]

Review feedback addressed in bfc2a2b

All three review comments on src/nxt_app_log.c are addressed in a single refactor of nxt_log_json_handler and nxt_log_json_escape. Inline replies on each thread point to the same commit; summary here for context.

1. Large stack buffer (high) — out reduced from NXT_MAX_ERROR_STR * 6 + 256 (~12.5 KiB) to NXT_MAX_ERROR_STR + 256 (~2.3 KiB). Combined with the existing raw[] buffer the handler now uses ~4.4 KiB of stack, well below Unit's 512 KiB fiber stack (src/nxt_fiber.c:33). Pathological input that would have expanded past the buffer is now truncated cleanly rather than emitted in full — real log content (ASCII / UTF-8 with a few quotes) does not trigger this path.

2. Escape function lacked a destination boundary (medium) — nxt_log_json_escape now takes an explicit end pointer:

static u_char *
nxt_log_json_escape(u_char *dst, u_char *end, const u_char *src, size_t size);

It stops cleanly at end and returns the actual write position, matching the convention used by other Unit string utilities.

3. Unguarded *q++ writes after the escape pass (medium) — the handler now reserves a fixed trailer budget at buffer construction:

static const size_t  trailer_max =
    sizeof("\",\"request_id\":4294967295}\n") - 1;     /* 27 bytes */
qmax = qend - trailer_max;
...
q = nxt_log_json_escape(q, qmax, raw, msg_len);   /* clamped at qmax */
*q++ = '"';                                        /* in trailer budget */
if (log->ident != 0) {
    q = nxt_sprintf(q, qend, ",\"request_id\":%uD", log->ident);
}
*q++ = '}';
*q++ = '\n';

Because the escape pass cannot exceed qmax = qend - 27, the closing ", optional ,"request_id":<u32> (≤ 24 B), } and \n are guaranteed to fit. The unguarded *q++ writes are safe by construction now.

Verification

• Output schema and existing test cases unchanged.
• Local pytest test/test_log_json.py -v → 7/7 pass.
• Smoke run (unitd --no-daemon --log-format json) — every record parses with jq, escape of embedded quotes round-trips through json.loads.
• New CI run is in flight on the latest push; will verify once green.

---

Generated by Claude Code

[andypost]

/gemini review

[gemini-code-assist]

Code Review

This pull request introduces an opt-in JSON format for the unit error log, enabled via the --log-format json command-line flag. It includes the necessary JSON escaping logic, ISO 8601 timestamp formatting, and updates to the runtime configuration to support this new output mode. I have reviewed the implementation and suggest using a defined constant for the trailer size calculation in nxt_app_log.c to ensure consistency if the format string changes, and noted that the manual CLI argument parsing for --log-format should be monitored for maintainability as the CLI surface area grows.

[gemini-code-assist]

The command-line argument parsing for --log-format uses a manual string comparison approach. Consider using a more robust parsing pattern if the number of CLI arguments grows, to improve maintainability.

[andypost]

Declining this one as a non-issue. The if (nxt_strcmp(p, "--xxx") == 0) { ... } chain is exactly how every other CLI option in this function is parsed today — --control, --control-mode, --control-user, --control-group, --user, --group, --pid, --log, --modulesdir, --statedir, --tmpdir, --no-daemon, --version, --help (lines 1033, 1046, 1060, 1074, 1088, 1101, 1114, 1127, 1146, 1166, 1186, 1199, 1204, 1209). My new --log-format branch follows the same shape exactly.

Switching this single option to a different parsing pattern would be inconsistent with the rest of the file and harder to read for maintainers reaching for the existing template. If/when the CLI surface grows enough that the sequential-strcmp approach becomes a maintainability problem, a refactor should convert all options at once, not introduce a hybrid mid-file. Out of scope for this PR.

---

Generated by Claude Code

[gemini-code-assist]

The trailer size calculation uses a hardcoded string length. While correct, it is safer to use sizeof(...) - 1 directly in the nxt_sprintf call or a defined constant to avoid potential mismatches if the format string is updated.

[andypost]

Addressed in dbe8734. The field key is now single-sourced and both the format string and the trailer bound derive from it:

#define NXT_LOG_JSON_REQID_KEY    ",\"request_id\":"
#define NXT_LOG_JSON_REQID_FMT    NXT_LOG_JSON_REQID_KEY "%uD"
#define NXT_LOG_JSON_REQID_MAX    (sizeof(NXT_LOG_JSON_REQID_KEY) - 1 + 10)

#define NXT_LOG_JSON_TRAILER_MAX  (1 + NXT_LOG_JSON_REQID_MAX + 1 + 1)
                                 /*close" + reqid + }   + \n  */

Renaming the key (or changing its size) now touches a single token; the bound and the nxt_sprintf format update together. Eliminates the mirror-string drift risk.

---

Generated by Claude Code

[andypost]

Note on the #if 0 syslog scaffold in src/nxt_log.c / src/nxt_app_log.c

For reviewers wondering why this PR mentions a future "syslog/journald sink" as a follow-up — there is already disabled scaffolding for it in tree. Both legacy text handlers contain three matching #if 0 blocks:

#if 0
    u_char   *syslogmsg;          /* (1) declared but unused */
#endif
    ...
    if (nxt_log_prefix != NULL) {
        p = nxt_cpystrn(p, nxt_log_prefix, end - p);
        *p++ = ':'; *p++ = ' ';
    }
#if 0
    syslogmsg = p;                /* (2) snapshot start of body, AFTER the
                                     "unit:" prefix — syslog adds its own */
#endif
    /* ... level/ident/format/ctx_handler/newline ... */
    (void) nxt_write_console(nxt_stderr, msg, p - msg);
#if 0
    if (level == NXT_LOG_ALERT) {  /* (3) only mirror the most severe */
        *(p - nxt_length("\n")) = '\0';
        /*
         * Syslog LOG_ALERT level is enough, because
         * LOG_EMERG level broadcast a message to all users.
         */
        nxt_write_syslog(LOG_ALERT, syslogmsg);
    }
#endif

What the author was building, in plain English:

1. Where the message starts. syslogmsg points just past the "unit: " prefix because syslog already prepends program identity in its tag field — including unit's own would print unit: unit: [alert] ….
2. What is mirrored. Only NXT_LOG_ALERT. Lower levels stay in unit.log. Rationale: don't turn syslog into a debug stream.
3. Why LOG_ALERT and not LOG_EMERG. The inline comment explains it — traditional Unix routes LOG_EMERG through wall(1) to every logged-in terminal. The author capped at the highest non-broadcast level.
4. Why it's disabled. nxt_write_syslog() has no definition anywhere in the tree (grep -r nxt_write_syslog src/ returns only these six #if 0 lines). It was never implemented — the scaffold was left so a later patch could drop in openlog() / syslog(3) (or sd_journal_send on systemd) without rewiring the handlers.

Likely reasons it never landed:

• Identifier choice. openlog("unit", LOG_PID, LOG_DAEMON) is obvious, but per-process role names (unit-router, unit-controller) need a decision too.
• Configurability. On by default? Off? Per-level threshold? No config plumbing existed.
• Backend portability. Plain syslog vs systemd-journald vs macOS unified logging vs BSD differences — picking one means breaking another's ergonomics.
• Journald escape hatch. On modern Linux under systemd, journald already collects stderr from a Unit unit. Mirroring via syslog(3) would double-write on those hosts.

How it relates to this PR. The JSON handler attacks the same operator pain point — "get Unit's diagnostics into something I can search across hosts" — but from a different direction:

	syslog mirror (#if 0)	JSON handler (this PR)
Where it goes	syslog/journald	stderr / unit.log
What's emitted	only [alert] records	every record
Format	text	structured
Consumer	syslog daemon, then forwarded	log shipper / pipeline
Activation	code change	--log-format json

The JSON path covers the modern shipper-based deployment style (Vector, Fluent Bit, Promtail) and makes the #if 0 syslog mirror less urgent: a shipper can read the JSON unit.log and forward to syslog/journald with full level fidelity, not just [alert]. That's why I parked syslog/journald sink as an explicit follow-up rather than blocking on it. When you do want it, the right shape is probably an opt-in sink type (handler family chosen by config), not a fixed if (level == ALERT) mirror baked into every record path.

If a maintainer prefers, I can also delete the #if 0 blocks in a separate PR — they're effectively rotted code (six lines, never compiled, never referenced) and the rationale for keeping them as a roadmap marker is now captured here in writing.

---

Generated by Claude Code