Skip to content

Add a dbg! macro like std::dbg! for quick-and-dirty debugging #185

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

Merged
merged 4 commits into from
Jan 7, 2025
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
16 changes: 16 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -83,3 +83,19 @@ See [the guide](https://emit-rs.io/producing-events/tracing.html) for details.
The above screenshot was generated by [this example application](https://github.com/emit-rs/emit/tree/main/examples/metric_prometheus).

See [the guide](https://emit-rs.io/producing-events/metrics.html) for details.

## Quick debugging

`emit` has a `dbg!` macro like the standard library's which you can use for quick-and-dirty debugging:

```rust
#[derive(Debug)]
pub struct User<'a> {
id: u32,
name: &'a str,
}

emit::dbg!(&User { id: 1, name: "Rust" });
```

See [the guide](https://emit-rs.io/producing-events/quick-debugging.html) for details.
1 change: 1 addition & 0 deletions book/src/SUMMARY.md
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
- [Time-series metrics](./producing-events/metrics/time-series-metrics.md)
- [Reporting from sources](./producing-events/metrics/reporting-sources.md)
- [Limitations](./producing-events/metrics/limitations.md)
- [Quick debugging](./producing-events/quick-debugging.md)
- [Filtering events](./filtering-events.md)
- [Working with events](./working-with-events.md)
- [Emitting events](./emitting-events.md)
Expand Down
18 changes: 18 additions & 0 deletions book/src/getting-started.md
Original file line number Diff line number Diff line change
Expand Up @@ -70,8 +70,26 @@ async fn add_item(user: &str, item: &str) {

Any diagnostics emitted within a traced function will be correlated with it. Any other traced functions it calls will form a trace hierarchy.

## Quick debugging

Use the [`dbg!`](https://docs.rs/emit/0.11.0-alpha.21/emit/macro.dbg.html) macro to help debug code as you're writing it:

```rust
# extern crate emit;
#[emit::span("add {item} to {user} cart")]
async fn add_item(user: &str, item: &str) {
emit::dbg!(user, item);

// Your code goes here
}
```

It works a lot like the standard library's `dbg!` macro, and is meant to be used as a quick, temporary debugging aid.

## Next steps

To learn more about configuring `emit`, see the [Emitting events](./emitting-events.md) section.

To learn more about using `emit`, see the [Producing events](./producing-events.md) section.

To learn `emit`'s architecture in more detail, see the [Reference](./reference.md) section.
Expand Down
1 change: 1 addition & 0 deletions book/src/producing-events.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,3 +5,4 @@ This section describes how to use `emit` to produce diagnostics in your applicat
- [Logging events](./producing-events/logging.md).
- [Tracing operations](./producing-events/tracing.md).
- [Sampling metrics](./producing-events/metrics.md).
- [Quick debugging](./producing-events/quick-debugging.md).
102 changes: 102 additions & 0 deletions book/src/producing-events/quick-debugging.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
# Quick debugging

It can be useful when you're actively working on a piece of code to get a quick window into what it's doing by logging data at various points. This kind of diagnostic is useful in the short term, but if left becomes noise. `emit` provides the [`dbg`](https://docs.rs/emit/0.11.0-alpha.21/emit/macro.dbg.html) as a quick alternative to [first-class logging](./logging.md) for these temporary debugging aids.

## The `dbg!` macro

`emit`'s [`dbg!`](https://docs.rs/emit/0.11.0-alpha.21/emit/macro.dbg.html) macro works similarly to [the standard library's of the same name](https://doc.rust-lang.org/std/macro.dbg.html), and shares the same motivations.

When given a field-value expression, `dbg!` will emit an event that includes it along with the source location:

```rust
# extern crate emit;
fn confirm_email(user: &str, email: &str) {
emit::dbg!(user);

// ..
}
```

```text
Event {
mdl: "dbg",
tpl: "user = {user} at {file}:{line}",
extent: Some(
"2025-01-07T03:55:19.738224881Z",
),
props: {
"file": "main.rs",
"line": 11,
"lvl": debug,
"user": "Rust",
},
}
```

`dbg!` accepts multiple field-values:

```rust
# extern crate emit;
fn confirm_email(user: &str, email: &str) {
emit::dbg!(user, email);

// ..
}
```

```text
Event {
mdl: "dbg",
tpl: "email = {email}, user = {user} at {file}:{line}",
extent: Some(
"2025-01-07T03:56:02.570025234Z",
),
props: {
"email": "rust@example.com",
"file": "main.rs",
"line": 11,
"lvl": debug,
"user": "Rust",
},
}
```

You can also specify a template, just like in [regular logging](./logging.md):

```rust
# extern crate emit;
fn confirm_email(user: &str, email: &str) {
emit::dbg!("got {user} and {email}");

// ..
}
```

```text
Event {
mdl: "dbg",
tpl: "got {user} and {email}",
extent: Some(
"2025-01-07T03:56:28.150050260Z",
),
props: {
"email": "rust@example.com",
"file": "main.rs",
"line": 11,
"lvl": debug,
"user": "Rust",
},
}
```

In order to be captured by `dbg!`, a value only needs to implement [`Debug`](https://doc.rust-lang.org/std/fmt/trait.Debug.html). This is different from regular logging, where values need to implement [`Display + 'static` by default](../reference/property-capturing.md).

## Where do `dbg!` events go?

`dbg!` events use the same infrastructure as [regular logging](./logging.md). In order to see them, you need to configure `emit` to write them to the console or other destination. See [Getting started](../getting-started.md) and [Emitting events](../emitting-events.md) for more details.

## `dbg!` vs `debug!`

`emit` also defines a [`debug!`](https://docs.rs/emit/0.11.0-alpha.21/emit/macro.debug.html) macro for events supporting live debugging. You should use `dbg!` for temporary logging that helps you actively debug code you're working on. You should use `debug!` for longer-lived logging that's useful for debugging a live system. When writing `debug!` or other logs, you should put more attention into when you're logging and what you're logging, so that you get the most value from the least volume. When writing `dbg!`, you should be unafraid to emit whatever you need to make sense of the code you're working on.

Don't simply convert `dbg!` statements to `debug!` ones. Once you're done with them, you're better off removing `dbg!` altogether. They're unlikely to be useful to you over time.
4 changes: 4 additions & 0 deletions examples/common_patterns/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,10 @@ version = "1"
version = "1"
features = ["derive"]

[[example]]
name = "dbg"
path = "dbg.rs"

[[example]]
name = "emit"
path = "emit.rs"
Expand Down
14 changes: 14 additions & 0 deletions examples/common_patterns/dbg.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
/*!
This example demonstrates how to use `emit::dbg!` for quick-and-dirty debugging.
*/

fn main() {
let rt = emit::setup().emit_to(emit_term::stdout()).init();

let id = 42;
let user = "Rust";

emit::dbg!(user, id);

rt.blocking_flush(std::time::Duration::from_secs(5));
}
12 changes: 8 additions & 4 deletions macros/src/build.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ use syn::{parse::Parse, spanned::Spanned, FieldValue, LitStr};

use crate::{
args::{self, Arg},
capture,
props::{push_evt_props, Props},
template,
util::ToRefTokens,
Expand Down Expand Up @@ -57,7 +58,8 @@ The `tpl_parts!` macro.
pub fn expand_tpl_parts_tokens(opts: ExpandTplTokens) -> Result<TokenStream, syn::Error> {
let span = opts.input.span();

let (_, template, props) = template::parse2::<TplPartsArgs>(opts.input, false)?;
let (_, template, props) =
template::parse2::<TplPartsArgs>(opts.input, capture::default_fn_name, false)?;

let template =
template.ok_or_else(|| syn::Error::new(span, "missing template string literal"))?;
Expand All @@ -73,7 +75,8 @@ The `tpl!` macro.
pub fn expand_tpl_tokens(opts: ExpandTplTokens) -> Result<TokenStream, syn::Error> {
let span = opts.input.span();

let (_, template, props) = template::parse2::<TplArgs>(opts.input, false)?;
let (_, template, props) =
template::parse2::<TplArgs>(opts.input, capture::default_fn_name, false)?;

let template =
template.ok_or_else(|| syn::Error::new(span, "missing template string literal"))?;
Expand All @@ -85,7 +88,7 @@ pub fn expand_tpl_tokens(opts: ExpandTplTokens) -> Result<TokenStream, syn::Erro

fn validate_props(props: &Props) -> Result<(), syn::Error> {
// Ensure that a standalone template only specifies identifiers
for key_value in props.iter() {
for (_, key_value) in props.iter() {
if !key_value.interpolated {
return Err(syn::Error::new(
key_value.span(),
Expand Down Expand Up @@ -164,7 +167,8 @@ The `evt!` macro.
pub fn expand_evt_tokens(opts: ExpandEvtTokens) -> Result<TokenStream, syn::Error> {
let span = opts.input.span();

let (args, template, mut props) = template::parse2::<EvtArgs>(opts.input, true)?;
let (args, template, mut props) =
template::parse2::<EvtArgs>(opts.input, capture::default_fn_name, true)?;

let template =
template.ok_or_else(|| syn::Error::new(span, "missing template string literal"))?;
Expand Down
37 changes: 20 additions & 17 deletions macros/src/capture.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,26 +33,10 @@ impl Parse for Args {
pub fn key_value_with_hook(
attrs: &[Attribute],
fv: &FieldValue,
fn_name: TokenStream,
interpolated: bool,
captured: bool,
) -> syn::Result<TokenStream> {
let fn_name = match &*fv.key_name() {
// Well-known properties
emit_core::well_known::KEY_LVL => quote_spanned!(fv.span()=> __private_capture_as_level),
emit_core::well_known::KEY_ERR => quote_spanned!(fv.span()=> __private_capture_as_error),
emit_core::well_known::KEY_SPAN_ID => {
quote_spanned!(fv.span()=> __private_capture_as_span_id)
}
emit_core::well_known::KEY_SPAN_PARENT => {
quote_spanned!(fv.span()=> __private_capture_as_span_id)
}
emit_core::well_known::KEY_TRACE_ID => {
quote_spanned!(fv.span()=> __private_capture_as_trace_id)
}
// In other cases, capture using the default implementation
_ => quote_spanned!(fv.span()=> __private_capture_as_default),
};

let key_expr = fv.key_expr();
let expr = &fv.expr;

Expand Down Expand Up @@ -83,6 +67,25 @@ pub fn key_value_with_hook(
)
}

pub fn default_fn_name(fv: &FieldValue) -> TokenStream {
match &*fv.key_name() {
// Well-known properties
emit_core::well_known::KEY_LVL => quote_spanned!(fv.span()=> __private_capture_as_level),
emit_core::well_known::KEY_ERR => quote_spanned!(fv.span()=> __private_capture_as_error),
emit_core::well_known::KEY_SPAN_ID => {
quote_spanned!(fv.span()=> __private_capture_as_span_id)
}
emit_core::well_known::KEY_SPAN_PARENT => {
quote_spanned!(fv.span()=> __private_capture_as_span_id)
}
emit_core::well_known::KEY_TRACE_ID => {
quote_spanned!(fv.span()=> __private_capture_as_trace_id)
}
// In other cases, capture using the default implementation
_ => quote_spanned!(fv.span()=> __private_capture_as_default),
}
}

pub struct RenameHookTokens<T> {
pub name: &'static str,
pub args: TokenStream,
Expand Down
Loading
Loading