Expand description
§Structured Contextual Logging (or tracing)
§Why
§Intention of this crate
This crate is designed ot be a place to experiment with ideas around tracing and structured logging. This crate will probably never stabilize. Instead it is my hope to feed any good ideas back into the underlying dependencies.
§Usage
There are a couple of ways to use structured logging.
§Console and filter
If you want to try and filter in on an issue it might be easiest to simply log to the console and filter on what you want. Here’s an example command:
RUST_LOG='core[a{something="foo"}]=debug' my_bin
Or a more simple version using the default Log
:
RUST_LOG=trace my_bin
§Types of tracing
There are many types of tracing exposed by this crate. The Output type is designed to be used with something like structopt so you can easily set which type you want with a command line arg. You could also use an environment variable. The Output variant is passing into the init_fmt function on start up.
§Filtering
RUST_LOG='core[a{something="foo"}]=debug'
Here we are saying show me all the events that are:
- In the
core
module - Inside a span called
a
- The span
a
has to have a field calledsomething
that is equal tofoo
- They are at least debug level.
Most of these options are optional. They can be combined like:
RUST_LOG='[{}]=error,[{something}]=debug'
The above means show me errors from anywhere but also any event or span with the field something that’s at least debug.
See here for more info.
§Json
Sometimes there’s too much data and it’s better to capture it to interact with using another tool later.
For this we can output everything as Json using the flag --structured Json
.
Then you can pipe the output from stdout to you’re file of choice.
Here’s some sample output:
{"time":"2020-03-03T08:07:05.910Z","name":"event crates/sim2h/src/sim2h_im_state.rs:695","level":"INFO","target":"sim2h::sim2h_im_state","module_path":"sim2h::sim2h_im_state","file":"crates/sim2h/src/sim2h_im_stat
e.rs","line":695,"fields":{"space_hashes":"[]"},"spans":[{"id":[1099511627778],"name":"check_gossip","level":"INFO","target":"sim2h::sim2h_im_state","module_path":"sim2h::sim2h_im_state","file":"crates/sim2h/src/s
im2h_im_state.rs","line":690}]}
Every log will include the above information expect for the spans which will only show up if there are parent spans in the context of the event.
You can combine filter with Json as well.
§Tools
Some useful tools for formatting and using the json data.
A sample workflow:
RUST_LOG='core[{}]=debug' my_bin --structured Json > log.json
cat out.json | jq '. | {time: .time, name: .name, message: .fields.message, file: .file, line: .line, fields: .fields, spans: .spans}' | json2csv -o log.csv
tad log.csv
Re-exports§
pub use open::should_run;
pub use tracing;
Modules§
- Error in the tracing/logging framework
- Metrics
Macros§
- Create a metrics set. Takes the name of the metric set followed by a list of metric names.
- Emit a tracing event with the context of a span.
Structs§
- Configuration for open telemetry tracing. These can all be configured by setting the
OPEN_TEL='process:true,file:false'
. They all have default settings. - The context holds the current state of a span. This can be used to transfer contexts across boundaries. A boundary crossing will show up as a follower for a span.
- Wrap a channel message in a span context. The context is automatically propagated to the current span by calling
msg_wrap.inner()
. The context is automatically propagated from the current span by callingt.into()
. If you wish to avoid either of these propagations you can usemsg_wrap.without_context()
andMsgWrap::from_no_context(t)
respectively.
Enums§
- Sets the kind of structured logging output you want
Traits§
- Opentelemetry span extension trait. This trait provides helper methods to the tracing::Span for crossing thread and process boundaries.
Functions§
- This checks RUST_LOG for a filter but doesn’t complain if there is none or it doesn’t parse. It then checks for CUSTOM_FILTER which if set will output an error if it doesn’t parse.
- Run logging in a unit test RUST_LOG or CUSTOM_FILTER must be set or this is a no-op
- Run tracing in a test that uses open telemetry to send span contexts across process and thread boundaries.
- Same as test_run but with timed spans
- Generate a flamegraph from timed spans “busy time”. Takes a path where you are piping the output into. If the path is provided a flamegraph will automatically be generated. TODO: Get auto inferno to work for now use (fish, or the bash equiv):
2>| inferno-flamegraph > flamegraph_test_ice_(date +'%d-%m-%y-%X').svg
And run withcargo test --quiet
- Generate a flamegraph from timed spans “idle time”. Takes a path where you are piping the output into. If the path is provided a flamegraph will automatically be generated. TODO: Get auto inferno to work for now use (fish, or the bash equiv):
2>| inferno-flamegraph -c blue > flamegraph_test_ice_(date +'%d-%m-%y-%X').svg
And run withcargo test --quiet
- Same as test_run_timed but saves as json
Type Aliases§
- ParseError is a String