Serving ASCII cats over HTTP

Our catscii program does everything we want it to do, except that it's a command-line application rather than a web server. Let's fix that.

Enter axum

The documentation for the axum crate tells us how to make a basic web server, and we honestly don't need much more than that.

So let's add axum:

amos@miles:~/catscii$ cargo add axum@0.6
    Updating crates.io index
      Adding axum =0.6 to dependencies.
             Features:
             + form
             + http1
             + json
             + matched-path
             + original-uri
             + query
             + tokio
             + tower-log
             - __private_docs
             - headers
             - http2
             - macros
             - multipart
             - w

And off we go! I won't repeat the get_cat_ascii_art function, it's fine as-is, so this listing includes everything except that:

// in `src/main.rs`

use axum::{
    body::BoxBody,
    http::header,
    response::{IntoResponse, Response},
    routing::get,
    Router,
};
use reqwest::StatusCode;
use serde::Deserialize;

#[tokio::main]
async fn main() {
    let app = Router::new().route("/", get(root_get));

    axum::Server::bind(&"0.0.0.0:8080".parse().unwrap())
        .serve(app.into_make_service())
        .await
        .unwrap();
}

async fn root_get() -> Response<BoxBody> {
    match get_cat_ascii_art().await {
        Ok(art) => (
            StatusCode::OK,
            [(header::CONTENT_TYPE, "text/plain; charset=utf-8")],
            art,
        )
            .into_response(),
        Err(e) => {
            println!("Something went wrong: {e}");
            (StatusCode::INTERNAL_SERVER_ERROR, "Something went wrong").into_response()
        }
    }
}
Cool bear

Cool bear's hot tip

We're not really explaining how returning a tuple suddenly creates an HTTP response, you can go read Migrating from warp to axum for that, or just check the axum docs themselves.

Running it prints nothing:

amos@miles:~/catscii$ cargo run
   Compiling tracing v0.1.37
   Compiling futures-task v0.3.25
   Compiling tower-layer v0.3.2
   (cut)
   Compiling hyper v0.14.23
   Compiling hyper-tls v0.5.0
   Compiling axum v0.6.0-rc.5
   Compiling reqwest v0.11.13
   Compiling catscii v0.1.0 (/home/amos/catscii)
    Finished dev [unoptimized + debuginfo] target(s) in 15.97s
     Running `target/debug/catscii`
(...nothing)

But if we open it in a browser...

A webkit window on Windows (via Playwright, just to mess with everyone) showing ANSI escape sequences

We see...what looks like garbage, but is really ANSI escape codes. That's how we were able to have colors in the terminal!

In the web world, though, to get colors, we need CSS. Luckily, the artem crate lets us configure the output "target", and we can just pick HTML:

    let ascii_art = artem::convert(
        image,
        artem::options::OptionBuilder::new()
            .target(artem::options::TargetType::HtmlFile(true, true))
            .build(),
    );

And then, we can change the response's content-type to HTML:

async fn root_get() -> Response<BoxBody> {
    match get_cat_ascii_art().await {
        Ok(art) => (
            StatusCode::OK,
            //           was text/plain 👇
            [(header::CONTENT_TYPE, "text/html; charset=utf-8")],
            art,
        )
            .into_response(),
        Err(e) => {
            println!("Something went wrong: {e}");
            (StatusCode::INTERNAL_SERVER_ERROR, "Something went wrong").into_response()
        }
    }
}

We can use Ctrl+C to exit out of the running catscii instance, press "Arrow Up" to get our "cargo run" command again, and press "Enter" to run it again.

A webkit window, showing colored ascii art now

Much better!

Cool bear

Wow, we're already done?

Well, this part is clearly not long enough, so let's do other things one would do if they meant to deploy this service to production.

Adding tracing

Have you staged, committed and pushed your work yet? I shouldn't have to say this anymore, you know — every time you make a meaningful change, boom, commit and push.

Good? Good. Right now we don't really print anything, and it'd be neat if we had some sort of access logs, so let's add that with tracing and tracing-subscriber:

amos@miles:~/catscii$ cargo add tracing@0.1
    Updating crates.io index
      Adding tracing v0.1 to dependencies.
             Features as of v0.1.0:
             - log
             (cut)
amos@miles:~/catscii$ cargo add tracing-subscriber@0.3 --features json
    Updating crates.io index
      Adding tracing-subscriber v0.3 to dependencies.
             Features as of v0.3.0:
             + alloc
             (cut)

Then install a handler, and log something to say we're listening on the address we're listening on:

use std::str::FromStr;
use tracing::{info, Level};
use tracing_subscriber::{filter::Targets, layer::SubscriberExt, util::SubscriberInitExt};

#[tokio::main]
async fn main() {
    let filter = Targets::from_str(std::env::var("RUST_LOG").as_deref().unwrap_or("info"))
        .expect("RUST_LOG should be a valid tracing filter");
    tracing_subscriber::fmt()
        .with_max_level(Level::TRACE)
        .json()
        .finish()
        .with(filter)
        .init();

    let app = Router::new().route("/", get(root_get));

    let addr = "0.0.0.0:8080".parse().unwrap();
    info!("Listening on {addr}");
    axum::Server::bind(&addr)
        .serve(app.into_make_service())
        .await
        .unwrap();
}

Now, cargo run displays a JSON-formatted log:

$ cargo run
(cut)
{"timestamp":"2022-11-24T17:09:53.795483Z","level":"INFO","fields":{"message":"Listening on 0.0.0.0:8080"},"target":"catscii"}
{"timestamp":"2022-11-24T17:09:57.118152Z","level":"INFO","fields":{"message":"Resizing image to fit new dimensions","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":84},"target":"artem"}
{"timestamp":"2022-11-24T17:09:57.434402Z","level":"INFO","fields":{"message":"Starting conversion to ascii","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":140},"target":"artem"}

If we set RUST_LOG=debug, we see a lot more messages:

$ RUST_LOG=debug cargo run
(cut)
amos@miles:~/catscii$ RUST_LOG=debug cargo run
    Finished dev [unoptimized + debuginfo] target(s) in 0.08s
     Running `target/debug/catscii`
{"timestamp":"2022-11-24T17:11:46.134975Z","level":"INFO","fields":{"message":"Listening on 0.0.0.0:8080"},"target":"catscii"}
{"timestamp":"2022-11-24T17:11:47.571800Z","level":"DEBUG","fields":{"message":"parsed 16 headers"},"target":"hyper::proto::h1::io"}
{"timestamp":"2022-11-24T17:11:47.571866Z","level":"DEBUG","fields":{"message":"incoming body is empty"},"target":"hyper::proto::h1::conn"}
{"timestamp":"2022-11-24T17:11:47.627471Z","level":"DEBUG","fields":{"message":"starting new connection: https://api.thecatapi.com/","log.target":"reqwest::connect","log.module_path":"reqwest::connect","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.11.13/src/connect.rs","log.line":429},"target":"reqwest::connect"}
{"timestamp":"2022-11-24T17:11:47.627715Z","level":"DEBUG","fields":{"message":"resolving host=\"api.thecatapi.com\""},"target":"hyper::client::connect::dns"}
{"timestamp":"2022-11-24T17:11:47.628244Z","level":"DEBUG","fields":{"message":"connecting to 142.250.75.243:443"},"target":"hyper::client::connect::http"}
{"timestamp":"2022-11-24T17:11:47.740736Z","level":"DEBUG","fields":{"message":"connected to 142.250.75.243:443"},"target":"hyper::client::connect::http"}
{"timestamp":"2022-11-24T17:11:47.765617Z","level":"DEBUG","fields":{"message":"flushed 72 bytes"},"target":"hyper::proto::h1::io"}
{"timestamp":"2022-11-24T17:11:47.965595Z","level":"DEBUG","fields":{"message":"parsed 17 headers"},"target":"hyper::proto::h1::io"}
{"timestamp":"2022-11-24T17:11:47.965673Z","level":"DEBUG","fields":{"message":"incoming body is content-length (89 bytes)"},"target":"hyper::proto::h1::conn"}
{"timestamp":"2022-11-24T17:11:47.965744Z","level":"DEBUG","fields":{"message":"incoming body completed"},"target":"hyper::proto::h1::conn"}
{"timestamp":"2022-11-24T17:11:47.965955Z","level":"DEBUG","fields":{"message":"pooling idle connection for (\"https\", api.thecatapi.com)"},"target":"hyper::client::pool"}
{"timestamp":"2022-11-24T17:11:47.966263Z","level":"DEBUG","fields":{"message":"starting new connection: https://cdn2.thecatapi.com/","log.target":"reqwest::connect","log.module_path":"reqwest::connect","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.11.13/src/connect.rs","log.line":429},"target":"reqwest::connect"}
{"timestamp":"2022-11-24T17:11:47.966436Z","level":"DEBUG","fields":{"message":"resolving host=\"cdn2.thecatapi.com\""},"target":"hyper::client::connect::dns"}
{"timestamp":"2022-11-24T17:11:47.966922Z","level":"DEBUG","fields":{"message":"connecting to 104.21.33.166:443"},"target":"hyper::client::connect::http"}
{"timestamp":"2022-11-24T17:11:47.978558Z","level":"DEBUG","fields":{"message":"connected to 104.21.33.166:443"},"target":"hyper::client::connect::http"}
{"timestamp":"2022-11-24T17:11:48.001162Z","level":"DEBUG","fields":{"message":"flushed 71 bytes"},"target":"hyper::proto::h1::io"}
{"timestamp":"2022-11-24T17:11:48.654150Z","level":"DEBUG","fields":{"message":"parsed 18 headers"},"target":"hyper::proto::h1::io"}
{"timestamp":"2022-11-24T17:11:48.654225Z","level":"DEBUG","fields":{"message":"incoming body is content-length (127435 bytes)"},"target":"hyper::proto::h1::conn"}
{"timestamp":"2022-11-24T17:11:48.672341Z","level":"DEBUG","fields":{"message":"incoming body completed"},"target":"hyper::proto::h1::conn"}
{"timestamp":"2022-11-24T17:11:48.672481Z","level":"DEBUG","fields":{"message":"pooling idle connection for (\"https\", cdn2.thecatapi.com)"},"target":"hyper::client::pool"}
{"timestamp":"2022-11-24T17:11:48.853276Z","level":"DEBUG","fields":{"message":"Using inverted color: false","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":46},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853357Z","level":"DEBUG","fields":{"message":"Input Image Width: 612","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":50},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853403Z","level":"DEBUG","fields":{"message":"Input Image Height: 612","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":51},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853447Z","level":"DEBUG","fields":{"message":"Columns: 80","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":62},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853489Z","level":"DEBUG","fields":{"message":"Rows: 38","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":63},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853531Z","level":"DEBUG","fields":{"message":"Tile Width: 7","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":64},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853572Z","level":"DEBUG","fields":{"message":"Tile Height: 16","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":65},"target":"artem"}
{"timestamp":"2022-11-24T17:11:48.853614Z","level":"INFO","fields":{"message":"Resizing image to fit new dimensions","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":84},"target":"artem"}
{"timestamp":"2022-11-24T17:11:49.174095Z","level":"DEBUG","fields":{"message":"Resized Image Width: 560","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":88},"target":"artem"}
{"timestamp":"2022-11-24T17:11:49.174177Z","level":"DEBUG","fields":{"message":"Resized Image Height: 608","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":89},"target":"artem"}
{"timestamp":"2022-11-24T17:11:49.174232Z","level":"INFO","fields":{"message":"Starting conversion to ascii","log.target":"artem","log.module_path":"artem","log.file":"/home/amos/.cargo/registry/src/github.com-1ecc6299db9ec823/artem-1.1.5/src/lib.rs","log.line":140},"target":"artem"}
{"timestamp":"2022-11-24T17:11:49.398312Z","level":"DEBUG","fields":{"message":"flushed 146453 bytes"},"target":"hyper::proto::h1::io"}

We probably don't need that level of detail for now, but it might come in handy if the service starts misbehaving!

Because we're printing all this to stdout (the standard output stream), it will get captured by wherever we deploy this service: an ADN (application delivery network) will probably have its own log ingestion pipeline. If we deploy it as a systemd service on some Linux host, it'll be in system logs.

Let's move on!

Cool bear

After staging, committing and pushing, of course?

Of course.

Adding crash reporting with Sentry

Disclaimer:

Sentry is a paid, hosted service. You can also host it yourself, because it's open core. I'm friendly with some of its developers, but I am not receiving money to say it's good.

I just like it, and it's what I use for my services.

The sentry crate comes with its own excellent documentation, so this should be easy for us.

amos@miles:~/catscii$ cargo add sentry@0.29
    Updating crates.io index
      Adding sentry v0.29 to dependencies.
             Features as of v0.29.0:
             + backtrace
             (cut)

The more interesting problem that isn't solved here is: how do we store our secrets?

The Sentry onboarding process (creating a new project of type Rust, etc.) gives us a code sample, pre-filled with our secret ingest URL:

let _guard = sentry::init(("https://redacted@redacted.ingest.sentry.io/redacted", sentry::ClientOptions {
    release: sentry::release_name!(),
    ..Default::default()
}));

Of all the secrets we'll handle, this is probably the least secret.

But still, to get into good habits, let's look into one possible way we could handle that secret without ever committing it to version control.

Here's what I ended up doing.

We're going to pass our secrets via environment variables, following the twelve-factor philosophy. Because exporting those environment variables manually is annoying, we'll store those in an .envrc file instead, with contents like:

# in `.envrc`
export SENTRY_DSN="https://redacted@redacted.ingest.sentry.io/redacted"

We can manually "apply" that .envrc file by running source .envrc in our terminal (more on that later).

And then we'll read it like so:

    // at the top of main
    let _guard = sentry::init((
        std::env::var("SENTRY_DSN").expect("$SENTRY_DSN must be set"),
        sentry::ClientOptions {
            release: sentry::release_name!(),
            ..Default::default()
        },
    ));

That works, however, we can't commit that .envrc file as-is: this would leak the secret.

What I used to do before, was simply add it to .gitignore, store the secrets in various 1Password entries (disclosure: I pay them money, they don't pay me) and every time I needed to set up the project again, I'd need to manually copy the secrets from 1Password to my .envrc file.

Using git-crypt to encrypt secrets

Instead, this time, let's use git-crypt. I followed this neat guide, let me give you the highlights.

First, we install git-crypt, because we don't currently have it:

amos@miles:~/catscii$ git-crypt
Command 'git-crypt' not found, but can be installed with:
sudo apt install git-crypt

Looks like it's in Ubuntu's default APT repositories, good enough — I doubt much has happened to it in the last year:

amos@miles:~/catscii$ sudo apt install git-crypt
[sudo] password for amos:
Reading package lists... Done
(cut)

Then we can generate a key:

amos@miles:~/catscii$ git-crypt init
Generating key...

And immediately save it somewhere:

amos@miles:~/catscii$ git-crypt export-key ../git-crypt-key

And I mean really save it, unless you feel like rotating all your secrets the next time you need to set up everything from scratch.

For example, we can use scp to copy it back to the host (remember we're doing all this in a VM):

❯ scp miles:~/git-crypt-key .
git-crypt-key                                                                             100%  148     0.1KB/s   00:00

And then store it in 1Password or whatever password manager you use. 1Password lets you upload arbitrary files, which is nice (and this one is small).

Is it saved? Really?

Let's continue.

By default, git-crypt encrypts nothing. We can make sure by running git-crypt status:

amos@miles:~/catscii$ git-crypt status
not encrypted: .envrc
not encrypted: .gitignore
not encrypted: Cargo.lock
not encrypted: Cargo.toml
not encrypted: README.md
not encrypted: src/main.rs

So we cannot commit yet!

We need to tell git-crypt what to encrypt, by creating a .gitattributes file at the root of our repository:

# in `.gitattributes`
.envrc filter=git-crypt diff=git-crypt

Let's run git-crypt status again:

amos@miles:~/catscii$ git-crypt status
    encrypted: .envrc
not encrypted: .gitattributes
not encrypted: .gitignore
not encrypted: Cargo.lock
not encrypted: Cargo.toml
not encrypted: README.md
not encrypted: src/main.rs

Looks good!

Now we can stage, commit, but NOT PUSH YET:

amos@miles:~/catscii$ git add . && git commit --message "Add crash reporting with Sentry"
[main b23246b] Add crash reporting with Sentry
 5 files changed, 285 insertions(+)
 create mode 100644 .envrc
 create mode 100644 .gitattributes

Before we push (an action that could be observed by anyone, and rewriting Git history, although possible, is annoying), let's make sure it has in fact been encrypted, because I have trust issues.

If we run git diff HEAD~, we'll see the unencrypted contents of .envrc. Same with git show .envrc. That's because in our .gitattributes, we added a "diff" attribute, which affects how Git generates diff.

If we want to see the encrypted version, we need to use something like git cat-file. Let's try it on the README first:

amos@miles:~/catscii$ git cat-file blob HEAD:README.md | xxd
00000000: 2320 6361 7473 6369 690a 0a53 6572 7665  # catscii..Serve
00000010: 7320 6361 7420 7069 6374 7572 6573 2061  s cat pictures a
00000020: 7320 4153 4349 4920 6172 7420 6f76 6572  s ASCII art over
00000030: 2074 6865 2069 6e74 6572 6e65 742e        the internet.
Cool bear

Cool bear's hot tip

We're piping the output of git cat-file into xxd here, so we get a hex dump, because if everything went fine, we're about to dump some binary into our terminal.

And now on our .envrc file:

amos@miles:~/catscii$ git cat-file blob HEAD:.envrc | xxd
00000000: 0047 4954 4352 5950 5400 7345 4900 bf7c  .GITCRYPT.sEI..|
00000010: d574 e8d7 2fa7 7b5f 48f5 f8af a8b6 e152  .t../.{_H......R
00000020: ccf7 e308 fbb0 d4bd 27f4 e24a 92aa 6331  ........'..J..c1
00000030: 7106 c210 c460 3f23 6b4c 0214 131f 9781  q....`?#kL......
00000040: 199a bfc2 cc1b 6e08 e57a 97e6 d68f f982  ......n..z......
00000050: c97c 0cd5 fe55 c853 8a54 2407 0960 b880  .|...U.S.T$..`..
00000060: c33a 5eaf 7793 4b05 d9a4 c80c a234 e57b  .:^.w.K......4.{
00000070: 20a0 92de d38d 416b 076b e961 4ba4        .....Ak.k.aK.

Alright! I am sufficiently convinced that our secrets are safe.

We can now push:

amos@miles:~/catscii$ git push
Enumerating objects: 13, done.
Counting objects: 100% (13/13), done.
Delta compression using up to 16 threads
Compressing objects: 100% (6/6), done.
Writing objects: 100% (8/8), 2.88 KiB | 2.88 MiB/s, done.
Total 8 (delta 3), reused 0 (delta 0), pack-reused 0
remote: Resolving deltas: 100% (3/3), completed with 3 local objects.
To github.com:fasterthanlime/catscii.git
   f0f1515..b23246b  main -> main

And do a last check in the GitHub Web UI:

The GitHub Web UI, showing our .envrc file

If it didn't work, we'd be looking at the plaintext contents of the file. But instead, it's showing us "View raw", which indicates the file is binary and it's refusing to render it in the browser.

Amos

It's a good thing GitHub's new Code view feature is in public beta now, because otherwise I would've had to opt out of the alpha just to show this 🥲

We're not done yet though!

Setting up direnv

Our secrets are safely encrypted in Git history, but usability isn't great yet: we have to source .envrc every time we want to run our application.

To try it out, press Ctrl+D in the integrated terminal, to close it, and open a new one with Ctrl+Backquote, and you'll see that it complains:

amos@miles:~/catscii$ cargo run
    Finished dev [unoptimized + debuginfo] target(s) in 0.09s
     Running `target/debug/catscii`
thread 'main' panicked at '$SENTRY_DSN must be set: NotPresent', src/main.rs:18:37
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

We can fix that by using direnv, which... we have to install:

amos@miles:~/catscii$ direnv
Command 'direnv' not found, but can be installed with:
sudo snap install direnv  # version v2.18.2, or
sudo apt  install direnv  # version 2.25.2-2
See 'snap info direnv' for additional versions.
amos@miles:~/catscii$ sudo apt install direnv
[sudo] password for amos:
Reading package lists... Done
(cut)

Then, we can follow the instructions to hook direnv to our shell:

amos@miles:~/catscii$ echo 'eval "$(direnv hook bash)"' >> ~/.bashrc

And close out of this terminal, to open yet another one.

We are now greeted with this:

direnv: error /home/amos/catscii/.envrc is blocked. Run `direnv allow` to approve its content
amos@miles:~/catscii$

It'll show us that every time we change the contents of .envrc: this is a security feature. We can review the contents of .envrc (it's in plain text when "checked out", ie. on our disk), and execute direnv allow if and when we're happy with it:

amos@miles:~/catscii$ direnv allow
direnv: loading ~/catscii/.envrc
direnv: export +SENTRY_DSN

Our application now works, and it'll also work in fresh terminals!

Here's what a fresh terminal shows for me:

direnv: loading ~/catscii/.envrc
direnv: export +SENTRY_DSN
amos@miles:~/catscii$

To finish it off, let's install a VS Code extension that also applies the .envrc file for extensions. Search for mkhl.direnv and install it, then use the "Reload window" command from the VS Code command palette.

We can see that our environment has been loaded thanks to a new little section at the bottom of VS Code:

There's a little folder icon, showing +1/~0/-0. It's hovered, so it says: direnv loaded: 1 added, 0 changed, 0 removed

Clicking that little area reloads the environment, if needed.

Testing crash reporting with Sentry

So the problem with crash reporting is that it's only useful when it crashes.

Right now, I can't think of a way to make our application crash. We don't have any unwrap anywhere, something would have to go seriously wrong for our application to crash (which is all the more reason to have crash reporting set up).

For now, let's add an HTTP endpoint that panics:

    // this used to only have one route
    let app = Router::new()
        .route("/", get(root_get))
        .route("/panic", get(|| async { panic!("This is a test panic") }));

Then, let's run our app again...

$ cargo run
(cut)

Then visit http://localhost:8080/panic from a web browser.

Our app shows this in the logs:

{"timestamp":"2022-11-24T18:07:20.673750Z","level":"INFO","fields":{"message":"Listening on 0.0.0.0:8080"},"target":"catscii"}
thread 'tokio-runtime-worker' panicked at 'This is a test panic', src/main.rs:36:41
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread 'tokio-runtime-worker' panicked at 'This is a test panic', src/main.rs:36:41
thread 'tokio-runtime-worker' panicked at 'This is a test panic', src/main.rs:36:41

Immediately, we get an e-mail:

An e-mail from Sentry telling me there's been a panic

(I use Fastmail for e-mail: they're not paying me either, but I like them too!)

Clicking the "View in Sentry" button shows us the full details:

A screenshot from Sentry's web UI

We can mark it as Resolved, we can ignore it, link it to GitHub, there's a lot of useful information in there!

Here it tells me the panic occured in the main.rs file, at line 36, which is exactly where I have my panic!() invocation, so, it's right on the money.

Moving on!

Sending traces to Honeycomb

Disclaimer:

Honeycomb is a paid product that you cannot self-host, but it has a generous free trial.

I am, once again, friendly with them, but they are not paying me money to say good things about their product. It's just good.

Although we could instrument functions and futures with tracing, then use tracing-opentelemetry, then send traces to something like the OpenTelemetry Collector, which could in turn be configured to forward those traces to Honeycomb, let's not.

There's two main reasons: the first, is that I don't like tying tracing and opentelemetry. I've had bad experiences in the past trying to dynamically filter the "tracing" end of things to make sure opentelemetry receives what I want.

(There's options, I just ran into trouble. It's a long story.)

The second is that we don't really need the flexibility of a full OpenTelemetry Collector, and I'd rather keep the number of executables we need to run to one.

The downside is that, as I am now realizing, opentelemetry-honeycomb is currently inactive, so... we'll just use my fork, and hope that this inspires someone to pick up its maintenance 🤷

First opentelemetry:

amos@miles:~/catscii$ cargo add opentelemetry@0.18 --features rt-tokio
    Updating crates.io index
      Adding opentelemetry v0.18 to dependencies.
             Features as of v0.18.0:
             + rt-tokio
             + trace
             - metrics
             - rt-async-std
             - rt-tokio-current-thread
             - testing

Then my weird fork of opentelemetry-honeycomb I guess:

amos@miles:~/catscii$ cargo add --git https://github.com/fasterthanlime/opentelemetry-honeycomb-rs --branch simplified
(cut)

And now, we can keep adding to the pile that is our main function:

    let (_honeyguard, _tracer) = opentelemetry_honeycomb::new_pipeline(
        std::env::var("HONEYCOMB_API_KEY").expect("$HONEYCOMB_API_KEY should be set"),
        "catscii".into(),
    )
    .install()
    .unwrap();

Then start instrumenting our get_cat_ascii_art function:

use opentelemetry::{
    global,
    trace::{get_active_span, FutureExt, Span, Status, TraceContextExt, Tracer},
    Context, KeyValue,
};

async fn get_cat_ascii_art() -> color_eyre::Result<String> {
    let tracer = global::tracer("");

    let client = reqwest::Client::default();

    let image_url = get_cat_image_url(&client)
        .with_context(Context::current_with_span(
            tracer.start("get_cat_image_url"),
        ))
        .await?;

    let image_bytes = download_file(&client, &image_url)
        .with_context(Context::current_with_span(tracer.start("download_file")))
        .await?;

    let image = tracer.in_span("image::load_from_memory", |cx| {
        let img = image::load_from_memory(&image_bytes)?;
        cx.span()
            .set_attribute(KeyValue::new("width", img.width() as i64));
        cx.span()
            .set_attribute(KeyValue::new("height", img.height() as i64));
        Ok::<_, color_eyre::eyre::Report>(img)
    })?;

    let ascii_art = tracer.in_span("artem::convert", |_cx| {
        artem::convert(
            image,
            artem::options::OptionBuilder::new()
                .target(artem::options::TargetType::HtmlFile(true, true))
                .build(),
        )
    });

    Ok(ascii_art)
}

async fn get_cat_image_url(client: &reqwest::Client) -> color_eyre::Result<String> {
    #[derive(Deserialize)]
    struct CatImage {
        url: String,
    }

    let api_url = "https://api.thecatapi.com/v1/images/search";

    let image = client
        .get(api_url)
        .send()
        .await?
        .error_for_status()?
        .json::<Vec<CatImage>>()
        .await?
        .pop()
        .ok_or_else(|| color_eyre::eyre::eyre!("The Cat API returned no images"))?;
    Ok(image.url)
}

async fn download_file(client: &reqwest::Client, url: &str) -> color_eyre::Result<Vec<u8>> {
    let bytes = client
        .get(url)
        .send()
        .await?
        .error_for_status()?
        .bytes()
        .await?;
    Ok(bytes.to_vec())
}

And our handler:

async fn root_get(headers: HeaderMap) -> Response<BoxBody> {
    let tracer = global::tracer("");
    let mut span = tracer.start("root_get");
    span.set_attribute(KeyValue::new(
        "user_agent",
        headers
            .get(header::USER_AGENT)
            .map(|h| h.to_str().unwrap_or_default().to_owned())
            .unwrap_or_default(),
    ));

    root_get_inner()
        .with_context(Context::current_with_span(span))
        .await
}

async fn root_get_inner() -> Response<BoxBody> {
    let tracer = global::tracer("");

    match get_cat_ascii_art()
        .with_context(Context::current_with_span(
            tracer.start("get_cat_ascii_art"),
        ))
        .await
    {
        Ok(art) => (
            StatusCode::OK,
            [(header::CONTENT_TYPE, "text/html; charset=utf-8")],
            art,
        )
            .into_response(),
        Err(e) => {
            get_active_span(|span| {
                span.set_status(Status::Error {
                    description: format!("{e}").into(),
                })
            });
            (StatusCode::INTERNAL_SERVER_ERROR, "Something went wrong").into_response()
        }
    }
}

And then, restart our service, visit http://localhost:8080/, and see if we get something in Honeycomb!

amos@miles:~/catscii$ cargo run
thread 'main' panicked at '$HONEYCOMB_API_KEY should be set: NotPresent', src/main.rs:23:44
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Ah, right, we need to set that in .envrc.

Honeycomb has the concept of "production" and "development" environments now, make sure you create a "development" API key for this part:

# in .envrc
export SENTRY_DSN="redacted"
export HONEYCOMB_API_KEY="redacted"

Because we changed .envrc, we can click the direnv extension's area at the bottom, and it'll show us a prompt where we can Allow the changes.

After that, simply pressing Enter in the terminal will show that it has applied the new environment, and now we can run our service:

amos@miles:~/catscii$
direnv: loading ~/catscii/.envrc
direnv: export +HONEYCOMB_API_KEY +SENTRY_DSN
amos@miles:~/catscii$ cargo run
(cut)

After loading the service once in a web browser, a new dataset appears in Honeycomb, and we can visualize it:

Honeycomb's Home view, for the catscii dataset

We can see in "Recent traces" that there was a recent trace! And we can click on the little tree icon to see the details:

A honeycomb trace, showing root_get, get_cat_ascii_art, get_cat_image_url, download_file, image::load_from_memory, and artem::convert

This all seems a bit slow, to be honest.

Making all this faster

There's two things we can do to improve that. Instead of doing a whole TLS handshake from scratch to the cat API and its CDN, we should be re-using the reqwest::Client.

We've talked about this before, but we've never done it, and there's no time like the present. Let's make a ServerState struct, that all handlers will be able to access:

#[derive(Clone)]
struct ServerState {
    client: reqwest::Client,
}

Then pass it to the application as state:

    // in main
    let state = ServerState {
        client: Default::default(),
    };

    let app = Router::new()
        .route("/", get(root_get))
        .route("/panic", get(|| async { panic!("This is a test panic") }))
        .with_state(state);

Finally, we can "extract" it from our handler, and pass it down:

use axum::extract::State;

//                                      👇 that's new!
async fn root_get(headers: HeaderMap, State(state): State<ServerState>) -> Response<BoxBody> {
    let tracer = global::tracer("");
    let mut span = tracer.start("root_get");
    span.set_attribute(KeyValue::new(
        "user_agent",
        headers
            .get(header::USER_AGENT)
            .map(|h| h.to_str().unwrap_or_default().to_owned())
            .unwrap_or_default(),
    ));

    //  passing it 👇
    root_get_inner(state)
        .with_context(Context::current_with_span(span))
        .await
}

//               to here 👇
async fn root_get_inner(state: ServerState) -> Response<BoxBody> {
    let tracer = global::tracer("");

    //       passing the client 👇
    match get_cat_ascii_art(&state.client)
        .with_context(Context::current_with_span(
            tracer.start("get_cat_ascii_art"),
        ))
        .await
    {
        Ok(art) => (
            StatusCode::OK,
            [(header::CONTENT_TYPE, "text/html; charset=utf-8")],
            art,
        )
            .into_response(),
        Err(e) => {
            get_active_span(|span| {
                span.set_status(Status::Error {
                    description: format!("{e}").into(),
                })
            });
            (StatusCode::INTERNAL_SERVER_ERROR, "Something went wrong").into_response()
        }
    }
}

//                   to here 👇
async fn get_cat_ascii_art(client: &reqwest::Client) -> color_eyre::Result<String> {
    let tracer = global::tracer("");

    //   and then our helper functions 👇
    let image_url = get_cat_image_url(client)
        .with_context(Context::current_with_span(
            tracer.start("get_cat_image_url"),
        ))
        .await?;

    //                  that one too 👇
    let image_bytes = download_file(client, &image_url)
        .with_context(Context::current_with_span(tracer.start("download_file")))
        .await?;

    let image = tracer.in_span("image::load_from_memory", |cx| {
        let img = image::load_from_memory(&image_bytes)?;
        cx.span()
            .set_attribute(KeyValue::new("width", img.width() as i64));
        cx.span()
            .set_attribute(KeyValue::new("height", img.height() as i64));
        Ok::<_, color_eyre::eyre::Report>(img)
    })?;

    let ascii_art = tracer.in_span("artem::convert", |_cx| {
        artem::convert(
            image,
            artem::options::OptionBuilder::new()
                .target(artem::options::TargetType::HtmlFile(true, true))
                .build(),
        )
    });

    Ok(ascii_art)
}

Also, we are running a debug build of our application. Let's try running it with release instead:

amos@miles:~/catscii$ cargo run --release
(cut)

With these changes, reloading our cat endpoint a couple times, we get traces like these:

Which is much better! Loading the image now takes 2ms, converting takes 15ms, which is... not great, but not terrible. The cat API is still much slower than I'd like, but you may have different results, maybe it's fast in the US?

Switching to a faster cat API

After saving our changes, let's see if we can't shave some milliseconds there by switching to https://cataas.com/.

The endpoint https://cataas.com/cat returns the image data directly, which save us a roundtrip.

Our code becomes:

async fn get_cat_ascii_art(client: &reqwest::Client) -> color_eyre::Result<String> {
    let tracer = global::tracer("");

    let image_bytes = download_file(client, "https://cataas.com/cat")
        .with_context(Context::current_with_span(tracer.start("download_file")))
        .await?;

    let image = tracer.in_span("image::load_from_memory", |cx| {
        let img = image::load_from_memory(&image_bytes)?;
        cx.span()
            .set_attribute(KeyValue::new("width", img.width() as i64));
        cx.span()
            .set_attribute(KeyValue::new("height", img.height() as i64));
        Ok::<_, color_eyre::eyre::Report>(img)
    })?;

    let ascii_art = tracer.in_span("artem::convert", |_cx| {
        artem::convert(
            image,
            artem::options::OptionBuilder::new()
                .target(artem::options::TargetType::HtmlFile(true, true))
                .build(),
        )
    });

    Ok(ascii_art)
}

And our traces now look like this:

The whole thing took 185ms. 156ms to download the image, 3ms to load it, 25ms to convert it to ASCII art

I don't know about you, but I think that's pretty good.

It'd be even better if that cat API supported HTTP/2 (we haven't enabled the relevant features on our side to take advantage of that, but I checked and it doesn't support it), but ah well.

We have visibility into the latency of our endpoint, thanks to Honeycomb:

HEATMAP(duration_ms), showing latencies up to 7 seconds before we switched to a release build, and under 200ms after we switched to a faster cat API

And we can group by any attribute we recorded: here, it's user_agent:

Graphing COUNT grouped by user_agent. There's Chromium, Webkit, Edge, and curl in there

What's next?

I think we're ready to put that service in production.

Right after we've staged, committed and pushed our latest changes, of course.

Comment on /r/fasterthanlime

(JavaScript is required to see this. Or maybe my stuff broke)

Here's another article just for you:

So you want to live-reload Rust

Good morning! It is still 2020, and the world is literally on fire, so I guess we could all use a distraction.

This article continues the tradition of me getting shamelessly nerd-sniped - once by Pascal about small strings, then again by a twitch viewer about Rust enum sizes.

This time, Ana was handing out free nerdsnipes, so I got in line, and mine was: