Closes#7995.
Fix duplicate fields being logged when the field exists in both the span and the event. Prefer event fields when this happens.
```
Sep 15 08:13:46.339 WARN State cache missed state_root: 0xc34826ff7794de63a553832b7aff13572d1c716b9e03d5ef7b29649adf98abe2, block_root: 0xf16d3f5b4cc6ec876b7faeccd9f2d4102dc56ed32e828754b62601637910ec1f, state_root: 0xc34826ff7794de63a553832b7aff13572d1c716b9e03d5ef7b29649adf98abe2, block_root: 0xf16d3f5b4cc6ec876b7faeccd9f2d4102dc56ed32e828754b62601637910ec1f
```
becomes
```
Sep 15 08:13:46.339 WARN State cache missed state_root: 0xc34826ff7794de63a553832b7aff13572d1c716b9e03d5ef7b29649adf98abe2, block_root: 0xf16d3f5b4cc6ec876b7faeccd9f2d4102dc56ed32e828754b62601637910ec1f
```
Co-Authored-By: Jimmy Chen <jchen.tc@gmail.com>
@chong-he noticed that the INFO/WARN/ERRO log counts on our dashboards had stopped working. Since switching to `tracing` we are now tracking total events _per crate_, and the global counters are unused.
Per-crate metrics are here:
cfb1f73310/common/logging/src/tracing_metrics_layer.rs (L61-L63)
Delete the unused global counters from the source.
We can sum across the per-crate metric in our dashboards to restore the previous functionality.
Co-Authored-By: Michael Sproul <michael@sigmaprime.io>
Potentially fixes#7995
changed `span_data` to a `HashMap` and added a new check to remove span fields whose base names are already present on the event.
Co-Authored-By: PoulavBhowmick03 <bpoulav@gmail.com>
Co-Authored-By: Michael Sproul <michael@sigmaprime.io>
#7234
Removes the `Arc<Mutex<_>` which was used to store and manage span data and replaces it with the inbuilt `Extension` for managing span-specific data. This also avoids an `unwrap` which was used when acquiring the lock over the mutex'd span data.
When we perform data column gossip verification, we sometimes see multiple proposer shuffling cache miss simultaneously and this results in multiple threads computing the shuffling cache and potentially slows down the gossip verification.
Proposal here is to use a `OnceCell` for each shuffling key to make sure it's only computed once. I have only implemented this in data column verification as a PoC, but this can also be applied to blob and block verification
Related issues:
- https://github.com/sigp/lighthouse/issues/4447
- https://github.com/sigp/lighthouse/issues/7203
#7153#7146#7147#7148 -> Thanks to @ackintosh
This PR does the following:
1. Disable logging to file when using either `--logfile-max-number 0` or `--logfile-max-size 0`. Note that disabling the log file in this way will also disable `discv5` and `libp2p` logging.
1. `discv5` and `libp2p` logging will be disabled by default unless running `beacon_node` or `boot_node`. This also should fix the VC panic we were seeing.
1. Removes log rotation and compression from `libp2p` and `discv5` logs. It is now limited to 1 file and will rotate based on the value of the `--logfile-max-size` flag. We could potentially add flags specifically to control the size/number of these, however I felt a single log file was sufficient. Perhaps @AgeManning has opinions about this?
1. Removes all dependency logging and references to `dep_log`.
1. Introduces workspace filtering to file and stdout. This explicitly allows logs from members of the Lighthouse workspace, disallowing all others. It uses a proc macro which pulls the member list from cargo metadata at compile time. This might be over-engineered but my hope is that this list will not require maintenance.
1. Unifies file and stdout JSON format. With slog, the formats were slightly different. @threehrsleep worked to maintain that format difference, to ensure there was no breaking changes. If these format differences are actually problematic we can restore it, however I felt the added complexity wasn't worth it.
1. General code improvements and cleanup.
* ensure file path passed to the rolling file appender only contains directories
* handle edge case
* handle edge case
* fix based on feedback
* Merge branch 'unstable' of https://github.com/sigp/lighthouse into rolling-file-apender-bug
* fmt
* linting
* ensure only bn inits tracing logfile
* ensure only bn inits tracing logfile
* Merge branch 'unstable' into rolling-file-apender-bug
* Get the metadata of `tracing_log_path` instead of `p`, which is a part of the path
* Merge pull request #11 from ackintosh/rolling-file-apender-bug-ackintosh
Get the metadata of `tracing_log_path` instead of `p`
* Merge branch 'unstable' of https://github.com/sigp/lighthouse into rolling-file-apender-bug
* fmt
* move gossipsub into a separate crate
* Merge branch 'unstable' of github.com:sigp/lighthouse into separate-gossipsub
* address review 2
* clippy beta
* update logging to log gossipsub logs
* add metrics layer
* add metrics
* simplify getting the target
* make clippy happy
* fix typos
* unify deps under workspace
* make import statement shorter, fix typos
* enable warn by default, mark flag as deprecated
* do not exit on error when initializing logging fails
* revert exit on error
* adjust bootnode logging
* add logging layer
* non blocking file writer
* non blocking file writer
* add tracing visitor
* use target as is by default
* make libp2p events register correctly
* adjust repilcated cli help
* refactor tracing layer
* linting
* filesize
* log gossipsub, dont filter by log level
* turn on debug logs by default, remove deprecation warning
* truncate file, add timestamp, add unit test
* suppress output (#5)
* use tracing appender
* cleanup
* Add a task to remove old log files and upgrade to warn level
* Add the time feature for tokio
* Udeps and fmt
---------
Co-authored-by: Diva M <divma@protonmail.com>
Co-authored-by: Divma <26765164+divagant-martian@users.noreply.github.com>
Co-authored-by: Age Manning <Age@AgeManning.com>
* add metrics layer
* add metrics
* simplify getting the target
* make clippy happy
* fix typos
* unify deps under workspace
* make import statement shorter, fix typos
* enable warn by default, mark flag as deprecated
* do not exit on error when initializing logging fails
* revert exit on error
* adjust bootnode logging
* use target as is by default
* make libp2p events register correctly
* adjust repilcated cli help
* turn on debug logs by default, remove deprecation warning
* suppress output (#5)
---------
Co-authored-by: Age Manning <Age@AgeManning.com>
## Issue Addressed
Synchronize dependencies and edition on the workspace `Cargo.toml`
## Proposed Changes
with https://github.com/rust-lang/cargo/issues/8415 merged it's now possible to synchronize details on the workspace `Cargo.toml` like the metadata and dependencies.
By only having dependencies that are shared between multiple crates aligned on the workspace `Cargo.toml` it's easier to not miss duplicate versions of the same dependency and therefore ease on the compile times.
## Additional Info
this PR also removes the no longer required direct dependency of the `serde_derive` crate.
should be reviewed after https://github.com/sigp/lighthouse/pull/4639 get's merged.
closes https://github.com/sigp/lighthouse/issues/4651
Co-authored-by: Michael Sproul <michael@sigmaprime.io>
Co-authored-by: Michael Sproul <micsproul@gmail.com>
## Issue Addressed
updates underlying dependencies and removes the ignored `RUSTSEC`'s for `cargo audit`.
Also switches `procinfo` to `procfs` on `eth2` to remove the `nom` warning, `procinfo` is unmaintained see [here](https://github.com/danburkert/procinfo-rs/issues/46).
This PR adds the ability to read the Lighthouse logs from the HTTP API for both the BN and the VC.
This is done in such a way to as minimize any kind of performance hit by adding this feature.
The current design creates a tokio broadcast channel and mixes is into a form of slog drain that combines with our main global logger drain, only if the http api is enabled.
The drain gets the logs, checks the log level and drops them if they are below INFO. If they are INFO or higher, it sends them via a broadcast channel only if there are users subscribed to the HTTP API channel. If not, it drops the logs.
If there are more than one subscriber, the channel clones the log records and converts them to json in their independent HTTP API tasks.
Co-authored-by: Michael Sproul <micsproul@gmail.com>
## Issue Addressed
#3010
## Proposed Changes
- move log debounce time latch to `./common/logging`
- add timelatch to limit logging for `attestations_delay_queue` and `queued_block_roots`
## Additional Info
- Is a separate crate for the time latch preferred?
- `elapsed()` could take `LOG_DEBOUNCE_INTERVAL ` as an argument to allow for different granularity.
## Proposed Changes
Lots of lint updates related to `flat_map`, `unwrap_or_else` and string patterns. I did a little more creative refactoring in the op pool, but otherwise followed Clippy's suggestions.
## Additional Info
We need this PR to unblock CI.
## Issue Addressed
New rust lints
## Proposed Changes
- Boxing some enum variants
- removing some unused fields (is the validator lockfile unused? seemed so to me)
## Additional Info
- some error fields were marked as dead code but are logged out in areas
- left some dead fields in our ef test code because I assume they are useful for debugging?
Co-authored-by: realbigsean <seananderson33@gmail.com>
## Issue Addressed
Closes#1996
## Proposed Changes
Run a second `Logger` via `sloggers` which logs to a file in the background with:
- separate `debug-level` for background and terminal logging
- the ability to limit log size
- rotation through a customizable number of log files
- an option to compress old log files (`.gz` format)
Add the following new CLI flags:
- `--logfile-debug-level`: The debug level of the log files
- `--logfile-max-size`: The maximum size of each log file
- `--logfile-max-number`: The number of old log files to store
- `--logfile-compress`: Whether to compress old log files
By default background logging uses the `debug` log level and saves logfiles to:
- Beacon Node: `$HOME/.lighthouse/$network/beacon/logs/beacon.log`
- Validator Client: `$HOME/.lighthouse/$network/validators/logs/validator.log`
Or, when using the `--datadir` flag:
`$datadir/beacon/logs/beacon.log` and `$datadir/validators/logs/validator.log`
Once rotated, old logs are stored like so: `beacon.log.1`, `beacon.log.2` etc.
> Note: `beacon.log.1` is always newer than `beacon.log.2`.
## Additional Info
Currently the default value of `--logfile-max-size` is 200 (MB) and `--logfile-max-number` is 5.
This means that the maximum storage space that the logs will take up by default is 1.2GB.
(200MB x 5 from old log files + <200MB the current logfile being written to)
Happy to adjust these default values to whatever people think is appropriate.
It's also worth noting that when logging to a file, we lose our custom `slog` formatting. This means the logfile logs look like this:
```
Oct 27 16:02:50.305 INFO Lighthouse started, version: Lighthouse/v2.0.1-8edd9d4+, module: lighthouse:413
Oct 27 16:02:50.305 INFO Configured for network, name: prater, module: lighthouse:414
```
## Issue Addressed
Fix#2585
## Proposed Changes
Provide a canonical version of test_logger that can be used
throughout lighthouse.
## Additional Info
This allows tests to conditionally emit logging data by adding
test_logger as the default logger. And then when executing
`cargo test --features logging/test_logger` log output
will be visible:
wink@3900x:~/lighthouse/common/logging/tests/test-feature-test_logger (Add-test_logger-as-feature-to-logging)
$ cargo test --features logging/test_logger
Finished test [unoptimized + debuginfo] target(s) in 0.02s
Running unittests (target/debug/deps/test_logger-e20115db6a5e3714)
running 1 test
Sep 10 12:53:45.212 INFO hi, module: test_logger:8
test tests::test_fn_with_logging ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Doc-tests test-logger
running 0 tests
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Or, in normal scenarios where logging isn't needed, executing
`cargo test` the log output will not be visible:
wink@3900x:~/lighthouse/common/logging/tests/test-feature-test_logger (Add-test_logger-as-feature-to-logging)
$ cargo test
Finished test [unoptimized + debuginfo] target(s) in 0.02s
Running unittests (target/debug/deps/test_logger-02e02f8d41e8cf8a)
running 1 test
test tests::test_fn_with_logging ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Doc-tests test-logger
running 0 tests
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
## Issue Addressed
N/A
## Proposed Changes
- Removing a bunch of unnecessary references
- Updated `Error::VariantError` to `Error::Variant`
- There were additional enum variant lints that I ignored, because I thought our variant names were fine
- removed `MonitoredValidator`'s `pubkey` field, because I couldn't find it used anywhere. It looks like we just use the string version of the pubkey (the `id` field) if there is no index
## Additional Info
Co-authored-by: realbigsean <seananderson33@gmail.com>
## Issue Addressed
- Resolves#1706
## Proposed Changes
Updates dependencies across the workspace. Any crate that was not able to be brought to the latest version is listed in #1712.
## Additional Info
NA
## Issue Addressed
N/A
## Proposed Changes
Earlier, to log to a file, the only options were to redirect stdout/stderr to a file or use json logging.
Redirecting to stdout/stderr works well but causes issues with mistakenly overwriting the file instead of appending which has resulted in loss of precious logs on multiple occasions for me.
Json logging creates a timestamped backup of the file if it already exists, but the json format itself is hugely annoying.
This PR modifies the `--logfile` option to log as it does in the terminal to a logfile.
