Structured logging in Rails 8.1

The LaunchKit boilerplate logs like most Rails applications log. Three lines in it read Rails.logger.warn("[CreditReferralReward] #{e.class}: #{e.message}"), or [GenerateFeature], or [Mail], and the square brackets are hand typed into the string every time. That habit is the entire subject of this post: the bracket is a field, the field is being encoded into prose by hand, and something downstream is going to have to parse it back out with a regular expression.

Rails 8.1 shipped an answer, and the answer is narrower than the phrase rails structured logging makes it sound. The Event Reporter does not replace the logger, does not reformat a single line of it, and out of the box does nothing at all. What follows is what the framework actually does, run against rails 8.1.3.1 on this machine, with the output pasted rather than described.

The formatter you already have

Rails.logger on a booted application is an ActiveSupport::BroadcastLogger wrapping one ActiveSupport::Logger, whose formatter is ActiveSupport::Logger::SimpleFormatter. The name is accurate. Here is the whole implementation, from activesupport-8.1.3.1/lib/active_support/logger.rb:39:

class SimpleFormatter < ::Logger::Formatter
  # This method is invoked when a log event occurs
  def call(severity, timestamp, progname, msg)
    "#{String === msg ? msg : msg.inspect}\n"
  end
end

Four arguments arrive and three are thrown away. Severity, timestamp and progname never reach the output. A logger.info "plain line" through that formatter produced exactly "plain line\n", which is worth sitting with for a second, because it means every piece of structure you have ever seen in a Rails log was put there by something above the formatter. The [a1b2c3] at the front is TaggedLogging. The Completed 200 OK in 303ms is ActionController::LogSubscriber building a sentence. The timestamp in your aggregator was added by your aggregator.

Ruby's own Logger::Formatter does print all of it. Its Format constant is "%.1s, [%s #%d] %5s -- %s: %s\n", which is severity initial, timestamp, pid, severity, progname, message. Rails replaces that on purpose, and the production template it generates does not put it back. So the baseline for rails logging is a stream of bare sentences with no machine readable field in them anywhere.

Where log_tags quietly stops working

Tagging is the one structure the framework does add, and it is a wrapper rather than a formatter option. ActiveSupport::TaggedLogging.new(logger) clones the logger, clones its formatter, and extends that formatter with a call that prefixes tag_stack.format_message(msg). Tags are held in an array on IsolatedExecutionState, keyed by the formatter's object id.

[d4c8f1] GET /yield
[d4c8f1] [user:41] rendered
[d4c8f1] [user:41] slow query

Those three lines came from logger.tagged("d4c8f1"), logger.tagged("d4c8f1", "user:41") and logger.tagged("d4c8f1") { logger.tagged("user:41") { ... } } respectively, which is the documented behaviour and the useful part: nesting composes.

The generated production environment wires it up with two settings that have to agree with each other:

config.log_tags = [ :request_id ]
config.logger   = ActiveSupport::TaggedLogging.logger(STDOUT)

Now the part nobody mentions. config.log_tags is consumed by Rails::Rack::Logger, and railties-8.1.3.1/lib/rails/rack/logger.rb:23 reads:

env["rails.rack_logger_tag_count"] = if logger.respond_to?(:push_tags)
  logger.push_tags(*compute_tags(request)).size
else
  0
end

A logger that cannot be tagged is not an error. It is a zero. Replace the second line of that config with config.logger = Logger.new(STDOUT) and config.log_tags keeps its value, the middleware keeps running, and no request id ever appears. What the branch is testing: ::Logger.new(io).respond_to?(:push_tags) is false, and so is ActiveSupport::BroadcastLogger.new(::Logger.new(io)).respond_to?(:push_tags), which matters because the bootstrap wraps your logger in a broadcast logger whether or not you asked. Calling it anyway raises NoMethodError: undefined method 'push_tags' for an instance of ActiveSupport::BroadcastLogger, but nothing in the request path calls it anyway. The tags just are not there.

Log levels, and the one that overwrites the others

config.log_level is a string or symbol that Rails::Application::Bootstrap turns into a constant: Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase). The six severities are DEBUG INFO WARN ERROR FATAL UNKNOWN, INFO is 1, and a bare ActiveSupport::Logger.new starts at 0. The boilerplate reads the rails log level from the environment, ENV.fetch("RAILS_LOG_LEVEL", "info"), which is the right shape because raising it to debug is a thing you want to do on a running dyno without a deploy.

What the level gates in practice is mostly Active Record. sql.active_record is logged at debug, so info in production is the line between "my logs are readable" and "my logs are every query". That is a blunt instrument, and the blunt part is the point of the second half of this post.

Two behaviours around the level are worth knowing before you debug a missing line.

BroadcastLogger#level= writes through to every sink. Two loggers, one at DEBUG and one at WARN, broadcast together: bc.info "hello" reached only the first, exactly as configured. Then bc.level = Logger::WARN, and afterwards a.level and c.level were both 2. The per-sink levels are gone, and the only way back is to set them on the sinks again.

logger.silence raises the level to ERROR for the duration of a block. A logger given d.silence { d.info "swallowed"; d.error "kept" } followed by d.info "after" produced "kept\nafter\n". That is the mechanism behind config.silence_healthcheck_path = "/up", which inserts Rails::Rack::SilenceRequest before the rack logger and wraps the call in Rails.logger.silence { @app.call(env) }. Remember that it is the logger being silenced and not the request. The distinction is about to cost something.

What Rails.event is

Rails.event is new in 8.1, contributed by Adrianna Chang at Shopify, and the release announcement of 2025-10-22 frames it plainly: "The default logger in Rails is great for human consumption, but less ideal for post-processing. The new Event Reporter provides a unified interface for producing structured events in Rails applications."

Rails.event returns ActiveSupport.event_reporter, an ActiveSupport::EventReporter. You call notify, it builds a hash, it hands that hash to every registered subscriber. Here is a real one, from a Rails.event.notify("checkout.completed", { order_id: 42, password: "hunter2", email: "a@b.c" }) in this repository:

{"name":"checkout.completed",
 "payload":{"order_id":42,"password":"[FILTERED]","email":"[FILTERED]"},
 "tags":{},"context":{},
 "timestamp":1790260336112405000,
 "source_location":{"filepath":".../ev1.rb","lineno":17,"label":"<main>"}}

Six keys, and two of them are the reason to bother. source_location is a caller_locations frame captured at the notify call, so every event carries the file, line and method that produced it, which is a thing no hand written log line has ever carried. And the payload went through ActiveSupport::ParameterFilter on the way out, against ActiveSupport.filter_parameters, which is the same list your params logging uses.

One documented detail is wrong. The class comment says timestamp: Float (The timestamp of the event, in nanoseconds). The code is Process.clock_gettime(Process::CLOCK_REALTIME, :nanosecond) and I printed the class: Integer. If you are writing the subscriber that divides it by a billion, divide an integer.

The API is strict about its arguments in a way that is easy to trip over. notify takes a name plus either a payload hash or keyword arguments, never both, and passing both produced ArgumentError: Rails.event.notify accepts either an event object, a payload hash, or keyword arguments. A subscriber that does not respond to emit is refused at registration time with ArgumentError: Event subscriber Object must respond to #emit.

Whether those raise depends on where you are. Rails.event.raise_on_error = config.consider_all_requests_local is set in railties-8.1.3.1/lib/rails/application/bootstrap.rb:75, so in development both raise and in production both go to ActiveSupport.error_reporter.report(..., handled: true) and your events silently stop arriving.

The subscriber Rails does not ship

Print Rails.event.subscribers on a freshly booted application and you get []. There is no default, no JSON writer, no config setting that turns one on. The feature as shipped is an interface and forty producers, with the consumer left to you.

That is a defensible design and it has one very good consequence, which is that the unused feature costs nothing. ActiveSupport::StructuredEventSubscriber#silenced? is:

def silenced?(event)
  ActiveSupport.event_reporter.subscribers.none? || @silenced_events[event]&.call
end

and ActiveSupport::Notifications::Fanout rejects silenced subscriptions before dispatching. I confirmed the two states on the Action Controller subscriber: with no event subscriber, silenced?("process_action.action_controller") is true; register one and it is falsy. So the framework's structured event machinery is wired up in every 8.1 application and dormant in almost all of them.

The consumer you have to write is genuinely small:

# config/initializers/event_subscriber.rb
class JsonEventSubscriber
  def emit(event)
    $stdout.puts JSON.generate(event)
  end
end

Rails.event.subscribe(JsonEventSubscriber.new)

subscribe also takes a filter block, Rails.event.subscribe(sub) { |event| event[:name].start_with?("user.") }, which is how you send billing events to one sink and everything else to another without a case statement inside emit.

One request, two streams

The claim to check in every "I replaced my logging with Rails 8.1" post is this one: registering a subscriber adds a stream, it does not remove one. Both ActionController::LogSubscriber and ActionController::StructuredEventSubscriber are attached to process_action.action_controller. I listed the fanout's listeners for that name:

["ActionController::LogSubscriber",
 "ActionController::StructuredEventSubscriber",
 "ActionDispatch::ServerTiming::Subscriber"]

So a single GET /yield against this site, with a JSON subscriber registered and both writing to the same sink, produced this:

Started GET "/yield" for 127.0.0.1 at 2026-09-24 16:36:26 +0200
Processing by YieldController#index as HTML
{"name":"action_controller.request_started","controller":"YieldController","action":"index","format":"HTML","params":{}}
  Rendered layout layouts/landing.html.erb (Duration: 58.9ms | GC: 19.7ms)
Completed 200 OK in 303ms (Views: 60.3ms | ActiveRecord: 19.7ms (2 queries, 0 cached) | GC: 37.1ms)
{"name":"action_controller.request_completed","controller":"YieldController","action":"index","status":200,"view_runtime":60.29,"db_runtime":19.67,"queries_count":2,"cached_queries_count":0,"duration_ms":302.7,"gc_time_ms":37.1}

The same request, twice, in two formats, at two levels of detail. If you are paying a vendor per gigabyte ingested, you just doubled the bill for no new information.

Turning the prose half off is a supported move and it is incomplete. ActionController::LogSubscriber.detach_from :action_controller plus the same for :action_view removed Processing by, Rendered layout and Completed 200 OK. What survived was Started GET "/yield" for 127.0.0.1, because that line is not a log subscriber at all: it is logger.info { started_request_message(request) } called directly inside Rails::Rack::Logger#call_app, and the only way to stop it is the log level or the middleware.

That queries_count: 2 in the completed event, by the way, is the cheapest N+1 alarm you will ever install. A request whose query count scales with its row count is the failure that N+1 queries in Rails is about, and a structured field beats a sentence for it, because you can alert on a number and you cannot alert on (37 queries, 0 cached) without a regex.

Forty events, and the eleven you will not see

Seven framework subscriber files exist in 8.1.3.1, under action_controller, action_dispatch, active_record, active_job, action_view, action_mailer and active_storage. Between them they emit 40 distinct event names: 29 through emit_event and 11 through emit_debug_event.

The Active Job set is the one I would turn on first, because it is the only place in a Rails application where the useful facts are already structured and the log line throws them away: active_job.enqueued, active_job.started, active_job.completed, active_job.retry_scheduled, active_job.retry_stopped, active_job.discarded, active_job.interrupt, active_job.resume. Two of those, interrupt and resume, exist because 8.1 also added job continuations, and a retry_stopped you can count is a different operational posture from a retry_stopped you can grep. If your jobs run on the database rather than on Redis, as in Solid Queue vs Sidekiq, this is the only instrumentation you get without installing a dashboard.

The eleven debug only events are the trap. active_record.sql is one of them, and so are action_view.render_partial, action_view.render_template, action_mailer.delivered and action_controller.unpermitted_parameters. Debug mode is set once, at boot: Rails.event.debug_mode = Rails.env.development?. Not from config.log_level, not from an environment variable, from the environment name. So a production application with a subscriber registered emits controller, job and storage events and no SQL events at all, and the way to get one is Rails.event.with_debug { ... } around a block you already suspect.

I confirmed the gate on the Active Record subscriber directly: with debug mode off, silenced?("sql.active_record") is true; with it on, false.

Tags, context, and the two classes called TagStack

ActiveSupport::TagStack lives in event_reporter.rb and holds a frozen Hash in Fiber[:event_reporter_tags]. ActiveSupport::TaggedLogging::TagStack lives in tagged_logging.rb and holds an Array in IsolatedExecutionState. Same name, different namespace, different data structure, and no relationship whatsoever. Run both at once:

LOG OUTPUT:
[req-1] log line inside logger tag
log line inside event tag
EVENT TAGS:
  in.logger.tag tags={}
  in.event.tag tags={evt: true}

A notify inside Rails.logger.tagged("req-1") came out with empty tags. A logger.info inside Rails.event.tagged("evt") came out with no prefix. Whatever you decided your log tags were, you are deciding it again for events.

Context is the other half and it is scoped differently: tags are a block, context is the whole request or job. Rails.event.set_context(request_id: "abcd123") and every subsequent event carries "context":{"request_id":"abcd123"}. ActiveSupport::Railtie clears it on app.executor.to_complete and on reloader.before_class_unload, so it cannot leak between requests.

And nothing ever sets it. That is the gap I did not expect to find. This application runs config.log_tags = [ :request_id ], and the two events from the real request above both came out with "context":{}. Rails clears the context store for you and populates nothing into it, so correlating a structured event back to a request is a before_action you write:

before_action { Rails.event.set_context(request_id: request.request_id) }

What the filter covers and what it does not

The payload filtering is real and it is the default. ActiveSupport.filter_parameters is fed from Rails.application.config.filter_parameters in an after_initialize, which on a generated app is [:passw, :email, :secret, :token, :_key, :crypt, :salt, :certificate, :otp, :ssn, :cvv, :cvc], and EventReporter#resolve_payload runs the hash through an ActiveSupport::ParameterFilter before the event is built. A password: key came out [FILTERED] without my asking.

The exception is event objects. notify accepts an arbitrary object instead of a name and a hash, uses its class name as the event name, and passes the object through untouched:

{name: "SignupCompleted", payload: #<SignupCompleted:0x0000000127041410 @id=7>, ...}

No filter ran, because there is no hash to filter. The class comment says so: "If an event object is given instead, subscribers will need to filter sensitive data themselves". Event objects are the feature's answer to schema enforcement, and they are also the feature's one way to ship a password to a log vendor. Whoever writes serialize is now responsible for redaction, in a codebase where everyone has learned that filter_parameters handles it.

Where structured events stop

The Event Reporter has no concept of severity. There is no Rails.event.error, no minimum level, nothing that config.log_level gates. Every notify reaches every subscriber that does not filter it out, and the only global switch is debug mode. If you want levels, the word level is a key in your payload and the filtering is in your subscriber.

Emission is synchronous and unbuffered. notify builds the hash on the calling thread, walks @subscribers in order, and calls emit inline. No queue, no batch, no sampling, no rate limit. A subscriber that writes to a socket writes to that socket inside the request, and a subscriber that blocks blocks the request. The caller_locations(caller_depth, 1) for source_location also runs on every single event, including the ones every subscriber's filter is about to reject, because the filter is applied after the hash is built.

And the silencing you already configured does not apply. config.silence_healthcheck_path = "/up" wraps the call in Rails.logger.silence, which touches the logger's level and nothing else. Running a health check through Rails::Rack::SilenceRequest with a JSON subscriber attached:

{"name":"action_controller.request_started","controller":"Rails::HealthController","action":"show","format":"HTML","params":{}}
{"name":"action_controller.request_completed","controller":"Rails::HealthController","action":"show","status":200,"view_runtime":2.13,"db_runtime":0.0,"queries_count":0,"cached_queries_count":0,"duration_ms":147.97,"gc_time_ms":15.8}

Two events per health check, forever, from the path you explicitly told Rails to keep out of the logs. On a load balancer polling /up every five seconds that is 34,560 events a day saying nothing. The filter block on subscribe is where you fix it, and you have to know to.

Nor is there a transport. Rails 8.1 gives you a hash and a hook. Getting that hash to a vendor, with batching, retries and backpressure, is entirely yours, and it is the part that is actually hard. The same shape as running Rails 8 without Redis: the framework now has a credible answer for the piece it used to delegate, and the piece it delegates now is one layer further out.

lograge, and whether you still need it

Lograge is the incumbent and it solves a narrower problem: collapse the multi-line request log into one line, optionally as JSON. Version 0.15.0 was released on 2026-07-08, it is MIT, and its README lists Rails 8.1 through 5.2 and Ruby 3.0 through 4.0 in its support matrix, so the "is it still alive" question has a clear answer. Its mechanism is the same detach_from I used above, plus its own subscriber.

What lograge gives you that Rails.event does not is the finished product: a sensible default set of fields, custom_options for adding your own, and formatters that already exist. What it does not give you is anything outside the request. No job events, no storage events, no source_location, and no place to put checkout.completed.

The other direction is rails_semantic_logger 5.2.0, released 2026-09-05, which replaces the logger wholesale with a levelled, structured, appender-based one and has the transports lograge and Rails.event both lack. It is a bigger commitment than either, and it predates the framework feature it now overlaps.

The call, and what would change it

Write the six line subscriber. Not because the events are better than the log, but because the source_location and the job lifecycle are information you cannot reconstruct from prose at any price, and because Rails.event.notify("checkout.completed", ...) in your own code is strictly better than Rails.logger.info("[Billing] checkout completed for #{user.id}") for the same reason a column is better than a string you parse.

Do not detach the log subscribers on day one. Run both, watch your ingest bill for a week, and detach when you can name the query you would have run against the prose. The two streams cost money and the prose one is what you will actually read at 3am during the first incident after you switch.

Install lograge instead when the request line is the only thing you care about and you want it finished today, which is a large and honest fraction of applications.

What would change the recommendation: a Rails release that ships a default JSON subscriber behind a config flag, which would remove the only real friction here, or one that populates request_id into the event context by default, which would remove the one gap that makes a hand written before_action mandatory. Either would move this from "worth doing" to "already done". A debug mode driven by something other than Rails.env.development? would be the third, because the absence of SQL events in production is currently a surprise rather than a decision.

The position has a cost. Two streams is genuinely worse than one until you commit, and the commit point is not obvious. There is a real risk of ending up with a JSON pipeline nobody queries, a prose log nobody trimmed, and a monthly invoice that went up.

What this post does not cover

The LaunchKit boilerplate does not use Rails.event. It has no subscriber, no initializer for one, and no notify call anywhere. What it does have is config.log_tags = [ :request_id ], ActiveSupport::TaggedLogging.logger(STDOUT), config.silence_healthcheck_path = "/up", a log level read from RAILS_LOG_LEVEL, and the three hand bracketed Rails.logger calls from the opening paragraph. That is the honest provenance: everything above about the Event Reporter is the framework's, run in this sales site, and the product is a good example of the before rather than the after.

Also absent: OpenTelemetry, which is the other answer to this question and a different post; ActiveSupport::Notifications as an instrumentation API in its own right, since the Event Reporter consumes it rather than replacing it; the Active Job continuation events beyond their names; log shipping, rotation and retention, none of which Rails has an opinion about; and any benchmark of emission overhead, because the interesting cost here is per event ingested by a vendor rather than per microsecond in the request.