Merge pull request #56 from epimorphics/spike/update-logging-params

Release v1.1.1

.github/workflows/unit-tests.yml

@@ -6,12 +6,26 @@ jobs:
   test:
     runs-on: ubuntu-latest
     steps:
-    - uses: actions/checkout@v3
-    - name: Set up Ruby
-      uses: ruby/setup-ruby@v1
-      with:
-        ruby-version: 2.6
-    - name: Install dependencies (bundle)
-      run: bundle install
-    - name: Run tests
-      run: rake test
+      - name: Checkout code
+        uses: actions/checkout@v4
+        with:
+          fetch-depth: 0
+
+      - name: "Record desired ruby version"
+        id: ruby
+        shell: bash
+        run: |
+          [ -f .ruby-version ] && echo version=$(cat .ruby-version) | tee -a $GITHUB_OUTPUT ||  echo "version=" >> $GITHUB_OUTPUT
+
+      - name: "Setup ruby"
+        if:  steps.ruby.outputs.version != ''
+        uses: ruby/setup-ruby@v1
+        with:
+          ruby-version: ${{ steps.ruby.outputs.version }}
+
+      - name: Install dependencies (bundle)
+        run: bundle install
+
+      - name: Run checks
+        run: |
+          PAT=${{ secrets.EPI_GPR_READ_ACCESS_TOKEN }} make lint test

CHANGELOG.md

@@ -1,8 +1,15 @@
 # Changelog for the JSON Rails Logger gem
 
+## 1.1.1 - 2024-10
+
+- (Jon) Updated the exposed keys to allow more flexibility in the logging
+- (Jon) Merged the two GitHub actions into one to reduce the number of actions
+  required to maintain the gem, while introducing dependency on successful linting
+  and tests before the gem is published
+
 ## 1.1.0 - 2024-10
 
-(Dan) Updates ruby to 2.7.8 and version cadence to 1.1.0
+- (Dan) Updates ruby to 2.7.8 and version cadence to 1.1.0
 
 ## 1.0.4-rc01 - 2023-08
 

Gemfile.lock

@@ -1,7 +1,7 @@
 PATH
   remote: .
   specs:
-    json_rails_logger (1.1.0)
+    json_rails_logger (1.1.1)
       json (~> 2.0)
       lograge (~> 0.11)
       railties (~> 6.0)
@@ -28,6 +28,7 @@ GEM
       minitest (>= 5.1)
       tzinfo (~> 2.0)
       zeitwerk (~> 2.3)
+    ast (2.4.2)
     builder (3.2.4)
     concurrent-ruby (1.2.2)
     crass (1.0.6)
@@ -51,8 +52,10 @@ GEM
       racc (~> 1.4)
     nokogiri (1.13.10-x86_64-darwin)
       racc (~> 1.4)
-    nokogiri (1.13.10-x86_64-linux)
-      racc (~> 1.4)
+    parallel (1.26.3)
+    parser (3.3.5.0)
+      ast (~> 2.4.1)
+      racc
     racc (1.6.2)
     rack (2.2.6.3)
     rack-test (2.0.2)
@@ -68,22 +71,39 @@ GEM
       method_source
       rake (>= 12.2)
       thor (~> 1.0)
+    rainbow (3.1.1)
     rake (13.0.6)
+    regexp_parser (2.9.2)
     request_store (1.5.1)
       rack (>= 1.4)
+    rexml (3.3.9)
+    rubocop (1.25.1)
+      parallel (~> 1.10)
+      parser (>= 3.1.0.0)
+      rainbow (>= 2.2.2, < 4.0)
+      regexp_parser (>= 1.8, < 3.0)
+      rexml
+      rubocop-ast (>= 1.15.1, < 2.0)
+      ruby-progressbar (~> 1.7)
+      unicode-display_width (>= 1.4.0, < 3.0)
+    rubocop-ast (1.32.3)
+      parser (>= 3.3.1.0)
+    ruby-progressbar (1.13.0)
     thor (1.2.1)
     tzinfo (2.0.6)
       concurrent-ruby (~> 1.0)
+    unicode-display_width (2.6.0)
     zeitwerk (2.6.7)
 
 PLATFORMS
   ruby
   x86_64-darwin-21
-  x86_64-linux
+  x86_64-darwin-23
 
 DEPENDENCIES
   json_rails_logger!
   rake (~> 13.0)
+  rubocop (~> 1.25.0)
 
 BUNDLED WITH
-   2.4.22
+   2.4.4

Makefile

@@ -12,10 +12,6 @@ SPEC=${NAME}.gemspec
 
 all: publish
 
-auth: ${AUTH}
-
-build: gem
-
 ${AUTH}:
 	@mkdir -p ${HOME}/.gem
 	@echo '---' > ${AUTH}
@@ -25,12 +21,21 @@ ${AUTH}:
 ${GEM}: ${SPEC} ./lib/${NAME}/version.rb
 	gem build ${SPEC}
 
+auth: ${AUTH}
+
+build: gem
+
+lint: gem
+	@bundle install
+	@echo "Running rubocop..."
+	@bundle exec rubocop
+
 gem: ${GEM}
 	@echo ${GEM}
 
 test: gem
 	@bundle install
-	@rake test
+	@bundle exec rake test
 
 publish: ${AUTH} ${GEM}
 	@echo Publishing package ${NAME}:${VERSION} to ${OWNER} ...

json_rails_logger.gemspec

@@ -32,4 +32,5 @@ Gem::Specification.new do |spec|
   spec.add_runtime_dependency 'railties', '~> 6.0'
 
   spec.add_development_dependency 'rake', '~> 13.0'
+  spec.add_development_dependency 'rubocop', '~> 1.25.0'
 end

lib/json_rails_logger/constants.rb

@@ -1,35 +1,46 @@
 # frozen_string_literal: true
 
 module JsonRailsLogger
+  BACKTRACE = :backtrace
+  DURATION = :duration
+  EXCEPTION = :exception
+  MESSAGE = :message
+  METHOD = :method
+  PATH = :request_path # Alias for REQUEST_PATH
+  QUERY_STRING = :query_string
   REQUEST_ID = :request_id
-  # * THE FOLLOWING ARE NOT CURRENTLY USED BUT AVAILABLE FOR FUTURE USE * #
-  # REQUEST_URI = :request_uri
-  # REQUEST_METHOD = :request_method
-  # REQUEST_PATH = :request_path
-  # SERVER_NAME = :server_name
-  # STATUS = :status
-  # DURATION = :duration
-  # USER_AGENT = :user_agent
+  REQUEST_PARAMS = :request_params
+  REQUEST_PATH = :request_path
+  REQUEST_STATUS = :request_status
+  REQUEST_URI = :request_uri
+  STATUS = :status
+  # * THE FOLLOWING ARE NOT CURRENTLY USED BUT AVAILABLE FOR USE * #
   # ACCEPT = :accept
-  # MESSAGE = :message
-  # EXCEPTION = :exception
-  # BACKTRACE = :backtrace
-  # CONTROLLER = :controller
   # ACTION = :action
-  # PARAMS = :params
-  # IP = :ip
   # AUTH = :auth
-  # HTTP_HOST = :http_host
-  # HTTP_VERSION = :http_version
-  # HTTP_REFERER = :http_referer
-  # HTTP_COOKIE = :http_cookie
+  # BODY = :body
+  # CONTROLLER = :controller
+  # FORWARDED_FOR = :forwarded_for
+  # GATEWAY = :gateway
+  # HTTP_ACCEPT_CHARSET = :http_accept_charset
   # HTTP_ACCEPT_ENCODING = :http_accept_encoding
   # HTTP_ACCEPT_LANGUAGE = :http_accept_language
-  # HTTP_ACCEPT_CHARSET = :http_accept_charset
   # HTTP_CACHE_CONTROL = :http_cache_control
+  # HTTP_COOKIE = :http_cookie
   # HTTP_CONNECTION = :http_connection
-  # HTTP_UPGRADE_INSECURE_REQUESTS = :http_upgrade_insecure_requests
-  # HTTP_ORIGIN = :http_origin
   # HTTP_DNT = :http_dnt
+  # HTTP_HOST = :http_host
+  # HTTP_ORIGIN = :http_origin
+  # HTTP_REFERER = :http_referer
+  # HTTP_UPGRADE_INSECURE_REQUESTS = :http_upgrade_insecure_requests
+  # HTTP_VERSION = :http_version
   # HTTP_X_REQUEST_ID = :http_x_request_id
+  # IP = :ip
+  # REMOTE_ADDR = :remote_addr
+  # REQUEST_METHOD = :request_method
+  # SERVER_NAME = :server_name
+  # SERVER_PORT = :server_port
+  # SERVER_PROTOCOL = :server_protocol
+  # SERVER_SOFTWARE = :server_software
+  # USER_AGENT = :user_agent
 end

lib/json_rails_logger/json_formatter.rb

@@ -2,20 +2,56 @@
 
 module JsonRailsLogger
   # This class is the json formatter for our logger
-  class JsonFormatter < ::Logger::Formatter
+  class JsonFormatter < ::Logger::Formatter # rubocop:disable Metrics/ClassLength
     ## Required keys to be logged to the output
     REQUIRED_KEYS = %w[
-      method path status duration user_agent accept request_id request_url message query_string
+      accept
+      action
+      backtrace
+      body
+      controller
+      duration
+      encoding
+      forwarded_for
+      gateway
+      http_accept_charset
+      http_accept_encoding
+      http_accept_language
+      http_cache_control
+      http_charset
+      http_cookie
+      http_connection
+      http_host
+      http_origin
+      http_referer
+      keep_alive
+      message
+      method
+      path
+      query_string
+      remote_addr
+      request_id
+      request_params
+      request_path
+      request_status
+      request_uri
+      request_url
+      server_name
+      server_port
+      server_protocol
+      server_software
+      status
+      user_agent
     ].freeze
 
     ## Optional keys to be ignored from the output for the time being
-    OPTIONAL_KEYS = %w[format controller action view exception exception_object].freeze
+    OPTIONAL_KEYS = %w[format exception exception_object view].freeze
 
     ## Request methods to check for in the message
     REQUEST_METHODS = %w[GET POST PUT DELETE PATCH].freeze
 
     # rubocop:disable Metrics/MethodLength
-    def call(severity, timestamp, _progname, raw_msg)
+    def call(severity, timestamp, _progname, raw_msg) # rubocop:disable Metrics/AbcSize
       sev = process_severity(severity)
       timestp = process_timestamp(timestamp)
       msg = process_message(raw_msg)
@@ -26,6 +62,7 @@ def call(severity, timestamp, _progname, raw_msg)
         level: sev
       }
 
+      payload.merge!(query_string.to_h)
       payload.merge!(request_id.to_h)
       payload.merge!(new_msg.to_h.except!(:optional).compact)
 
@@ -50,6 +87,11 @@ def request_id
       { request_id: request_id } if request_id
     end
 
+    def query_string
+      query_string = Thread.current[JsonRailsLogger::QUERY_STRING]
+      { query_string: query_string } if query_string
+    end
+
     def process_message(raw_msg)
       msg = normalize_message(raw_msg)
 
@@ -69,13 +111,15 @@ def format_message(msg)
 
       return new_msg.merge(msg) unless msg.is_a?(Enumerable)
 
+      # If the message is a hash, check if it contains the required keys
       split_msg = msg.partition { |k, _v| REQUIRED_KEYS.include?(k.to_s) }.map(&:to_h)
+      # If the returned hash is empty, check if the message is a hash with optional keys
       if split_msg[0].empty?
         split_msg = msg.partition do |k, _v|
           OPTIONAL_KEYS.exclude?(k.to_s)
         end.map(&:to_h)
       end
-
+      # Check if the message contains a duration key and normalise it
       split_msg[0] = normalise_duration(split_msg[0]) if includes_duration?(split_msg[0])
 
       new_msg.merge!(split_msg[0])
@@ -139,9 +183,9 @@ def includes_duration?(msg)
       msg.key?('duration')
     end
 
-    # If duration is a float, convert it to an integer as microseconds
+    # If duration is a float, convert it to an integer as milliseconds µs -> ms
     def normalise_duration(msg)
-      msg.to_h { |k, v| k.to_s == 'duration' && v.is_a?(Float) ? [k, (v * 1000).round(0)] : [k, v] }
+      msg.to_h { |k, v| k.to_s == 'duration' && v.is_a?(Float) ? [k, v.round(0)] : [k, v] }
     end
   end
 end

lib/json_rails_logger/version.rb

@@ -3,7 +3,7 @@
 module JsonRailsLogger
   MAJOR = 1
   MINOR = 1
-  PATCH = 0
+  PATCH = 1
   SUFFIX = nil
   VERSION = "#{MAJOR}.#{MINOR}.#{PATCH}#{SUFFIX && "-#{SUFFIX}"}"
 end

test/formatter_test.rb

@@ -92,13 +92,13 @@
     end
   end
 
-  it 'should correctly format a millisecond duration into microseconds' do
+  it 'should correctly format a microsecond duration into milliseconds' do
     message = '{"duration": 1234567.89}'
 
     log_output = fixture.call('INFO', timestamp, progname, message)
     _(log_output).must_be_kind_of(String)
 
     json_output = JSON.parse(log_output)
-    _(json_output['duration']).must_equal(1_234_567_890)
+    _(json_output['duration']).must_equal(1_234_568)
   end
 end