Exit quickly when Better Stack can't be reached, and deliver lines logged during shutdown

[PetrHeinz]

Every Logtail::Logger.new registered its own at_exit { close } (logger.rb:196), and HTTP#close waits up to 20 seconds (wait_on_request_queue) for an outlet thread that can't reach the ingesting host. With an unreachable host, exiting took 20 seconds per logger: rails runner, console, db:migrate and assets:precompile each gained about 20 seconds in the red-team, and three loggers on one device took 60. The hooks also kept every logger alive until exit. A line logged while Ruby shuts down, e.g. by a gem's background thread in its ensure block, made write start a thread, which Ruby refuses at that point: Ruby's Logger printed log writing failed. can't alloc thread and the line was lost. A line written after the device closed, e.g. by an at_exit hook registered before the logger, vanished without a word.

Reported in logtail/logtail-ruby-rails#42

• Each HTTP device registers one at_exit hook that closes it, when the device is created. Logtail::Logger no longer registers one, and close does nothing the second time.
• close stops waiting as soon as the outlet can't deliver: its thread is dead, or it has never had a response from the host and has backed off after a failed connection. A normal close still waits until everything is delivered.
• A line written after close, or when Ruby refuses to start a thread, is delivered right away in the thread that writes it, with 2-second connect and read timeouts. Errors only go to the Logtail::Config debug log, never to stderr, also those outside StandardError (WebMock refuses connections with one); signals such as Interrupt are raised as usual. After one such delivery fails, later lines are dropped, so an unreachable host can't slow down the exit line by line.
• While Ruby shuts down it also refuses the thread Net::HTTP needs (before Ruby 4.0) to time out connecting. The device then connects without that timeout, but only to a host that has answered this process before; otherwise the line is dropped quietly.

Behaviour and compatibility:

• Loggers with other devices (STDOUT, files) are no longer closed at exit. Ruby's ::Logger::LogDevice writes synchronously, so nothing is lost, and STDOUT stays open for output from later at_exit hooks.
• The at_exit hook is registered per HTTP device when it's created, so it runs after the hooks registered later, as before. It keeps the device referenced, not the loggers.
• A refused connection or a failed DNS lookup is noticed within about a second. A host that drops packets still keeps close waiting until the outlet's first connection attempt times out (10 seconds) and backs off.
• A line delivered right away counts any HTTP response as delivered, as the outlet does today.
• A line written from a finalizer during shutdown can still be dropped, quietly.
• The process tests start Ruby subprocesses with RbConfig.ruby -Ilib against a local TCP server on an ephemeral port.

Locally, with the red-team's manyloggers.rb (loggers sharing one device, refused port): main took 20.5 s to run and exit with one logger and 61.0 s with three, this branch 1.2 s with either, Ruby's start included. 100,000 Logtail::Logger.new on one device leave 1 logger alive and add 1 MB RSS, where the red-team measured 115 MB on main. A script that logs from an at_exit hook registered before the logger, from a background thread's ensure at exit and from a finalizer: on main, Ruby's Logger printed log writing failed. can't alloc thread twice and only the regular line arrived; here stderr stays empty and all four lines arrive, on Ruby 2.7, 3.0, 3.2, 3.3 and 3.4.

#57 (fork safety and Logger#flush) also changes http.rb. Both PRs add the same deliver_synchronously(requests) helper, SYNCHRONOUS_DELIVERY_TIMEOUT and spec/support/processes.rb, and otherwise touch different lines, so they merge cleanly in either order; a local merge of both branches passes the suite on Ruby 2.7, 3.0, 3.2 and 3.4. With both, close also delivers synchronously when the outlet thread is gone, and waits 5 seconds at most.

Follow-up after the E2E run of the release candidate (two more commits, the first one only a test, red on the Ruby 2.5 to 2.7 jobs): with warnings on (ruby -w), Ruby 2.7 and older warned that @closed, @last_resp and @late_delivery_failed were read before they were set: on every write, while close waits, and for a line written after close. They're set in initialize now. The warnings left with -w on Ruby 2.7 are the ones 0.1.20 prints too. #57 sets @last_resp on the same line, so the two still merge cleanly.

Targets the logtail 0.1.21 patch release. No dependencies on the other open PRs.

The first commit only adds the tests and is expected to fail on CI; the fix follows in the next commit. The last two add a failing test and the fix for an error outside StandardError escaping the delivery of a late line.

Follow-up (062d287 test, 6d27d8f change): synchronous deliveries now wait up to 5 seconds to connect and 5 seconds for the response (SYNCHRONOUS_DELIVERY_TIMEOUT, previously 2), Petr's choice. They cover lines logged after close, lines logged while Ruby refuses new threads at exit, and flush without an outlet thread. Normal delivery from the outlet thread keeps its 10 second connect and 30 second read timeouts. The new test logs two lines after close to a host that answers after 3 seconds; with 2 seconds the first delivery timed out and the second line was dropped.

Follow-up (fd9e3f2 test, b866aa7 fix): close waits until the request queue is empty and nothing is in flight. The outlet used to take a batch off the queue first and only then count it as in flight. If close checked in between, it saw neither, killed the outlet, and the batch was lost at exit. The same code is in 0.1.20. On MRI the window is tiny, but it made "closes a device once at exit" flaky on TruffleRuby, which runs threads in parallel (failed once on 6d27d8f, passed on re-run). The test widens the window: the line was lost 3 times out of 3 before the fix and delivered after it. The outlet now counts the batch as in flight before it takes it off the queue.

🤖 Generated with Claude Code