completed_duration

app/controllers/scores_controller.rb

@@ -12,7 +12,7 @@ class ScoresController < ApplicationController
     # logger.debug BigDecimal('0.0003')
     # logger.debug 'scores are', @scores
     # logger.debug @scores
-    # sleep 1
+    # sleep 0.5
   end
 
   # GET /scores/1

lib/formatters/basic_formatter.rb

@@ -10,6 +10,7 @@ class BasicFormatter < SemanticLogger::Formatters::Color # rubocop:disable Metri
   CONTENT_PREFIX = '   '.freeze
 
   RENDERED_VIEW_DURATION = 100
+  COMPLETED_DURATION = RENDERED_VIEW_DURATION * 5
 
   ANSI_RESET = "\e[0m".freeze
   ANSI_BOLD = "\e[1m".freeze
@@ -119,23 +120,32 @@ class BasicFormatter < SemanticLogger::Formatters::Color # rubocop:disable Metri
       log = transform_action_view_base(log)
     elsif log.name == 'Rails' && log.message
       log.message = transform_rails_message(log.message.rstrip)
+      log.level = :debug if log.message.lstrip =~ /^Processing/ || log.message.lstrip =~ /^Parameters/
     end
     log
   end
 
   def transform_rails_message(message)
     case message
-    when /^Completed [23]/
-      "#{message}\n"
+    when /^Completed/
+      transform_rails_completed(message)
     when /^Started/
       two_captures_last_as_bold(message, /(^Started \w* )"(.*?)"/)
     when /^Processing/
-      two_captures_last_as_bold(message, /(^Processing by \w*#\w* as )(.*)/)
+      "  #{two_captures_last_as_bold(message, /(^Processing by \w*#\w* as )(.*)/)}"
     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}"