Ruby on Rails
Structured Event Reporting with Rails.event in Rails 8.1
By Daniel Rice · · 3 min read
Rails logs are good for a person reading a terminal. They are a bad database. A line like User 123 signed up has to be parsed with a regex before anyone can count signups, and the regex breaks the day someone adds an email address to the message. Rails 8.1 adds a structured event reporter, Rails.event, so the interesting facts leave the process as data.
The default logger stays. This is not a replacement for Rails.logger.info when you are debugging a request. It is a second channel for the events you want to search, graph, or alert on.
Emitting an event
notify takes a name and a payload. Names are coerced to strings. The payload should be the fields you would put in a WHERE clause later.
Rails.event.notify("user.signup", user_id: 123, email: "user@example.com")
What subscribers receive is not that hash alone. The reporter wraps it:
nameis the event name.payloadis the hash you passed.tagsis extra labeling, separate from the payload.contextis ambient data set earlier in the call stack.timestampis in nanoseconds.source_locationincludes the file, line, and label of the call site.
That last one is why this is better than sprinkling logger.info through a service object. You do not have to remember to add the class name to the message. The call site comes with the event.
Tags and context are not the same thing
Tags describe the kind of work. Context describes the request or the tenant. Mixing them into the payload works until you want every event during a request to carry the request id without every call site knowing about it.
Rails.event.tagged("graphql") do
Rails.event.notify("user.signup", user_id: 123, email: "user@example.com")
end
Inside that block the event's tags include graphql. Use tags for a subsystem: GraphQL, a webhook controller, a billing job.
Context is sticky in a different way. Set it once, high in the stack, and later events inherit it.
Rails.event.set_context(request_id: "abc123", shop_id: 456)
A signup emitted after that line carries request_id and shop_id without the signup code mentioning them. That is the right place for a tenant id. It is the wrong place for the user's email. The email is a fact about this event. The shop id is a fact about the surroundings.
A subscriber decides the format
Rails does not pick your log drain. You register a subscriber that implements emit and receives the event hash. The subscriber's job is to encode the event for wherever it is going.
class LogSubscriber
def emit(event)
payload = event[:payload].map { |key, value| "#{key}=#{value}" }.join(" ")
source = event[:source_location]
Rails.logger.info("[#{event[:name]}] #{payload} at #{source[:filepath]}:#{source[:lineno]}")
end
end
Rails.event.subscribe(LogSubscriber.new)
A filter is optional. This subscriber only hears signup events:
Rails.event.subscribe(LogSubscriber.new) { |event| event[:name].start_with?("user.") }
Production subscribers usually write JSON to a collector instead of calling Rails.logger. The logger subscriber is still worth having in development, because you can read the stream in the same terminal as the rest of the request.
If you pass an object instead of a hash, the object is the payload and its class name becomes the event name. Subscribers then call something like serialize on it. Hashes are enough until a payload has grown a third slightly-different shape. An object is how you stop that.
What we emit, and what we leave as logs
A useful event is something you will query. Signups, failed charges, import finished, job gave up, permission denied. A useless event is a narration of the code: "entering method", "validations passed", "about to save". That narration belongs in a log line you delete later.
Keep payloads small and stable. Adding a key is safe. Renaming a key is a migration for every dashboard that reads it. Treat the event name like a public API.
Rails.event.debug is there for the noisy ones. Those events are only reported when the reporter is in debug mode, so you can leave them in the code without paying for them in production.
If the logs are already a mess
You do not have to convert the whole app. Pick the three events that page you, emit those through Rails.event, and leave the rest of the logger alone. The win is a name and a payload you can count. The rest can wait.
When the current alerting is a Slack search for a sentence somebody logged in 2019, we start here. Rails Agency will wire the few events that matter and leave the debug noise where it belongs.
FAQ
- Does Rails.event replace the Rails logger?
- No. The logger is still right for debugging a request. Rails.event is for the events you want to count, graph, or alert on.