Skip to content

feature/improved logging#888

Open
nachog00 wants to merge 24 commits intodevfrom
feature/improved-logging
Open

feature/improved logging#888
nachog00 wants to merge 24 commits intodevfrom
feature/improved-logging

Conversation

@nachog00
Copy link
Contributor

Summary

Adds centralized logging infrastructure to zaino-common with configurable output formats (stream, tree, JSON) controlled via environment variables (RUST_LOG, ZAINO_LOG_FORMAT, ZAINO_LOG_COLOR). The logging module is now used consistently across zainod and zaino-testutils.

This PR also introduces NamedAtomicStatus for observable component status (logged at debug level), adds tracing instrumentation to key functions in zaino-state and TestManager, and improves log readability with compact timestamps, truncated hash displays, and structured tracing fields.

Container tests now pass through RUST_LOG and ZAINO_LOG_FORMAT so developers can control log verbosity and format during test runs.

See docs/logging.md for usage examples.

Related Issues

This is foundational work toward #856 (Observability Metrics) by establishing consistent, structured logging patterns. It also partially addresses the concerns in #598 (Uncontrollable test printout) by giving developers control over log output during tests via environment variables.

Adds a logging module with support for multiple output formats:
- Tree view (hierarchical span-based output) - DEFAULT
- Stream view (flat chronological output)
- JSON output (machine-parseable)

Configuration via ZAINO_LOG_FORMAT environment variable.
Includes DisplayHash/DisplayHexStr utilities for compact hash rendering.
Replaces inline tracing_subscriber setup with zaino_common::logging::init().
Replaces inline tracing_subscriber setup with zaino_common::logging::try_init().
- Change default format to stream (with timestamps)
- Filter to only zaino crates by default (no zebra noise)
- Add ZAINO_LOG_COLOR env var to force color on/off
- Users can opt-in to all crates via RUST_LOG=info
Show first 8 hex characters (4 bytes) followed by ".." in BlockHash
and TransactionHash Display implementations for cleaner log output.
- Use time-only format (HH:MM:SS.ms) instead of full RFC3339 dates
- Enable ANSI colors by default for better dev experience
- Add "auto" option for ZAINO_LOG_COLOR to opt into TTY detection
Switches stream format to use tracing-subscriber's built-in pretty
formatter which provides colored targets, cleaner output, and
source file locations.
Replace hardcoded string interpolation with structured tracing fields
for better filtering, searchability, and consistency. Key changes:

- Service spawn logs now include rpc_address and network fields
- Sync progress logs use height, hash fields instead of inline format
- Chain tip changes log old/new heights and hashes as separate fields
- Database operations include version fields
- Remove redundant log messages (got tip!, got blockchain info!)
Add indent_lines for ASCII tree rendering and verbose entry/exit
for span context. Note: tree mode benefits most when #[instrument]
attributes are added to key functions.
Add #[instrument] attributes to spawn and sync functions for proper
span hierarchy in logs. This enables the tree logger format to show
meaningful hierarchical structure.

Instrumented functions:
- StateService::spawn
- FetchService::spawn
- NonFinalizedState::initialize and sync
- ChainIndex::start_sync_loop
- Mempool::spawn
- ZainoDB::spawn
Provides human-readable network names in logs and error messages.
- Enable deferred spans (only show spans when they have events)
- Disable verbose entry/exit to reduce noise
Logs status transitions at debug level with component name, making it
easier to trace component lifecycle during debugging.
Replace AtomicStatus with NamedAtomicStatus in:
- gRPC server
- JSON-RPC server
- ChainIndex
- Mempool
- ZainoDB (v0 and v1)
Changes ?config.network to %config.network for cleaner log output.
Also updates StateService to use NamedAtomicStatus.
- Add instrument macro to TestManager::launch and poll_until_ready
- Add debug logs for test lifecycle phases
- Derive Debug for ValidatorKind
Allows controlling log level and format in containerized tests.
@nachog00 nachog00 requested review from AloeareV and zancas February 26, 2026 17:11
@nachog00 nachog00 marked this pull request as draft February 26, 2026 17:15
- Remove duplicate logging initialization in zainodlib that conflicted
  with the centralized logging in zaino-common
- Rename ZAINO_LOG_FORMAT -> ZAINOLOG_FORMAT and ZAINO_LOG_COLOR ->
  ZAINOLOG_COLOR to avoid conflict with config loader's ZAINO_* prefix
@nachog00 nachog00 marked this pull request as ready for review February 26, 2026 18:40
@nachog00 nachog00 requested review from idky137 and pacu February 26, 2026 19:21
pacu
pacu previously approved these changes Feb 26, 2026
Copy link
Contributor

@pacu pacu left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think these changes look OK. Modulo the fmt::Display changed is verified.

Copy link
Contributor

@AloeareV AloeareV left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unfortunately, there's at least one load-bearing to_string():

.get_block(id.to_string(), Some(0))

@AloeareV
Copy link
Contributor

Unfortunately, there's at least one load-bearing to_string():

.get_block(id.to_string(), Some(0))

If I merge this PR into #864, zainod fails on

thread 'main' (910691) panicked at zaino-state/src/backends/fetch.rs:144:14:
called `Result::unwrap()` on an `Err` value: InvalidNodeData(Unrecoverable("unexpected error response from server: RPC Error (code: -8): parse error: could not convert the input string to a hash or height"))

which I believe to be due to sending a truncated block hash to the validator.

Replace .to_string() with .encode_hex::<String>() for TransactionHash
in test assertions. Display should be for human-readable logging, not
machine-readable formats.

Fixes #896
@nachog00
Copy link
Contributor Author

nachog00 commented Mar 2, 2026

Unfortunately, there's at least one load-bearing to_string():

.get_block(id.to_string(), Some(0))

If I merge this PR into #864, zainod fails on

thread 'main' (910691) panicked at zaino-state/src/backends/fetch.rs:144:14:
called `Result::unwrap()` on an `Err` value: InvalidNodeData(Unrecoverable("unexpected error response from server: RPC Error (code: -8): parse error: could not convert the input string to a hash or height"))

which I believe to be due to sending a truncated block hash to the validator.

I think this is being called on zebra types, not ours... whether that's the right contract to rely on them or not for this usage... not sure. Do they advertise Display stability? sounds like we might be looking at a similar problem just not related to the Display changes in this PR.

@nachog00
Copy link
Contributor Author

nachog00 commented Mar 2, 2026

Unfortunately, there's at least one load-bearing to_string():

.get_block(id.to_string(), Some(0))

If I merge this PR into #864, zainod fails on

thread 'main' (910691) panicked at zaino-state/src/backends/fetch.rs:144:14:
called `Result::unwrap()` on an `Err` value: InvalidNodeData(Unrecoverable("unexpected error response from server: RPC Error (code: -8): parse error: could not convert the input string to a hash or height"))

which I believe to be due to sending a truncated block hash to the validator.

As i stated above, that id.to_string() is called on zebra, but i did identify a bunch of callsites of to_string on the affected type on this PR. they were all in chain_index/tests/finalised_state/v1.rs

nachog00 and others added 2 commits March 2, 2026 12:50
Replace .to_string() with .encode_hex::<String>() for TransactionHash
in test assertions. Display should be for human-readable logging, not
machine-readable formats.

This affects all test comparisons against JSON test vectors which
contain full 64-character hex strings.

Fixes #896
@nachog00
Copy link
Contributor Author

nachog00 commented Mar 2, 2026

I updated all .to_string calls to .hex_encode. Display on thus type should be free to change now.

as i mentioned in #896 , taking on the work planned in #640 should come right after and will make us way more robust against this sort of situations.

@AloeareV
Copy link
Contributor

AloeareV commented Mar 3, 2026

Unfortunately, there's at least one load-bearing to_string():

.get_block(id.to_string(), Some(0))

If I merge this PR into #864, zainod fails on

thread 'main' (910691) panicked at zaino-state/src/backends/fetch.rs:144:14:
called `Result::unwrap()` on an `Err` value: InvalidNodeData(Unrecoverable("unexpected error response from server: RPC Error (code: -8): parse error: could not convert the input string to a hash or height"))

which I believe to be due to sending a truncated block hash to the validator.

I think this is being called on zebra types, not ours... whether that's the right contract to rely on them or not for this usage... not sure. Do they advertise Display stability? sounds like we might be looking at a similar problem just not related to the Display changes in this PR.

Yeah, this is a zebra type, not a zaino type!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants