Better Logging for the Web Application

I replace log and simple_logger with slog and sloggers, and then change again

Part of a Series: Designing a Full-Featured WebApp with Rust
Part 1: Piecing Together a Rust Web Application
Part 2: My Next Step in Rust Web Application Dev
Part 3: It’s Not a Web Application Without a Database
Part 4: Better Logging for the Web Application
Part 5: Rust Web App Session Management with AWS
Part 6: OAuth Requests, APIs, Diesel, and Sessions
Part 7: Scraping off the Dust: Redeploy of my Rust web app
Part 8: Giving My App Secrets to the AWS SecretManager

A journal ledger of accounts... like logging but only uses numbers
See… structured logging…

When I last left my sample web application, I was doing simple logging to the terminal which is not useful for very long. I want structured logging and I want the app and Rocket to write to (separate) files. So, let’s switch out the crates log and simple_log for slog and sloggers to get better logging for my web application.

Application Logging

Slog‘s “ambition is to be The Logging Library for Rust” and it sure seems adaptable. There are several “helper” crates to log to the terminal or syslog, log as json, etc. However, slog is complex! Which seems to be the main reason sloggers came about. Sloggers brings you the most useful features of slog without the complex setup. It happens to include an example of configuring via an inline TOML string. I’ve already got my CONFIG global pulling from a TOML file, so I add this to conf/development.toml:

<conf/development.toml>

...
[logconfig]
type = "file"
format = "compact"
source_location = "module_and_line"
timezone = "local"
level = "debug"
path = "log/error.log"
rotate_size = 1073741824
rotate_keep = 2

[webservice]
weblog_path = "log/access.log"
...

Plus, I add logging.rs to set up the global LOGGING instance so everyone can log; just like everyone can pull from the global CONFIG instance:

<logging.rs>

use crate::settings::CONFIG;
use crate::sloggers::{Build, Config};
use once_cell::sync::Lazy;

#[derive(Debug)]
pub struct Logging {
    pub logger: slog::Logger,
}

pub static LOGGING: Lazy<Logging> = Lazy::new(|| {
    let logconfig = &CONFIG.logconfig;

    let builder = logconfig.try_to_builder().unwrap();
    let logger = builder.build().unwrap();

    Logging { logger: logger }
});

Sloggers is really easy to use to set up a slog instance. Here, I simply pull the logconfig from my global CONFIG, build the logger, and store it in my new OnceCell Lazy LOGGING global.




And then, Web Access Logging

A spider web, wet from rain...

At this point, application logging is going to my new log/error.log file, but Rocket logging is still coming to the screen. This is actually good – as I mentioned, I want to have them going to separate files anyway. So now with some slogging experience, it’s a simple matter to set up a second file, specifically for Rocket. I do need to add yet another crate, this time rocket_slog – so that Rocket internals can glom on to the slog instance that I make. Here is the new start_webservice function:

<src/lib.src>

...
pub fn start_webservice() {
    let logger = &LOGGING.logger;

    let weblog_path = &CONFIG.webservice.weblog_path;
    let bind_address = &CONFIG.webservice.bind_address;
    let bind_port = &CONFIG.webservice.bind_port;

    // start rocket webservice
    let version = include_str!("version.txt");

    let mut builder = FileLoggerBuilder::new(weblog_path);
    builder.level(Severity::Debug);
    let weblogger = builder.build().unwrap();
    let fairing = SlogFairing::new(weblogger);

    warn!(
        logger,
        "Waiting for connections..."; "address" => bind_address, "port" => bind_port, "version" => version);

    rocket::ignite()
        .attach(fairing)
        .attach(Template::fairing())
        .attach(SpaceHelmet::default())
        .mount("/", routes![routes::index, routes::favicon])
        .mount("/img", StaticFiles::from("src/view/static/img"))
        .mount("/css", StaticFiles::from("src/view/static/css"))
        .mount("/js", StaticFiles::from("src/view/static/js"))
        .launch();
}

Now I have log/error.log for application logging (I’ll rename that later to log/app.log) and log/access.log for Rocket logging. But I still don’t have structured logs!

Finally, Structured Logs

I try several ways (with my limited Rust knowledge and experience) but it appears that with sloggers ease of use, you trade away options if you want to get fancy. At least, I couldn’t figure out how to get slog_json or something called slog_bunyan to work with sloggers. It looks like I have to deal with slog directly.

Later, on another night, I tackle these changes. I dump sloggers and, though much searching around, I end up with a merge of two examples I find (from slog and slog-bunyan). Thankfully, I am getting a little better at understanding the API docs that are posted for crates! Anyway, here is how the app logging setup looks now:

<src/logging.rs>

...
pub static LOGGING: Lazy<Logging> = Lazy::new(|| {
    let logconfig = &CONFIG.logconfig;

    let logfile = &logconfig.applog_path;
    let file = OpenOptions::new()
        .create(true)
        .write(true)
        .truncate(true)
        .open(logfile)
        .unwrap();

    let applogger = slog::Logger::root(
        Mutex::new(slog_bunyan::default(file)).fuse(),
        o!("location" => FnValue(move |info| {
        format!("{}:{} {}", info.file(), info.line(), info.module(), )
                })
        ),
    );

    Logging { logger: applogger }
});

Notice I still pull the applog_path from the CONFIG and then create that filehandle. Next, a single but complicated call into slog returns a Logger instance, which I store into my global. The o! macro, provided by the slog crate, lets me add a JSON field to every log record that gets written. I copy from an example and add the file, line number, and module name where the log was generated. I’ll probably come back to this later and add more data. Also, notice I am using slog_bunyan for the JSON formatting. slog-json actually recommends using slog_bunyan for a “more complete output format.” Bunyan logging seems to originate as a node.js module. Lastly, I also change the weblogger in the same way – now both are JSON logs and still log to separate files.

This actually wasn’t as complicated as I feared. I’ve lost some of the easily configurable sloggers features like auto file rotation, but I’ll figure that out as well – it’s probably actually just a slog feature that I need to enable.

Results, JSON Style

Here is how both look now – I think next post I’ll work on a JSON log viewer so we can watch these easier, as we develop.

<log/app.log>

{"msg":"Service starting","v":0,"name":"slog-rs","level":40,"time":"2019-07-20T03:40:13.781382592+00:00","hostname":"ip-169-254-169-254","pid":6368,"location":"src/lib.rs:48 ppslib","run_level":"development"}
{"msg":"Waiting for connections...","v":0,"name":"slog-rs","level":40,"time":"2019-07-20T03:40:13.784899718+00:00","hostname":"ip-169-254-169-254","pid":6368,"location":"src/lib.rs:76 ppslib","version":"0.1.0","port":3000,"address":"0.0.0.0"}

<log/access.log>
{"msg":"listening","v":0,"name":"slog-rs","level":30,"time":"2019-07-20T05:31:21.068959173+00:00","hostname":"ip-169-254-169-254","pid":7700,"address":"http://0.0.0.0:3000"}
{"msg":"request","v":0,"name":"slog-rs","level":30,"time":"2019-07-20T05:31:22.402815352+00:00","hostname":"ip-169-254-169-254","pid":7700,"uri":"\"/\"","method":"Get"}
{"msg":"response","v":0,"name":"slog-rs","level":30,"time":"2019-07-20T05:31:22.404425952+00:00","hostname":"ip-169-254-169-254","pid":7700,"status":"200 OK","route":"\u001b[32mGET\u001b[0m \u001b[34m/\u001b[0m \u001b[36m(\u001b[0m\u001b[35mindex\u001b[0m\u001b[36m)\u001b[0m"}

Again, if all that was complicated to follow and you prefer to look at the git commits as I went through this ordeal, check out the repository.

It’s Not a Web Application Without a Database

The all important database ORM tooling… a light shining in the dark!

Part of a Series: Designing a Full-Featured WebApp with Rust
Part 1: Piecing Together a Rust Web Application
Part 2: My Next Step in Rust Web Application Dev
Part 3: It’s Not a Web Application Without a Database
Part 4: Better Logging for the Web Application
Part 5: Rust Web App Session Management with AWS
Part 6: OAuth Requests, APIs, Diesel, and Sessions
Part 7: Scraping off the Dust: Redeploy of my Rust web app
Part 8: Giving My App Secrets to the AWS SecretManager

Rack of hard drives perhaps attached to a database server supporting a web application
I think I just skipped a bit!?

What did we even use computers for before the Internet!? How much is your smartphone or laptop worth if you have zero Internet connectivity? What good is a web application without a database? Which is more important, the language or the architecture? The actors or the writing? These… are all questions… but one wouldn’t have a job without the other. Still, a web application needs a strong database layer but with abstractions to hide the raw SQL inside the code. So, we need to pick a database solution as carefully as we choose the programming language. True, that is, if we aren’t talking about the solution for our father’s VHS rental store and its single register (been there before!)

Don’t Spare the Database Layer

As a developer, the idea of Object-relational mapping (ORM) is about decoupling the low-level semantics of data storage and retrieval from the application code. An ORM abstracts database functionality inside your code just like a templating system abstracts HTML or JavaScript in your code. Everyone’s favorite, Stack Overflow, has a really good posted definition of ORMs along with the pros and cons of using one in a project. While you’re there, also check out Stack Overflow’s latest questions tagged [Rust] – maybe you can help someone out!

The ORM tools handle a big responsibility in app development. The Diesel crate has taken on this task for my sample app here at the beginning. With Rust and Diesel both being so new, I need to cut these tools some slack, but I also desperately want them to be fairly mature for the benefit of the language.




Sample Web Application Goals

Let me explain my concept for this sample app first – it likely won’t ever get finished, but that’s ok, it gives me something to practice with. A friend (check out his Kindle book, Seeing in the Dark: A Guide to Night Photography) and I came up with this idea over 10 years ago when we were scouring the local 200 mi radius for great places to shoot photographs. My 500px profile is filled with them – nearly all landscapes, I don’t do portraits or models.

Our idea came to be known as PinpointShooting.com (which isn’t a website yet, duh). Photographers could sign up for free and, using a Google Maps interface, indicate the best places to get some terrific shots. Some might be obvious, but there are some hidden places out there to spice up your photography.

Woman laying on stomach to take photograph, maybe my web application could give her some tips
She seems to be having fun!!

Handy tip: a photograph is often more interesting because it was taken from an angle or a hidden spot that no one else has picked. That way, your picture doesn’t look so much like a “touristy postcard.” That’s a reason photography books tell you to kneel or lay down or climb on things to take a picture. In fact, anything to change the normal viewing angle. What’s more boring than seeing a photo of a flower from 5′-6′ above? That’s the angle we see ALL the time, just walking around! Plus, that’s why photographers often refer to it as “making a shot” rather than “taking a shot.” There’s art involved above pressing the shutter release!

Back to the Database Chat

Anyway, enough about that – I need to store some data!! I’m sure this will expand and evolve, but this is what I’m thinking for tables so far:

  • Users – to store the free user profiles, passwords, email address
  • Locations – to store the address and/or lat/long of the good spot to shoot from that a user has shared
  • Photos – by users to store the pictures (or links to pictures) taken from a location in the database
  • Ratings – by users of the locations they have been to and if the agree
  • Likes – by users of the photos uploaded or linked to
  • Visits – to the location linking together a User/Location when they share a good spot, or a User/Photo when they upload/link one, or a User/Rating when they leave one

I start the DB design with some Enum types inside Postgresql. Most of these tables are going to have a status field with just a few possible choices. The enums turn out to be something that Diesel doesn’t seem to handle well (yet). In fact, I found a crate because of that fact. Wait… I take that back… I found 3 crates. Diesel-derive-enum has, by far, the most downloads, so I download that one. However, I only fooled with it a short time before I gave up. This is just a silly practice app, so I will switch to charfields. Well, they don’t work right away for me either, and it is getting late. I’ll just use some varchars which I already have a ton of.

A database was not the first thing to migrate, here are some birds headed south
Databases were not the first things to migrate!

Diesel Database Migration Tool

Diesel has a database migration tool to allow your project to record (and store in the repository) the entire path of changes the database undergoes during the product lifetime. It seems that tool name may have come from Rails – or there are only so many synonyms to choose from. I have used (and beat my head against) Sqitch and I’m just becoming aware of Skeema. Database schema management turns out to be a somewhat complex and fragile flow when you work with over 100 other developers in a fast-moving codebase. Because of the field issues I had (and because this project is ONLY me and is just starting), I reset my database to start over several times. In the end, I have a successful compile of the above DB structure abstracted into my code.

Diesel, btw, has a wonderfully impressive website to introduce you to the available functionality. I use the DBIX::Class module (often referred to as DBIC) with Perl, and it is as complicated as DB queries can become! But those are mostly the exception; DBIC generally abstracts the SQL nicely into some OO code to get me the data I need from the database. Most importantly, the Diesel Getting Started Guide is a great introduction to what using this crate is like. Plus, in addition to the normal crate API-style documentation, there are several other guides – some diving deep into the mechanics and benefits of Diesel.

I need to really get into some code to see how Diesel will be, but I have high hopes from what I’ve seen so far. A systems programmer (which I’m not) probably has far less need for the tools and add-ons that I’ve been playing with these past three posts. However, for big-scale web application development, most of these are key requirements!

More to come…

I hope all of these tools continue to develop with the pace of Rust itself, and I hope to get good enough with Rust that I can help out with some of the modules in the future! Once again, here’s the repository link to my code (at whatever state it exists when you read this post). I expect to have more to share about the PinpointShooting web application soon.

Edit: Meanwhile, go check out this fantastic post that looks at using Rust on both the front-end AND back-end of a web application! Web Assembly is hot right now, so this is a great read!

My Next Step in Rust Web Application Dev

Part II: I am impressed with Rocket and the add-ons and pile things into my sample web application

Part of a Series: Designing a Full-Featured WebApp with Rust
Part 1: Piecing Together a Rust Web Application
Part 2: My Next Step in Rust Web Application Dev
Part 3: It’s Not a Web Application Without a Database
Part 4: Better Logging for the Web Application
Part 5: Rust Web App Session Management with AWS
Part 6: OAuth Requests, APIs, Diesel, and Sessions
Part 7: Scraping off the Dust: Redeploy of my Rust web app
Part 8: Giving My App Secrets to the AWS SecretManager

Bridge Day 2017, New River Gorge, WV – a framework is important!

My previous post on working towards a shell of a Rust web application covered global, static application settings and logging. There is still, probably, a change to come to allow for structured logging. However, this time lets start with the actual framework I’m using. First I download Iron, but it doesn’t feel right and I notice it hasn’t been worked on for two years. That’s an immediate clue to keep looking, so I move on to another I have heard mentioned: Rocket.

Check out the podcast archives!

I’ve been listening to the archives of the mostly-discontinued podcast New Rustacean by Chris Krycho and, even though they are a couple of years old now (which is pretty old considering the pace of Rust), I still get an idea of where Rust started and how far it has come. Two episodes I just listened to – a 2016 episode about Diesel and a 2017 episode about Rocket – even helped me with this web application example I’m working on. It’s impressive these two Crates have continued getting updates and support after a couple of years. I’ll talk about Diesel in the next post, but for now let’s look at Rocket, plus some add-ons for templating, static web serving, web security, and interactive communication.

Rocket – Rust Framework

The Rocket crate received some high praise from Krycho in his “Crates You Should Know” episode and it seems the maintainers have continued with what impressed him. Rocket has a fantastic website and documentation guide making it a breeze to get started. The built-in route handling reminds me of perl Catalyst (how different could it be?). This feels very familiar. Here is my (simplified at this early point) implementation of getting Rocket started in my web application. The global static CONFIG I talked about last time continues to help here:

pub fn start_webservice() {
    // start rocket webservice
    let bind_address = &CONFIG.webservice.bind_address;
    let bind_port = &CONFIG.webservice.bind_port;
    let version = include_str!("version.txt");

    rocket::ignite()
        .attach(Template::fairing())
        .attach(SpaceHelmet::default())
        .mount("/", routes![routes::index])
        .mount("/img", StaticFiles::from("src/view/static/img"))
        .mount("/css", StaticFiles::from("src/view/static/css"))
        .mount("/js", StaticFiles::from("src/view/static/js"))
        .launch();

    warn!(
        "Listening on {}:{} as version {}",
        bind_address, bind_port, version
    );
}

Just as important as Rocket, in my view, are the capabilities added with the rocket_contrib crate. You can see some of them referenced in the chain of functions getting Rocket configured and running in my code above. So far, I already pull in the handlebars_templates, serve, helmet and JSON features.




rocket_contrib::handlebars_templates

I am pretty familiar with Template::Toolkit for use with Perl, but I’m only getting started with handlebars. Also, there is another rocket_contrib::templates option called tera templates. I mostly picked one of the two at random. I’m not yet to the point of working in HTML templates for this sample app, so this choice might change in the future. Who knows – maybe we need the option of a Template::Toolkit add-on as well!?

rocket_contrib::serve

Since Rocket builds-in the webserver funcionality (and I’m not sure I like this – I think I can front the web application with Nginx or some other service, so I need to look into that), I need it to serve local, static files (like CSS, Javascript, and images) as well. Rocket_contrib::serve handles this job for me with just some mount calls in the Rocket chain (see above). Again, I’m just getting set up, but this seems a good first step to get me going.

rocket_contrib::helmet

Security needs to extend past the coding language, of course, and rocket_contrib::helmet gives you a start at just a couple of HTTP concerns. The web is an absolutely crazy place – having read The Tangled Web by Michal Zalewski, I’m even more acutely aware of the convoluted and contentious history of web servers, web browsers, and the web languages we’ve ended up with, and I’m surprised things work at all! If helmet stops even one or two classes of those dangers, in it goes.

rocket_contrib::JSON

JSON is convenient to let the client browser (with Javascript) communicate back and forth with the server via (ahem) AJAX calls. I’ve included rocket_contrib::json just for this eventuality. Maybe there a more Rustic device or maybe this is still just “one way to do it”. I’ll learn more when I get to that point.

Ok, next up, we talk about the all-important ORM piece. I’m really impressed with Diesel so far, especially with the guide and documentation… but we’ll get to that with the next post.