Reducing log noise and other current issues

CHANGELOG.md

@@ -4,6 +4,22 @@ This app allows the user to explore HMLR price-paid open linked data.
 
 ## Changelog
 
+## 2.0.1 - 2024-12
+
+- (Jon) Updated the error template path to use `Rails.public_path` as well as
+  contain the `html` extension to ensure the correct template is rendered
+- (Jon) Improves error metrics reporting to ensure that logging always happens
+  with the appropriate severity depending on the exception status while reducing
+  the types of errors that can trigger a an error metric and therefore a
+  notification in slack
+  [GH-149](https://github.com/epimorphics/hmlr-linked-data/issues/149)
+- (Jon) Added catch for missing `SENTRY_API_KEY` env var to `entrypoint.sh` for
+  docker build
+- (Jon) Updated target status level to trigger internal error metrics to 500
+  status codes only in the `search_controller`
+- (Jon) Added `message`, `status`, and `type` arguments to be logged by the
+  `json_rails_logger` gem for respective error responses in the `search_controller`
+
 ## 2.0.0 - 2024-11
 
 - (Bogdan) Updated all gems by regenerating `Gemfile.lock`
@@ -13,7 +29,8 @@ This app allows the user to explore HMLR price-paid open linked data.
 
 ## 1.8.0 - 2024-10
 
-- (Dan) Updates ruby version to 2.7.8 and alpine version to 3.16 [GH-253](https://github.com/epimorphics/ppd-explorer/issues/253)
+- (Dan) Updates ruby version to 2.7.8 and alpine version to 3.16
+  [GH-253](https://github.com/epimorphics/ppd-explorer/issues/253)
 
 ## 1.7.11 - 2024-10
 

Gemfile.lock

@@ -428,10 +428,10 @@ GEM
       faraday_middleware (~> 1.2.0)
       json (~> 2.6.1)
       yajl-ruby (~> 1.4.1)
-    json_rails_logger (1.0.3)
+    json_rails_logger (2.0.1)
       json
       lograge
-      railties
+      railties (~> 7.0)
     lr_common_styles (2.1.3)
       bootstrap-sass
       font-awesome-rails

app/controllers/application_controller.rb

@@ -1,7 +1,7 @@
 # frozen_string_literal: true
 
 # :nodoc:
-class ApplicationController < ActionController::Base
+class ApplicationController < ActionController::Base # rubocop:disable Metrics/ClassLength
   # Prevent CSRF attacks by raising an exception.
   # For APIs, you may want to use :null_session instead.
 
@@ -36,11 +36,6 @@ def log_request_result
   # or attempt to render a generic error page if no specific error page exists
   unless Rails.application.config.consider_all_requests_local
     rescue_from StandardError do |e|
-      # Instrument ActiveSupport::Notifications for internal errors but only for non-404 errors:
-      unless e.is_a?(ActionController::RoutingError) || e.is_a?(ActionView::MissingTemplate)
-        ActiveSupport::Notifications.instrument('internal_error.application', exception: e)
-      end
-
       # Trigger the appropriate error handling method based on the exception
       case e.class
       when ActionController::RoutingError, ActionView::MissingTemplate
@@ -61,6 +56,8 @@ def handle_internal_error(exception)
       render_error(400)
     else
       Rails.logger.warn "No explicit error page for exception #{exception} - #{exception.class}"
+      # Instrument ActiveSupport::Notifications for internal server errors only:
+      instrument_internal_error(exception)
       render_error(500)
     end
   end
@@ -93,7 +90,7 @@ def render_error(status)
 
   def render_html_error_page(status)
     render(layout: true,
-           file: Rails.root.join('public', 'landing', status.to_s),
+           file: Rails.public_path + "landing/#{status}.html",
            status: status)
   end
 
@@ -129,4 +126,26 @@ def detailed_request_log(duration)
     end
   end
   # rubocop:enable Metrics/AbcSize, Metrics/MethodLength
+
+  # Notify subscriber(s) of an internal error event with the payload of the
+  # exception once done
+  # @param [exc] exp the exception that caused the error
+  # @return [ActiveSupport::Notifications::Event] provides an object-oriented
+  # interface to the event
+  def instrument_internal_error(exc) # rubocop:disable Metrics/AbcSize, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity
+    err = {
+      message: exc&.message || exc,
+      status: exc&.status || Rack::Utils::SYMBOL_TO_STATUS_CODE[exc]
+    }
+    err[:type] = exc.class&.name if exc&.class
+    err[:cause] = exc&.cause if exc&.cause
+    err[:backtrace] = exc&.backtrace if exc&.backtrace && Rails.env.development?
+    # Log the exception to the Rails logger with the appropriate severity
+    Rails.logger.send(err[:status] < 500 ? :warn : :error, JSON.generate(err))
+    # Return unless the status code is 500 or greater to ensure subscribers are NOT notified
+    return unless err[:status] >= 500
+
+    # Instrument the internal error event to notify subscribers of the error
+    ActiveSupport::Notifications.instrument('internal_error.application', exception: err)
+  end
 end

app/controllers/search_controller.rb

@@ -56,13 +56,24 @@ def render_error_page(err, message, status, template = 'ppd/error')
     # link the error to the actual request id otherwise generate one for this error
     uuid = Thread.current[:request_id] || SecureRandom.uuid
 
+    status_code = Rack::Utils::SYMBOL_TO_STATUS_CODE[status]
+
     @message = message
 
     # log the error with as much detail as possible in development to aid in resolving the issue
-    @message = "#{Rack::Utils::SYMBOL_TO_STATUS_CODE[status]} ~ #{err.class.name} error: #{message}" if Rails.env.development?
+    @message = "#{status_code} ~ #{err.class.name} error: #{message}" if Rails.env.development?
 
     # Keep it simple silly in production!
-    log_error(Rack::Utils::SYMBOL_TO_STATUS_CODE[status], message)
+    log_error(status_code, message)
+
+    # Trigger metric on internal errors
+    if status_code >= 500
+      instrument_internal_error({
+                                  message: message,
+                                  status: status_code,
+                                  type: err.class.name
+                                })
+    end
 
     @error_message =
       [
@@ -85,5 +96,4 @@ def log_error(status, message)
       Rails.logger.info(message)
     end
   end
-
 end

app/lib/version.rb

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

app/subscribers/application_prometheus_subscriber.rb

@@ -5,9 +5,9 @@ class ApplicationPrometheusSubscriber < ActiveSupport::Subscriber
   attach_to :application
 
   def internal_error(event)
-    message = event.payload[:exception]
+    error = event.payload[:exception]
     Prometheus::Client.registry
                       .get(:internal_application_error)
-                      .increment(labels: { message: message.to_s })
+                      .increment(labels: { result: 'failure', message: "#{error[:type]}: #{error[:message]}", status: error[:status].to_i }) # rubocop:disable Layout/LineLength
   end
 end

config/initializers/prometheus.rb

@@ -26,7 +26,7 @@
 prometheus.counter(
   :internal_application_error,
   docstring: 'Unexpected events and internal error count, labelled by message',
-  labels: [:message]
+  labels: %i[message result status]
 )
 
 # Prometheus gauges
@@ -50,5 +50,5 @@
 )
 
 # Middleware instrumentation
-  # This fixes the 0 memory bug by notifying Action Dispatch subscribers on Prometheus initialise
-  ActiveSupport::Notifications.instrument('process_middleware.action_dispatch')
+# This fixes the 0 memory bug by notifying Action Dispatch subscribers on Prometheus initialise
+ActiveSupport::Notifications.instrument('process_middleware.action_dispatch')

config/routes.rb

@@ -8,59 +8,4 @@
   resource :ppd_data
 
   get '*unmatched_route', to: 'application#render_404'
-
-  # The priority is based upon order of creation: first created -> highest priority.
-  # See how all your routes lay out with "rake routes".
-
-  # You can have the root of your site routed with "root"
-  # root 'welcome#index'
-
-  # Example of regular route:
-  #   get 'products/:id' => 'catalog#view'
-
-  # Example of named route that can be invoked with purchase_url(id: product.id)
-  #   get 'products/:id/purchase' => 'catalog#purchase', as: :purchase
-
-  # Example resource route (maps HTTP verbs to controller actions automatically):
-  #   resources :products
-
-  # Example resource route with options:
-  #   resources :products do
-  #     member do
-  #       get 'short'
-  #       post 'toggle'
-  #     end
-  #
-  #     collection do
-  #       get 'sold'
-  #     end
-  #   end
-
-  # Example resource route with sub-resources:
-  #   resources :products do
-  #     resources :comments, :sales
-  #     resource :seller
-  #   end
-
-  # Example resource route with more complex sub-resources:
-  #   resources :products do
-  #     resources :comments
-  #     resources :sales do
-  #       get 'recent', on: :collection
-  #     end
-  #   end
-
-  # Example resource route with concerns:
-  #   concern :toggleable do
-  #     post 'toggle'
-  #   end
-  #   resources :posts, concerns: :toggleable
-  #   resources :photos, concerns: :toggleable
-
-  # Example resource route within a namespace:
-  #   namespace :admin do
-  #     # Directs /admin/products/* to Admin::ProductsController
-  #     # (app/controllers/admin/products_controller.rb)
-  #     resources :products
-  #   end
 end

entrypoint.sh

@@ -8,6 +8,9 @@ mkdir -pm 1777 ./tmp
 # Set the environment
 [ -z "$RAILS_ENV" ] && RAILS_ENV=production
 
+# Check for SENTRY_API_KEY variable and report if missing
+[ -z "$SENTRY_API_KEY" ] && echo "{\"ts\":\"$(date -u +%FT%T.%3NZ)\",\"level\":\"ERROR\",\"message\":\"SENTRY_API_KEY is required\"}"
+
 # Check for API Service URL variable and log it
 [ -n "$API_SERVICE_URL" ] && echo "{\"ts\":\"$(date -u +%FT%T.%3NZ)\",\"level\":\"INFO\",\"message\":\"API_SERVICE_URL=${API_SERVICE_URL}\"}"