Taming Ruby on Rails Logging with Lograge and Mezmo

    4 MIN READ

    LogDNA is now Mezmo but the product you know and live is here to stay

    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 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}

    Now that the logs are both condensed and parsable, they're 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 Mezmo's own Ruby/Rails logger to ingest logs from your application. In two short steps, you can have your entire application sending logs to Mezmo.

    Step One: Include the logdna gem

    gem 'logdna'

    Step Two: Configure the Rails logger to use Mezmo 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!

    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!