From 5c9e8c70be44ea281630591024c572444814c07d Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Thu, 1 Oct 2026 19:00:10 +0200 Subject: [PATCH 01/10] Add failing tests for a fast, quiet shutdown that delivers late lines Every Logtail::Logger registers its own at_exit hook that closes the device, and close waits up to 20 seconds for an outlet that can't reach the host, so an unreachable host makes exit take 20 seconds per logger. A line logged while Ruby kills threads at exit prints "log writing failed. can't alloc thread" and is lost, and a line written after the device closed, e.g. by an earlier at_exit hook, vanishes. The exit tests run logtail in a separate Ruby process against a local ingesting server. Co-Authored-By: Claude Opus 5.5 --- spec/logtail/log_devices/http_exit_spec.rb | 79 +++++++++++++++++++++ spec/logtail/log_devices/http_spec.rb | 16 +++++ spec/spec_helper.rb | 1 + spec/support/processes.rb | 82 ++++++++++++++++++++++ 4 files changed, 178 insertions(+) create mode 100644 spec/logtail/log_devices/http_exit_spec.rb create mode 100644 spec/support/processes.rb diff --git a/spec/logtail/log_devices/http_exit_spec.rb b/spec/logtail/log_devices/http_exit_spec.rb new file mode 100644 index 0000000..97ce907 --- /dev/null +++ b/spec/logtail/log_devices/http_exit_spec.rb @@ -0,0 +1,79 @@ +require "spec_helper" + +# What the HTTP device does while the process that logs with it exits. These run logtail in a +# real Ruby process, and count what reaches a local ingesting server. +describe Logtail::LogDevices::HTTP, "when the process exits" do + let(:ingest) { LocalIngestServer.new } + + after { ingest.stop } + + # A local port that nothing listens on, so connecting to it is refused. + def unused_port + server = TCPServer.new("127.0.0.1", 0) + server.addr[1] + ensure + server.close + end + + it "delivers a line that a thread logs while Ruby kills it at exit, without printing an error" do + result = run_ruby(<<-RUBY) + require "logtail" + logger = Logtail::Logger.new(Logtail::LogDevices::HTTP.new("token", #{ingest.device_options})) + logger.info("logged before exit") + started = Queue.new + Thread.new do + begin + started << true + sleep + ensure + logger.info("logged by a thread that Ruby kills at exit") + end + end + started.pop + RUBY + + expect(result.stderr).not_to include("log writing failed") + expect(ingest.messages).to contain_exactly("logged before exit", "logged by a thread that Ruby kills at exit") + end + + it "delivers a line that an at_exit hook logs after the device closed" do + result = run_ruby(<<-RUBY) + require "logtail" + logger = nil + at_exit { logger.info("logged by an at_exit hook registered first, which runs last") } + logger = Logtail::Logger.new(Logtail::LogDevices::HTTP.new("token", #{ingest.device_options})) + logger.info("logged before exit") + RUBY + + expect(result.status).to be_success, result.stderr + expect(ingest.messages).to contain_exactly("logged before exit", "logged by an at_exit hook registered first, which runs last") + end + + it "closes a device once at exit, however many loggers write to it" do + result = run_ruby(<<-RUBY) + require "logtail" + closes = 0 + at_exit { puts "closes: " + closes.to_s } + Logtail::LogDevices::HTTP.prepend(Module.new { define_method(:close) { closes += 1; super() } }) + device = Logtail::LogDevices::HTTP.new("token", #{ingest.device_options}) + 3.times { |n| Logtail::Logger.new(device).info("line " + n.to_s) } + RUBY + + expect(result.stdout).to eq("closes: 1\n"), result.stderr + expect(ingest.messages).to contain_exactly("line 0", "line 1", "line 2") + end + + it "exits within 5 seconds when the ingesting host can't be reached, however many loggers there are" do + result = run_ruby(<<-RUBY) + exiting = nil + at_exit { puts Process.clock_gettime(Process::CLOCK_MONOTONIC) - exiting } + require "logtail" + device = Logtail::LogDevices::HTTP.new("token", ingesting_host: "127.0.0.1", ingesting_port: #{unused_port}, ingesting_scheme: "http") + 2.times { |n| Logtail::Logger.new(device).info("line " + n.to_s) } + exiting = Process.clock_gettime(Process::CLOCK_MONOTONIC) + RUBY + + expect(result.status).to be_success, result.stderr + expect(result.stdout.to_f).to be < 5 + end +end diff --git a/spec/logtail/log_devices/http_spec.rb b/spec/logtail/log_devices/http_spec.rb index 2f6ac4e..2295196 100755 --- a/spec/logtail/log_devices/http_spec.rb +++ b/spec/logtail/log_devices/http_spec.rb @@ -68,6 +68,22 @@ expect(http).to receive(:flush).exactly(1).times http.close end + + it "does nothing when called again, e.g. by the device's at_exit hook" do + http.close + expect(http).not_to receive(:flush) + http.close + end + + it "stops waiting for the outlet thread once it has died" do + stub_request(:post, "https://in.logs.betterstack.com/") + http.write(Logtail::LogEntry.new("INFO", Time.now, nil, "test log message", nil, nil)) + http.instance_variable_get(:@request_outlet_thread).kill.join + + closing = Process.clock_gettime(Process::CLOCK_MONOTONIC) + http.close + expect(Process.clock_gettime(Process::CLOCK_MONOTONIC) - closing).to be < 1 + end end # Testing a private method because it helps break down our tests diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index a16418e..36a96a7 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -12,6 +12,7 @@ require File.join(File.dirname(__FILE__), 'support', 'timecop') require File.join(File.dirname(__FILE__), 'support', 'webmock') require File.join(File.dirname(__FILE__), 'support', 'logtail') +require File.join(File.dirname(__FILE__), 'support', 'processes') RSpec::Support::ObjectFormatter.default_instance.max_formatted_output_length = 5_000 diff --git a/spec/support/processes.rb b/spec/support/processes.rb new file mode 100644 index 0000000..15332fe --- /dev/null +++ b/spec/support/processes.rb @@ -0,0 +1,82 @@ +require "msgpack" +require "rbconfig" +require "socket" +require "tmpdir" +require "zlib" + +# A local stand-in for the Better Stack ingesting host, for tests that run logtail in a separate +# process: it answers every request with 202 and records the message of every line it receives. +class LocalIngestServer + def initialize + @server = TCPServer.new("127.0.0.1", 0) + @messages = [] + @lock = Mutex.new + @connections = [] + @thread = Thread.new do + loop { @connections << Thread.new(@server.accept) { |socket| serve(socket) } } + end + end + + # The options for Logtail::LogDevices::HTTP.new that deliver to this server, as Ruby code. + def device_options + %(ingesting_host: "127.0.0.1", ingesting_port: #{@server.addr[1]}, ingesting_scheme: "http") + end + + def messages + @lock.synchronize { @messages.dup } + end + + def stop + @thread.kill.join + @connections.each { |connection| connection.kill.join } + @server.close + end + + private + + def serve(socket) + while socket.gets + headers = {} + while (header = socket.gets) && header != "\r\n" + name, value = header.split(":", 2) + headers[name.downcase] = value.strip + end + lines = MessagePack.unpack(Zlib::Inflate.inflate(socket.read(headers["content-length"].to_i))) + @lock.synchronize { @messages.concat(lines.map { |line| line["message"] }) } + socket.write("HTTP/1.1 202 Accepted\r\nContent-Length: 0\r\n\r\n") + end + rescue IOError, SystemCallError + ensure + socket.close + end +end + +module ProcessHelpers + ProcessResult = Struct.new(:stdout, :stderr, :status) + + # Runs the Ruby script in a new process with logtail from lib/ and waits for it to exit, at + # most `timeout` seconds (generous: TruffleRuby starts slowly on CI). + def run_ruby(script, timeout: 120) + Dir.mktmpdir do |dir| + File.write(File.join(dir, "script.rb"), script) + lib = File.expand_path("../../lib", __dir__) + pid = Process.spawn(RbConfig.ruby, "-I", lib, File.join(dir, "script.rb"), + out: File.join(dir, "stdout"), err: File.join(dir, "stderr")) + deadline = Process.clock_gettime(Process::CLOCK_MONOTONIC) + timeout + status = nil + until (status = Process.waitpid2(pid, Process::WNOHANG)) + if Process.clock_gettime(Process::CLOCK_MONOTONIC) > deadline + Process.kill("KILL", pid) + Process.wait(pid) + raise "The Ruby process didn't exit within #{timeout} seconds:\n#{File.read(File.join(dir, "stderr"))}" + end + sleep 0.05 + end + ProcessResult.new(File.read(File.join(dir, "stdout")), File.read(File.join(dir, "stderr")), status[1]) + end + end +end + +RSpec.configure do |config| + config.include ProcessHelpers +end From 0c3b93300b19246551fd5c9369db9090209c7fd2 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Thu, 1 Oct 2026 19:03:41 +0200 Subject: [PATCH 02/10] Exit quickly when Better Stack can't be reached, and deliver late lines - Each HTTP device registers one at_exit hook that closes it, instead of one hook per Logtail::Logger, and close does nothing the second time. - close stops waiting for the outlet thread once it can't deliver: the thread is dead, or the host has never answered and the outlet has backed off after a failed connection. A refused port or a failed DNS lookup now costs about a second at exit instead of 20 per logger. - A line written after close, or when Ruby refuses to start a thread while it shuts down, is delivered right away in the writing thread, with 2-second timeouts and errors only in the debug log, so Ruby's Logger no longer prints "log writing failed. can't alloc thread". Once such a delivery fails, later lines are dropped. - Ruby also refuses the thread Net::HTTP (before Ruby 4.0) needs to time out connecting then, so the device connects without that timeout, but only to a host that has answered before. Co-Authored-By: Claude Opus 5.5 --- lib/logtail/log_devices/http.rb | 76 ++++++++++++++++++++++++++++++++- lib/logtail/logger.rb | 2 - 2 files changed, 74 insertions(+), 4 deletions(-) diff --git a/lib/logtail/log_devices/http.rb b/lib/logtail/log_devices/http.rb index eeb6c7a..b70c4c5 100755 --- a/lib/logtail/log_devices/http.rb +++ b/lib/logtail/log_devices/http.rb @@ -24,6 +24,7 @@ class HTTP USER_AGENT = "Logtail Ruby/#{Logtail::VERSION} (HTTP)".freeze INITIAL_RECONNECT_WAIT = 1 # second MAX_RECONNECT_WAIT = 30 # seconds + SYNCHRONOUS_DELIVERY_TIMEOUT = 2 # seconds, to connect and to read the response # Instantiates a new HTTP log device that can be passed to {Logtail::Logger#initialize}. # @@ -86,6 +87,10 @@ def initialize(source_token, options = {}) @successive_error_count = 0 @requests_in_flight = 0 @reconnect_wait = INITIAL_RECONNECT_WAIT + + # Delivers what is still buffered when the process exits. One hook per device, however + # many loggers write to it. + at_exit { close } end # Write a new log line message to the buffer, and flush asynchronously if the @@ -96,12 +101,21 @@ def write(msg) return unless Logtail.config.send_to_better_stack?(msg) @msg_queue.enq(msg) + # No thread delivers what is written after #close, e.g. by an at_exit hook that runs + # after the device's own. + return deliver_late_lines if @closed # Lazily start flush threads to ensure threads are alive after forking processes. # If the threads are started during instantiation they will not be copied when # the current process is forked. This is the case with various web servers, # such as phusion passenger. - ensure_flush_threads_are_started + begin + ensure_flush_threads_are_started + rescue ThreadError + # Ruby refuses new threads while it shuts down, e.g. to a thread that logs in an + # `ensure` block as it is killed at exit. + return deliver_late_lines + end if @msg_queue.full? Logtail::Config.instance.debug { "Flushing HTTP buffer via write" } @@ -119,8 +133,12 @@ def flush true end - # Closes the log device, cleans up, and attempts one last delivery. + # Closes the log device, cleans up, and attempts one last delivery. Closing it again does + # nothing; lines written after it are delivered right away (see {#write}). def close + return if @closed + @closed = true + # Kill the flush thread immediately since we are about to flush again. @flush_thread.kill.join if @flush_thread @@ -241,6 +259,32 @@ def flush_async end end + # Sends the requests in the calling thread, for when no outlet thread delivers them. + # Returns whether all of them were sent; errors only go to the debug log. + def deliver_synchronously(requests) + return true if requests.empty? + + http = build_http + http.open_timeout = http.read_timeout = SYNCHRONOUS_DELIVERY_TIMEOUT + begin + http.start + rescue ThreadError + # While Ruby shuts down it refuses new threads, and Net::HTTP (before Ruby 4.0) needs + # one to time out connecting. Then it connects without a timeout, but only to a host + # that has answered before. + raise if @last_resp.nil? + http.open_timeout = nil + http.start + end + requests.each { |request| @last_resp = http.request(request) } + true + rescue => e + Logtail::Config.instance.debug { "Synchronous delivery failed: #{e.message}" } + false + ensure + http.finish if http && http.started? + end + # Waits on the request queue. This is used in {#flush} to ensure # the log data has been delivered before returning. def wait_on_request_queue @@ -250,6 +294,10 @@ def wait_on_request_queue Logtail::Config.instance.debug { "Request queue is empty and no requests are in flight, finish waiting" } return true end + if outlet_stalled? + Logtail::Config.instance.debug { "The HTTP outlet can't deliver the requests, finish waiting" } + return false + end Logtail::Config.instance.debug do "Request size #{@request_queue.size}, reqs in-flight #{@requests_in_flight}, " \ "continue waiting (iteration #{i + 1})" @@ -258,6 +306,30 @@ def wait_on_request_queue end end + # Whether the outlet thread can't deliver anything while {#close} waits for it: the thread + # is dead, or the host has never answered and the outlet has already waited to reconnect + # after a failed connection (@reconnect_wait grows after each wait until a response). + def outlet_stalled? + return true unless @request_outlet_thread && @request_outlet_thread.alive? + + @last_resp.nil? && @reconnect_wait > INITIAL_RECONNECT_WAIT + end + + # Delivers the buffered lines in the calling thread, for {#write} when no thread can. After + # a delivery fails, e.g. to an unreachable host, later lines are dropped so they can't + # hold up the exit one by one. + def deliver_late_lines + msgs = @msg_queue.flush + return true if msgs.empty? + + if @late_delivery_failed + Logtail::Config.instance.debug { "Dropping #{msgs.size} log lines, an earlier synchronous delivery failed" } + else + @late_delivery_failed = !deliver_synchronously([build_request(msgs)]) + end + true + end + # Flushes the message queue on an interval. You will notice that {#write} also # flushes the buffer if it is full. This method takes note of this via the # `@last_async_flush` variable as to not flush immediately after a write flush. diff --git a/lib/logtail/logger.rb b/lib/logtail/logger.rb index c2dc67f..f21bc21 100755 --- a/lib/logtail/logger.rb +++ b/lib/logtail/logger.rb @@ -192,8 +192,6 @@ def initialize(*io_devices_and_loggers) Logtail::Config.instance.debug { "Logtail::Logger instantiated, level: #{level}, formatter: #{formatter.class}" } @initialized = true - - at_exit { self.close } end # Sets a new formatted on the logger. From f4a2ee6438ea174a5041f28f4403d699a4c5648f Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Thu, 1 Oct 2026 19:30:14 +0200 Subject: [PATCH 03/10] Add a failing test for a late line raising WebMock's error A line written after close is delivered synchronously, which only rescued StandardError, so an error outside it, like the one WebMock refuses connections with, escaped write. Through Ruby's Logger that prints "log writing failed" to stderr. Co-Authored-By: Claude Opus 5.5 --- spec/logtail/log_devices/http_spec.rb | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/spec/logtail/log_devices/http_spec.rb b/spec/logtail/log_devices/http_spec.rb index 2295196..fa807da 100755 --- a/spec/logtail/log_devices/http_spec.rb +++ b/spec/logtail/log_devices/http_spec.rb @@ -75,6 +75,13 @@ http.close end + it "doesn't let a line written after it raise when delivering it fails, whatever the error" do + http.close + + # WebMock refuses to connect with an error that isn't a StandardError + expect { http.write(Logtail::LogEntry.new("INFO", Time.now, nil, "test log message", nil, nil)) }.not_to raise_error + end + it "stops waiting for the outlet thread once it has died" do stub_request(:post, "https://in.logs.betterstack.com/") http.write(Logtail::LogEntry.new("INFO", Time.now, nil, "test log message", nil, nil)) From a260a7a02afa553c5154b61ec4cdace167479dfb Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Thu, 1 Oct 2026 19:30:14 +0200 Subject: [PATCH 04/10] Keep any error of a synchronous delivery out of the caller deliver_synchronously now rescues every Exception but signals and only writes it to the debug log, so a late line can't print "log writing failed" or raise into the app. Interrupt and other signals are raised as before. The helper stays the same as in the fork-safety PR. Co-Authored-By: Claude Opus 5.5 --- lib/logtail/log_devices/http.rb | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/lib/logtail/log_devices/http.rb b/lib/logtail/log_devices/http.rb index b70c4c5..07212fa 100755 --- a/lib/logtail/log_devices/http.rb +++ b/lib/logtail/log_devices/http.rb @@ -260,7 +260,8 @@ def flush_async end # Sends the requests in the calling thread, for when no outlet thread delivers them. - # Returns whether all of them were sent; errors only go to the debug log. + # Returns whether all of them were sent. Errors only go to the debug log, also those that + # aren't StandardErrors (WebMock refuses to connect with one); signals are raised as usual. def deliver_synchronously(requests) return true if requests.empty? @@ -278,7 +279,9 @@ def deliver_synchronously(requests) end requests.each { |request| @last_resp = http.request(request) } true - rescue => e + rescue SignalException + raise + rescue Exception => e Logtail::Config.instance.debug { "Synchronous delivery failed: #{e.message}" } false ensure From 12a71bdd437454b63991ed5310f880fc8ea84f14 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 08:25:41 +0200 Subject: [PATCH 05/10] Add a failing test for warnings about uninitialized instance variables With warnings on, Ruby 2.7 and older warn about every instance variable that is read before it's set. The device reads @closed on every write and in close, @last_resp while close waits, and @late_delivery_failed for a line written after close, before setting them. ruby -w on 2.7 printed these warnings, which 0.1.20 doesn't. The test fails on the Ruby 2.5 to 2.7 jobs only, newer Rubies don't warn about this. Co-Authored-By: Claude Opus 5.5 --- spec/logtail/log_devices/http_exit_spec.rb | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/spec/logtail/log_devices/http_exit_spec.rb b/spec/logtail/log_devices/http_exit_spec.rb index 97ce907..8493d7d 100644 --- a/spec/logtail/log_devices/http_exit_spec.rb +++ b/spec/logtail/log_devices/http_exit_spec.rb @@ -36,6 +36,22 @@ def unused_port expect(ingest.messages).to contain_exactly("logged before exit", "logged by a thread that Ruby kills at exit") end + it "doesn't warn about the instance variables it uses to close, with warnings on" do + # Ruby 2.7 and older warn about an instance variable that is read before it's set + result = run_ruby(<<-RUBY) + $VERBOSE = true + require "logtail" + logger = Logtail::Logger.new(Logtail::LogDevices::HTTP.new("token", #{ingest.device_options})) + logger.info("logged before close") + logger.close + logger.info("logged after close") + RUBY + + expect(result.status).to be_success, result.stderr + expect(result.stderr).not_to match(/@(closed|late_delivery_failed|last_resp) not initialized/) + expect(ingest.messages).to contain_exactly("logged before close", "logged after close") + end + it "delivers a line that an at_exit hook logs after the device closed" do result = run_ruby(<<-RUBY) require "logtail" From e142a4d03ef5ad7ebc4d0e990009989e0d63f4f4 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 08:26:09 +0200 Subject: [PATCH 06/10] Set the device's closing state in initialize @closed, @late_delivery_failed and @last_resp are set in initialize, so Ruby 2.7 and older no longer warn that they are read before they're set. The warnings left with -w on Ruby 2.7 are the ones 0.1.20 prints too. Co-Authored-By: Claude Opus 5.5 --- lib/logtail/log_devices/http.rb | 3 +++ 1 file changed, 3 insertions(+) diff --git a/lib/logtail/log_devices/http.rb b/lib/logtail/log_devices/http.rb index 07212fa..952cae5 100755 --- a/lib/logtail/log_devices/http.rb +++ b/lib/logtail/log_devices/http.rb @@ -86,7 +86,10 @@ def initialize(source_token, options = {}) @request_queue = options[:request_queue] || FlushableDroppingSizedQueue.new(25) @successive_error_count = 0 @requests_in_flight = 0 + @last_resp = nil @reconnect_wait = INITIAL_RECONNECT_WAIT + @closed = false + @late_delivery_failed = false # Delivers what is still buffered when the process exits. One hook per device, however # many loggers write to it. From 062d2877b0893a2eb2b093b25787a701409416dc Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 11:17:53 +0200 Subject: [PATCH 07/10] Test that lines logged after close reach a host that answers in 3 seconds Lines logged after close are delivered in the calling thread. With the 2 second timeout a host that takes 3 seconds to answer fails the first delivery, and the next line is dropped. This fails until the timeout is raised to 5 seconds. Co-Authored-By: Claude Opus 5.5 --- spec/logtail/log_devices/http_exit_spec.rb | 34 ++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/spec/logtail/log_devices/http_exit_spec.rb b/spec/logtail/log_devices/http_exit_spec.rb index 8493d7d..f5ebee2 100644 --- a/spec/logtail/log_devices/http_exit_spec.rb +++ b/spec/logtail/log_devices/http_exit_spec.rb @@ -1,4 +1,21 @@ require "spec_helper" +require "delegate" + +# A local ingesting server that takes 3 seconds to answer each request +class SlowAnsweringIngestServer < LocalIngestServer + class SlowSocket < SimpleDelegator + def write(*args) + sleep 3 + super + end + end + + private + + def serve(socket) + super(SlowSocket.new(socket)) + end +end # What the HTTP device does while the process that logs with it exits. These run logtail in a # real Ruby process, and count what reaches a local ingesting server. @@ -65,6 +82,23 @@ def unused_port expect(ingest.messages).to contain_exactly("logged before exit", "logged by an at_exit hook registered first, which runs last") end + it "waits up to 5 seconds for a slow host when it delivers lines logged after closing" do + slow_ingest = SlowAnsweringIngestServer.new + result = run_ruby(<<-RUBY) + require "logtail" + logger = Logtail::Logger.new(Logtail::LogDevices::HTTP.new("token", #{slow_ingest.device_options})) + logger.close + logger.info("first line after close") + logger.info("second line after close") + RUBY + + # A delivery that times out would drop the second line + expect(result.status).to be_success, result.stderr + expect(slow_ingest.messages).to contain_exactly("first line after close", "second line after close") + ensure + slow_ingest.stop if slow_ingest + end + it "closes a device once at exit, however many loggers write to it" do result = run_ruby(<<-RUBY) require "logtail" From 6d27d8f07ec87882e7c3dd36d072b1cd0238e48b Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 11:18:24 +0200 Subject: [PATCH 08/10] Give synchronous deliveries 5 seconds to connect and to get a response 2 seconds left little room for a slow network. 5 seconds matches how long flush waits for the outlet, and still keeps exits short when Better Stack can't be reached. Co-Authored-By: Claude Opus 5.5 --- lib/logtail/log_devices/http.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/logtail/log_devices/http.rb b/lib/logtail/log_devices/http.rb index 952cae5..727c6e4 100755 --- a/lib/logtail/log_devices/http.rb +++ b/lib/logtail/log_devices/http.rb @@ -24,7 +24,7 @@ class HTTP USER_AGENT = "Logtail Ruby/#{Logtail::VERSION} (HTTP)".freeze INITIAL_RECONNECT_WAIT = 1 # second MAX_RECONNECT_WAIT = 30 # seconds - SYNCHRONOUS_DELIVERY_TIMEOUT = 2 # seconds, to connect and to read the response + SYNCHRONOUS_DELIVERY_TIMEOUT = 5 # seconds, to connect and to read the response # Instantiates a new HTTP log device that can be passed to {Logtail::Logger#initialize}. # From fd9e3f2200fa00694a0427e6b2a62fcd29e2fb9c Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 11:21:35 +0200 Subject: [PATCH 09/10] Test that close waits for a batch the outlet has just taken off the queue The outlet takes a batch off the request queue before it counts it as in flight. When close checks in between, it sees an empty queue and nothing in flight, stops waiting and kills the outlet, and the batch is lost. The test widens that moment; it fails until the outlet counts the batch first. Co-Authored-By: Claude Opus 5.5 --- spec/logtail/log_devices/http_exit_spec.rb | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/spec/logtail/log_devices/http_exit_spec.rb b/spec/logtail/log_devices/http_exit_spec.rb index f5ebee2..625d607 100644 --- a/spec/logtail/log_devices/http_exit_spec.rb +++ b/spec/logtail/log_devices/http_exit_spec.rb @@ -99,6 +99,19 @@ def unused_port slow_ingest.stop if slow_ingest end + it "delivers a batch that the outlet takes off the queue while close checks whether it's done" do + result = run_ruby(<<-RUBY) + require "logtail" + # Widens the moment between the outlet taking a batch off the queue and counting it as in flight + Logtail::LogDevices::HTTP::RequestAttempt.prepend(Module.new { define_method(:attempted!) { sleep 1.5; super() } }) + logger = Logtail::Logger.new(Logtail::LogDevices::HTTP.new("token", #{ingest.device_options})) + logger.info("logged right before exit") + RUBY + + expect(result.status).to be_success, result.stderr + expect(ingest.messages).to eq(["logged right before exit"]) + end + it "closes a device once at exit, however many loggers write to it" do result = run_ruby(<<-RUBY) require "logtail" From b866aa7d0fc9babf7ddc8b44ba752b5cbc952697 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Fri, 2 Oct 2026 11:22:29 +0200 Subject: [PATCH 10/10] Count a batch as in flight before the outlet takes it off the queue 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 count it afterwards, so close could see neither, kill the outlet and lose the batch at exit. Rare on MRI, but it made the exit tests flaky on TruffleRuby, which runs threads in parallel. It's the same in 0.1.20. Co-Authored-By: Claude Opus 5.5 --- lib/logtail/log_devices/http.rb | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/lib/logtail/log_devices/http.rb b/lib/logtail/log_devices/http.rb index 727c6e4..c266d7f 100755 --- a/lib/logtail/log_devices/http.rb +++ b/lib/logtail/log_devices/http.rb @@ -421,13 +421,15 @@ def deliver_requests(conn) Logtail::Config.instance.debug { "Waiting on next request, threads waiting: #{@request_queue.size}" } end + # Counted as in flight before it leaves the queue, so close never sees neither + @requests_in_flight += 1 request_attempt = @request_queue.deq if request_attempt.nil? + @requests_in_flight -= 1 sleep(1) else request_attempt.attempted! - @requests_in_flight += 1 begin resp = conn.request(request_attempt.request)