Skip to content

Graceful stop: long-lived responses (SSE) get no signal and are SIGKILLed mid-response at the deadline #368

Description

@willcosgrove

AI disclaimer: I worked on this with Claude, but I've edited the below text and manually confirmed the issue

On a graceful stop, Falcon drains in-flight responses nicely: a finite streamed response keeps writing after SIGTERM and finishes cleanly. But a response that never finishes on its own, like a Server-Sent Events stream, gets no indication that the worker is stopping. It keeps running until the graceful timeout expires, the worker is SIGKILLed, and the client sees the connection close mid-response.

An SSE body could end its response cleanly if it knew a stop had begun (EventSource reconnects automatically, ideally to the new server). As far as I can tell there's no supported way for application code to find out.

Versions

falcon 0.57.0, async 2.46.0, async-http 0.105.0, async-container 0.38.0, async-service 0.25.0, protocol-rack 0.23.0, io-event 1.22.1, Ruby 4.0.7. Reproduced on macOS; we see the same behavior in production on Heroku.

Reproduction

falcon.rb:

#!/usr/bin/env -S falcon host
require "falcon/environment/rack"

service "repro" do
  include Falcon::Environment::Rack

  count 1
  port { 9292 }

  endpoint do
    Async::HTTP::Endpoint
      .parse("http://127.0.0.1:#{port}")
      .with(protocol: Async::HTTP::Protocol::HTTP11)
  end
end

config.ru: /slow streams 12 chunks and finishes, /sse streams forever. Both log Async::Task.current.cancel_deferred?.

def log(message)
  $stderr.puts "[#{Time.now.strftime("%T.%L")}] #{message}"
end

run do |env|
  path = env["PATH_INFO"]

  body = proc do |stream|
    task = Async::Task.current
    count = path == "/sse" ? Float::INFINITY : 12

    (0...count).each do |i|
      stream.write(path == "/sse" ? "data: tick #{i}\n\n" : "chunk #{i}\n")
      log "#{path} wrote #{i} (cancel_deferred?=#{task.cancel_deferred?})"
      sleep 1
    end
  ensure
    log "#{path} body finished"
    stream.close
  end

  content_type = path == "/sse" ? "text/event-stream" : "text/plain"
  [200, { "content-type" => content_type }, body]
end
repro.rb: starts falcon host, opens both requests, sends SIGTERM 3s in, reports how each response ended
require "socket"
$stdout.sync = true

PORT = 9292
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
elapsed = -> { format("%4.1fs", Process.clock_gettime(Process::CLOCK_MONOTONIC) - start) }

server = Process.spawn("bundle", "exec", "falcon", "host", "falcon.rb", chdir: __dir__)

100.times do
  TCPSocket.new("127.0.0.1", PORT).close
  break
rescue Errno::ECONNREFUSED
  sleep 0.1
end
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)

clients = %w[/slow /sse].map do |path|
  Thread.new do
    socket = TCPSocket.new("127.0.0.1", PORT)
    socket.write("GET #{path} HTTP/1.1\r\nHost: localhost\r\n\r\n")
    data = +""
    begin
      loop { data << socket.readpartial(4096) }
    rescue EOFError, Errno::ECONNRESET => error
      ending = data.end_with?("0\r\n\r\n") ? "complete response (chunked terminator received)" : "TRUNCATED: connection closed mid-response"
      puts "#{elapsed.call}  #{path.ljust(5)} connection closed (#{error.class}): #{ending}"
    end
  end
end

sleep 3
puts "#{elapsed.call}  sending SIGTERM to falcon host (pid #{server})"
Process.kill("TERM", server)

clients.each { |client| client.join(30) }
Process.wait(server)
puts "#{elapsed.call}  falcon host exited (#{$?})"

Output of bundle exec ruby repro.rb (application log lines trimmed):

 3.0s  sending SIGTERM to falcon host (pid 50849)
[12:55:23.473] /slow wrote 3 (cancel_deferred?=false)
[12:55:23.474] /sse wrote 3 (cancel_deferred?=false)
...
[12:55:31.523] /slow wrote 11 (cancel_deferred?=false)
[12:55:31.523] /sse wrote 11 (cancel_deferred?=false)
[12:55:32.524] /slow body finished
[12:55:32.524] /sse wrote 12 (cancel_deferred?=false)
12.1s  /slow connection closed (EOFError): complete response (chunked terminator received)
13.0s  /sse  connection closed (EOFError): TRUNCATED: connection closed mid-response
13.1s  falcon host exited (pid 50849 exit 0)

And from Falcon's log:

12:55:49  Stopping container...
12:55:49  Sending interrupt to 1 running processes...
12:55:59  Killing processes after graceful shutdown failed...
12:55:59  Child exited with error! status: "pid 50972 SIGKILL (signal 9)"

So:

  • /slow drains correctly. 🎉
  • /sse never learns that a stop has begun. It is killed at the 10s deadline (Async::Container::Group's default graceful timeout) mid-response.
  • cancel_deferred? stays false for the entire drain. The request task is never asked to stop, so even a body willing to poll has nothing to check.

Why it matters for us

We run on Heroku with preboot. On every deploy (and the daily dyno restart), each open SSE connection on the old dyno is truncated, and Heroku's router logs it as an H18 "Server Request Interrupted" error. The streams themselves are fine: the browser reconnects. But it's a steady source of platform errors that we can't make go away cleanly.

What we're doing now

Our workaround chains onto the INT/TERM traps that Async::Container::Forked installs in each worker (from a Falcon::Server#run prepend, so it runs after the traps exist). Our trap handler starts a thread that closes all SSE subscriber queues, then calls the original handler. Each stream wakes, ends its response normally, and the worker exits well before the deadline. It works, but it relies on async-container's internal trap setup, which feels fragile.

A task-based hook doesn't work: we first tried a transient child task of the server task that runs cleanup in its ensure. It fired immediately in an idle worker, but in a worker with an open stream it never ran before the SIGKILL. That matches cancel_deferred? never becoming true above.

What would help

A supported way for application code to learn that a graceful stop has begun. For example:

  • something in the Rack env that a streaming body can wait on or check (e.g. an Async::Notification, or a condition under env["falcon.*"]), or
  • a documented hook in the service/environment configuration (e.g. on_graceful_stop { ... }) that runs in each worker when the stop begins.

Separately, it would be handy if the graceful timeout were configurable from falcon.rb for falcon host. falcon serve has --graceful-stop, but under falcon host we get async-container's default of 10s, while Heroku allows 30s between SIGTERM and SIGKILL.

Is the drain behavior above (request tasks never being cancelled during the graceful period) the intended design? Happy to help test whichever direction makes sense. Thanks for Falcon and all the work you do on the Async Ruby ecosystem!

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions