Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Documentation for V27 logging & tracing #704

Merged
merged 4 commits into from
Aug 31, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 0 additions & 30 deletions docs/running-a-node/configuration.md
Original file line number Diff line number Diff line change
Expand Up @@ -236,36 +236,6 @@ enable_control = false

More advanced options for controlling the process the RPC server runs under can be found in the [Running Nano as a service guide](../integration-guides/advanced.md#running-nano-as-a-service).

#### logging.stable_log_filename

--8<-- "known-issue-windows-logging-stable.md"

This configuration option is set in the [`config-node.toml` file](../running-a-node/configuration.md#configuration-file-locations).

By default this option is set to `false` which results in all log files having a timestamp appended to them, even the currently active file. If set to `true` the currently active log file will have a static name at `log/node.log` for easier management.

```toml
[node.logging]

# Append to log/node.log without a timestamp in the filename.
# The file is not emptied on startup if it exists, but appended to.
# type:bool
stable_log_filename = true
```

#### logging.log_rpc
This configuration option is set in the [`config-rpc.toml`](../running-a-node/configuration.md#configuration-file-locations) file.

By default, all RPC calls and the time spent handling each one are [logged](../running-a-node/troubleshooting.md#log-files). This can be optionally turned off by switching option `logging.log_rpc` to `false`

```toml
[logging]

# Whether to log RPC calls.
# type:bool
log_rpc = true
```

### IPC
See the [IPC Integration guide](../integration-guides/ipc-integration.md#configuration).

Expand Down
2 changes: 1 addition & 1 deletion docs/running-a-node/ledger-management.md
Original file line number Diff line number Diff line change
Expand Up @@ -105,7 +105,7 @@ In order to minimize downtime, consider performing the update in a different mac
* Copy [`data.ldb`](#ledger-file) from Machine A to `/home/<user>/Nano_Update/data.ldb` on Machine B.
* Start the node again on Machine A, resuming operation.
1. Download the [latest node version](/releases/node-releases/#current-release) to Machine B. For the purposes of this guide, using a binary is easier.
1. Run the following command on Machine B (varies based on your operating system): `./nano_node --debug_block_count --data_path /home/<user>/Nano_Update --config node.logging.log_to_cerr=true`
1. Run the following command on Machine B (varies based on your operating system): `./nano_node --debug_block_count --data_path /home/<user>/Nano_Update --config log.console.to_cerr=true`
1. The message *"Upgrade in progress..."* will be displayed if a ledger upgrade is required. Wait until the command finishes and **do not stop the upgrade preemptively**.
1. Copy `/home/<user>/Nano_Update/data.ldb` from Machine B to a temporary location on Machine A. **do not overwrite data.ldb on Machine A while the node is running**.
1. **Stop** the node on Machine A.
Expand Down
184 changes: 184 additions & 0 deletions docs/running-a-node/logging-tracing.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,184 @@
# Nano Node Logging Documentation

## Introduction

This documentation covers the logging facilities of the Nano Node, including configuration options, environment variables, and usage of tracing and stats logging.

## Overview - V27 and later

### Log Levels

Log levels are used to control the verbosity of log output. The available log levels are:

```toml
- trace
- debug
- info
- warn
- error
- critical
- off
```

For users, log levels up to debug are useful. Tracing and stats logging are primarily for developers debugging the node.

### Configuration - V27 and later

There are two ways to configure the logger:

* The first is to use a **config file** `config-log.toml`, which is located in the data directory alongside other configuration files.

* The second is to use `NANO_LOG` and `NANO_LOG_LEVELS` **environment variables**. The environment variables take precedence over the configuration file.


#### Config File (config-log.toml)

During normal node operation, the configuration file is loaded from the data directory.
When running test suites, the configuration is loaded from the current working directory.

##### Example config-log.toml
```
[log]
default_level = "info"

[log.console]
#colors = true
enable = true
#to_cerr = false

[log.file]
enable = true
#max_size = 33554432
#rotation_count = 4

[log.levels]
#active_transactions = "info"
#all = "info"
#blockprocessor = "info"
#bootstrap = "info"
#bootstrap_lazy = "info"
#...
#log_type = "log_level"
```

The full list of `log_types` can be found [here](https://github.com/nanocurrency/nano-node/blob/develop/nano/lib/logging_enums.hpp#L24-L95)


#### Environment Variables

Environment variables override the configuration file. This is useful when running test suites.

##### Set default log level
```
NANO_LOG = [trace|debug|info|warn|error|critical|off]
```

##### Set log level for individual loggers
```
NANO_LOG_LEVELS = log_type_1=level_1[,log_type_2=level_2,...]
```

Example:
```
export NANO_LOG=warn
export NANO_LOG_LEVELS=active_transactions=debug,bootstrap=debug
```


### Unit Tests

By default, the logger is disabled when running unit tests to keep the output clean. To enable it, set the `NANO_LOG` environment variable to a desired log level.
Alternatively a configuration file inside the current working directory will be loaded by the test suites.

In test suite mode, each log line additionally contains the identifier of the node that produced the log line (first 10 characters of its node ID). This makes it easier to follow the flow of events and will become much more useful once full tracing is implemented.


### Tracing

The goal of tracing is to introduce a framework for tracing events in the node. This is meant to be used for debugging and profiling purposes, e.g., by visualizing the flow of votes through the network or analyzing the delay between receiving a block and confirming it.

#### Tracing Usage
To use tracing, it must be enabled **at compile time** by passing the `-DNANO_TRACING=ON` flag to CMake. By default, it is disabled for release builds and enabled for debug builds.

After that, tracing can be enabled by setting the logging verbosity level to `trace`:
```
NANO_LOG=trace
```

Since the amount of logs when setting the logging level to `trace` is very large, it is recommended to use the trace level only for specific components. This can be done by setting the `NANO_LOG_LEVELS` environment variable to a comma-separated list of components to trace. For example, to trace only `active_transactions` and `vote_processor`, set:
```
NANO_LOG_LEVELS="active_transactions=trace,vote_processor=trace"
```

Alternatively, this can also be done by modifying the `config-log.toml` file.


### Tracing Formats

It is possible to specify the format of tracing output at runtime. This is done by setting the `NANO_TRACE_FORMAT` environment variable to one of the following: `standard` or `json`.

#### Standard Tracing
Standard tracing is enabled by default. It is a simple key: { value } format with indentation that should be easy to read.

#### JSON Tracing
JSON tracing is meant to be parsed by external tools. There is no indentation or newlines, so each log output line can be treated as a separate event, which simplifies parsing.

##### Sample JSON Tracing output:
```
[2024-01-30 17:56:53.312] [vote_processor::vote_processed] [trace] "event":"vote_processor::vote_processed","time":1706633813312751,"vote":{"account":"FD16B0FE0102F68C2D9482348AE7211E3CBF86681364E53D8793A5E551167A6C","final":true,"timestamp":18446744073709551615,"hashes":["7DEF4D1F5EB222BC5DE2123293EE5A8CE58E283176AB65DF3373DA009FD99E86"]},"result":"indeterminate"
```


### Stats Logging

This allows logging individual stat counter increments. This is useful for debugging tests. This functionality can be enabled by setting the `NANO_LOG_STATS=[1,true,on]` environment variable.

#### Example output:
```
[2024-05-02 18:43:27.939] [node_16gzg] [stats] [debug] Stat: bootstrap_server::request::in += 1
[2024-05-02 18:43:27.939] [node_16gzg] [stats] [debug] Stat: bootstrap_server_request::blocks::in += 1
[2024-05-02 18:43:27.939] [node_3e5x4] [stats] [debug] Stat: traffic_tcp::all::out += 51
[2024-05-02 18:43:27.939] [node_3e5x4] [stats] [debug] Stat: bootstrap_ascending::track::in += 1
[2024-05-02 18:43:27.939] [node_3e5x4] [stats] [debug] Sample: bootstrap_tag_duration -> 1
```



## Overview - V26 and prior

V26 and prior version use a different method to enable logs.

### Configuration - V26 and prior

```toml
[node.logging]

# Append to log/node.log without a timestamp in the filename.
# The file is not emptied on startup if it exists, but appended to.
# type:bool
stable_log_filename = true
```

This configuration option is set in the [`config-node.toml` file](../running-a-node/configuration.md#configuration-file-locations).

To generate a config file with all logging options, run `nano_node --generate_config node`

#### logging.stable_log_filename

--8<-- "known-issue-windows-logging-stable.md"

By default this option is set to `false` which results in all log files having a timestamp appended to them, even the currently active file. If set to `true` the currently active log file will have a static name at `log/node.log` for easier management.


#### logging.log_rpc
This configuration option is set in the [`config-rpc.toml`](../running-a-node/configuration.md#configuration-file-locations) file.

By default, all RPC calls and the time spent handling each one are [logged](../running-a-node/troubleshooting.md#log-files). This can be optionally turned off by switching option `logging.log_rpc` to `false`

```toml
[logging]

# Whether to log RPC calls.
# type:bool
log_rpc = true
```
9 changes: 8 additions & 1 deletion docs/running-a-node/troubleshooting.md
Original file line number Diff line number Diff line change
Expand Up @@ -839,8 +839,15 @@ or via cli flag
```

### Enable UPnP logging
Appending this to your launch command will enable upnp logging.
Appending this to your launch command will enable upnp debug logging.

```bash
#V27 or later
--config log.console.upnp=debug
```

```bash
# V26 or before
--config node.logging.upnp_details=true
```
### Error UPnP Messages
Expand Down
1 change: 1 addition & 0 deletions docs/snippets/toml-config-commands.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,5 +2,6 @@
|---------|--------------|--------------|
| `config-node.toml` | Node configuration | `nano_node --generate_config node` |
| `config-rpc.toml` | RPC configuration | `nano_node --generate_config rpc` |
| `config-log.toml` | Log configuration | `nano_node --generate_config log` |
| `config-nano-pow-server.toml` | Proof of work server configuration | `nano_pow_server --generate_config` |
| `config-qtwallet.toml` | Qt developer wallet configuration | This file is maintained by the Qt wallet |
1 change: 1 addition & 0 deletions mkdocs.yml
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ nav:
- Wallet Setup: running-a-node/wallet-setup.md
- Docker Management: running-a-node/docker-management.md
- Configuration: running-a-node/configuration.md
- Logging & Tracing: running-a-node/logging-tracing.md
- Ledger Management: running-a-node/ledger-management.md
- Voting as a Representative: running-a-node/voting-as-a-representative.md
- Advanced Monitoring: running-a-node/advanced-monitoring.md
Expand Down
Loading