easy-going-rails/lib/formatters/basic_formatter.rb

require_relative 'wrapper'
require_relative 'base'
require 'io/console'
require 'amazing_print'
require 'json'

# Opinioned Rails custom formatter
class BasicFormatter < SemanticLogger::Formatters::Color # rubocop:disable Metrics/ClassLength
  NAME_MAX_SIZE = 25
  TERMINAL_PREFIX = ENV['TERMINAL_PREFIX'].to_i || 0
  CONTENT_PREFIX = '   '.freeze
  PREFIX_RAILS_INTERNAL = '⬂ '.freeze
  PREFIX_RECORD_INTERNAL = '⬄ '.freeze
  PREFIX_ACTION_INTERNAL = '⬃ '.freeze
  PREFIX_BUG_INTERNAL = '➟ '.freeze

  RENDERED_VIEW_DURATION = 100
  COMPLETED_DURATION = RENDERED_VIEW_DURATION * 5

  ANSI_RESET = "\e[0m".freeze
  ANSI_BOLD = "\e[1m".freeze
  ANSI_DEBUG = "\e[90m".freeze
  ANSI_INFO = SemanticLogger::AnsiColors::GREEN
  ANSI_WARN = SemanticLogger::AnsiColors::YELLOW
  ANSI_ERROR = "\e[91m".freeze
  ANSI_NEUTRAL_INFO = SemanticLogger::AnsiColors::WHITE
  ANSI_REVERSED_WARNING = "\e[0;30;43m".freeze
  ANSI_REVERSED_ERROR = "\e[1;30;41m".freeze
  ANSI_REVERSED_FATAL = "\e[1;30;41m".freeze

  CONTENT_COLOR_MAP = ColorMap.new(
    debug: ANSI_DEBUG,
    info: ANSI_NEUTRAL_INFO,
    warn: ANSI_REVERSED_WARNING,
    error: ANSI_REVERSED_ERROR,
    fatal: ANSI_REVERSED_FATAL
  )

  # exclude log eagerly!
  EXCLUDE_LAMBDA = lambda { |log|
    if log.name == 'ActionView::Base'
      !log.message.starts_with?('  Rendering')
    elsif log.name == 'Rails' && !log.message.nil?
      log.message.exclude?('Started GET "/rails/live/reload')
    elsif log.name == 'ActiveRecord::Base'
      log.message.exclude?('↳ lib/formatters/basic_formatter.rb')
    else
      true
    end
  }

  def initialize
    super(color_map: ColorMap.new(
      debug: ANSI_DEBUG,
      info: ANSI_INFO,
      warn: ANSI_WARN,
      error: ANSI_ERROR,
      fatal: ANSI_ERROR
    ))
  end

  def message
    return unless log.message

    message = wrap_message(log.message)
    "#{CONTENT_COLOR_MAP[log.level]}#{message}#{color_map.clear}"
  end

  def payload
    return unless log.payload

    lines = log.payload.ai(ruby19_syntax: true, indent: 2).split("\n")
    first_line = lines.shift
    space_prefix = first_line.match(/^\s*/)
    lines = lines.map do |l|
      "#{before_message(wrapped: true)}#{space_prefix}#{l}"
    end
    result = lines.unshift(first_line).join("\n")
    result.sub!(/\s*/) { |m| '-' * m.length }
    result
  end

  def level
    case log.level
    when :info, :debug then draw_rails ' '
    else draw_rails(log.level.to_s.chr.upcase)
    end
  end

  def name
    "#{ANSI_DEBUG}#{log.name.truncate(NAME_MAX_SIZE).center(NAME_MAX_SIZE)}#{color_map.clear}"
  end

  def exception # rubocop:disable Metrics/AbcSize
    return unless log.exception

    root_path = Rails.root.to_s
    stack = log.exception.backtrace.select { |line| line.starts_with?(root_path) }
    stack = stack.map { |line| line.delete_prefix("#{root_path}/") }

    "#{ANSI_REVERSED_WARNING}#{log.exception.class}#{color_map.clear} #{ANSI_REVERSED_ERROR}#{log.exception.message}#{color_map.clear}#{backtrace(stack)}" # rubocop:disable Layout/LineLength
  end

  def call(log, logger)
    self.log = transform_log(log)
    self.color = color_map[self.log.level]
    self.logger = logger

    before_message + [message, payload, exception].compact.join(' ')
  end

  private

  def draw_rails(char)
    "#{color}╣#{char}╠#{color_map.clear}"
  end

  def continuation
    draw_rails('┆')
  end

  # transform log before display
  def transform_log(log)
    case log.name
    when 'ActionView::Base' then transform_action_view_base(log)
    when 'Rails' then transform_rails_log(log)
    when 'ActiveRecord::Base'
      log.message = transform_active_record_message(log.message)
      log
    else log end
  end

  def transform_rails_log(log)
    return log unless log.message

    log.message = transform_rails_message(log.message.rstrip)
    log.level = :debug if log.message =~ /^#{PREFIX_RAILS_INTERNAL}(Processing|Parameters)/
    log
  end

  def transform_active_record_message(message)
    message = message.lstrip.sub(/^↳ /, 'Processed by ')
    "#{PREFIX_RECORD_INTERNAL}#{message.lstrip}"
  end

  def transform_rails_message(message)
    case message
    when /^Completed/
      transform_rails_completed(message)
    when /^Started/
      two_captures_last_as_bold(message, /(^Started \w* )"(.*?)"/)
    when /^Processing/
      "#{PREFIX_RAILS_INTERNAL}#{two_captures_last_as_bold(message, /(^Processing by \w*#\w* as )(.*)/)}"
    when /  Parameters/
      parameters = message.lstrip.match(/Parameters: ({.*}$)/).match(1)
      parameters = JSON.parse(parameters.gsub('=>', ':'), symbolize_names: true)
      "#{PREFIX_RAILS_INTERNAL}Parameters: #{parameters.ai(ruby19_syntax: true, plain: true, multiline: false)}"
    else
      message
    end
  end

  def transform_rails_completed(message)
    m1, m2, m3, m4 = message.match(/^Completed (\d*) (.*) in (\d*)ms(.*)$/).captures
    message = "Completed #{ANSI_BOLD}#{m1} #{m2}#{ANSI_RESET} in #{m3}ms"
    message += m4 if m3.to_i > COMPLETED_DURATION
    message += "\n" if m1 =~ /^[23]/
    message
  end

  def two_captures_last_as_bold(message, regex)
    m1, m2 = message.match(regex).captures
    "#{m1}#{ANSI_BOLD}#{m2}#{ANSI_RESET}"
  end

  def transform_action_view_base(log)
    log.level, message = transform_log_debug_lstrip(log)
    message = transform_rendered_message_with_filename(message)
    message = transform_duration_strip(message)
    log.message = "#{PREFIX_ACTION_INTERNAL}#{message}"
    log
  end

  def transform_duration_strip(message)
    md2 = message.match(/( \(Duration: \d+\.?\d?ms.*\))/)
    md3 = md2.match(1).match(/Duration: (\d+\.?\d?)ms/)
    duration = md3.match(1).to_f
    duration < RENDERED_VIEW_DURATION ? md2.pre_match : message
  end

  def transform_rendered_message_with_filename(message)
    md = message.match(/^Rendered( layout| collection of|) (.*?\.erb)/)
    filename = "app/views/#{md.match(2)}"
    log.message = "Rendered#{md.match(1)} #{filename}#{md.post_match}"
  end

  def transform_log_debug_lstrip(log)
    [:debug, log.message.lstrip]
  end

  def wrap_message(message)
    message, space_prefix = split_spaces_in_front(message)
    message = Wrapper.wrap("#{CONTENT_COLOR_MAP[log.level]}#{message}",
                           before_message(wrapped: true) + space_prefix.to_s,
                           compute_useful_length - space_prefix.length)
    "#{space_prefix}#{message}"
  end

  def split_spaces_in_front(message)
    md = message.match(/^\s*/)
    [md.post_match, md.match(0)]
  end

  def compute_useful_length
    IO.console.winsize[1] - TERMINAL_PREFIX - before_message.length + CONTENT_PREFIX.length + 12
  rescue StandardError
    100 # FIXME: CONSTANTIZE, only useful in DEBUGGER, no IO.console detected!
  end

  def before_message(wrapped: false)
    [name, wrapped ? continuation : level, tags, named_tags, duration].compact.join(' ') + CONTENT_PREFIX
  end

  def backtrace(stack)
    return "\n" unless stack.count.positive?

    "\n#{before_message}#{ANSI_ERROR}#{PREFIX_BUG_INTERNAL}#{stack.join("\n#{before_message}#{ANSI_ERROR}#{PREFIX_BUG_INTERNAL}")}#{color_map.clear}\n"
  end

  def color_content
    color
  end
end