Serving ASCII cats over HTTP
fasterthanlime
This article is part of the Building a Rust service with Nix series.
-
Enter
axum - Adding tracing
- Adding crash reporting with Sentry
- Using git-crypt to encrypt secrets
-
Setting up
direnv - Testing crash reporting with Sentry
- Sending traces to Honeycomb
- Making all this faster
- Switching to a faster cat API
- What's next?
Contents
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()
}
}
}
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...
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.
Much better!
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!
After staging, committing and pushing, of course?
Of course.
Adding crash reporting with Sentry
Disclosure: 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.
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:
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.
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:
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:
(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:
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
Disclosure: 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:
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:
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:
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:
And we can group by any attribute we recorded: here, it's user_agent:
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.
This article is part 4 of the Building a Rust service with Nix series.
If you liked what you saw, please support my work!
