diff --git a/lib/sapience/configuration/grape.rb b/lib/sapience/configuration/grape.rb new file mode 100644 index 0000000..03a4d88 --- /dev/null +++ b/lib/sapience/configuration/grape.rb @@ -0,0 +1,9 @@ +module Sapience + class Configuration + class Grape + def self.configure + Grape::API.send(:include, Sapience::Loggable) + end + end + end +end diff --git a/lib/sapience/configuration/rails.rb b/lib/sapience/configuration/rails.rb new file mode 100644 index 0000000..b92863b --- /dev/null +++ b/lib/sapience/configuration/rails.rb @@ -0,0 +1,29 @@ +module Sapience + class Configuration + class Rails + # rubocop:disable LineLength, AbcSize, CyclomaticComplexity, PerceivedComplexity + def self.configure + ::Rails.logger = Sapience[::Rails] + [:active_record, :action_controller, :action_mailer, :action_view].each do |name| + ActiveSupport.on_load(name) { include Sapience::Loggable } + end + ActiveSupport.on_load(:action_cable) { self.logger = Sapience["ActionCable"] } + require("sapience/extensions/action_cable/tagged_logger_proxy") if defined?(ActionCable) + require("sapience/extensions/action_controller/live") if defined?(ActionController::Live) + require("sapience/extensions/action_dispatch/debug_exceptions") if defined?(ActionDispatch::DebugExceptions) + require("sapience/extensions/action_view/streaming_template_renderer") if defined?(ActionView::StreamingTemplateRenderer::Body) + require("sapience/extensions/active_job/logging") if defined?(ActiveJob) + require("sapience/extensions/active_model_serializers/logging") if defined?(ActiveModelSerializers) + + require("sapience/extensions/rack/logger") if defined?(Rails::Rack::Logger) + require("sapience/extensions/action_controller/log_subscriber") if defined?(ActionController) + require("sapience/extensions/active_record/log_subscriber") if defined?(ActiveRecord::LogSubscriber) + + require("sapience/extensions/rack/logger_info_as_debug") if defined?(Rails::Rack::Logger) + require("sapience/extensions/action_view/log_subscriber") if defined?(ActionView::LogSubscriber) + require("sapience/extensions/action_controller/log_subscriber_processing") if defined?(ActionView::LogSubscriber) + end + # rubocop:enable LineLength, AbcSize, CyclomaticComplexity, PerceivedComplexity + end + end +end diff --git a/lib/sapience/extensions/action_controller/live.rb b/lib/sapience/extensions/action_controller/live.rb new file mode 100644 index 0000000..a60fe18 --- /dev/null +++ b/lib/sapience/extensions/action_controller/live.rb @@ -0,0 +1,6 @@ +# Log actual exceptions, not a string representation +module ActionController::Live # rubocop:disable ClassAndModuleChildren + def log_error(exception) + logger.fatal(exception) + end +end diff --git a/lib/sapience/extensions/action_controller/log_subscriber.rb b/lib/sapience/extensions/action_controller/log_subscriber.rb new file mode 100644 index 0000000..0eab18a --- /dev/null +++ b/lib/sapience/extensions/action_controller/log_subscriber.rb @@ -0,0 +1,95 @@ +require "action_controller/log_subscriber" + +class ActionController::LogSubscriber # rubocop:disable ClassAndModuleChildren + # Log as debug to hide Processing messages in production + def start_processing(event) + controller_logger(event).debug { "Processing ##{event.payload[:action]}" } + end + + def process_action(event) # rubocop:disable AbcSize, CyclomaticComplexity, PerceivedComplexity + controller_logger(event).info do + payload = event.payload.dup + payload[:params].except!(*INTERNAL_PARAMS) + payload.delete(:params) if payload[:params].empty? + + format = payload[:format] + payload[:format] = format.to_s.upcase if format.is_a?(Symbol) + + payload[:path] = extract_path(payload[:path]) if payload.key?(:path) + + exception = payload.delete(:exception) + if payload[:status].nil? && exception.present? + exception_class_name = exception.first + payload[:status] = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name) + end + + # Rounds off the runtimes. For example, :view_runtime, :mongo_runtime, etc. + payload.keys.each do |key| + payload[key] = payload[key].to_f.round(2) if key.to_s.match(/(.*)_runtime/) + end + + payload[:message] = "Completed ##{payload[:action]}" + payload[:status_message] = Rack::Utils::HTTP_STATUS_CODES[payload[:status]] if payload[:status].present? + payload[:duration] = event.duration + # Causes excessive log output with Rails 5 RC1 + payload.delete(:headers) + payload + end + end + + def halted_callback(event) + controller_logger(event).info { "Filter chain halted as #{event.payload[:filter].inspect} rendered or redirected" } + end + + def send_file(event) + controller_logger(event).info("Sent file") { { path: event.payload[:path], duration: event.duration } } + end + + def redirect_to(event) + controller_logger(event).info("Redirected to") { { location: event.payload[:location] } } + end + + def send_data(event) + controller_logger(event).info("Sent data") { { file_name: event.payload[:filename], duration: event.duration } } + end + + def unpermitted_parameters(event) + controller_logger(event).debug do + unpermitted_keys = event.payload[:keys] + "Unpermitted parameter#{"s" if unpermitted_keys.size > 1}: #{unpermitted_keys.join(", ")}" + end + end + + %w(write_fragment read_fragment exist_fragment? + expire_fragment expire_page write_page).each do |method| + class_eval <<-METHOD, __FILE__, __LINE__ + 1 + def #{method}(event) + controller_logger(event).info do + key_or_path = event.payload[:key] || event.payload[:path] + {message: "#{method.to_s.humanize} \#{key_or_path}", duration: event.duration} + end + end + METHOD + end + + private + + # Returns the logger for the supplied event. + # Returns ActionController::Base.logger if no controller is present + def controller_logger(event) + if (controller = event.payload[:controller]) + begin + controller.constantize.logger + rescue NameError + ActionController::Base.logger + end + else + ActionController::Base.logger + end + end + + def extract_path(path) + index = path.index("?") + index ? path[0, index] : path + end +end diff --git a/lib/sapience/extensions/action_controller/log_subscriber_processing.rb b/lib/sapience/extensions/action_controller/log_subscriber_processing.rb new file mode 100644 index 0000000..889e868 --- /dev/null +++ b/lib/sapience/extensions/action_controller/log_subscriber_processing.rb @@ -0,0 +1,24 @@ +require "action_controller/log_subscriber" + +class ActionController::LogSubscriber # rubocop:disable ClassAndModuleChildren + # Log as info to show Processing messages in production + def start_processing(event) + controller_logger(event).info { "Processing ##{event.payload[:action]}" } + end + + private + + # Returns the logger for the supplied event. + # Returns ActionController::Base.logger if no controller is present + def controller_logger(event) + if (controller = event.payload[:controller]) + begin + controller.constantize.logger + rescue NameError + ActionController::Base.logger + end + else + ActionController::Base.logger + end + end +end diff --git a/lib/sapience/extensions/action_dispatch/debug_exceptions.rb b/lib/sapience/extensions/action_dispatch/debug_exceptions.rb new file mode 100644 index 0000000..d52446e --- /dev/null +++ b/lib/sapience/extensions/action_dispatch/debug_exceptions.rb @@ -0,0 +1,11 @@ +# Log actual exceptions, not a string representation + +class ActionDispatch::DebugExceptions # rubocop:disable ClassAndModuleChildren + private + + def log_error(_request, wrapper) + ActiveSupport::Deprecation.silence do + ActionController::Base.logger.fatal(wrapper.exception) + end + end +end diff --git a/lib/sapience/extensions/action_view/log_subscriber.rb b/lib/sapience/extensions/action_view/log_subscriber.rb new file mode 100644 index 0000000..8381eb6 --- /dev/null +++ b/lib/sapience/extensions/action_view/log_subscriber.rb @@ -0,0 +1,9 @@ +class ActionView::LogSubscriber # rubocop:disable ClassAndModuleChildren + def info(message = nil, &block) + debug(message, &block) + end + + def info? + debug? + end +end diff --git a/lib/sapience/extensions/action_view/streaming_template_renderer.rb b/lib/sapience/extensions/action_view/streaming_template_renderer.rb new file mode 100644 index 0000000..160f3a3 --- /dev/null +++ b/lib/sapience/extensions/action_view/streaming_template_renderer.rb @@ -0,0 +1,11 @@ +# Log actual exceptions, not a string representation + +class ActionView::StreamingTemplateRenderer # rubocop:disable ClassAndModuleChildren + class Body + private + + def log_error(exception) #:nodoc: + ActionView::Base.logger.fatal(exception) + end + end +end diff --git a/lib/sapience/extensions/active_job/logging.rb b/lib/sapience/extensions/active_job/logging.rb new file mode 100644 index 0000000..d448a60 --- /dev/null +++ b/lib/sapience/extensions/active_job/logging.rb @@ -0,0 +1,12 @@ +# Patch ActiveJob logger +require "active_job/logging" + +module ActiveJob::Logging # rubocop:disable ClassAndModuleChildren + include Sapience::Loggable + + private + + def tag_logger(*tags, &block) + logger.tagged(*tags, &block) + end +end diff --git a/lib/sapience/extensions/active_model_serializers/logging.rb b/lib/sapience/extensions/active_model_serializers/logging.rb new file mode 100644 index 0000000..89a26e6 --- /dev/null +++ b/lib/sapience/extensions/active_model_serializers/logging.rb @@ -0,0 +1,12 @@ +# Patch ActiveModelSerializers logger +require "active_model_serializers/logging" + +module ActiveModelSerializers::Logging # rubocop:disable ClassAndModuleChildren + include Sapience::Loggable + + private + + def tag_logger(*tags, &block) + logger.tagged(*tags, &block) + end +end diff --git a/lib/sapience/extensions/active_record/log_subscriber.rb b/lib/sapience/extensions/active_record/log_subscriber.rb new file mode 100644 index 0000000..45e8fc3 --- /dev/null +++ b/lib/sapience/extensions/active_record/log_subscriber.rb @@ -0,0 +1,33 @@ +class ActiveRecord::LogSubscriber # rubocop:disable ClassAndModuleChildren + def sql(event) # rubocop:disable AbcSize + self.class.runtime += event.duration + + return unless logger.debug? + + payload = event.payload + name = payload[:name] + return if IGNORE_PAYLOAD_NAMES.include?(name) + + log = { + message: name, + sql: payload[:sql], + duration: event.duration, + } + unless (payload[:binds] || []).empty? + log[:binds] = binds = {} + # Changed with Rails 5 + if Rails.version.to_i >= 5 + payload[:binds].each do |attr| + attr_name, value = render_bind(attr) + binds[attr_name] = value + end + else + payload[:binds].each do |col, v| + attr_name, value = render_bind(col, v) + binds[attr_name] = value + end + end + end + debug(log) + end +end diff --git a/lib/sapience/extensions/rack/logger.rb b/lib/sapience/extensions/rack/logger.rb new file mode 100644 index 0000000..9536901 --- /dev/null +++ b/lib/sapience/extensions/rack/logger.rb @@ -0,0 +1,11 @@ +# Replace rack started message with a semantic equivalent +class Rails::Rack::Logger # rubocop:disable ClassAndModuleChildren + def started_request_message(request) + { + message: "Started", + method: request.request_method, + path: request.filtered_path, + ip: request.ip, + } + end +end diff --git a/lib/sapience/extensions/rack/logger_info_as_debug.rb b/lib/sapience/extensions/rack/logger_info_as_debug.rb new file mode 100644 index 0000000..029d4c9 --- /dev/null +++ b/lib/sapience/extensions/rack/logger_info_as_debug.rb @@ -0,0 +1,22 @@ +# Drop rack Started message to debug level message +class Rails::Rack::Logger # rubocop:disable ClassAndModuleChildren + private + + module LogInfoAsDebug + def info(*args, &block) + debug(*args, &block) + end + + def info? + debug? + end + end + + def logger + @logger ||= begin + logger = Sapience["Rails"] + logger.extend(LogInfoAsDebug) + logger + end + end +end diff --git a/lib/sapience/rails.rb b/lib/sapience/rails.rb deleted file mode 100644 index 9508868..0000000 --- a/lib/sapience/rails.rb +++ /dev/null @@ -1,15 +0,0 @@ -module Sapience - class Rails < ::Rails::Engine - ::Rails::Application::Bootstrap.initializers.delete_if { |i| i.name == :initialize_logger } - initializer :initialize_logger, group: :all do - # TODO: Is this really needed? - # Existing loggers are ignored because servers like trinidad supply their - # own file loggers which would result in duplicate logging to the same log file - # ::Rails.logger = config.logger = begin - # Sapience[::Rails] - # end - - # Replace Rails loggers - end - end -end diff --git a/spec/lib/sapience/configuration/grape_spec.rb b/spec/lib/sapience/configuration/grape_spec.rb new file mode 100644 index 0000000..3df3093 --- /dev/null +++ b/spec/lib/sapience/configuration/grape_spec.rb @@ -0,0 +1,6 @@ +require "spec_helper" + +describe Sapience::Configuration::Grape do + describe ".configure" do + end +end diff --git a/spec/lib/sapience/configuration/rails_spec.rb b/spec/lib/sapience/configuration/rails_spec.rb new file mode 100644 index 0000000..6d95668 --- /dev/null +++ b/spec/lib/sapience/configuration/rails_spec.rb @@ -0,0 +1,6 @@ +require "spec_helper" + +describe Sapience::Configuration::Rails do + describe ".configure" do + end +end