From e2b1c16ade09c0afde11d8b39bac9f1974c9b057 Mon Sep 17 00:00:00 2001
From: Stan Hu <stanhu@gmail.com>
Date: Mon, 17 Jul 2017 15:54:13 -0700
Subject: Add structured logging for Rails processes

This introduces JSON logging for Rails views saved to a file called
`development_json.log`, `production_json.log`, etc.

For example, instead of this unparsable log:

```
Started GET "/" for 127.0.0.1 at 2012-03-10 14:28:14 +0100
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)
  Rendered layouts/_google_analytics.html.erb (0.4ms)
Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms)
```

We get a single line with this:

```
{"method":"GET","path":"/,"format":"html","controller":"HomeController","action":"index","status":200,"duration":79,"view":78.8,"db":0.0,"location":"http://localhost/","time":"2017-07-18 09:35:17 -0700"}
```

Part of #20060
---
 Gemfile                                         |  3 +++
 Gemfile.lock                                    |  5 +++++
 changelogs/unreleased/sh-structured-logging.yml |  4 ++++
 config/initializers/lograge.rb                  | 21 +++++++++++++++++++++
 4 files changed, 33 insertions(+)
 create mode 100644 changelogs/unreleased/sh-structured-logging.yml
 create mode 100644 config/initializers/lograge.rb

diff --git a/Gemfile b/Gemfile
index abf9f323fb4..ddda5901a08 100644
--- a/Gemfile
+++ b/Gemfile
@@ -390,3 +390,6 @@ gem 'toml-rb', '~> 0.3.15', require: false
 # Feature toggles
 gem 'flipper', '~> 0.10.2'
 gem 'flipper-active_record', '~> 0.10.2'
+
+# Structured logging
+gem 'lograge', '~> 0.5'
diff --git a/Gemfile.lock b/Gemfile.lock
index a24636ad512..f9783a3468c 100644
--- a/Gemfile.lock
+++ b/Gemfile.lock
@@ -443,6 +443,10 @@ GEM
     logging (2.2.2)
       little-plugger (~> 1.1)
       multi_json (~> 1.10)
+    lograge (0.5.1)
+      actionpack (>= 4, < 5.2)
+      activesupport (>= 4, < 5.2)
+      railties (>= 4, < 5.2)
     loofah (2.0.3)
       nokogiri (>= 1.5.9)
     mail (2.6.5)
@@ -998,6 +1002,7 @@ DEPENDENCIES
   letter_opener_web (~> 1.3.0)
   license_finder (~> 2.1.0)
   licensee (~> 8.7.0)
+  lograge (~> 0.5)
   loofah (~> 2.0.3)
   mail_room (~> 0.9.1)
   method_source (~> 0.8)
diff --git a/changelogs/unreleased/sh-structured-logging.yml b/changelogs/unreleased/sh-structured-logging.yml
new file mode 100644
index 00000000000..d89eb93f689
--- /dev/null
+++ b/changelogs/unreleased/sh-structured-logging.yml
@@ -0,0 +1,4 @@
+---
+title: Add structured logging for Rails processes
+merge_request:
+author:
diff --git a/config/initializers/lograge.rb b/config/initializers/lograge.rb
new file mode 100644
index 00000000000..14902316240
--- /dev/null
+++ b/config/initializers/lograge.rb
@@ -0,0 +1,21 @@
+# Only use Lograge for Rails
+unless Sidekiq.server?
+  filename = File.join(Rails.root, 'log', "#{Rails.env}_json.log")
+
+  Rails.application.configure do
+    config.lograge.enabled = true
+    # Store the lograge JSON files in a separate file
+    config.lograge.keep_original_rails_log = true
+    # Don't use the Logstash formatter since this requires logstash-event, an
+    # unmaintained gem that monkey patches `Time`
+    config.lograge.formatter = Lograge::Formatters::Json.new
+    config.lograge.logger = ActiveSupport::Logger.new(filename)
+    # Add request parameters to log output
+    config.lograge.custom_options = lambda do |event|
+      {
+        time: event.time,
+        params: event.payload[:params].except(%w(controller action format))
+      }
+    end
+  end
+end
-- 
cgit v1.2.1