Validate HttpLogger configuration instead of trusting it

CHANGELOG.md

@@ -1,5 +1,15 @@
 # Changelog
 
+## Unreleased
+
+- **`HttpLogger` validates its configuration instead of trusting it.** A non-numeric or zero
+  `ONLYLOGS_OPEN_TIMEOUT` used to become `0`, which Net::HTTP reads as "no timeout", so the sender
+  could block on connect forever; an `ONLYLOGS_MAX_BATCH_BYTES` smaller than the truncation marker
+  made every oversized line raise; a malformed `ONLYLOGS_DRAIN_URL` raised from `production.rb` and
+  prevented the app from booting. Numbers that are not positive (or a batch cap that cannot hold
+  the marker) now fall back to their default with a warning, and a drain URL that is not `http(s)`
+  or has no host falls back to local-only logging with a warning.
+
 ## 0.10.0
 
 - **`HttpLogger` no longer burns a CPU core and stalls every request.** The sender thread polled

lib/onlylogs/http_device.rb

@@ -71,31 +71,36 @@ def initialize(message, retry_after: nil)
     # the same second.
     CIRCUIT_COOLDOWN = 30
 
+    # Every setting is validated up front: a typo in an env var must never leave the sender without
+    # timeouts (Net::HTTP treats 0 as "no timeout") or unable to truncate a line. Invalid numbers
+    # fall back to the default with a warning; a drain URL that is not http(s) or has no host falls
+    # back to local-only logging. A misconfiguration is never a boot failure.
     def initialize(
       drain_url: ENV["ONLYLOGS_DRAIN_URL"],
-      batch_size: ENV.fetch("ONLYLOGS_BATCH_SIZE", DEFAULT_BATCH_SIZE).to_i,
-      flush_interval: ENV.fetch("ONLYLOGS_FLUSH_INTERVAL", DEFAULT_FLUSH_INTERVAL).to_f,
-      max_queue_size: ENV.fetch("ONLYLOGS_MAX_QUEUE_SIZE", DEFAULT_MAX_QUEUE_SIZE).to_i,
-      max_batch_bytes: ENV.fetch("ONLYLOGS_MAX_BATCH_BYTES", DEFAULT_MAX_BATCH_BYTES).to_i,
-      open_timeout: ENV.fetch("ONLYLOGS_OPEN_TIMEOUT", DEFAULT_OPEN_TIMEOUT).to_f,
-      read_timeout: ENV.fetch("ONLYLOGS_READ_TIMEOUT", DEFAULT_READ_TIMEOUT).to_f,
-      circuit_cooldown: ENV.fetch("ONLYLOGS_CIRCUIT_COOLDOWN", CIRCUIT_COOLDOWN).to_f,
-      keep_alive_timeout: ENV.fetch("ONLYLOGS_KEEP_ALIVE_TIMEOUT", DEFAULT_KEEP_ALIVE_TIMEOUT).to_f,
+      batch_size: ENV.fetch("ONLYLOGS_BATCH_SIZE", DEFAULT_BATCH_SIZE),
+      flush_interval: ENV.fetch("ONLYLOGS_FLUSH_INTERVAL", DEFAULT_FLUSH_INTERVAL),
+      max_queue_size: ENV.fetch("ONLYLOGS_MAX_QUEUE_SIZE", DEFAULT_MAX_QUEUE_SIZE),
+      max_batch_bytes: ENV.fetch("ONLYLOGS_MAX_BATCH_BYTES", DEFAULT_MAX_BATCH_BYTES),
+      open_timeout: ENV.fetch("ONLYLOGS_OPEN_TIMEOUT", DEFAULT_OPEN_TIMEOUT),
+      read_timeout: ENV.fetch("ONLYLOGS_READ_TIMEOUT", DEFAULT_READ_TIMEOUT),
+      circuit_cooldown: ENV.fetch("ONLYLOGS_CIRCUIT_COOLDOWN", CIRCUIT_COOLDOWN),
+      keep_alive_timeout: ENV.fetch("ONLYLOGS_KEEP_ALIVE_TIMEOUT", DEFAULT_KEEP_ALIVE_TIMEOUT),
       spool_dir: ENV.fetch("ONLYLOGS_SPOOL_DIR", default_spool_dir),
-      spool_max_bytes: ENV.fetch("ONLYLOGS_SPOOL_MAX_BYTES", Spool::DEFAULT_MAX_BYTES).to_i
+      spool_max_bytes: ENV.fetch("ONLYLOGS_SPOOL_MAX_BYTES", Spool::DEFAULT_MAX_BYTES)
     )
-      @drain_url = drain_url
-      @uri = URI.parse(drain_url) if drain_url
-      @batch_size = batch_size
-      @flush_interval = flush_interval
-      @max_queue_size = max_queue_size
-      @max_batch_bytes = max_batch_bytes
-      @open_timeout = open_timeout
-      @read_timeout = read_timeout
-      @circuit_cooldown = circuit_cooldown
-      @keep_alive_timeout = keep_alive_timeout
+      @uri = parse_drain_url(drain_url)
+      @drain_url = drain_url if @uri
+      @batch_size = integer_setting("ONLYLOGS_BATCH_SIZE", batch_size, DEFAULT_BATCH_SIZE)
+      @flush_interval = float_setting("ONLYLOGS_FLUSH_INTERVAL", flush_interval, DEFAULT_FLUSH_INTERVAL)
+      @max_queue_size = integer_setting("ONLYLOGS_MAX_QUEUE_SIZE", max_queue_size, DEFAULT_MAX_QUEUE_SIZE)
+      @max_batch_bytes = integer_setting("ONLYLOGS_MAX_BATCH_BYTES", max_batch_bytes, DEFAULT_MAX_BATCH_BYTES,
+        min: MIN_BATCH_BYTES)
+      @open_timeout = float_setting("ONLYLOGS_OPEN_TIMEOUT", open_timeout, DEFAULT_OPEN_TIMEOUT)
+      @read_timeout = float_setting("ONLYLOGS_READ_TIMEOUT", read_timeout, DEFAULT_READ_TIMEOUT)
+      @circuit_cooldown = float_setting("ONLYLOGS_CIRCUIT_COOLDOWN", circuit_cooldown, CIRCUIT_COOLDOWN)
+      @keep_alive_timeout = float_setting("ONLYLOGS_KEEP_ALIVE_TIMEOUT", keep_alive_timeout, DEFAULT_KEEP_ALIVE_TIMEOUT)
       @spool_dir = spool_dir
-      @spool_max_bytes = spool_max_bytes
+      @spool_max_bytes = integer_setting("ONLYLOGS_SPOOL_MAX_BYTES", spool_max_bytes, Spool::DEFAULT_MAX_BYTES)
       @supervisor_mutex = Mutex.new
       reset_process_state
 
@@ -104,7 +109,7 @@ def initialize(
         # at_exit procs are inherited by forked children, so this is registered exactly once: a
         # child that rebuilt its state after the fork closes through the same block.
         at_exit { close }
-      else
+      elsif blank?(drain_url)
         safe_warn "Onlylogs::HttpDevice: ONLYLOGS_DRAIN_URL is not set; logging locally only."
       end
     end
@@ -135,6 +140,44 @@ def close
 
     TRUNCATION_MARKER = "...[truncated by onlylogs]"
 
+    # A cap that cannot hold the marker would make every truncation raise.
+    MIN_BATCH_BYTES = TRUNCATION_MARKER.bytesize + 1
+
+    def parse_drain_url(url)
+      return if blank?(url)
+
+      uri = URI.parse(url.to_s)
+      raise URI::InvalidURIError, "not an http(s) URL with a host" unless uri.is_a?(URI::HTTP) && !blank?(uri.host)
+
+      uri
+    rescue URI::InvalidURIError => e
+      safe_warn "Onlylogs::HttpDevice: ONLYLOGS_DRAIN_URL #{url.inspect} is invalid (#{e.message}); logging locally only."
+      nil
+    end
+
+    def blank?(value)
+      value.nil? || value.to_s.strip.empty?
+    end
+
+    def integer_setting(name, value, default, min: 1)
+      number = Integer(value, exception: false)
+      return number if number && number >= min
+
+      fallback_setting(name, value, default, "an integer of at least #{min}")
+    end
+
+    def float_setting(name, value, default)
+      number = Float(value, exception: false)
+      return number if number&.positive?
+
+      fallback_setting(name, value, default, "a positive number")
+    end
+
+    def fallback_setting(name, value, default, expected)
+      safe_warn "Onlylogs::HttpDevice: #{name} is #{value.inspect}, expected #{expected}; using #{default}"
+      default
+    end
+
     def truncate(line)
       return line if line.bytesize <= @max_batch_bytes
 

test/lib/onlylogs/http_logger_test.rb

@@ -476,6 +476,75 @@ class HttpLoggerTest < ActiveSupport::TestCase
       ::FileUtils.remove_entry(dir) if dir && ::File.directory?(dir)
     end
 
+    test "falls back to the default with a warning when a numeric setting is not a positive number" do
+      drain = build_drain
+      logger = nil
+
+      stderr = StringIO.new
+      with_stderr(stderr) do
+        logger = build_logger(drain, open_timeout: "abc", read_timeout: 0, batch_size: -5, flush_interval: 0.05)
+      end
+      device = logger.device
+
+      assert_equal HttpDevice::DEFAULT_OPEN_TIMEOUT, device.instance_variable_get(:@open_timeout)
+      assert_equal HttpDevice::DEFAULT_READ_TIMEOUT, device.instance_variable_get(:@read_timeout)
+      assert_equal HttpDevice::DEFAULT_BATCH_SIZE, device.instance_variable_get(:@batch_size)
+      assert_match(/ONLYLOGS_OPEN_TIMEOUT is "abc", expected a positive number; using 0.5/, stderr.string)
+      assert_match(/ONLYLOGS_READ_TIMEOUT is 0, expected/, stderr.string)
+      assert_match(/ONLYLOGS_BATCH_SIZE is -5, expected an integer of at least 1/, stderr.string)
+
+      logger.add(Logger::INFO, "still shipping")
+      assert wait_until { drain.received.include?("still shipping") }
+    end
+
+    test "reads and validates settings from the environment" do
+      original = ENV.to_h.slice("ONLYLOGS_OPEN_TIMEOUT", "ONLYLOGS_MAX_QUEUE_SIZE")
+      ENV["ONLYLOGS_OPEN_TIMEOUT"] = "0"
+      ENV["ONLYLOGS_MAX_QUEUE_SIZE"] = "250"
+      logger = nil
+
+      stderr = StringIO.new
+      with_stderr(stderr) { logger = build_logger(build_drain) }
+      device = logger.device
+
+      assert_equal HttpDevice::DEFAULT_OPEN_TIMEOUT, device.instance_variable_get(:@open_timeout)
+      assert_equal 250, device.instance_variable_get(:@max_queue_size)
+      assert_match(/ONLYLOGS_OPEN_TIMEOUT is "0"/, stderr.string)
+    ensure
+      ENV.delete("ONLYLOGS_OPEN_TIMEOUT")
+      ENV.delete("ONLYLOGS_MAX_QUEUE_SIZE")
+      ENV.update(original)
+    end
+
+    test "rejects a batch byte cap too small to hold the truncation marker" do
+      drain = build_drain
+      logger = nil
+
+      stderr = StringIO.new
+      with_stderr(stderr) { logger = build_logger(drain, max_batch_bytes: 5, flush_interval: 0.05) }
+
+      assert_match(/ONLYLOGS_MAX_BATCH_BYTES is 5, expected an integer of at least #{HttpDevice::MIN_BATCH_BYTES}/o, stderr.string)
+      logger.add(Logger::INFO, "huge #{"y" * 2000}")
+      assert wait_until { drain.received.include?("huge") }
+    end
+
+    test "logs locally only when the drain URL is malformed instead of failing to boot" do
+      ["http://bad host/drain", "onlylogs.io/drain", "ftp://onlylogs.io/drain", "http:///drain", "   "].each do |url|
+        local = StringIO.new
+        logger = nil
+
+        stderr = StringIO.new
+        with_stderr(stderr) do
+          assert_nothing_raised { logger = build_logger(url, local_fallback: local) }
+        end
+
+        assert_match(/logging locally only/, stderr.string, "expected a warning for #{url.inspect}")
+        logger.add(Logger::INFO, "local line for #{url}")
+        logger.close
+        assert_includes local.string, "local line for #{url}"
+      end
+    end
+
     private
 
     # Spins up a MockDrain and registers it so teardown closes it. See MockDrain for `status:`.