rails_trace.rb

require 'singleton'

# outputs a colored call-trace graph to the Rails logger of the lines of ruby code
# invoked during a single request.
#
# Example:
#
# 1) Make sure this file is loaded in an initializer
#
# 2) Add the following to your application.rb in Rails3:
#   if ENV["TRACE"] == "on"
#     config.middleware.use 'RailsTrace'
#   end
#
# 3) then invoke webrick: 
#   $ TRACE=on rails s
#
class RailsTrace

  def initialize(app)
    @app = app
  end
  
  def call(env)
    dup._call(env)
  end
  
  def _call(env)
    t = Tracer.instance
    t.record
    status, headers, response = @app.call(env)
    t.stop
    t.dump
    [status, headers, response]
  end

  class Tracer  
    include Singleton

    def initialize
      @recording = false
      set_trace_func proc { |event, file, line, id, binding, classname|
        if event != "c-call" && event != "c-return" && file =~ /(app\/.*)/
          store_trace(event, $1, file, line)
        end
      }
      log "TRACER: initialized."
    end

    def log(msg, comment = "")
      Rails.logger.debug("\033[1;32m%s\033[0m\033[1;30m%s\033[0m" % [msg, comment])
    end

    def record
      log "TRACER: (recording)"
      @trace_lines = []
      @recording = true
    end

    def recording?
      @recording 
    end
    
    def stop
      @recording = false
      log "TRACER: (stopped)"
    end
    
    def store_trace(event, rel_path, full_path, line)
      @trace_lines << [event, rel_path, full_path, line] if recording?
    end

    def dump
      log "TRACER: dumping trace:"
      indent = 0
      @trace_lines.each do |arr|
        event, rel_path, full_path, line = arr
        source_line = get_line(full_path,line)
        case event
        when /return/
          log( "%s. %s" % ["| "*indent, source_line.chop], " # TRACE %s:%-2d" % [rel_path, line] )
          indent -= 1
        when /call/
          indent += 1
          log( "%s %s" % ["|-"*indent, source_line.chop], " # TRACE %s:%-2d" % [rel_path, line] )
        else
            log( "%s| %s" % ["| "*indent, source_line.chop], " # TRACE %s:%-2d" % [rel_path, line] )
        end
      end
    end

    def get_line(file, line)
      @script_lines ||= {}
      unless list = @script_lines[file]
        begin
          f = ::File::open(file)
          begin
            @script_lines[file] = list = f.readlines
          ensure
            f.close
          end
        rescue Exception => e
          @script_lines[file] = list = []
        end
      end

      if l = list[line - 1]
        l
      else
        "\n"
      end
    end
  end

end