-
|
The docs indicate the following:
I am new to rust and have been struggling to produce an example that emits log records for span lifecycle events. Can someone help me put together an example that does this? Here is what I have: https://github.com/maowen/tracing_span_activity Example OutputNote: No $ RUST_LOG=trace,tracing::span::activity=error cargo run
Finished dev [unoptimized + debuginfo] target(s) in 0.01s
Running `target/debug/tracing_span_activity`
2022-05-19T05:47:11.887718Z DEBUG tracing_span_activity: preparing to shave 3 yaks
2022-05-19T05:47:11.887793Z INFO shaving_yaks{yaks=3}: tracing_span_activity::yak_shave: shaving yaks
2022-05-19T05:47:11.887829Z TRACE shaving_yaks{yaks=3}:shave{yak=1}: tracing_span_activity::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
2022-05-19T05:47:11.887850Z TRACE shaving_yaks{yaks=3}:shave{yak=1}: tracing_span_activity::yak_shave: yak shaved successfully
2022-05-19T05:47:11.887877Z DEBUG shaving_yaks{yaks=3}: yak_events: yak=1 shaved=true
2022-05-19T05:47:11.887894Z TRACE shaving_yaks{yaks=3}: tracing_span_activity::yak_shave: yaks_shaved=1
2022-05-19T05:47:11.887917Z TRACE shaving_yaks{yaks=3}:shave{yak=2}: tracing_span_activity::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
2022-05-19T05:47:11.887933Z TRACE shaving_yaks{yaks=3}:shave{yak=2}: tracing_span_activity::yak_shave: yak shaved successfully
2022-05-19T05:47:11.887953Z DEBUG shaving_yaks{yaks=3}: yak_events: yak=2 shaved=true
2022-05-19T05:47:11.887967Z TRACE shaving_yaks{yaks=3}: tracing_span_activity::yak_shave: yaks_shaved=2
2022-05-19T05:47:11.887988Z TRACE shaving_yaks{yaks=3}:shave{yak=3}: tracing_span_activity::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
2022-05-19T05:47:11.888008Z WARN shaving_yaks{yaks=3}:shave{yak=3}: tracing_span_activity::yak_shave: could not locate yak
2022-05-19T05:47:11.888030Z DEBUG shaving_yaks{yaks=3}: yak_events: yak=3 shaved=false
2022-05-19T05:47:11.888048Z ERROR shaving_yaks{yaks=3}: tracing_span_activity::yak_shave: failed to shave yak yak=3 error=missing yak error.sources=[out of space, out of cash]
2022-05-19T05:47:11.888065Z TRACE shaving_yaks{yaks=3}: tracing_span_activity::yak_shave: yaks_shaved=2
2022-05-19T05:47:11.888084Z DEBUG tracing_span_activity: yak shaving completed. all_yaks_shaved=falseCode for referenceCargo.toml[package]
name = "tracing_span_activity"
version = "0.1.0"
edition = "2021"
# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
[dependencies]
tracing = { version = "0.1" }
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
# fmt examples
snafu = "0.6.10"
thiserror = "1.0.26"
src/main.rs#![deny(rust_2018_idioms)]
#[path = "fmt/yak_shave.rs"]
mod yak_shave;
use tracing;
fn main() {
use tracing_subscriber::{fmt, EnvFilter};
fmt()
.with_max_level(tracing::Level::TRACE)
.with_env_filter(EnvFilter::from_default_env())
.init();
let number_of_yaks = 3;
tracing::debug!("preparing to shave {} yaks", number_of_yaks);
let number_shaved = yak_shave::shave_all(number_of_yaks);
tracing::debug!(
message = "yak shaving completed.",
all_yaks_shaved = number_shaved == number_of_yaks,
);
}src/fmt/yak_shave.rsuse snafu::{ResultExt, Snafu};
use std::error::Error;
use thiserror::Error;
use tracing::{debug, error, info, span, trace, warn, Level};
// the `#[tracing::instrument]` attribute creates and enters a span
// every time the instrumented function is called. The span is named after
// the function or method. Paramaters passed to the function are recorded as fields.
#[tracing::instrument]
pub fn shave(yak: usize) -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
// this creates an event at the TRACE log level with two fields:
// - `excitement`, with the key "excitement" and the value "yay!"
// - `message`, with the key "message" and the value "hello! I'm gonna shave a yak."
//
// unlike other fields, `message`'s shorthand initialization is just the string itself.
trace!(excitement = "yay!", "hello! I'm gonna shave a yak");
if yak == 3 {
warn!("could not locate yak");
return OutOfCash
.fail()
.map_err(|source| MissingYakError::OutOfSpace { source })
.context(MissingYak)
.map_err(|err| err.into());
} else {
trace!("yak shaved successfully");
}
Ok(())
}
pub fn shave_all(yaks: usize) -> usize {
// Constructs a new span named "shaving_yaks" at the INFO level,
// and a field whose key is "yaks". This is equivalent to writing:
//
// let span = span!(Level::INFO, "shaving_yaks", yaks = yaks);
//
// local variables (`yaks`) can be used as field values
// without an assignment, similar to struct initializers.
let span = span!(Level::INFO, "shaving_yaks", yaks);
let _enter = span.enter();
info!("shaving yaks");
let mut yaks_shaved = 0;
for yak in 1..=yaks {
let res = shave(yak);
debug!(target: "yak_events", yak, shaved = res.is_ok());
if let Err(ref error) = res {
// Like spans, events can also use the field initialization shorthand.
// In this instance, `yak` is the field being initialized.
error!(yak, error = error.as_ref(), "failed to shave yak");
} else {
yaks_shaved += 1;
}
trace!(yaks_shaved);
}
yaks_shaved
}
// Error types
// Usually you would pick one error handling library to use, but they can be mixed freely
#[derive(Debug, Snafu)]
enum OutOfSpaceError {
#[snafu(display("out of cash"))]
OutOfCash,
}
#[derive(Debug, Error)]
enum MissingYakError {
#[error("out of space")]
OutOfSpace { source: OutOfSpaceError },
}
#[derive(Debug, Snafu)]
enum YakError {
#[snafu(display("missing yak"))]
MissingYak { source: MissingYakError },
} |
Beta Was this translation helpful? Give feedback.
Answered by
hawkw
May 19, 2022
Replies: 1 comment 1 reply
-
|
The span activity events you're referring to are In your code, you're not using the If you're interested in configuring use tracing_subscriber::{fmt, fmt::format::FmtSpan, EnvFilter};
fmt()
.with_max_level(tracing::Level::TRACE)
.with_env_filter(EnvFilter::from_default_env())
.with_span_events(FmtSpan::FULL)
.init();Hope that helps! |
Beta Was this translation helpful? Give feedback.
1 reply
-
|
Thank you for your help! Work got very busy. Sorry for the slow response. Here is the example I put together using Example Output:Source Code:Cargo.toml[package]
name = "tracing_span_activity"
version = "0.1.0"
edition = "2021"
# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
[dependencies]
tracing = { version = "0.1", features = ["log", "log-always"] }
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
# fmt examples
snafu = "0.6.10"
thiserror = "1.0.26"main.rs#![deny(rust_2018_idioms)]
#[path = "fmt/yak_shave.rs"]
mod yak_shave;
use tracing;
fn main() {
use tracing_subscriber::{fmt, fmt::format::FmtSpan, EnvFilter};
fmt()
.with_max_level(tracing::Level::TRACE)
.with_env_filter(EnvFilter::from_default_env())
.with_span_events(FmtSpan::FULL)
.init();
let number_of_yaks = 3;
tracing::debug!("preparing to shave {} yaks", number_of_yaks);
let number_shaved = yak_shave::shave_all(number_of_yaks);
tracing::debug!(
message = "yak shaving completed.",
all_yaks_shaved = number_shaved == number_of_yaks,
);
}fmt/yak_shave.rsuse snafu::{ResultExt, Snafu};
use std::error::Error;
use thiserror::Error;
use tracing::{debug, error, info, span, trace, warn, Level};
// the `#[tracing::instrument]` attribute creates and enters a span
// every time the instrumented function is called. The span is named after
// the function or method. Paramaters passed to the function are recorded as fields.
#[tracing::instrument]
pub fn shave(yak: usize) -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
// this creates an event at the TRACE log level with two fields:
// - `excitement`, with the key "excitement" and the value "yay!"
// - `message`, with the key "message" and the value "hello! I'm gonna shave a yak."
//
// unlike other fields, `message`'s shorthand initialization is just the string itself.
trace!(excitement = "yay!", "hello! I'm gonna shave a yak");
if yak == 3 {
warn!("could not locate yak");
return OutOfCash
.fail()
.map_err(|source| MissingYakError::OutOfSpace { source })
.context(MissingYak)
.map_err(|err| err.into());
} else {
trace!("yak shaved successfully");
}
Ok(())
}
pub fn shave_all(yaks: usize) -> usize {
// Constructs a new span named "shaving_yaks" at the INFO level,
// and a field whose key is "yaks". This is equivalent to writing:
//
// let span = span!(Level::INFO, "shaving_yaks", yaks = yaks);
//
// local variables (`yaks`) can be used as field values
// without an assignment, similar to struct initializers.
let span = span!(Level::INFO, "shaving_yaks", yaks);
let _enter = span.enter();
info!("shaving yaks");
let mut yaks_shaved = 0;
for yak in 1..=yaks {
let res = shave(yak);
debug!(target: "yak_events", yak, shaved = res.is_ok());
if let Err(ref error) = res {
// Like spans, events can also use the field initialization shorthand.
// In this instance, `yak` is the field being initialized.
error!(yak, error = error.as_ref(), "failed to shave yak");
} else {
yaks_shaved += 1;
}
trace!(yaks_shaved);
}
yaks_shaved
}
// Error types
// Usually you would pick one error handling library to use, but they can be mixed freely
#[derive(Debug, Snafu)]
enum OutOfSpaceError {
#[snafu(display("out of cash"))]
OutOfCash,
}
#[derive(Debug, Error)]
enum MissingYakError {
#[error("out of space")]
OutOfSpace { source: OutOfSpaceError },
}
#[derive(Debug, Snafu)]
enum YakError {
#[snafu(display("missing yak"))]
MissingYak { source: MissingYakError },
} |
Beta Was this translation helpful? Give feedback.
Answer selected by
maowen
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
The span activity events you're referring to are
logrecords, from thelogcrate. They are nottracingevents, and are only emitted whentracing'slogbackwards-compatibility feature is enabled. This is becausetracingsubscribers can natively consume span activity without requiring special log records, while thelogcrate is not aware of the concept of "spans" and this mechanism is the only waylogusers can record this data.In your code, you're not using the
logcrate; instead, you're usingtracing_subscriber::fmtto logtracingevents. Thefmtsubscriber is also aware of span activity, but it doesn't emit a log line by default when spans are created/entered/exited/closed. Instead, it …