From ef147d17dbb2a21059a7e6a16fb6bc8afb61a785 Mon Sep 17 00:00:00 2001 From: Jeremy Daer Date: Tue, 1 Sep 2026 12:40:55 -0700 Subject: [PATCH] Redact bot key from request logs (#269) The bot HTTP API carries the bot key as a URL path segment (/rooms/:room_id/:bot_key/...). config.filter_parameters redacts query and form parameters but never path segments, so the key was written verbatim to the request log (the "Started POST ..." line) and to any log line echoing the pagination Link header. Add a log formatter that redacts the bot-key path segment wherever it appears in a formatted line, and wire it into the production logger. --- config/environments/production.rb | 3 +- lib/rails_ext/log_scrubbing_formatter.rb | 16 ++++++ .../rails_ext/log_scrubbing_formatter_test.rb | 54 +++++++++++++++++++ 3 files changed, 72 insertions(+), 1 deletion(-) create mode 100644 lib/rails_ext/log_scrubbing_formatter.rb create mode 100644 test/lib/rails_ext/log_scrubbing_formatter_test.rb diff --git a/config/environments/production.rb b/config/environments/production.rb index d58644a..369bb5b 100644 --- a/config/environments/production.rb +++ b/config/environments/production.rb @@ -1,5 +1,6 @@ require "active_support/core_ext/integer/time" require "active_support/core_ext/numeric/bytes" +require_relative "../../lib/rails_ext/log_scrubbing_formatter" Rails.application.configure do # Settings specified here will take precedence over those in config/application.rb. @@ -50,7 +51,7 @@ Rails.application.configure do # Log to STDOUT by default config.logger = ActiveSupport::Logger.new(STDOUT) - .tap { |logger| logger.formatter = ::Logger::Formatter.new } + .tap { |logger| logger.formatter = LogScrubbingFormatter.new } .then { |logger| ActiveSupport::TaggedLogging.new(logger) } # Prepend all log lines with the following tags. diff --git a/lib/rails_ext/log_scrubbing_formatter.rb b/lib/rails_ext/log_scrubbing_formatter.rb new file mode 100644 index 0000000..231fae9 --- /dev/null +++ b/lib/rails_ext/log_scrubbing_formatter.rb @@ -0,0 +1,16 @@ +# Bot requests carry the bot key as a URL path segment (/rooms/:room_id/:bot_key/...). +# config.filter_parameters redacts query and form parameters but never path segments, +# so the key would otherwise be written verbatim to the request log. Redact it wherever +# it appears in a formatted log line. +class LogScrubbingFormatter < ::Logger::Formatter + BOT_KEY_IN_PATH = %r{(/rooms/\d+/)\d+-[A-Za-z0-9]+} + + def call(severity, time, progname, message) + scrub(super) + end + + private + def scrub(line) + line.gsub(BOT_KEY_IN_PATH, '\1[FILTERED]') + end +end diff --git a/test/lib/rails_ext/log_scrubbing_formatter_test.rb b/test/lib/rails_ext/log_scrubbing_formatter_test.rb new file mode 100644 index 0000000..307e126 --- /dev/null +++ b/test/lib/rails_ext/log_scrubbing_formatter_test.rb @@ -0,0 +1,54 @@ +require "test_helper" + +class LogScrubbingFormatterTest < ActiveSupport::TestCase + setup { @formatter = LogScrubbingFormatter.new } + + test "redacts the bot key path segment from a request log line" do + line = format(%(Started POST "/rooms/1/5-Ab3xK9mQz1Rt/messages" for 203.0.113.10)) + assert_includes line, "/rooms/1/[FILTERED]/messages" + assert_not_includes line, "Ab3xK9mQz1Rt" + end + + test "redacts the bot key reflected in a pagination Link header" do + line = format(%(Link: ; rel="next")) + assert_includes line, "/rooms/42/[FILTERED]/messages?before=99" + assert_not_includes line, "Zt9QmK1xz3Ab" + end + + test "redacts every occurrence on a line" do + line = format("/rooms/1/5-Ab3xK9mQz1Rt/messages and /rooms/2/6-Cd4yL0nR2St7/messages/9/boosts") + assert_not_includes line, "Ab3xK9mQz1Rt" + assert_not_includes line, "Cd4yL0nR2St7" + assert_equal 2, line.scan("[FILTERED]").length + end + + test "leaves non-bot room paths untouched" do + line = format(%(Started GET "/rooms/1/messages" for 203.0.113.10)) + assert_includes line, "/rooms/1/messages" + assert_not_includes line, "[FILTERED]" + end + + test "preserves surrounding log content" do + line = format("hello") + assert_includes line, "hello" + end + + test "scrubs through the TaggedLogging + STDOUT logger stack as production wires it" do + io = StringIO.new + logger = ActiveSupport::Logger.new(io) + .tap { |logger| logger.formatter = LogScrubbingFormatter.new } + .then { |logger| ActiveSupport::TaggedLogging.new(logger) } + + logger.tagged("req-123") { logger.info(%(Started POST "/rooms/1/5-Ab3xK9mQz1Rt/messages")) } + + output = io.string + assert_includes output, "[req-123]" + assert_includes output, "/rooms/1/[FILTERED]/messages" + assert_not_includes output, "Ab3xK9mQz1Rt" + end + + private + def format(message) + @formatter.call("INFO", Time.now, "app", message) + end +end