From 656d4526c336311123866e41d97a7536d01fe9ab Mon Sep 17 00:00:00 2001 From: pvincent Date: Thu, 12 Sep 2024 16:36:57 +0400 Subject: [PATCH] semantic subscribers --- lib/semantic/dev_loader.rb | 27 ++-- lib/semantic/log_subscriber.rb | 124 ----------------- lib/semantic/subscribers/action_controller.rb | 130 ++++++++++++++++++ lib/semantic/subscribers/action_view.rb | 19 +++ 4 files changed, 159 insertions(+), 141 deletions(-) delete mode 100644 lib/semantic/log_subscriber.rb create mode 100644 lib/semantic/subscribers/action_controller.rb create mode 100644 lib/semantic/subscribers/action_view.rb diff --git a/lib/semantic/dev_loader.rb b/lib/semantic/dev_loader.rb index f9ed82b..5921147 100644 --- a/lib/semantic/dev_loader.rb +++ b/lib/semantic/dev_loader.rb @@ -4,16 +4,14 @@ module Semantic def initialize(session_key) @session_key = session_key - force_preload_module RailsSemanticLogger::ActionController::LogSubscriber.logger.level = :fatal # useful for remanent Rack::Log started - once_and_reload do - NotificationUtil.clear_subscribers(/\.action_controller$/) - NotificationUtil.clear_subscribers(/\.action_view$/) + Semantic::NotificationUtil.clear_subscribers(/\.action_controller$/) + Semantic::NotificationUtil.clear_subscribers(/\.action_view$/) append_ansi_formatter reset_subscribers - register_log_subscriber + register_action_controller end end @@ -24,10 +22,6 @@ module Semantic Rails.autoloaders.main.on_load('ApplicationController', &) end - def force_preload_module - self.class.module_parent.constants.each { |const| self.class.module_parent.const_get(const) } - end - def append_ansi_formatter SemanticLogger.clear_appenders! formatter = Semantic::AnsiFormatter.new @@ -36,17 +30,18 @@ module Semantic filter: ->(log) { !formatter.reject(log) }) end - def register_log_subscriber - register_to_action_controller(:start_processing) - register_to_action_controller(:process_action, :finish_processing) - register_to_action_controller(:redirect_to) + def register_action_controller + @log_subscriber = Semantic::Subscribers::ActionController.new(@session_key) + register_action_controller_hook(:start_processing) + register_action_controller_hook(:process_action, :finish_processing) + register_action_controller_hook(:redirect_to) %i[send_file send_data halted_callback unpermitted_parameters send_stream write_fragment read_fragment expire_fragment exist_fragment?].each do |hook| - register_to_action_controller(hook, :any_hook) + register_action_controller_hook(hook, :any_hook) end end - def register_to_action_controller(hook, method = hook) + def register_action_controller_hook(hook, method = hook) @subscribers << ActiveSupport::Notifications.subscribe("#{hook}.action_controller") do |event| @log_subscriber.send(method, event) end @@ -59,8 +54,6 @@ module Semantic else @subscribers = [] end - - @log_subscriber = Semantic::LogSubscriber.new(@session_key) end end end diff --git a/lib/semantic/log_subscriber.rb b/lib/semantic/log_subscriber.rb deleted file mode 100644 index cfff593..0000000 --- a/lib/semantic/log_subscriber.rb +++ /dev/null @@ -1,124 +0,0 @@ -module Semantic - class LogSubscriber < ActiveSupport::LogSubscriber - include SemanticLogger::Loggable - include AnsiColors - def logger = SemanticLogger['Rails'] - - INTERNAL_PARAMS = %i[controller action format _method only_path].freeze - DEFAULT_DEV_HOSTS = ['127.0.0.1', 'localhost'].freeze - TERMINUS_STRING = '╙─╜'.freeze - - def initialize(session_key) - @session_key = session_key - @transactions = {} - super() - end - - def start_processing(event) - session_value = session_value(event) - @transactions[event.transaction_id] = session_value # preserve session_value to help finish_processing - - SemanticLogger.tagged(session_value) do - request = event.payload[:request] - path = colorize(request.filtered_path, BOLD) - - dimensions = Semantic::AnsiDimensions.new(rails: '╓─╖', before: 1) - if defined?(@previously_redirect) && @previously_redirect - dimensions = Semantic::AnsiDimensions.new(rails: '╓║╖', before: 0) - @previously_redirect = false - end - logger.info("Started #{request.raw_request_method} #{path}", dimensions:) - - format = event.payload[:format] - format = format.to_s.upcase if format.is_a?(Symbol) - format = '*/*' if format.nil? - format = colorize(format, BOLD) - logger.debug("Processing by #{event.payload[:controller]}##{event.payload[:action]} as #{format}") - - params = event.payload[:params].deep_symbolize_keys.except(*INTERNAL_PARAMS) - unless params.empty? - params = params.ai(ruby19_syntax: true, plain: true, multiline: false) - params.gsub!(/(\w+):/, "#{TEXT_CYAN}\\1#{CLEAR}:") - params.gsub!(/"(.*?)"/, "\"#{TEXT_YELLOW}\\1#{CLEAR}\"") - end - logger.debug("Parameters: #{params}") unless params.empty? - end - end - - def finish_processing(event) - session_value = @transactions.delete(event.transaction_id) # delete previous session_value from start_processing - SemanticLogger.tagged(session_value) do - payload = event.payload - additions = ActionController::Base.log_process_action(payload) - status = payload[:status] - - if status.nil? && (exception_class_name = payload[:exception]&.first) - status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name) - end - - additions << "GC: #{event.gc_time.round(1)}ms" - if event.duration >= 1200 - logger.error process_duration(event, additions) - elsif event.duration >= 600 - logger.warn process_duration(event, additions) - elsif event.duration >= 300 - logger.info process_duration(event, additions) - elsif event.duration >= 100 - logger.debug process_duration(event, additions) - end - - status_family = status / 100 - - dimensions = case status_family - when 2 - Semantic::AnsiDimensions.new(rails: TERMINUS_STRING) - when 3 - Semantic::AnsiDimensions.new(rails: '╙║╜') - when 4 - Semantic::AnsiDimensions.new(rails: '╙╨╜') - when 5 - Semantic::AnsiDimensions.new(rails: '╙║╜') - end - logger.info("Completed #{colorize(status, BOLD)} #{Rack::Utils::HTTP_STATUS_CODES[status]}", dimensions:) - logger.info(' ', dimensions: Semantic::AnsiDimensions.new(rails: ' ║ ')) if status_family == 3 - logger.info(' ', dimensions: Semantic::AnsiDimensions.new(rails: '╓║╖')) if status_family == 5 - end - end - - def redirect_to(event) - SemanticLogger.tagged(@transactions[event.transaction_id]) do - location = capture_path(event.payload[:location]) - logger.debug("Redirected to #{colorize(location, BOLD)}") - end - @previously_redirect = true - end - - def any_hook(event) - SemanticLogger.tagged(@transactions[event.transaction_id]) do - logger.warn("action_controller hook=<#{event.name.split('.')[0]}> needs a proper message handling!", - event.payload.keys) - end - end - - private - - def redirect_regex - return @redirect_regex if defined?(@redirect_regex) - - options = Rails.application.routes.default_url_options - dev_hosts = DEFAULT_DEV_HOSTS + Array.wrap(options[:host]) - dev_hosts_or = dev_hosts.uniq.join('|') - dev_from = "http://(?:#{dev_hosts_or}):#{options[:port]}(.*)" - - @redirect_regex = /^#{dev_from}/ - end - - def capture_path(url) - m = redirect_regex.match(url) - m.nil? ? url : m[1] - end - - def session_value(event) = event.payload[:headers]['rack.session'].fetch(@session_key, nil) - def process_duration(event, additions) = "Processed in #{event.duration.round}ms (#{additions.join(' | ')})" - end -end diff --git a/lib/semantic/subscribers/action_controller.rb b/lib/semantic/subscribers/action_controller.rb new file mode 100644 index 0000000..3f0a5ae --- /dev/null +++ b/lib/semantic/subscribers/action_controller.rb @@ -0,0 +1,130 @@ +module Semantic + module Subscribers + class ActionController < ActiveSupport::LogSubscriber + include AnsiColors + + INTERNAL_PARAMS = %i[controller action format _method only_path].freeze + DEFAULT_DEV_HOSTS = ['127.0.0.1', 'localhost'].freeze + TERMINUS_STRING = '╙─╜'.freeze + + attr_reader :logger + + def initialize(session_key) + @session_key = session_key + @transactions = {} + + short_name = self.class.to_s.split('::').last + @logger = SemanticLogger[short_name] + + super() + end + + def start_processing(event) + session_value = session_value(event) + @transactions[event.transaction_id] = session_value # preserve session_value to help finish_processing + + SemanticLogger.tagged(session_value) do + request = event.payload[:request] + path = colorize(request.filtered_path, BOLD) + + dimensions = Semantic::AnsiDimensions.new(rails: '╓─╖', before: 1) + if defined?(@previously_redirect) && @previously_redirect + dimensions = Semantic::AnsiDimensions.new(rails: '╓║╖', before: 0) + @previously_redirect = false + end + logger.info("Started #{request.raw_request_method} #{path}", dimensions:) + + format = event.payload[:format] + format = format.to_s.upcase if format.is_a?(Symbol) + format = '*/*' if format.nil? + format = colorize(format, BOLD) + logger.debug("Processing by #{event.payload[:controller]}##{event.payload[:action]} as #{format}") + + params = event.payload[:params].deep_symbolize_keys.except(*INTERNAL_PARAMS) + unless params.empty? + params = params.ai(ruby19_syntax: true, plain: true, multiline: false) + params.gsub!(/(\w+):/, "#{TEXT_CYAN}\\1#{CLEAR}:") + params.gsub!(/"(.*?)"/, "\"#{TEXT_YELLOW}\\1#{CLEAR}\"") + end + logger.debug("Parameters: #{params}") unless params.empty? + end + end + + def finish_processing(event) + session_value = @transactions.delete(event.transaction_id) # delete previous session_value from start_processing + SemanticLogger.tagged(session_value) do + payload = event.payload + additions = ::ActionController::Base.log_process_action(payload) + status = payload[:status] + + if status.nil? && (exception_class_name = payload[:exception]&.first) + status = ::ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name) + end + + additions << "GC: #{event.gc_time.round(1)}ms" + if event.duration >= 1200 + logger.error process_duration(event, additions) + elsif event.duration >= 600 + logger.warn process_duration(event, additions) + elsif event.duration >= 300 + logger.info process_duration(event, additions) + elsif event.duration >= 100 + logger.debug process_duration(event, additions) + end + + status_family = status / 100 + + dimensions = case status_family + when 2 + Semantic::AnsiDimensions.new(rails: TERMINUS_STRING) + when 3 + Semantic::AnsiDimensions.new(rails: '╙║╜') + when 4 + Semantic::AnsiDimensions.new(rails: '╙╨╜') + when 5 + Semantic::AnsiDimensions.new(rails: '╙║╜') + end + logger.info("Completed #{colorize(status, BOLD)} #{Rack::Utils::HTTP_STATUS_CODES[status]}", dimensions:) + logger.info(' ', dimensions: Semantic::AnsiDimensions.new(rails: ' ║ ')) if status_family == 3 + logger.info(' ', dimensions: Semantic::AnsiDimensions.new(rails: '╓║╖')) if status_family == 5 + end + end + + def redirect_to(event) + SemanticLogger.tagged(@transactions[event.transaction_id]) do + location = capture_path(event.payload[:location]) + logger.debug("Redirected to #{colorize(location, BOLD)}") + end + @previously_redirect = true + end + + def any_hook(event) + SemanticLogger.tagged(@transactions[event.transaction_id]) do + logger.warn("action_controller hook=<#{event.name.split('.')[0]}> needs a proper message handling!", + event.payload.keys) + end + end + + private + + def redirect_regex + return @redirect_regex if defined?(@redirect_regex) + + options = Rails.application.routes.default_url_options + dev_hosts = DEFAULT_DEV_HOSTS + Array.wrap(options[:host]) + dev_hosts_or = dev_hosts.uniq.join('|') + dev_from = "http://(?:#{dev_hosts_or}):#{options[:port]}(.*)" + + @redirect_regex = /^#{dev_from}/ + end + + def capture_path(url) + m = redirect_regex.match(url) + m.nil? ? url : m[1] + end + + def session_value(event) = event.payload[:headers]['rack.session'].fetch(@session_key, nil) + def process_duration(event, additions) = "Processed in #{event.duration.round}ms (#{additions.join(' | ')})" + end + end +end diff --git a/lib/semantic/subscribers/action_view.rb b/lib/semantic/subscribers/action_view.rb new file mode 100644 index 0000000..4713b6d --- /dev/null +++ b/lib/semantic/subscribers/action_view.rb @@ -0,0 +1,19 @@ +module Semantic + module Subscribers + class ActionView < ActiveSupport::LogSubscriber + include AnsiColors + + attr_reader :logger + + def initialize + short_name = self.class.to_s.split('::').last + @logger = SemanticLogger[short_name] + super + end + + def render_partial(event) + logger.info('Rendered partial', event) + end + end + end +end