easy-going-rails/lib/semantic/log_subscriber.rb

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

    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)
        logger.info("Started #{request.raw_request_method} #{path}")

        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 >= 250
          logger.info process_duration(event, additions)
        elsif event.duration >= 80
          logger.debug process_duration(event, additions)
        end

        logger.info("Completed #{colorize(status, BOLD)} #{Rack::Utils::HTTP_STATUS_CODES[status]}")
      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
    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