A Web App in Rust - 15 Logging

Welcome back! We're getting to the end of our journey now! One thing that you may or may not have noticed after the previous chapter is that our errors are now gone. If we handle all our errors then it means that our errors won't be printed to the screen anymore!

Not good, how are we, the developers, going to know how and why things have gone wrong. To fix this, we now need to add logging!

Let's get started!

Logging

I did only bring up errors, but ideally we also want to log all of the requests and maybe even more, this is because if a user runs into a problem, rarely will they have enough information for us to actually investigate. Really what we need are comprehensive logs of what our server is doing and that we can look to our logs when a user has a problem, or if our application has a problem.

Luckily there is a simple way for us to add logging. We need to use the env_logger crate with actix's own logging middleware. We then have our App use this. The idea of logging each request is very similar to the idea of adding cookies to every request. So it isn't surprising that we do both in a similar way!

./Cargo.toml

...
r2d2 = "0.8"
env_logger = "0.8"

We first add env_logger to our list of dependencies.

Next let's set the RUST_LOG level. We do this in our .env file.

./.env

DATABASE_URL=postgres://postgres:password@localhost/hackerclone
SECRET_KEY="THIS IS OUR SUPER SUPER SUPER SUPER SECRET KEY"
RUST_LOG="actix_web=info"

We'll use the info level for our logging, this way we can print our anything inside info!() and error!() as well.

Before we can start using these functions though, we first need to include the logger in our main.rs file.

./src/main.rs

use argonautica::Verifier;
use actix_web::middleware::Logger;

Here we include the Logger utility from actix.

./src/main.rs

#[actix_web::main]
async fn main() -> std::io::Result<()> {
    dotenv().ok();
    env_logger::init();

    HttpServer::new(|| {
        dotenv().ok();

Inside our main function we include the environment variables as we need to pick up our RUST_LOG level. We then initialize the env_logger.

Finally we need to register the logger to our App object.

./src/main.rs

        App::new()
            .wrap(Logger::default())
            .wrap(IdentityService::new(
                    CookieIdentityPolicy::new(&[0;32])
                    .name("auth-cookie")
                    .secure(false)
            )
            )
            .data(tera)
            .data(pool)

We use the same wrap option we used for our cookie, this way every request we get will know have logging functionality added to it.

Now, we can navigate to 127.0.0.1:8000/ and we should get our index page. But now in our terminal window we should also be seeing the actual requests.

[2020-10-22T01:33:14Z INFO  actix_web::middleware::logger] 127.0.0.1:61671 "GET / HTTP/1.1" 200 2270 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:81.0) Gecko/20100101 Firefox/81.0" 0.003334
[2020-10-22T01:33:14Z INFO  actix_web::middleware::logger] 127.0.0.1:61671 "GET /favicon.ico HTTP/1.1" 404 0 "http://127.0.0.1:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:81.0) Gecko/20100101 Firefox/81.0" 0.000411

Now we can see every request that hits our server! Perfect!

Now let's add the ability to log what we want to log, which in this case will be the errors.

First let's add the log crate to our application.

./Cargo.toml

...
env_logger = "0.8"
log = "0.4"

Now let's update our .env file to also log our application and not just actix_web.

./.env

RUST_LOG="hacker_clone=info,actix_web=info"

One thing to note is that if you have -, dashes, in your application name, you'll need to make it an underscore.

Now let's log the error we get when a user tries to login with a username that doesn't exist. In the previous chapter we set it up so that it triggers a ServerError::UserError.

./src/main.rs

...
impl From<diesel::result::Error> for ServerError {
    fn from(err: diesel::result::Error) -> ServerError {
        match err {
            diesel::result::Error::NotFound => {
                log::error!("{:?}", err);
                ServerError::UserError("Username not found.".to_string())
            },
            _ => ServerError::DieselError
        }
    }
}
...

All we do is log the error and voila! We have our error saved in our logs now. We can also use log::info! to log things as well.

Now we can update all of our errors, so that in addition to letting the user know, we can also log the errors for ourselves.

Next, we'll work on deploying our application!