7

I use tail -f to display the log file when developing my Rails app. It shows the log messages (in color! :), which is great.

But with so much information in the 80-width console, it becomes difficult to track where a certain "set" of log messages started when, say, I clicked on a button to GET a resource.

It would be easier if there was a line number or even a time stamp at the start of each log message/line. This way I could remember that I need to start looking at the log "after line number 2365" or "after 2010/10/10 23:33:23:45".

Is this possible to do? Is there some Rails internal option for this ?

Zabba
  • 64,285
  • 47
  • 179
  • 207

3 Answers3

10

why don't you just edit your desired environment's log tags

development.rb

config.log_tags [ lambda {|r| DateTime.now } ]
Community
  • 1
  • 1
marknery
  • 1,533
  • 3
  • 19
  • 27
  • 1
    If you want the line number of the source, you could add something like this: `config.log_tags [ lambda {|r| __LINE__ } ]`. To increment the line number in the log file you could do something like this: `config.log_tags [ lambda {|r| @rails_log_line_number=(@rails_log_line_number||0)+1 } ]` – jwadsack Feb 13 '13 at 16:11
  • 4
    That would give you the "the timestamp at the beginning of the request", not "the current timestamp". – sayap Oct 04 '13 at 10:51
  • 5
    rails 4.1.2 requires '=', config.log_tags = [ lambda {|r| DateTime.now } ] – gayavat Sep 11 '14 at 08:06
3

If you wanted to get a time stamp:

class ApplicationController < ActionController::Base
  # ...
  before_filter :log_tracker

  def log_tracker
    Rails.logger.add(1, "Log Date: #{DateTime.now}")
  end
end

And format the date however you see fit....

That would work for Rails 2.1 +, prior you could access the ActiveSupport::Buffered log object with the constant: RAILS_DEFAULT_LOGGER

Get access to the actual log file with Rails.logger.instance_values["log"]

Getting the number of lines is difficult because the logger only opens the file for writing, probably for economy. I get an IOError: not opened for reading when I try. `

scaney
  • 1,746
  • 13
  • 16
1

Thanks @scaney.

I found a solution here.

I modified that code to add my own coloring highlights (for development only of course!) and now I can see things like 'parameters' in yellow in the console and I'm very pleased now!

In case someone is interested, here is the code I put at the end of environment.rb. Here is my current (dirty) implementation. Will probably fix this up later (maybe make a gem, but for now this serves me fine)

WARNING

DIRTY CODE FOLLOWS! Use at your own risk!

module ActiveSupport
  class BufferedLogger

    #define the ANSI escape codes for normal and bright colors
    $my_my_ansi_colors = {

      :normal => "\x1B[0m",

      :black => "\x1B[30m",
      :red => "\x1B[31m", #red
      :green => "\x1B[32m",
      :yellow => "\x1B[33m",
      :blue => "\x1B[34m",
      :magenta => "\x1B[35m",
      :cyan => "\x1B[36m",
      :white => "\x1B[37m",

      :bred => "\x1B[1m\x1B[31m", #bright red
      :bgreen => "\x1B[1m\x1B[32m",
      :byellow => "\x1B[1m\x1B[33m",
      :bblue => "\x1B[1m\x1B[34m",
      :bmagenta => "\x1B[1m\x1B[35m",
      :bcyan => "\x1B[1m\x1B[36m",
      :bwhite => "\x1B[1m\x1B[37m",
    }

    #take a string and using the keys in the hash, replace the keys in the 
    #string but surround the keys with ANSI color codes
    #No idea how to retain the case of the key!(TODO someday)
    def my_highlight msgx,hash
      return msgx if msgx.blank?
      return msgx if hash.empty?
      hash.each_pair do |k,v|
        if not k.nil?
          msgx.gsub! Regexp.new(k, Regexp::IGNORECASE), $my_my_ansi_colors[:normal]+$my_my_ansi_colors[v]+k.upcase+$my_my_ansi_colors[:normal]
        end
      end
      msgx
    end


    def add(severity, message = nil, progname = nil, &block)
      return if @level > severity

      message = (message || (block && block.call) || progname).to_s

      #INSERT BEGINS
      if not $myownglobalnumbercounter.nil?
        $myownglobalnumbercounter += 1
      else
        $myownglobalnumbercounter = 1
      end

      level = {
        0 => "DEBUG",
        1 => "INFO",
        2 => "WARN",
        3 => "ERROR",
        4 => "FATAL"
      }[severity] || "U"

      message = "\x1B[0m[%d %s] : %s" % [$myownglobalnumbercounter,level,message]
      message = my_highlight message, {
        "debug" => :white,
        "error" => :bred,
        "info" => :bwhite,
        "warning" => :byellow,
        "warn" => :byellow ,
        "parameters" => :byellow,
        "#" => :bgreen,
        "ms " => :bmagenta,
        "GET " => :bmagenta,
        "PUT " => :bmagenta,
        "POST " => :bmagenta,
        "DELETE " => :bmagenta
        }
      #INSERT ENDS

      message = "#{message}\n" unless message[-1] == ?\n
      buffer << message
      auto_flush
      message
    end
  end
end
Community
  • 1
  • 1
Zabba
  • 64,285
  • 47
  • 179
  • 207
  • Also, if you're overloading the class, you might be able to change the internal file handling to allow you to get the number of lines at the time of writing, not sure if it would work, just a thought – scaney Dec 24 '10 at 02:31
  • Yeah, probably will look into logger in more detail sometime; right now I just wanted a quickfix – Zabba Dec 24 '10 at 02:35