Boyang Yan

rust-lang/log

10 min read

The log crate

Logging is the process of recording the activities of a program. Logs can be a textual flow in a specified format, which prints to a console or writes to a file. Rust has a great logging ecosystem based on the log crate. It is worth noting that the log crate contains macros without a real logger implementation. This gives you an opportunity to use different loggers depending on what you need them for.

Loggers

The actual logger implementations that are contained in some crates are as follows:

  • env_logger
  • simple_logger
  • simplelog
  • pretty_env_logger
  • stderrlog
  • flexi_logger
  • log4rs
  • fern

It can be difficult to choose between these logger implementations. I recommend that you explore them on crates.io to learn how they differ. The most popular one is env_logger, which is the one that we are going to use. env_logger reads the RUST_LOG environment variable to configure logging and prints logs to stderr. There is also the pretty_env_logger crate, which is built on top of env_logger and prints logs with a compact and colorful format. Both use the same environment variable for configuration.

Add the logger to the dependencies list of your Cargo.toml  file:

[dependencies]
log = "0.4"
pretty_env_logger = "0.2"
hyper = "0.12"
rand = "0.5"

Then add these types to your main.rs file:

use hyper::{Body, Response, Server};
use hyper::rt::Future;
use hyper::service::service_fn_ok;
use log::{debug, info, trace};

Log levels

As we discussed earlier, with the log crate, we need to import the following logging macros. We can use the following:

  • trace!
  • debug!
  • info!
  • warn!
  • error!

These are ordered by the importance of the information they print, with trace! being the least important and error! being the most important:

  • trace!: Used to print verbose information about any pivotal activity. It allows web servers to trace any incoming chunk of data.
  • debug!: Used for less verbose messages, such as the incoming server requests. It is useful for debugging.
  • info!: Used for important information such as the runtime or server configuration. It is rarely used in library crates.
  • warn!: Informs the user about non-critical errors, such as if the client has used broken cookies or if the necessary microservice is temporarily unavailable and cached data is used for responses instead.
  • error!: Provides an alert about critical errors. This is used when the database connection is broken.

We imported the necessary macro directly from the log crate.

Logging messages

Logging is not useful without the contextual data of the code. Every logging macro expects a text message that can contain positional parameters. For example, take a look at the println! macro:

debug!("Trying to bind server to address: {}", addr);

The preceding code will work for types that implement the Display trait. As in the println! macro, you can add types that implement the Debug trait with the {:?} formatter. It’s useful to derive the Debug trait for all types in your code with #[derive(Debug)] and set the #![deny(missing_debug_implementations)] attribute for the whole crate.

Custom level of messages

Levels have an important role in the logging process. They are used for filtering the records by their priority. If you set the info level for the logger, it will skip all the debug and trace records. Obviously, you need more verbose logging for debugging purposes and less verbose logging to use the server in production.

Internally, every macro of the log crate uses the log! macro, which has an argument to set the level:

log!(Level::Error, "Error information: {}", error);

It takes an instance of the Level enumeration that has the following variants—Trace, Debug, Info, Warn, and Error.

Checking logging is enabled

Sometimes, logging may require a lot of resources. In this case, you can use the log_enabled! macro to check that a certain logging level has been enabled:

if log_enabled!(Debug) {
    let data = get_data_which_requires_resources();
    debug!("expensive data: {}", data);
}

Own target

Every log record has a target. A typical logging record looks as follows: The log record consists of the logging level, the time (not shown in this output), the target, and the message. You can think about the target as a namespace. If no target is specified, the log crate uses the module_path! macro to set one. We can use the target to detect the module where an error or warning has happened or use it for filtering records by name. We will see how to set filtering by environment variable in the following section.

Using logging

We can now add logging to our microservice. In the following example, we will print information about the socket address, the incoming request, and a generated random value:

fn main() {
     logger::init();
     info!("Rand Microservice - v0.1.0");
     trace!("Starting...");
     let addr = ([127, 0, 0, 1], 8080).into();
     debug!("Trying to bind server to address: {}", addr);
     let builder = Server::bind(&addr);
     trace!("Creating service handler...");
     let server = builder.serve(|| {
         service_fn_ok(|req| {
             trace!("Incoming request is: {:?}", req);
             let random_byte = rand::random::<u8>();
             debug!("Generated value is: {}", random_byte);
             Response::new(Body::from(random_byte.to_string()))
         })
     });
     info!("Used address: {}", server.local_addr());
     let server = server.map_err(drop);
     debug!("Run!");
     hyper::rt::run(server);
 }

Using logging is quite simple. We can use macros to print the address of the socket and information about the request and response.

Configuring a logger with variables

There are some environment variables that you can use to configure a logger. Let’s take a look at each variable.

RUST_LOG

Compile this example. To run it with an activated logger, you have to set the RUST_LOG environment variable. The env_logger crate reads it and configures the logger using filters from this variable. A logger instance must be configured with a corresponding logging level.

  • You can set the RUST_LOG variable globally. If you use the Bash shell, you can set it in your .bashrc file.
  • You can set RUST_LOG temporarily before the cargo run command: 
    RUST_LOG=trace cargo run

However, this will also print a lot of cargo tool and compiler records, because the Rust compiler also uses the log crate for logging. You can exclude all records except for those of your program using filtering by name. You only need to use part of the target name, as follows:

RUST_LOG=random_service=trace,warn cargo run

This value of the RUST_LOG variable filters all records by the warn level and uses the trace level for targets starting with the random_service prefix.

RUST_LOG_STYLE

The RUST_LOG_STYLE variable sets the style of printed records. It has three variants:

  • auto: Tries to use the style characters
  • always: Always uses the style characters
  • never: Turns off the style characters

See the following example:

RUST_LOG_STYLE=auto cargo run

I recommend that you use the never value if you redirect the stderr output a file or if you want to use grep or awk to extract values with special patterns.

Changing the RUST_LOG variable to your own

If you release your own product, you may need to change the name of the RUST_LOG and the RUST_LOG_STYLE variable to your own. New releases of the env_logger contain the init_from_env special function to fix this. This expects one argument—an instance of the Env object. Take a look at the following code:

let env = env_logger::Env::new()
    .filter("OWN_LOG_VAR")
    .write_style("OWN_LOG_STYLE_VAR");
env_logger::init_from_env(env);

It creates an Env instance and sets the OWN_LOG_VAR variable to configure logging and the OWN_LOG_STYLE_VAR variable to control the style of the logs. When the env object is created, we will use it as an argument for the init_from_env function call of the env_logger crate.

Reading environment variables

In the previous example, we used a value of the RUST_LOG environment variable to set filtering parameters for logging. We can use other environment variables to set parameters for our server as well. In the following example, we will use the ADDRESS environment variable to set the address of the socket we want to bind.

Standard library

There are enough functions in the std::env standard module to work with environment variables. It contains the var function to read external values. This function returns a Result with a String value of the variable if it exists, or a VarError error if it doesn’t exist. Add the import of the env module to your main.rs file:

use std::env;

We need to replace the following line:

let addr = ([127, 0, 0, 1], 8080).into();

Replace it with the following:

let addr = env::var("ADDRESS")
    .unwrap_or_else(|_| "127.0.0.1:8080".into())
    .parse()
    .expect("can't parse ADDRESS variable");

This new code reads the ADDRESS value. If this value doesn’t exist, we won’t let the code throw a panic. Instead, we will replace it with the default value, “127.0.0.1:8080”, using the unwrap_or_else method call. As the var function returns a String, we also have to convert &‘static str into a String instance with the into method call.

If we can’t parse an address, we will throw a panic in the except method call.

Your server will now use the addr variable, which takes a value from the ADDRESS environment variable or from the default value.

Environment variables are a simple way of configuring your application. They are also widely supported with hosting or cloud platforms and Docker containers.

Remember that all sensitive data is visible to the system administrator of the host. In Linux, the system administrator can read this data simply by using the

cat /proc/`pidof random-service-with-env`/environ` | tr '\0' '\n'

This means that it’s not a good idea to set the secret key of your bitcoin wallet to the environment variable.

Using the .env file

Setting many environment variables is time-consuming. We can simplify this using configuration files, which we will explore further at the end of this chapter. However, configuration files can’t be used in cases where the crates or dependencies use environment variables.

To make this process simple, we can use the dotenv crate. This is used to set environment variables from a file. This practice appeared as part of The Twelve-Factor App methodology (https://12factor.net/).

The Twelve-Factor App approach is a methodology for building Software as a Service (SaaS) applications to fulfill the following three objectives:

  • Configurations in declarative formats
  • Maximum portability with operating systems and clouds
  • Continuous deployment and scaling

This methodology encourages you to use environment variables to configure the application. The Twelve-Factor App approach doesn’t require disk space for configuration and it is extremely portable, meaning that all operating systems support the environment variables.

Using the dotenv crate

The dotenv crate allows you to set environment variables in a file called .env and join them with variables set in the traditional way. You don’t need to read this file manually. All you need to do is add the dependency and call the initialization method of the crate.

Add this crate to the list of dependencies:

dotenv = "0.13"

Add the following imports to the main.rs file of the previous example to use the dotenv crate:

use dotenv::dotenv;
use std::env;

Initialize it with the dotenv function, which will try to find the .env file. It will return a Result with a path to this file. Call the ok method of the Result to ignore it if the file hasn’t been found.

Adding variables to the .env file

The .env file contains pairs of names and values of environment variables. For our service, we will set the RUST_LOG, RUST_BACKTRACE, and ADDRESS variables:

RUST_LOG=debug
RUST_BACKTRACE=1
ADDRESS=0.0.0.0:1234

As you can see, we set all the targets of the logger to the debug level, because cargo doesn’t use dotenv and therefore skips these settings.

The RUST_BACKTRACE variable sets the flag to print a backtrace of the application in the case of panic.

Store this file in the working directory from which you will run the application. You can have multiple files and use them for different configurations. This file format is also compatible with Docker and can be used to set variables to the container.

I recommend that you add the .env file to your .gitignore to prevent leaking of sensitive or local data. This means that every user or developer who works with your project has their own environment and needs their own version of the .env file.

Graph View

Backlinks