Files
panda-rpki-oss/docs/logging.md
yuyr 4975128945
Some checks failed
ci / rust (push) Has been cancelled
ci / docker (push) Has been cancelled
ci / audit (push) Has been cancelled
20260914 强制 TOML 配置并完善 TA 刷新与 daemon
2026-09-14 16:58:08 +08:00

9.0 KiB

Diagnostic logging

For every field, default, constraint and complete example, see the TOML configuration reference。

The validator writes diagnostics to stderr. Under daemon, that stream is saved as runs/run_XXXXXX/validator.log; it contains all enabled levels, not only errors. process-output.txt captures ordinary output and is normally empty. The daemon's own lifecycle diagnostics remain in the container log. No duplicate log forwarding is performed. Historical stderr.log files are not renamed.

TOML defaults and the shipped Compose TOML examples use info and text. Compose does not independently select the logging format. Text is written for people, with independently authored English sentences for run lifecycle, validation stages, progress, output files and failures. It does not enumerate event fields or translate event identifiers into prose. Progress reports elapsed time, publication points processed when known, and active repository sync attempts. Old progress snapshots are explicitly described as the last reported update. UUIDs, worker queues and unrelated counters are not printed. The synthetic initializing-stage completion is omitted in text only. Control characters are escaped to keep each record on one line. Diagnostic filenames do not select the format. Text is not a stable machine-parsing interface.

2026-09-11T10:44:14Z INFO [run 230] Starting validation with delta synchronization across 5 trust anchors.
2026-09-11T10:44:24Z INFO [run 230] Synchronizing repositories and validating objects; 10.0 seconds elapsed. Processed 32000 publication points so far. 3 repository sync attempts are still in progress.
2026-09-11T10:45:36Z INFO [run 230] Validation completed in 82.0 seconds.

Set log-format = "json" in the TOML for machine consumers; the JSON event names and fields are unchanged. Both formats redact sensitive data. Text error reasons are limited to 240 Unicode characters with an explicit notice when shortened. Unknown extension/debug events retain a diagnostic identifier and their message, not an arbitrary field dump. Use JSON (and debug/trace as needed) for full technical details, category examples and counter snapshots. JSON is one complete object per line: timestamp, level, event, fields, source. Timestamps are UTC RFC3339. Run context is in fields.run_id and fields.run_seq (null for standalone validation). Logging failures do not change validation results.

Every emitted text line ends with [source/file.rs:line]. JSON records include source: {"file": "source/file.rs", "line": 123} at the top level. These are compile-time source paths and one-based line numbers from the logger call site, not the shared output sink; progress forwarding preserves the caller location. Logs emitted inside artifact/stage helpers point to the emit call inside that helper. Match locations against the source revision used to build the binary.

2026-09-11T10:45:36Z INFO [run 230] Validation completed in 82.0 seconds. [src/cli/validate.rs:123]

The source line in this example is illustrative; actual logs report the compiled location.

Event contract

Events Level Meaning / frequency
validation_started/completed/summary info Run boundaries and exact final business counts
validation_failed, command_failed error Run/command failure, with error and elapsed time where available
validation_stage_started/completed/failed info/error State store, setup, TA discovery, online validation, output, CSV conversion
validation_progress info Default every 10s, independent of blocked network/store calls
trust_anchor_started/completed/failed info/error One pair per TAL, fatal failure includes TAL ID
validation_warnings warn Existing final total, not a declaration that the run failed
validation_warning_category info Category count and up to three redacted 1KiB examples
validation_warning_detail debug Full warning message and context
artifact_write_started/completed/failed info/error Type, path, wall milliseconds and bytes; CCR, CSV, summary, timings
rrdp_sync_attempt/success debug Transport attempt and successful object writes/duration
rrdp_sync_failed, http_fetch_failed warn Recoverable attempt failures; retryable does not imply will_retry
rrdp_sync_selected debug Actual snapshot/delta/unchanged selection, reason, serial/session
rrdp_download_completed debug Snapshot/delta decoded payload bytes, not wire traffic
rrdp_cross_origin_rejected, rrdp_delta_fallback warn Protocol security rejection / delta application fallback
repo_terminal_failure warn Failed publication point, not a fatal command error
http_fetch_slow, rsync_sync_slow, phase2_*_slow debug Detailed slow operations, aggregated into info progress
phase1_repo_* debug Repository task scheduling and worker decisions
phase2 batch/queue/object events, publication_point_* trace Detailed high-volume processing; not recommended for continuous all5
daemon_started/state_recovered/run_started/child_started info Effective configuration, recovery and per-run log path
daemon_run_completed/sleeping/retention_applied/exited info/warn Outcome, next scheduled time and retention decisions
daemon_stop_requested info Graceful stop request observed outside the signal handler
daemon_child_terminate/child_kill warn One event per signal escalation, with reason

src/logging/progress.rs explicitly registers progress event levels, including the dynamic finalize-worker label; a source-inventory regression detects new unregistered literal call sites. Unknown library-supplied names default to debug.

Progress and volume

log-progress-interval-secs is configured in TOML and defaults to 10. 0 suppresses periodic events, not stage events. off/error/warn do not create a progress thread. Queue snapshots are refreshed at most every 250ms. statistics_age_ms is the age of the queue/PP snapshot, not the repository event counters. progress_stalled means no observed completion for 30s, not proof of deadlock. Progress does not predict the total tree size or invent completion percentages.

  • Repository counters count attempts, not publication points or unique repositories.
  • repository_objects_written counts writes, including updates; it is not unique validated objects.
  • roa_tasks_completed counts returned parallel ROA tasks, not all object types.
  • downloaded_snapshot_delta_bytes excludes notifications and measures decoded payload.
  • The serial path reports PP completed/failed counts; absent parallel queue fields are not zeroes.
  • Slow-operation counts are cumulative per run. Detailed slow events stay debug.

Warning categories are assigned at typed source sites. Opaque legacy string errors remain unclassified; they are not classified by substring guesses. The category total equals the existing warning total, which may contain both tree and audit warnings. Examples are redacted before UTF-8-safe truncation.

Category Assignment at currently instrumented sites Meaning / example
unclassified No typed classification retained Opaque repository-sync error; do not guess its cause
ber_compatible_cms_encoding Existing BER-compatible CMS warning Accepted non-DER encoding
transport Typed fetch error in RRDP fallback warning Download failure
rrdp_protocol Typed RRDP error in fallback warning Invalid RRDP response
security_policy Cross-origin fallback, manifest location/hash/rollback rejection Integrity or anti-rollback check
certificate Child discovery or typed manifest EE/issuer certificate errors Certificate/path/resource failure
manifest_crl Typed manifest errors or missing required CRL Stale manifest or missing CRL
object_validation Parallel ROA/ASPA rejection Invalid signed routing object

This is incremental typed coverage, not a promise that every historical warning site is already classified. Uninstrumented sites intentionally remain unclassified.

tail -f /path/to/data/runs/run_000001/validator.log
jq -c 'select(.event == "validation_progress")' /path/to/validator.log
jq -c 'select(.level == "warn" or .level == "error")' /path/to/validator.log

The jq examples require JSON logging to have been explicitly enabled.

Retention removes completed run directories including their logs. Archive needed runs before the configured retention window expires. Summary history is append-only.

Change an existing daemon to text

Set log-format = "text" at the TOML top level, before [[anchors]]. Keep log-level = "info" or the desired existing level. Do not use the removed --log-format flag or PANDA_RPKI_LOG_FORMAT environment override. TOML is read at process start, so stop and recreate the service as described in Docker configuration reload. Each new validator child inherits the controller configuration; prior run logs and JSON summary/metadata files are not converted.