Taming Ruby on Rails Logging with Lograge and LogDNA

Engineering
September 7, 2021
Lograge was developed by Mathias Meyer "to bring sanity to Rails' noisy and unusable, unparsable and, in the context of running multiple processes and servers, unreadable default logging output."

Ruby on Rails is a powerful and intuitive way to build web applications. With its low barrier of entry, it’s also straightforward to get started. However, the designing of Ruby on Rails (previously referred to as Rails)  took place when systems existed on a single server.  Every action taken by the web app, from loading a page to sending a form, gets automatically logged in a fragmented manner where multiple logs get generated for each event.

Even for a single instance of a Rails application, a specific event can quickly turn into many unique, unconnected loglines.

Started GET "/" for 127.0.0.1 at 2021-07-10 09:42:10 +0700 Processing by HomeController#index as HTML Rendered text template within layouts/application (0.0ms) Rendered layouts/_assets.html.erb (2.0ms) Rendered layouts/_top.html.erb (2.6ms) Rendered layouts/_about.html.erb (0.3ms) Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms)

One must then keep these in our head to make sense of what happened.  For a small app, this is certainly manageable.  But as systems scale both horizontally and vertically, things quickly get out of hand. Today's modern deployment paradigms utilizing containers and serverless functions only exacerbate the problem.  Troubleshooting and pinpointing issues become a considerable challenge as the structure and verbosity of standard Rails logs increase with scale. 

In direct response to this problem, Mathias Meyer developed Lograge "to bring sanity to Rails' noisy and unusable, unparsable and, in the context of running multiple processes and servers, unreadable default logging output."

Remember the multi-line log from above? With Lograge, we get:

{"method":"GET", "format:"html", "path":"/ controller=HomeController", "action":"home#index", "status":200, "duration":79, "view":78.8, "db":7.4}

With condensed to a single log and parsable by a computer, our logs are now set to be actionable.

A key feature of Lograge is the ability to enrich log data with custom information. By modifying the environment configuration as shown, we can add request time, request parameters, ids, exceptions, and anything else your team may find helpful.

# config/environments/development.rb Rails.application.configure do config.lograge.enabled = true config.lograge.custom_options = lambda do |event| { application: Rails.application.class.parent_name, host: event.payload[:host], rails_env: Rails.env, process_id: Process.pid, request_id: event.payload[:headers]['action_dispatch.request_id'], request_time: Time.now, remote_ip: event.payload[:remote_ip], ip: event.payload[:ip], x_forwarded_for: event.payload[:x_forwarded_for], params: event.payload[:params].except(*exceptions).to_json, exception: event.payload[:exception]&.first, exception_message: "#{event.payload[:exception]&.last}", exception_backtrace: event.payload[:exception_object]&.backtrace&.join(",") }.compact end end

To get the additional custom variables in the event payload you must add them to your controller. For instance, we could do something like

# app/controllers/application_controller.rb class ApplicationController < ActionController::Base def append_info_to_payload(payload) super payload[:host] = request.host paylod[:x_forwarded_for] = request.env['HTTP_X_FORWARDED_FOR'] end end

Since Meyer designed Lograge to integrate naturally with Ruby's built-in logging, we can use LogDNA's own Ruby/Rails logger to ingest logs from your application. In two short steps, you can have your entire application sending logs to LogDNA.


Step 1: Include the logdna gem

gem 'logdna'

Step Two: Configure the Rails logger to use LogDNA with JSON-formatted Lograge

Rails.application.configure do config.lograge.enabled = true config.lograge.formatter = Lograge::Formatters::Json.new config.logger = Logdna::Ruby.new(YOUR_API_KEY, OPTIONS) end

And with that, your logs are both concise and aggregated, allowing you to monitor and troubleshoot your Rails app faster.

Pro Tip

LogDNA always takes the top-level "message" key as the human-readable version of a log. It will be used for display in our log viewer, enabling you to quickly scan and "read" your logs while retaining all additional metrics you may send for searching, alerting, and visualization. Rest assured that you can search, alter, and view all data via our context menu.

Check out the guide in our example repo to learn how to build a simple Rails decoder app, tooled with Lograge and LogDNA!

Are you interested in learning more about LogDNA? Meet with one of our experts here, check out our docs, and join our community to keep in touch!

Tags: 

No items found.
Engineering
September 7, 2021
Lograge was developed by Mathias Meyer "to bring sanity to Rails' noisy and unusable, unparsable and, in the context of running multiple processes and servers, unreadable default logging output."

Logging in the Age of DevOps eBook

Download Now