Skip to content

All About Logs

Jump to bottom
Diwaker Gupta edited this page Jun 2, 2023 · 5 revisions

Overview

This codebase uses the slog crate for structured logging. Use the info!, debug! etc macros. See existing usage for examples, and also the log macro documentation.

Structure of a log message

Here's what a typical log message might look like:

INFO [1685718425.067022] [testnet/stacks-node/src/main.rs:82] [main] stacks-node 0.1.0 (chore/logs:a93c2867d+, debug build, macos [aarch64])

Let's break down the components:

  1. Log level: DEBG, INFO, WARN or ERRO (4 chars wide)
  2. Timestamp: By default, this is the Unix time (basically, time since std::time::UNIX_EPOCH), in seconds and nanoseconds (6 degrees of precision). This can be changed using STACKS_LOG_FORMAT_TIME, see below for details.
  3. Filename and line number: where the log message comes from in the source.
  4. Thread identifier: A string that identifies the thread where the log message was generated. Most threads will have descriptive identifiers like main, chains-coordinator-0.0.0.0:20443, p2p-(0.0.0.0:20444,0.0.0.0:20443). Note that some of the thread identifiers include a host/port on which that thread might be listening on.
  5. Log message: the actual contents of the log. This is where the "structured" part of slog comes in, among other things.

Tips and Tricks

Logs go stderr

The stacks-node binary output logs to stderr (vs. stdout). To easily capture / pipe / filter logs (e.g. using tools like tee), redirect stderr to stdout. In bash, this is accomplished with 2>&1, like so:

$ stacks-node start --config follower.toml 2>&1 | tee info-logs.txt`

Enabling debug logs

By default, the log level is set to INFO. To enable debug logging, set the environment variable STACKS_LOG_DEBUG=1.

$ STACKS_LOG_DEBUG=1 stacks-node start --config follower.toml 2>&1 | tee info-logs.txt`

To set the log-level to TRACE, set STACKS_LOG_TRACE=1 instead.

Output logs in JSON

First, you must compile stacks-node with the slog_json feature enabled, like so:

$ cargo build -F slog_json -p stacks-node --bin stacks-node

Once enabled, set the environment variable STACKS_LOG_JSON=1:

$ STACKS_LOG_JSON=1  stacks-node check-config --config follower.toml 2>&1 | jq .
{
  "msg": "stacks-node 0.1.0 (chore/logs:a93c2867d+, debug build, macos [aarch64])",
  "level": "INFO",
  "ts": "2023-06-02T16:54:04.377153Z",
  "thread": "main",
  "line": 82,
  "file": "testnet/stacks-node/src/main.rs"
}

Change timestamp format

Set the STACKS_LOG_FORMAT_TIME environment variable to change the default timestamp formatting. Any valid strftime is acceptable.

Here's an example:

$ STACKS_LOG_FORMAT_TIME="%F:%T" ./target/debug/stacks-node start --config follower.toml
# Note the timestamp format
INFO [2023-06-02:14:10:12] [testnet/stacks-node/src/main.rs:82] [main] stacks-node 0.1.0 (chore/logs:a93c2867d+, debug build, macos [aarch64])
INFO [2023-06-02:14:10:12] [testnet/stacks-node/src/main.rs:140] [main] Loading config at path follower.toml
Clone this wiki locally