Lumberjack Rails

Continuous Integration Ruby Style Guide Gem Version

The lumberjack_rails gem provides support for using the lumberjack logging library in Rails applications.

Rails has some of its own extensions to the Ruby standard library logger, and this gem bridges the gap between the two logging systems to add Lumberjack features to the Rails.logger and Rails features to Lumberjack loggers.

Usage

With this gem installed, your main application logger will be a Lumberjack logger. The logger that gets initialized is defined by your application's configuration.

Configuration Options

config.lumberjack.enabled

Enables or disables the Lumberjack logger. If this is set to false, then Lumberjack will not be used.

config.lumberjack.level

Sets the log level for the Lumberjack logger. This can be set to any valid log level supported by Lumberjack. This will defer to the standard Rails config.log_level setting or default to :debug if neither is set.

config.lumberjack.device

The device to write logs to (file path, IO object, etc.). Defaults to the Rails log file.

config.lumberjack.attributes

Hash of attributes to apply to all log messages. These attributes will be included in every log entry.

config.lumberjack.shift_age

The age (in seconds) of log files before they are rotated, or a shift name (daily, weekly, monthly). The default is no log rotation. See the logger gem documentation for details.

config.lumberjack.shift_size

The size (in bytes) of log files before they are rotated if shift_age is set to an integer. Defaults to 1048576 (1MB). See the logger gem documentation for details.

config.lumberjack.log_rake_tasks

Whether to redirect $stdout and $stderr to Rails.logger for rake tasks that depend on the :environment task when using a Lumberjack::Logger. Defaults to false.

[!TIP] This is useful for getting output from db:migrate and other rake tasks run in production into your logs. It can often be difficult to track down issues in these tasks without proper logging.

[!NOTE] This setting is ignored when running in an interactive terminal session.

config.lumberjack.middleware

Whether to install Rack middleware that adds a Lumberjack context to each request. Defaults to true.

config.lumberjack.silence_rack_request_started

When set to true, the "Started ..." log lines generated by Rails::Rack::Logger will be suppressed. This can help reduce log noise in applications where these lines are not needed. Defaults to false.

config.lumberjack.request_attributes_proc

A proc to add to log entries for each Rack request. The proc will be called with the request object.

[!TIP] You can use this feature to add both static attributes and dynamic attributes (using a proc) to all log entries within a request context.

config.lumberjack.request_attributes_proc = ->(request) {
  {
    host: request.host,
    method: request.request_method,
    path: request.path,
    request_id: request.request_id
  }
}

Additional Options

[!TIP] For more readable logs in development or test environments, you can set config.lumberjack.template to :local to use the built-in template intended for human readability.

If you have attributes that are logged on every entry but don't want them cluttering up your development logs (i.e. host, version, etc.), you can set config.lumberjack.exclude_attributes to the attribute names to exclude.

You can include Lumberjack::Rails.active_record_entry_formatter in your logger formatter to format ActiveRecord models in log attributes with just the model name and id.

config.lumberjack.formatter = Lumberjack.build_formatter do |formatter|
  formatter.include(Lumberjack::Rails.active_record_entry_formatter)
end

Example Configuration

Here's an example of how you might configure Lumberjack in your config/application.rb:

config.log_level = :info

# Set the program name on the logger
config.lumberjack.progname = Rails.application.railtie_name

# Add values we want on all log entries
config.lumberjack.attributes = {
  host: Lumberjack::Utils.hostname, # Ensures hostname is UTF-8 encoded
  pid: Lumberjack::Utils.global_pid # Returns a global PID value across all hosts
}

config.lumberjack.device = STDOUT

# Build the log entry formatter
config.lumberjack.formatter = Lumberjack.build_formatter do |formatter|
  formatter.add(ActiveRecord::Base, :id)

  # Format the :tags attribute as tags (e.g. [tag1] [tag2])
  formatter.add_attribute("tags", :tags)

  formatter.add_attribute("cost", :round, 2)
  formatter.add_attribute_class("User") { |user| {id: user.id, username: user.username} }
end

# Use a custom template that adds the request id on all log entry lines.
config.lumberjack.template = "[{{time}} {{severity}} {{progname}} {{request_id}}] {{tags}} {{message}} -- {{attributes}}"
config.lumberjack.additional_lines = "> :request_id :message"

# Format log attributes as "[name=value]" (default is [name:value])
config.lumberjack.attribute_format = "[name=value]"

# Convert db:migrate and other rails task output to log entries
config.lumberjack.log_rake_tasks = true

[!TIP] If you are using a logging pipeline in production that supports JSONL logs, then check out the lumberjack_json_device. The gem provides a mechanism for defining the JSON schema for your logs and outputting them to JSONL.

[!TIP] If you want more easily readable log output in development or test environments, you can set the config.lumberjack.template to :local.

If you have attributes that are logged on every entry but don't want them cluttering up your development logs, you can set config.lumberjack.exclude_attributes to the attribute names to exclude.

You can also colorize the logs by setting config.lumberjack.colorize to true and set the format of the severity with config.lumberjack.severity_format.

config.lumberjack.template = :local
config.lumberjack.exclude_progname = true
config.lumberjack.exclude_attributes = [:host, :request_id]
config.lumberjack.colorize = true
config.lumberjack.severity_format = :emoji

TaggedLogger

Rails has its own solution for logging metadata in the tagged method added to logger which can add an array of tags to log entries.

Lumberjack supports the tagged method and will put the tags into the tags attribute. You can format these similar to how Rails formats them in the logger template with the {{tags}} formatter.

# The :tags placeholder will be replaced with the tags attribute. This is the default template.
config.lumberjack.template = "[{{time}} {{severity}} {{progname}} ({{pid}})] {{tags}} {{message}} -- {{attributes}}"

# Add the :tags formatter. If you don't do this, then the tags will be formatted as an inspected array.
config.lumberjack.formatter = Lumberjack.build_formatter do |formatter|
  formatter.add_attribute(:tags, :tags)
end

Broadcast Logger

Rails provides a built-in mechanism for broadcasting log messages to multiple destinations. Rails.logger is actually an ActiveSupport::BroadcastLogger object wrapping one or more underlying loggers. When you call a method on Rails.logger, it will call that method on all underlying loggers. This can create some problems for methods that take a block since that block could get called once for each logger being broadcast to. Only one Lumberjack logger should be added Rails.logger. If more than one is added, method like tag or context that take a block will only be called on one of the loggers.

If you want to send your logs to multiple devices with Lumberjack, you can use the Multi device instead.

The one place that Rails uses multiple loggers out of the box is in development mode where logs are also sent to the console in addition to the log file. This functionality is supported.

Lumberjack Contexts

Contexts are used in Lumberjack to provide isolation for changes to your logger. Within a context block, you can change the log level, progname, or attributes and they will only apply within that block execution.

Contexts will be added via around callbacks to the following frameworks if they are installed:

  • ActionController
  • ActiveJob
  • ActionCable
  • ActionMailer
  • ActionMailbox

In addition, a Rack middleware will be added to ensure a context is set on Rails.logger for each request.

This allows you to change the log level or tag attributes on Rails.logger within your application code in these frameworks without affecting the global logger or the settings in any concurrent requests.

Log Subscribers

Rails comes with several built-in log subscribers that are extended with Lumberjack. These include:

  • ActiveRecord::LogSubscriber
  • ActionController::LogSubscriber
  • ActionDispatch::LogSubscriber
  • ActionView::LogSubscriber
  • ActiveJob::LogSubscriber
  • ActionMailer::LogSubscriber
  • ActiveStorage::LogSubscriber

These log subscribers will all use fork loggers. This these forked loggers are isolated from the main logger allowing you to change the log level and add attributes that is isolated to that log subscriber.

# Set up log subscribers in an initializer

ActiveSupport.on_load(:action_controller) do
  ActionController::LogSubscriber.logger.tag!(user_id: Current.user_id) # Tag all log entries with the user ID
end

ActiveSupport.on_load(:action_view) do
  unless Rails.env.local?
    ActionView::LogSubscriber.logger.level = :warn # Silence view rendering logs in non-local environments
  end
end

You can also silence individual log subscriber events if you don't want to see them in your logs.

ActiveSupport.on_load(:action_controller) do
  ActionController::LogSubscriber.silence_event!!(:start_processing) # Silence the "Started ..." log lines
end

You can also silence the logs that Rack adds when a request starts processing. This subscriber is implemented a bit differently by Rails, so there is a different method to silence it.

Lumberjack::Rails.silence_rack_request_started = true

You can also silence the Rack logger in your application's configuration.

config.lumberjack.silence_rack_request_started = true

Enhanced ActionController Logging

The ActionController::LogSubscriber has been enhanced to allow you to specify additional attributes to be logged in the log entry when each request is finished processing. This log entry can be extremely useful as a canonical log entry for the request and Rails already supports adding some metadata onto the message. This extension allows you to add more metadata and add it as attributes for better structured logging.

# Setup the additional attributes in an initializer.

ActiveSupport.on_load(:action_controller) do
  # Add the IP address from the request to the canonical log entry for the request.
  # The notification event is passed to the block.
  ActionController::LogSubscriber.add_process_log_attribute(:ip_address) { |event| event.payload[:request].remote_ip }

  # You can also add multiple attributes with with a block that returns a hash.
  ActionController::LogSubscriber.process_log_attributes do |event|
    request = event.payload[:request]

    # Get the HTTP status code from the event payload.
    status = event.payload[:status]
    if status.nil? && (exception_class_name = event.payload[:exception]&.first)
      status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
    end

    {
      http: {
        status: status,
        method: request.method,
        url: request.base_url + request.filtered_path,
        useragent: request.user_agent,
      }
    }
  end
end

Log Formatter

ActiveRecord models logged in attributes will automatically be logged with a formatter that will only log the class name and id for the model. You can add additional formatters for ApplicationRecord or for your models to override this behavior.

Testing

Lumberjack comes with built-in support for testing that critical log messages are generated. See the lumberjack documentation for more information.

If you are using RSpec, then you can use the lumberjack_rails_rspec gem for to add RSpec matchers for testing log messages to your test suite.

# In spec/rails_helper.rb

require "lumberjack/capture_device/rspec"

RSpec.configure do |config|
  config.around do |example|
    capture_logger_around_example(Rails.logger, example)
  end
end

RSpec.describe MyModel do
  it "logs a message when doing something" do
    MyModel.do_something_important
    expect(Rails.logger).to include_log_entry(:info, /did something important/)
  end
end

Installation

Add this line to your application's Gemfile:

gem 'lumberjack_rails'

And then execute:

$ bundle

Or install it yourself as:

$ gem install lumberjack_rails

Contributing

Open a pull request on GitHub.

Please use the standardrb syntax and lint your code with standardrb --fix before submitting.

License

The gem is available as open source under the terms of the MIT License.