Structured logging in Rails 8.1 with Rails.event

Structured logging in Rails 8.1 with Rails.event

If you've ever had to write regular expressions to extract meaningful data from log files, you know how painful the process can be. Modern observability platforms practically beg for structured data. They love to parse JSON, extract fields, build amazing dashboards, and notify us of specific anomalies. Unfortunately, our good old friend "Rails.logger" has always produced human-readable but completely unstructured lines of text.

We lost valuable context, and the slightest change in the log format could ruin the entire analysis. In this article, we will look at a new first-class solution that comes to us in Rails 8.1 - the Structured Event Reporter module, available through the new Rails.event API.

Traditional logging and its drawbacks

Before we move on to the new features, let's recall what our everyday life looked like. Logging in Rails meant working with plain, unstructured text. To record the action of creating a new project in the system, we usually wrote something like this:

# Old way of logging project creation
Rails.logger.info("Project created: id=#{project.id}, name=#{project.name}")

This produced a line in the console like Project created: id=123, name=Super Secret Project. To do anything with this in analytics tools, we had to parse it. If anyone on the team changed the format of this string slightly, our parsing would stop working. We also lacked consistent metadata. Where did this log come from? What request triggered this action? What was the exact time, down to the nanosecond? Teams often built their own custom solutions, wrapping loggers in JSON formatters and manually adding request IDs, hoping that all developers would stick to the same convention.

A new era with Rails.event

Rails 8.1 solves this problem by introducing a mechanism that emits events with always consistent metadata. Instead of building strings, we pass specific data in the form of a hash.

# Emitting a structured event using the new API
Rails.event.notify("project.created", project_id: 123, title: "Super Secret Project")

This simple code produces a beautifully structured event underneath. Each such event contains standardised metadata: event name, payload, tags, context, timestamp (with nanosecond precision) and the exact location in the source code from which it was emitted (file, line number, method name). No more wondering where in the code a given entry was generated.

Tags and context for better visibility

The new API offers two separate mechanisms for enriching events with additional information: tags and context. The difference between them is crucial for the correct design of logic in an application.

Tags

Tags add domain-specific information and can be nested. All events within a block of code surrounded by a tag inherit those tags. Imagine a project management application where we want to track all events that occur during the process of configuring a new project and assigning initial tasks to it.

class ProjectsController < ApplicationController
  def create
    # Tagging all events within this block with a "project_setup" tag
    Rails.event.tagged("project_setup") do
      Rails.event.notify("project.started", team_id: @team.id, initial_members: @team.members.count)

      create_default_tasks
      assign_project_manager

      Rails.event.notify("project.completed", project_id: @project.id, status: @project.status)
    end
  end
end

All events emitted in this block will contain the field tags: { project_setup: true }, which makes filtering them in the analytics platform very easy. Tags can also be nested, which is useful when you want to categorise events, for example, by API version and specific administrative section of the application.

Context

Context, on the other hand, is designed for metadata that exists at the level of an entire HTTP request or background task. A typical use case is setting the context in middleware or the main controller callback.

class ApplicationController < ActionController::Base
  before_action :set_event_context

  private

  def set_event_context
    # Setting global context for all subsequent events in this request
    Rails.event.set_context(
      request_id: request.request_id,
      user_id: current_user&.id,
      ip_address: request.remote_ip,
      user_agent: request.user_agent
    )
  end
end

Now, if we emit any event in a controller inheriting from ApplicationController, it will automatically attach the above context to its payload. The context expands during the lifetime of the work unit and sticks to each event.

Debug mode and schemas

Sometimes we need very detailed logs during development, but we absolutely do not want them in production. The tool from Rails 8.1 introduces conditional debug events that completely replace the need to use classic logging levels.

# Emitting debug events only when debug mode is active
Rails.event.with_debug do
  Rails.event.debug("sql.query", sql: "SELECT * FROM projects WHERE id = ?", binds: [123])
end

This is a bold design decision. Instead of info, warn or error levels, we simply have notify for events that matter to users and the business, and debug for events that are only of interest to developers when searching for errors in SQL queries or complex logic.

For teams that require strong typing, the ability to schematise events has been introduced. Instead of passing a loose hash, we can pass an instance of a pre-prepared class.

class ProjectPublishedEvent
  attr_reader :project_id, :title, :task_count, :visibility

  # Initialize the structured event object
  def initialize(project_id:, title:, task_count:, visibility:)
    @project_id = project_id
    @title = title
    @task_count = task_count
    @visibility = visibility
  end
end

Rails.event.notify(
  ProjectPublishedEvent.new(
    project_id: 456,
    title: "Project Apollo",
    task_count: 12,
    visibility: "public"
  )
)

This ensures that we use consistent data structures throughout the code base, and subscribers can handle the appropriate serialisation based on verified object types.

Subscriptions and testing

Rails.event separates the moment an event is emitted from its processing. We register subscribers to control where and how data ends up. Each subscriber must implement the ‘emit’ method.

class LogSubscriber
  # Emit method receives the finalized event hash
  def emit(event)
    payload = event[:payload].map { |key, value| "#{key}=#{value}" }.join(" ")
    source_location = event[:source_location]
    log = "[#{event[:name]}] #{payload} at #{source_location[:filepath]}:#{source_location[:lineno]}"
    Rails.logger.info(log)
  end
end

Rails.event.subscribe(LogSubscriber.new)

This code will generate an entry in our standard log file that looks something like this: [project.created] project_id=123 title=Super Secret Project at app/services/project_service.rb:43. Of course, we can go a step further and create a DatadogSubscriber that will send the same payload directly to an external service.

Testing has not been forgotten either. We have dedicated helpers assert_event_reported and assert_no_event_reported at our disposal, thanks to which we can easily verify whether our code emits the appropriate events with the correct data payload.

Summary

The introduction of structured events is a huge step forward, bringing Ruby on Rails-based applications straight into the modern era of observability. This mechanism is based on Fibre-based isolation - tags and context are assigned to a specific fibre, which guarantees security in modern, multi-threaded environments. Thanks to a unified API, we get rid of guesswork and unreadable text in favour of machine-readable, perfectly organised events. Instead of struggling with logs, we can finally start to take full advantage of them.

Happy logging!