home ~ projects ~ socials

Write Logs To A File And STDOUT At The Same Time In Rust

For most projects I send log messages to the command line or to a files. Sometimes, I want both. This is how I'm doing that in Rust with the tracing crate.

````cargo
[dependencies]
tracing = "0.1.40"
tracing-appender = "0.2"
tracing-subscriber = { version = "0.3", features = ["json"] }
```

use tracing::{Level, event, instrument};
use tracing_subscriber::prelude::*;
use tracing_subscriber::{fmt, filter};

fn main() {
  let log_dir = "./";
  let log_basename = "example-log.log";

  let file_appender = tracing_appender::rolling::never(log_dir, log_basename);
  let (file_writer, _guard) = tracing_appender::non_blocking(file_appender);
  let file_layer_format = tracing_subscriber::fmt::format()
    .json();
  let file_layer = fmt::Layer::default()
    .event_format(file_layer_format)
    .with_writer(file_writer)
    .json();

  let stdout_layer = fmt::Layer::default()
    .with_writer(std::io::stdout)
    .with_ansi(false)
    .with_filter(filter::LevelFilter::INFO);

  let subscriber = tracing_subscriber::Registry::default()
    .with(file_layer)
    .with(stdout_layer);

  tracing::subscriber::set_global_default(subscriber).expect("unable to set global subscriber");

  do_something();
}

#[instrument]
fn do_something() {
  event!(Level::ERROR, "Error message");
  event!(Level::WARN, "Warn message");
  event!(Level::INFO, "Info message");
  event!(Level::DEBUG, "Debug message");
  event!(Level::TRACE, "Trace message");
}
Output:
2024-04-23T14:58:51.966020Z ERROR do_something: _active_nvim_run: Error message
2024-04-23T14:58:51.966056Z  WARN do_something: _active_nvim_run: Warn message
2024-04-23T14:58:51.966078Z  INFO do_something: _active_nvim_run: Info message

Details

  • I didn't realize at first that the tracing create is mainly a foundation that other things are built off of. In this case, the file and STDOUT comes from a combination of tracing::subscriber and tracing::appender
  • I'm using tracing_appender::rolling::never() in this example. It always writes to the same file ("example-log.log" in this case). There are also ::daily(), ::hourly(), and ::minutely() versions that append strings with intervals to the filenames to create a rotation mechanism
  • The .with_ansi(false) calls turn off extra characters in the output that enable colors on the terminal. I find it useful to skip that for the STDOUT output in prod, but it shows up weird in this web output so I've got it set to false
  • There are five levels available. In order, they are: ERROR, WARN, INFO, DEBUG, TRACE
  • All five layres are output by default
  • The .with_filter(filter::LevelFilter::INFO) call on the STDOUT layer limits that output to just INFO and above. That is, ERROR, WARN, and INFO messages all appear, but DEBUG and TRACE messages do not
  • Being able to set different log levels a big reason why I set this up instead of just running a tail -f on the log file itself
  • In some of my reading it sounds like you can set up the subscriber in a function outside of main, but if you do you need to make sure to keep the _guard in scope. If it goes out of scope, nothing else will be written to the file
  • I'm also using `.json()rust to make JSON formatted logs. That's not strictly necessary, but I find them way more useful
-- end of line --

References

This is three years old and didn't seem to work for me when I tried to use the same technique. (I might not have don't it right though. So, YMMV). Also, the current docs talk about putting Layers in Registry and not Subscribers. Probably this works somehow, but I punted trying to figure it out.