DEV Community

Menshikov Vasil
Menshikov Vasil

Posted on

The Bug That Made Me Fall Back in Love With rack.response_finished

#debugging #performance #rails #ruby

There is a particular kind of production bug that doesn't feel like a bug. It feels like weather. Every few days something leaks, a worker gets cranky, p99 creeps up during a traffic spike, and you shrug and restart it because it clears up on its own. For the better part of a year that was my relationship with rack.response_finished - except I didn't know that was the name of my problem yet. I just knew our Rails app was quietly bleeding resources and I kept blaming the wrong things.

This is the story of how it finally clicked, why it bugged me for so long, and how I migrated a high-traffic app to rack.response_finished without spending a single night watching a dashboard with my stomach in knots.

Why this bugged me for years

Our symptoms were the vague kind that make you feel a little crazy. Occasional resource leaks under load. Tail latency that crept up when traffic spiked and settled back down when it didn't. Metrics that never quite matched what I believed was happening. We streamed large files and Server-Sent Events, so the Rack triplet [status, headers, body] was returning long before the last byte ever reached the client.

Here's the piece I genuinely did not appreciate for months: our middleware was freeing resources - closing DB connections, clearing caches, wiping thread-locals - well before the client had the full response. I found a lovely deep-dive on exactly what happens between returning a Rack triplet and delivering that last byte, and reading it was the moment the fog lifted. All those vague symptoms suddenly had one concrete cause. We'd been treating a lifecycle bug as an infrastructure flake - restarting workers, bumping pool sizes, side-eyeing the load balancer. It was none of that. It was an assumption I'd baked into how we wrapped response bodies, and I'd never once questioned it.

The thing I'd been doing without thinking

For years, if you wanted a "run this when the request is done" hook, you wrapped the body in Rack::BodyProxy. It's a tidy little object that calls your block when the wrapped body closes. Elegant on paper. The trouble is every middleware that wanted a callback added its own wrapper, so a single request ended up dragging a Russian-doll stack of proxies around:

original_body = ["Hello World"]
body = Rack::BodyProxy.new(original_body) { logger.info "Request finished" }
body = Rack::BodyProxy.new(body) { metrics.record_latency }
body = Rack::BodyProxy.new(body) { cleanup_thread_locals }
body = Rack::BodyProxy.new(body) { close_db_connections }
Enter fullscreen mode Exit fullscreen mode

The Shopify Rails infrastructure folks wrote up this exact pain in "Friendship Ended with Rack::BodyProxy", and honestly it was validating to read, because it named three things that had been nagging at me.

First, allocation pressure. Every proxy is one more object. At tens of thousands of requests a second, even tiny per-request allocations add up - and because these callbacks capture closures, the objects hang around long enough to get promoted into older GC generations, which is exactly where you don't want churn.

Second, timing you can't trust. #close gets called by the server, sure, but the spec never promised it happens after the client has everything. Depending on the server and buffering, my callbacks could fire before, during, or after transmission. I was cleaning up at a moment I couldn't actually pin down.

Third - and this is the one that was actually paging me at 3am - exceptions skipped cleanup entirely. If the body raised while iterating, the proxy's callback might just never run:

class ProblematicBody
  def each
    yield "Part 1"
    raise "Something went wrong"  # BodyProxy#close might not be called
    yield "Part 2"
  end
end
Enter fullscreen mode Exit fullscreen mode

That right there was the leak. A stream raises halfway through a big download, the cleanup silently gets skipped, and the resource just... stays open. Multiply by traffic and you get weather.

The thing that finally clicked

The replacement is so much calmer, and I mean that emotionally as much as technically. Instead of N proxy objects, there's one standard key in env holding an array of callbacks:

def call(env)
  callbacks = env["rack.response_finished"] ||= []
  callbacks << lambda do |env, status, headers, error|
    # Runs AFTER complete response delivery
    cleanup_resources
    log_metrics(status, headers)
  end

  @app.call(env)
end
Enter fullscreen mode Exit fullscreen mode

What sold me wasn't the elegance, it was the promise. Unlike BodyProxy#close, these callbacks are guaranteed to run in three cases: a clean finish after all data is sent, an application exception even if the body never started iterating, and a server exception during network trouble. Each callback gets (env, status, headers, error), and per Rack's Lint spec they fire in reverse registration order, so you can branch on what actually happened. It shipped as part of Rack 3.x, and Puma added real server-side support (puma#3681) so it isn't a quiet no-op in production.

The one guarantee I kept coming back to: the callbacks run even when the body raises mid-stream. That single sentence killed my entire class of leaks. I remember reading it and feeling almost annoyed at how simple the fix was.

How I migrated without holding my breath

I couldn't flip everything at once - our services spanned Rack versions, and I'm allergic to big-bang changes on infrastructure I can't fully see. So the critical middleware learned to speak both dialects and pick whichever the server offered:

class SafeMigrationMiddleware
  def initialize(app)
    @app = app
  end

  def call(env)
    status, headers, body = @app.call(env)

    if env["rack.response_finished"]
      register_new_callback(env)
    else
      body = wrap_with_proxy(body)  # fallback
    end

    [status, headers, body]
  end

  private

  def register_new_callback(env)
    callbacks = env["rack.response_finished"] ||= []
    callbacks << method(:cleanup_resources)
  end

  def wrap_with_proxy(body)
    Rack::BodyProxy.new(body) { cleanup_resources }
  end

  def cleanup_resources(*)  # accepts any number of args
    logger.info "Request completed"
  end
end
Enter fullscreen mode Exit fullscreen mode

The cleanup_resources(*) splat is on purpose - the new API hands you four arguments, the proxy hands you none, and a splat lets one method serve both paths without a branch. Small thing, but it made the diff read cleanly, which matters to me more than I'll admit.

Then I refused to guess. I put a StatsD counter on each path so I could watch, in real numbers, how much traffic had moved to the new mechanism:

if env["rack.response_finished"]
  StatsD.increment('middleware.response_finished.new_api')
  register_new_callback(env)
else
  StatsD.increment('middleware.response_finished.fallback')
  body = wrap_with_proxy(body)
end
Enter fullscreen mode Exit fullscreen mode

The mistake I almost shipped

Callbacks run in the same thread as the request. That makes thread-local cleanup delightful, and it makes slow work a trap. My first draft casually fired off a notification email inside the callback, which is a wonderful way to block a worker for seconds at a time. Fast cleanup belongs in the callback; anything with I/O belongs in a background job:

# Good: fast cleanup
callbacks << lambda do |env, status, headers, error|
  Thread.current[:request_id] = nil
  ActiveRecord::Base.clear_active_connections!
end
Enter fullscreen mode Exit fullscreen mode

Rails itself gets happier here too: ActionDispatch::Executor can now reliably clear thread-locals right after the response completes, and gems like rack-timeout, newrelic_rpm, skylight, and sentry-ruby line up their timing and errors far more accurately.

How it feels now

I want to be honest about the size of the win, because it's easy to oversell a refactor you're proud of. Average latency barely moved - most requests were never the problem. What changed was the shape of things. Objects allocated per request dropped on our streaming endpoints, major GC ran a little less often, and the p99 tail got quieter during spikes because fewer long-lived closures were being promoted into old-gen. And the leak alerts that used to page me during big downloads simply stopped, because the cleanup now runs even when the body raises.

The order of operations mattered as much as the code. I audited every middleware that touched BodyProxy, bumped Rack to 3.x in development first, shipped the dual-API middleware, and let the StatsD counters tell me when the new path dominated. I only pulled the fallback after a service had run for weeks at effectively 100% new-API with zero callback errors. I left it in longer than felt necessary, on purpose - rushing that last step is exactly how you turn a calm migration into a scary one. Profiling before and after with memory_profiler and ruby-prof gave me actual numbers instead of a vibe, which is the difference between "trust me" and a graph.

If I could hand one note back to the version of me who kept restarting workers: the leak was never infrastructure. It was an abstraction I'd stopped questioning because it looked so tidy. BodyProxy was elegant right up until it wasn't, and the replacement is simpler and more honest about what it promises. That combination - less clever, more trustworthy - is the trade I'll take every single time now. If you run a busy Rack app, start the dual-API pattern today; you get to learn the new mechanism at zero risk, and future-you gets to sleep.

Sources & further reading

Top comments (0)