--- title: "Taming A Voracious Rust Proxy" description: "The Integral Principles of the Structural Dynamics of Async Rust" --- # Taming A Voracious Rust Proxy [Annie Ruygt](https://annieruygtillustration.com/) Here’s a fun bug. The basic idea of our service is that we run containers for our users, as hardware-isolated virtual machines (Fly Machines), on hardware we own around the world. What makes that interesting is that we also connect every Fly Machine to a global Anycast network. If your app is running in Hong Kong and Dallas, and a request for it arrives in Singapore, we’ll route it to `HKG`. Our own hardware fleet is roughly divided into two kinds of servers: edges, which receive incoming requests from the Internet, and workers, which run Fly Machines. Edges exist almost solely to run a Rust program called `fly-proxy`, the router at the heart of our Anycast network. So: a week or so ago, we flag an incident. Lots of things generate incidents: synthetic monitoring failures, metric thresholds, health check failures. In this case two edge tripwires tripped: elevated `fly-proxy` HTTP errors, and skyrocketing CPU utilization, on a couple hosts in `IAD`. Our incident process is pretty ironed out at this point. We created an incident channel (we ❤️ [Rootly](https://rootly.com/) for this, [seriously check out Rootly](https://rootly.com/), an infra MVP here for years now), and incident responders quickly concluded that, while something hinky was definitely going on, the platform was fine. We have a lot of edges, and we’ve also recently converted many of our edge servers to significantly beefier hardware. Bouncing `fly-proxy` clears the problem up on an affected proxy. But this wouldn’t be much of an interesting story if the problem didn’t later come back. So, for some number of hours, we’re in an annoying steady-state of getting paged and bouncing proxies. While this is happening, Pavel, on our proxy team, pulls a profile from an angry proxy. ![A flamegraph profile, described better in the prose anyways.](https://fly.io/blog/taming-rust-proxy/assets/proxy-profile.jpg) So, this is fuckin’ weird: a huge chunk of the profile is dominated by Rust `tracing`‘s `Subscriber`. But that doesn’t make sense. The entire point of Rust `tracing`, which generates fine-grained span records for program activity, is that `entering` and `exiting` a span is very, very fast. If the mere act of `entering` a span in a Tokio stack is chewing up a significant amount of CPU, something has gone haywire: the actual code being traced must be doing next to nothing. ## A Quick Refresher On Async Rust So in Rust, like a lot of `async/await` languages, you’ve got `Futures`. A `Future` is a type that represents the future value of an asynchronous computation, like reading from a socket. `Futures` are state machines, and they’re lazy: they expose one basic operation, `poll`, which an executor (like Tokio) calls to advance the state machine. That `poll` returns whether the `Future` is still `Pending`, or `Ready` with a result. In theory, you could build an executor that drove a bunch of `Futures` just by storing them in a list and busypolling each of them, round robin, until they return `Ready`. This executor would defeat the much of the purpose of asynchronous program, so no real executor works that way. Instead, a runtime like Tokio integrates `Futures` with an event loop (on [epoll](https://man7.org/linux/man-pages/man7/epoll.7.html) or [kqeue](https://en.wikipedia.org/wiki/Kqueue)) and, when calling `poll`, passes a `Waker`. The `Waker` is an abstract handle that allows the `Future` to instruct the Tokio runtime to call `poll`, because something has happened. To complicate things: an ordinary `Future` is a one-shot value. Once it’s `Ready`, it can’t be `polled` anymore. But with network programming, that’s usually not what you want: data usually arrives in streams, which you want to track and make progress on as you can. So async Rust provides `AsyncRead` and `AsyncWrite` traits, which build on `Futures`, and provide methods like `poll_read` that return `Ready` *every time* there’s data ready. So far so good? OK. Now, there are two footguns in this design. The first footgun is that a `poll` of a `Future` that isn’t `Ready` wastes cycles, and, if you have a bug in your code and that `Pending` poll happens to trip a `Waker`, you’ll slip into an infinite loop. That’s easy to see. The second and more insidious footgun is that an `AsyncRead` can `poll_read` to a `Ready` that doesn’t actually progress its underlying state machine. Since the idea of `AsyncRead` is that you keep `poll_reading` until it stops being `Ready`, this too is an infinite loop. When we look at our profiles, what we see are samples that almost terminate in libc, but spend next to no time in the kernel doing actual I/O. The obvious explanation: we’ve entered lots of `poll` functions, but they’re doing almost nothing and returning immediately. ## J'accuse! Wakeup issues are annoying to debug. But the flamegraph gives us the fully qualified type of the `Future` we’re polling: ``` &mut fp_io::copy::Duplex<&mut fp_io::reusable_reader::ReusableReader>>>>, connect::conn::Conn ``` This loops like a lot, but much of it is just wrapper types we wrote ourselves, and those wrappers don’t do anything interesting. What’s left to audit: - `Duplex`, the outermost type, one of ours, *and* - `TlsStream`, from [Rustls](https://github.com/rustls/rustls). `Duplex` is a beast. It’s the core I/O state machine for proxying between connections. It’s not easy to reason about in specificity. But: it also doesn’t do anything directly with a `Waker`; it’s built around `AsyncRead` and `AsyncWrite`. It hasn’t changed recently and we can’t trigger misbehavior in it. That leaves `TlsStream`. `TlsStream` is an ultra-important, load-bearing function in the Rust ecosystem. Everybody uses it. Could it harbor an async Rust footgun? Turns out, it did! Unlike our `Duplex`, Rustls actually does have to get intimate with the underlying async executor. And, looking through the repository, Pavel uncovers [this issue](https://github.com/rustls/tokio-rustls/issues/72): sometimes, `TlsStreams` in Rustls just spin out. And it turns out, what’s causing this is a TLS state machine bug: when a TLS session is orderly-closed, with a `CloseNotify` `Alert` record, the sender of that record has informed its counterparty that no further data will be sent. But if there’s still buffered data on the underlying connection, `TlsStream` mishandles its `Waker`, and we fall into a busy-loop. [Pretty straightforward fix](https://github.com/rustls/rustls/pull/1950/files)! ## What Actually Happened To Us Our partners in object storage, [Tigris Data](https://www.tigrisdata.com/), were conducting some kind of load testing exercise. Some aspect of their testing system triggered the `TlsStream` state machine bug, which locked up one or more `TlsStreams` in the edge proxy handling whatever corner-casey stream they were sending. Tigris wasn’t generating a whole lot of traffic; tens of thousands of connections, tops. But all of them sent small HTTP bodies and then terminated early. We figured some of those connections errored out, and set up the “TLS CloseNotify happened before EOF” scenario. To be truer to the chronology, we knew pretty early on in our investigation that something Tigris was doing with their load testing was probably triggering the bug, and we got them to stop. After we worked it out, and Pavel deployed the fix, we told them to resume testing. No spin-outs. ## Lessons Learned Keep your dependencies updated. Unless you shouldn’t keep your dependencies updated. I mean, if there’s a vulnerability (and, technically, this was a DoS vulnerability), always update. And if there’s an important bugfix, update. But if there isn’t an important bugfix, updating for the hell of it might also destabilize your project? So update maybe? Most of the time? Really, the truth of this is that keeping track of *what needs to be updated* is valuable work. The updates themselves are pretty fast and simple, but the process and testing infrastructure to confidently metabolize dependency updates is not. Our other lesson here is that there’s an opportunity to spot these kinds of bugs more directly with our instrumentation. Spurious wakeups should be easy to spot, and triggering a metric when they happen should be cheap, because they’re not supposed to happen often. So that’s something we’ll go do now.