Skip to content

Never drop a line, log CSRF errors where Rails raises them, and log in forked workers - #25

Merged
ndbroadbent merged 10 commits into
mainfrom
nathan/robustness
Oct 18, 2026
Merged

ndbroadbent merged 10 commits into
mainfrom
nathan/robustness

Conversation

@ndbroadbent

@ndbroadbent ndbroadbent commented Oct 17, 2026 •

Copy link
Copy Markdown
Member

Tenth of twelve stacked PRs for 0.2.0.

Lines that were dropped or never written

  • Invalid UTF-8 dropped the whole line. Puma passes headers as binary strings, so a byte like \xFF in a
    User-Agent stopped the line from being written as JSON, and SemanticLogger dropped it. Anyone could hide their
    request line, and the IP spoofing and CSRF lines. Strings and Hash keys are now written as valid UTF-8 (other bytes
    become U+FFFD), and NaN and Infinity as strings. A line that still can't be written is replaced by one that says so,
    with the error's class.
  • New config.limits. Hashes write their first 100 keys (and _more_keys), backtraces their first 100 lines,
    other Arrays 10 items, and strings are cut at 32 KB after they're scrubbed, so one huge value can't hold up the
    thread that writes every line.
  • logger.error(exception) wrote an empty line, and the message logged beside a Hash (logger.info("Saved", id: 1))
    was dropped. Exceptions are error lines with their class, message and backtrace; a message logged with one goes in
    msg and the exception's in the new error_message field. SemanticLogger's error(msg, payload, e) form no longer
    raises ArgumentError.
  • Forked workers wrote nothing. SemanticLogger writes from a background thread, which a forked child doesn't get,
    so lines from Unicorn, Passenger and Pitchfork workers, Resque jobs and other forked children were lost. A
    Process._fork hook reopens the appenders in each child. It replaces the Puma cluster worker patch, which covered
    only Puma.
  • Sidekiq.logger turned a logged Hash into a String before LogStruct saw it, so its keys weren't filtered. Hashes,
    LogStruct entries and exceptions now take the structured path.

CSRF and IP spoofing

  • CSRF lines never appeared. The middleware sat outside ShowExceptions, which turns
    InvalidAuthenticityToken into a 422 first. LogStruct now registers a DebugExceptions interceptor and logs CSRF
    and IP spoofing errors there, in the security_errors mode (reported by default), and Rails responds as it would
    without LogStruct.
  • The IP spoofing check ran on every request and answered 403 app-wide, ignoring the proxies set on RemoteIp.
    Rails raises only where remote_ip is read, and that's where the error is logged now.
  • Error lines have typed request fields (path, method, source_ip, user_agent, referer), and ActiveJob errors
    are a typed Log::ActiveJob::Error.
  • Removed integrations/rack.rb, which nothing loaded and which required a file that doesn't exist.

Behaviour changes

  • Breaking: production logs to STDOUT only. It added a log/production.log appender that nothing rotated, unless
    RAILS_LOG_TO_STDOUT was set, overriding an app's config.logger = STDOUT. Development keeps STDOUT and its log
    file, and test its log file.
  • Breaking: type_checking_errors defaults to ReportProduction: raised in development and test, logged and
    reported in production. Type errors were only logged, so they went unreported.
  • Blocked hosts get the app's own response_app if it set one (LogStruct's 403 page otherwise).

Integrations that could fail the app

  • Requiring LogStruct with server in ARGV and no Puma installed raised LoadError, and the app didn't boot. The Puma
    patches now check that Puma is loaded and that LogStruct is enabled, and Puma's TERM/INT handlers run after
    LogStruct logs the shutdown.
  • Ahoy: a String of properties (from the browser) raised a type error and, in production, failed the request. The
    wrapper now takes Ahoy's arguments as given and logs what it gets.
  • ActiveModelSerializers, Dotenv and Puma: a failure building their line is a LogStruct error (logged in production),
    not one of the app's, so it can't fail a render, stop the app booting or break Puma.
  • GoodJob: the app's thread error handler runs even if LogStruct's line fails.

Testing

New tests for each change. Sorbet and the unit suite (367 tests) pass at this branch's tip.


Stack for 0.2.0, merged in order: #16 → #17 → #18 → #19 → #20 → #21 → #22 → #23 → #24 → #25 → #26 → #27

- Strings and Hash keys are written as valid UTF-8. Puma passes headers as
  binary strings, so a byte like \xFF in a User-Agent stopped the whole line
  from being written as JSON, and SemanticLogger dropped it: anyone could hide
  their request line, and the IP spoofing and CSRF lines. Bytes that aren't
  valid UTF-8 become U+FFFD. NaN and Infinity are written as strings.
- A line that still can't be written as JSON is replaced by one that says so,
  with the error's class, and the error is handled like LogStruct's own.
- New config.limits: Hashes write their first 100 keys (and _more_keys),
  backtrace-like Arrays their first 100 lines (an Array of "a:0" strings was
  written whole), other Arrays 10 items, and strings are cut at 32 KB after
  they're scrubbed. One huge value no longer holds up the thread that writes
  every line.
- logger.error(exception) wrote an empty line, and the message logged beside a
  Hash (logger.info("Saved", id: 1)) was dropped. Exceptions are now error
  lines with their class, message and backtrace; a message logged with one
  goes in msg and the exception's in the new error_message field. The log
  methods take SemanticLogger's exception argument (error(msg, payload, e)),
  which raised an ArgumentError.
- A SystemStackError from an object's as_json is summarized like other
  errors instead of escaping the formatter.
Sidekiq.logger turned a logged Hash into a String before LogStruct saw it,
so its keys weren't filtered ({password: "hunter2"} was logged as it was),
and dropped the Hash logged beside a message. Hashes, LogStruct entries and
exceptions now take the structured path, as with GoodJob's logger; a Hash
beside a message adds its keys to the Sidekiq line, and a message with an
exception is an error line with both.
- CSRF lines never appeared: the middleware sat outside ShowExceptions,
  which turns InvalidAuthenticityToken into a 422 before any middleware
  outside it sees the error. LogStruct now registers a DebugExceptions
  interceptor, which Rails calls with every error from the app in every
  environment, and logs CSRF and IP spoofing errors there. They're handled
  in the security_errors mode (reported by default; the IP spoofing line was
  never reported), and Rails responds as it would without LogStruct.
- The IP spoofing check ran on every request and answered 403 app-wide,
  ignoring the proxies set on RemoteIp. Rails only raises where remote_ip is
  read, and that's where the error is logged now.
- The middleware still logs errors that get past ShowExceptions (or come
  from the middleware outside it), each once, and raises them again.
- Error lines have typed request fields (path, method, source_ip,
  user_agent, referer), and ActiveJob errors are a typed Log::ActiveJob::Error,
  instead of known fields in additional_data.
- Removed integrations/rack.rb, which nothing loaded and which required a
  file that doesn't exist.
Production added a log/production.log file appender unless
RAILS_LOG_TO_STDOUT was set, overriding an app's config.logger = STDOUT.
Nothing rotated the file, and the README said LogStruct adds no file
appender. Environments outside config.local_environments now log to STDOUT
only; development keeps STDOUT and the log file, and test the log file.
…Puma's signal handlers

- With "server" in ARGV and no Puma, requiring LogStruct raised LoadError and the app didn't boot.
- The Puma patches, the boot banner replacement and the puma_lifecycle initializer now check LogStruct.enabled?.
- The TERM/INT traps log the shutdown and then run the handler they replaced (or the signal's default action).
type_checking_errors now defaults to ReportProduction: raised in development and test, logged and reported in
production. With LogProduction they were only logged, so type errors in an app and its gems went unreported. The
docs said "log and report"; they now describe each error group's default.
- Ahoy: the tracking wrapper takes Ahoy's arguments as given (so Ahoy's default properties still apply), logs
  Symbol event names and non-Hash properties (from the browser) without raising, and reports its own failures as
  LogStruct errors. Before, a String of properties raised a type error and, in production, failed the request.
- ActiveModelSerializers, Dotenv and Puma: a failure building their log line is a LogStruct error
  (logstruct_errors: logged in production, raised in development and test), not one of the app's (standard_errors,
  raised everywhere), so it can't fail a render, stop the app booting or break Puma in production.
SemanticLogger writes from a background thread, which a forked child doesn't get, so lines logged in Unicorn,
Passenger and Pitchfork workers, Resque jobs and other forked children were never written. A Process._fork hook
reopens the appenders in each child. It replaces the Puma cluster worker patch, which covered only Puma.
The host authorization integration replaced an app's response_app with its own. It now logs the blocked host and
then calls the app's response_app if there is one (LogStruct's 403 page otherwise), and a failure building the line
doesn't stop the response.
@coderabbitai

coderabbitai Bot commented Oct 17, 2026 •

Copy link
Copy Markdown

Warning

Review limit reached

  • Run on-demand review

This review includes 59 billable files and costs up to $14.75.

  • Ask an admin to make reviews automatic

Open in CodeRabbit

Reviews can continue after your included limit without a manual trigger. An admin must approve usage-based billing.

Or wait 40 minutes for your next included review.

Check out review usage here.

View limit details

Limit details: You’ve used all 2 included reviews currently available. Your 54 included PR review attempts over the past 7 days set your current allowance at 2 reviews per hour.

Learn how review limits work.

Review configuration:

⚙️ Run configuration
  • Configuration used: Organization UI
  • Review profile: CHILL
  • Plan: Essentials
  • Run ID: 0532e111-7008-41db-89ea-d9d7b4e4a89e
📥 Commits

Reviewing files that changed from the base of the PR and between 34ad9a8 and f24a3fc.

📒 Files selected for processing: 59
  • .cspell/project-words.txt
  • README.md
  • docs/app/docs/configuration/page.tsx
  • docs/app/docs/integrations/page.tsx
  • docs/app/docs/logging/page.tsx
  • docs/app/docs/sorbet-types/page.tsx
  • lib/log_struct.rb
  • lib/log_struct/config_struct/error_handling_modes.rb
  • lib/log_struct/config_struct/limits.rb
  • lib/log_struct/configuration.rb
  • lib/log_struct/formatter.rb
  • lib/log_struct/integrations/active_job/log_subscriber.rb
  • lib/log_struct/integrations/active_model_serializers.rb
  • lib/log_struct/integrations/ahoy.rb
  • lib/log_struct/integrations/dotenv.rb
  • lib/log_struct/integrations/good_job.rb
  • lib/log_struct/integrations/good_job/logger.rb
  • lib/log_struct/integrations/host_authorization.rb
  • lib/log_struct/integrations/puma.rb
  • lib/log_struct/integrations/rack.rb
  • lib/log_struct/integrations/rack_error_handler.rb
  • lib/log_struct/integrations/rack_error_handler/error_lines.rb
  • lib/log_struct/integrations/rack_error_handler/middleware.rb
  • lib/log_struct/integrations/rack_middleware.rb
  • lib/log_struct/integrations/request_context/middleware.rb
  • lib/log_struct/integrations/sidekiq/logger.rb
  • lib/log_struct/log/active_job.rb
  • lib/log_struct/log/active_job/error.rb
  • lib/log_struct/log/error.rb
  • lib/log_struct/log/sidekiq/error.rb
  • lib/log_struct/log/sidekiq/log.rb
  • lib/log_struct/rails_boot_banner_silencer.rb
  • lib/log_struct/railtie.rb
  • lib/log_struct/semantic_logger/concerns/log_methods.rb
  • lib/log_struct/semantic_logger/formatter.rb
  • lib/log_struct/semantic_logger/reopen_after_fork.rb
  • lib/log_struct/semantic_logger/setup.rb
  • rails_test_app/templates/app/controllers/security_controller.rb
  • rails_test_app/templates/config/routes.rb
  • rails_test_app/templates/test/integration/security_errors_test.rb
  • schemas/log_sources/active_job.yml
  • schemas/log_sources/error.yml
  • schemas/log_sources/sidekiq.yml
  • test/code_examples/configuration_test.rb
  • test/code_examples/exhaustiveness_test.rb
  • test/log_struct/error_handling_test.rb
  • test/log_struct/formatter_test.rb
  • test/log_struct/integrations/active_job/log_subscriber_test.rb
  • test/log_struct/integrations/active_model_serializers_test.rb
  • test/log_struct/integrations/ahoy_test.rb
  • test/log_struct/integrations/dotenv_test.rb
  • test/log_struct/integrations/good_job/logger_test.rb
  • test/log_struct/integrations/good_job_test.rb
  • test/log_struct/integrations/host_authorization_test.rb
  • test/log_struct/integrations/puma_unit_test.rb
  • test/log_struct/integrations/rack_error_handler_test.rb
  • test/log_struct/integrations/sidekiq_test.rb
  • test/log_struct/rails_boot_banner_silencer_test.rb
  • test/log_struct/semantic_logger_test.rb
  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Comment @coderabbitai help to get the list of available commands.

@ndbroadbent
ndbroadbent changed the base branch from nathan/filtering-gaps to main October 18, 2026 00:40
@ndbroadbent
ndbroadbent merged commit 9f15d27 into main Oct 18, 2026
1 check was pending
@ndbroadbent
ndbroadbent deleted the nathan/robustness branch October 18, 2026 00:41
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant