Files
gps-denied-onboard/_docs/02_tasks/done/AZ-266_log_module.md
T
Oleksandr Bezdieniezhnykh 8e71f6c002 [AZ-266] [AZ-269] [AZ-277] [AZ-280] Cross-cutting log/config + SE3/SHA256 helpers
AZ-266: schema-compliant JSON logging entrypoint, level normalisation,
handler-topology guard, format-error fallback (log_record_schema v1.0.0).
AZ-269: env > YAML > defaults config loader, frozen Config dataclass,
missing-var fail-fast with pointer to .env.example, component-block registry.
AZ-277: GTSAM-backed SE3Utils (matrix<->SE3 + exp/log/adjoint) with strict
orthogonality, dtype, and bottom-row contract enforcement.
AZ-280: atomicwrites-backed write_atomic + independent verify +
order-deterministic aggregate_hash; sidecar format strictness.
pyproject.toml pins gtsam>=4.2,<5.0 and atomicwrites>=1.4,<2.0
(named-backend deps per the AZ-277 / AZ-280 contracts).
139 unit tests pass (44 new). Review verdict: PASS_WITH_WARNINGS;
findings are perf-NFR + journald deferrals, no blocking issues.

Co-authored-by: Cursor <cursoragent@cursor.com>
2026-05-11 01:33:42 +03:00

6.9 KiB

Shared Structured Logging Module

Task: AZ-266_log_module Name: Shared Logging Module Description: Provide the get_logger(component_id) entrypoint, a stable JSON formatter that emits records matching the log_record_schema contract, and the stdout / journald handlers used by Tier-1 and Tier-2 deployments. Complexity: 3 points Dependencies: AZ-263_initial_structure Component: shared.logging (cross-cutting; epic AZ-245 / E-CC-LOG) Tracker: AZ-266 Epic: AZ-245 (E-CC-LOG)

Problem

Every onboard component must emit structured JSON logs at DEBUG / INFO / WARN / ERROR with a stable, machine-parseable shape so post-flight analysis (FDR tooling, blackbox scenario checks, traceability matrix verification) can correlate events across components. Without one shared logger, format drift is guaranteed within a few weeks of parallel component development.

Outcome

  • A single get_logger(component_id) call is the only logging entrypoint any onboard module ever uses.
  • Every emitted record is a single-line JSON object whose key set, key order, and value types match the log_record_schema contract version 1.0.0.
  • Tier-1 deployments capture logs via Docker stdout; Tier-2 deployments capture logs via journald — switched by config, not by code.

Scope

Included

  • get_logger(component_id: str) -> Logger factory backed by Python stdlib logging.
  • A JSON formatter that emits the schema's 8 fields in the contract-mandated order, regardless of construction order. Implementation may use python-json-logger or orjson-backed formatter — whichever is already pinned in the project's lockfile from AZ-263.
  • A stdout handler for Tier-1 (Docker) and a journald handler for Tier-2 (Jetson). Selection is config-driven via the structured-logging entry of the cross-cutting config epic (AZ-246 / E-CC-CONF).
  • Per-frame structured-logging helpers for the documented per-component shapes referenced in epic AZ-245 (vio.tick, vpr.query, etc.) so component code can emit one-liner logs without rebuilding the kv dict.
  • Public interface contract published at _docs/02_document/contracts/shared_logging/log_record_schema.md.

Excluded

  • The FDR bridge that forwards ERROR + WARN records into the Flight Data Recorder — owned by the next task (03_fdr_log_bridge, parented to the same epic).
  • Per-component log call sites (each component epic owns its own logging call sites).
  • Log schema versioning beyond 1.0.0 — handled by future change-log entries on the contract file.

Acceptance Criteria

AC-1: Single logger entrypoint Given any onboard Python module that imports the shared logging package When the module calls get_logger("c2_vpr") Then it receives a Logger whose every record passes the schema contract test (no other logger configuration is required by the caller)

AC-2: Field order is stable Given a logger configured with the JSON formatter When a component calls logger.info(msg, extra={"frame_id": 42, "kind": "vpr.query", "kv": {...}}) Then the emitted bytes parse as a single-line JSON object whose keys appear in the order ts, level, component, frame_id, kind, msg, kv, exc, regardless of the order the caller passed the fields

AC-3: Level normalisation Given a logger receiving a record at level WARNING (Python stdlib name) When the formatter emits the JSON record Then the level field reads WARN (per contract), not WARNING

AC-4: Handler topology selection Given the structured-logging config block selects tier=1 (or tier=2) When runtime_root.py initialises logging Then exactly one stdout handler (or journald handler) is attached, with no duplicate handlers and no handler from the wrong tier

AC-5: Non-frame records omit frame_id Given a startup or shutdown log call that does not pass a frame_id When the record is emitted Then frame_id appears as JSON null (never as a synthesised value, never absent from the key list)

Non-Functional Requirements

Performance

  • Per-record formatter latency p99 ≤ 0.2 ms on Tier-2 (Jetson Orin Nano Super) for a record with len(kv) ≤ 8 scalar entries. Validated by a microbenchmark in unit tests.
  • DEBUG records on the steady-state hot path allocate at most one new string (the formatted JSON line); no transient dict copies of kv are permitted.

Reliability

  • Formatter never raises into the caller. A serialisation failure logs an internal WARN with kind="log.format_error" and drops the offending record's kv payload (replaces with {"_format_error": "<reason>"}); the rest of the record is still emitted.
  • No global mutable state outside the standard logging module's own logger registry; multiple get_logger("c2_vpr") calls return the same cached Logger instance.

Unit Tests

AC Ref What to Test Required Outcome
AC-1 get_logger("c2_vpr") returns a Logger with the JSON formatter attached Logger instance present; formatter produces valid contract record
AC-2 Emit a record with kwargs in shuffled order Parsed JSON keys appear in the contract's mandated order
AC-3 Log at logging.WARNING level Emitted JSON level field equals "WARN"
AC-4 Initialise logging twice with the same tier-1 config Exactly one stdout handler attached; no duplicates
AC-5 Log a startup INFO without frame_id Emitted JSON contains "frame_id": null
NFR-perf Microbenchmark formatter on a record with 8 scalar kv entries p99 ≤ 0.2 ms over 10k iterations
NFR-reliability Pass a non-JSON-serialisable object in kv (e.g. a class instance) Formatter emits the record with kv={"_format_error": "..."}; caller does not see an exception

Constraints

  • Public interface frozen by _docs/02_document/contracts/shared_logging/log_record_schema.md v1.0.0 — any change requires a contract version bump.
  • Stdlib logging is the only allowed underlying logging mechanism (per epic AZ-245 architecture note: "no third-party log aggregator").
  • No new dependency beyond what AZ-263 / E-BOOT already pinned in pyproject.toml.

Risks & Mitigation

Risk 1: Formatter performance regression

  • Risk: Naïve json.dumps on each record exceeds the 0.2 ms p99 budget on Jetson.
  • Mitigation: Bench against orjson-backed formatter as a fallback if stdlib json misses budget; choice is reversible because the contract is the public surface, not the formatter implementation.

Risk 2: Handler duplication on hot-reload

  • Risk: Re-initialising logging during integration tests stacks duplicate handlers, multiplying every emitted record.
  • Mitigation: get_logger checks for existing handlers on the named logger before adding new ones; integration test fixture asserts handler count after teardown.

Contract

This task produces the contract at _docs/02_document/contracts/shared_logging/log_record_schema.md. Consumers MUST read that file — not this task spec — to discover the interface.