2011-05-17 16:16:23 -04:00
|
|
|
##
|
|
|
|
# = Tracer
|
1999-01-19 23:59:39 -05:00
|
|
|
#
|
2011-05-17 16:16:23 -04:00
|
|
|
# Tracer outputs a source level execution trace of a Ruby program. It does
|
|
|
|
# this by registering an event handler with <code>Kernel#set_trace_func</code>
|
|
|
|
# for processing incoming events. It also provides methods for filtering
|
|
|
|
# unwanted trace output (see Tracer.add_filter, Tracer.on, and Tracer.off).
|
1999-01-19 23:59:39 -05:00
|
|
|
#
|
2011-05-17 16:16:23 -04:00
|
|
|
# == Example
|
2011-05-15 07:55:52 -04:00
|
|
|
#
|
2011-05-17 16:16:23 -04:00
|
|
|
# Consider the following ruby script
|
2009-03-05 22:56:38 -05:00
|
|
|
#
|
2011-05-17 16:16:23 -04:00
|
|
|
# class A
|
|
|
|
# def square(a)
|
|
|
|
# return a*a
|
|
|
|
# end
|
|
|
|
# end
|
|
|
|
#
|
|
|
|
# a = A.new
|
|
|
|
# a.square(5)
|
|
|
|
#
|
|
|
|
# Running the above script using <code>ruby -r tracer example.rb</code> will
|
|
|
|
# output the following trace to STDOUT (Note you can also explicitly
|
|
|
|
# <code>require 'tracer'</code>)
|
|
|
|
#
|
|
|
|
# #0:<internal:lib/rubygems/custom_require>:38:Kernel:<: -
|
|
|
|
# #0:example.rb:3::-: class A
|
|
|
|
# #0:example.rb:3::C: class A
|
|
|
|
# #0:example.rb:4::-: def square(a)
|
|
|
|
# #0:example.rb:7::E: end
|
|
|
|
# #0:example.rb:9::-: a = A.new
|
|
|
|
# #0:example.rb:10::-: a.square(5)
|
|
|
|
# #0:example.rb:4:A:>: def square(a)
|
|
|
|
# #0:example.rb:5:A:-: return a*a
|
|
|
|
# #0:example.rb:6:A:<: end
|
|
|
|
# | | | | |
|
|
|
|
# | | | | ---------------------+ event
|
|
|
|
# | | | ------------------------+ class
|
|
|
|
# | | --------------------------+ line
|
|
|
|
# | ------------------------------------+ filename
|
|
|
|
# ---------------------------------------+ thread
|
|
|
|
#
|
|
|
|
# Symbol table used for displaying incoming events:
|
|
|
|
#
|
|
|
|
# <tt>}</tt>:: call a C-language routine
|
|
|
|
# <tt>{</tt>:: return from a C-language routine
|
|
|
|
# <tt>></tt>:: call a Ruby method
|
|
|
|
# <tt>C</tt>:: start a class or module definition
|
|
|
|
# <tt>E</tt>:: finish a class or module definition
|
|
|
|
# <tt>-</tt>:: execute code on a new line
|
|
|
|
# <tt>^</tt>:: raise an exception
|
|
|
|
# <tt><</tt>:: return from a Ruby method
|
|
|
|
#
|
|
|
|
# == Copyright
|
|
|
|
#
|
|
|
|
# by Keiju ISHITSUKA(keiju@ishitsuka.com)
|
|
|
|
#
|
|
|
|
#--
|
|
|
|
# $Release Version: 0.3$
|
|
|
|
# $Revision: 1.12 $
|
2009-07-21 07:45:24 -04:00
|
|
|
require "thread"
|
1999-01-19 23:59:39 -05:00
|
|
|
|
|
|
|
#
|
|
|
|
# tracer main class
|
|
|
|
#
|
1998-01-16 07:13:05 -05:00
|
|
|
class Tracer
|
1999-01-19 23:59:39 -05:00
|
|
|
class << self
|
2011-05-17 16:16:23 -04:00
|
|
|
# display additional debug information (defaults to false)
|
2006-07-20 13:36:36 -04:00
|
|
|
attr_accessor :verbose
|
1999-01-19 23:59:39 -05:00
|
|
|
alias verbose? verbose
|
2009-07-21 07:45:24 -04:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# output stream used to output trace (defaults to STDOUT)
|
2006-07-20 13:36:36 -04:00
|
|
|
attr_accessor :stdout
|
2011-05-17 16:16:23 -04:00
|
|
|
|
|
|
|
# mutex lock used by tracer for displaying trace output
|
2009-07-21 07:45:24 -04:00
|
|
|
attr_reader :stdout_mutex
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# display process id in trace output (defaults to false)
|
2009-07-21 07:45:24 -04:00
|
|
|
attr_accessor :display_process_id
|
|
|
|
alias display_process_id? display_process_id
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# display thread id in trace output (defaults to true)
|
2009-07-21 07:45:24 -04:00
|
|
|
attr_accessor :display_thread_id
|
|
|
|
alias display_thread_id? display_thread_id
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# display C-routine calls in trace output (defaults to false)
|
2009-07-21 07:45:24 -04:00
|
|
|
attr_accessor :display_c_call
|
|
|
|
alias display_c_call? display_c_call
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
2011-05-17 16:16:23 -04:00
|
|
|
|
2009-07-21 07:45:24 -04:00
|
|
|
Tracer::stdout = STDOUT
|
|
|
|
Tracer::verbose = false
|
|
|
|
Tracer::display_process_id = false
|
|
|
|
Tracer::display_thread_id = true
|
|
|
|
Tracer::display_c_call = false
|
|
|
|
|
|
|
|
@stdout_mutex = Mutex.new
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# Symbol table used for displaying trace information
|
1998-01-16 07:13:05 -05:00
|
|
|
EVENT_SYMBOL = {
|
|
|
|
"line" => "-",
|
|
|
|
"call" => ">",
|
|
|
|
"return" => "<",
|
|
|
|
"class" => "C",
|
2000-12-21 22:22:25 -05:00
|
|
|
"end" => "E",
|
2009-07-21 07:45:24 -04:00
|
|
|
"raise" => "^",
|
|
|
|
"c-call" => "}",
|
|
|
|
"c-return" => "{",
|
|
|
|
"unknown" => "?"
|
2000-12-21 22:22:25 -05:00
|
|
|
}
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def initialize # :nodoc:
|
1999-01-19 23:59:39 -05:00
|
|
|
@threads = Hash.new
|
|
|
|
if defined? Thread.main
|
2002-11-07 14:18:16 -05:00
|
|
|
@threads[Thread.main.object_id] = 0
|
1999-01-19 23:59:39 -05:00
|
|
|
else
|
2002-11-07 14:18:16 -05:00
|
|
|
@threads[Thread.current.object_id] = 0
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
@get_line_procs = {}
|
|
|
|
|
|
|
|
@filters = []
|
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def stdout # :nodoc:
|
2000-10-11 02:29:16 -04:00
|
|
|
Tracer.stdout
|
|
|
|
end
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def on # :nodoc:
|
2000-06-28 04:31:35 -04:00
|
|
|
if block_given?
|
1999-01-19 23:59:39 -05:00
|
|
|
on
|
|
|
|
begin
|
2011-05-18 17:19:18 -04:00
|
|
|
yield
|
1999-01-19 23:59:39 -05:00
|
|
|
ensure
|
2011-05-18 17:19:18 -04:00
|
|
|
off
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
|
|
|
else
|
2003-06-16 03:14:50 -04:00
|
|
|
set_trace_func method(:trace_func).to_proc
|
2000-10-11 02:29:16 -04:00
|
|
|
stdout.print "Trace on\n" if Tracer.verbose?
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def off # :nodoc:
|
1998-01-16 07:13:05 -05:00
|
|
|
set_trace_func nil
|
2000-10-11 02:29:16 -04:00
|
|
|
stdout.print "Trace off\n" if Tracer.verbose?
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
1999-01-19 23:59:39 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def add_filter(p = proc) # :nodoc:
|
1999-01-19 23:59:39 -05:00
|
|
|
@filters.push p
|
|
|
|
end
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def set_get_line_procs(file, p = proc) # :nodoc:
|
1999-01-19 23:59:39 -05:00
|
|
|
@get_line_procs[file] = p
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def get_line(file, line) # :nodoc:
|
1999-01-19 23:59:39 -05:00
|
|
|
if p = @get_line_procs[file]
|
2002-06-28 10:42:46 -04:00
|
|
|
return p.call(line)
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
|
|
|
|
2001-12-21 04:23:28 -05:00
|
|
|
unless list = SCRIPT_LINES__[file]
|
1999-01-19 23:59:39 -05:00
|
|
|
begin
|
2011-05-18 17:19:18 -04:00
|
|
|
f = File::open(file)
|
|
|
|
begin
|
|
|
|
SCRIPT_LINES__[file] = list = f.readlines
|
|
|
|
ensure
|
|
|
|
f.close
|
|
|
|
end
|
1999-01-19 23:59:39 -05:00
|
|
|
rescue
|
2011-05-18 17:19:18 -04:00
|
|
|
SCRIPT_LINES__[file] = list = []
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
|
|
|
end
|
2004-10-20 02:53:42 -04:00
|
|
|
|
1999-01-19 23:59:39 -05:00
|
|
|
if l = list[line - 1]
|
|
|
|
l
|
|
|
|
else
|
|
|
|
"-\n"
|
|
|
|
end
|
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def get_thread_no # :nodoc:
|
2002-11-07 14:18:16 -05:00
|
|
|
if no = @threads[Thread.current.object_id]
|
1999-01-19 23:59:39 -05:00
|
|
|
no
|
|
|
|
else
|
2002-11-07 14:18:16 -05:00
|
|
|
@threads[Thread.current.object_id] = @threads.size
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
def trace_func(event, file, line, id, binding, klass, *) # :nodoc:
|
2006-02-17 10:40:32 -05:00
|
|
|
return if file == __FILE__
|
2009-03-05 22:56:38 -05:00
|
|
|
|
1999-01-19 23:59:39 -05:00
|
|
|
for p in @filters
|
2000-12-21 22:22:25 -05:00
|
|
|
return unless p.call event, file, line, id, binding, klass
|
1999-01-19 23:59:39 -05:00
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-15 07:55:52 -04:00
|
|
|
return unless Tracer::display_c_call? or
|
2009-07-21 07:45:24 -04:00
|
|
|
event != "c-call" && event != "c-return"
|
|
|
|
|
|
|
|
Tracer::stdout_mutex.synchronize do
|
|
|
|
if EVENT_SYMBOL[event]
|
2011-05-18 17:19:18 -04:00
|
|
|
stdout.printf("<%d>", $$) if Tracer::display_process_id?
|
|
|
|
stdout.printf("#%d:", get_thread_no) if Tracer::display_thread_id?
|
|
|
|
if line == 0
|
|
|
|
source = "?\n"
|
|
|
|
else
|
|
|
|
source = get_line(file, line)
|
|
|
|
end
|
2012-11-19 21:05:21 -05:00
|
|
|
stdout.printf("%s:%d:%s:%s: %s",
|
2011-05-18 17:19:18 -04:00
|
|
|
file,
|
|
|
|
line,
|
|
|
|
klass || '',
|
|
|
|
EVENT_SYMBOL[event],
|
|
|
|
source)
|
2009-07-21 07:45:24 -04:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# Reference to singleton instance of Tracer
|
1998-01-16 07:13:05 -05:00
|
|
|
Single = new
|
2011-05-17 16:16:23 -04:00
|
|
|
|
|
|
|
##
|
|
|
|
# Start tracing
|
|
|
|
#
|
|
|
|
# === Example
|
|
|
|
#
|
|
|
|
# Tracer.on
|
|
|
|
# # code to trace here
|
|
|
|
# Tracer.off
|
|
|
|
#
|
|
|
|
# You can also pass a block:
|
|
|
|
#
|
|
|
|
# Tracer.on {
|
|
|
|
# # trace everything in this block
|
|
|
|
# }
|
|
|
|
|
1998-01-16 07:13:05 -05:00
|
|
|
def Tracer.on
|
2000-06-28 04:31:35 -04:00
|
|
|
if block_given?
|
1999-01-19 23:59:39 -05:00
|
|
|
Single.on{yield}
|
|
|
|
else
|
|
|
|
Single.on
|
|
|
|
end
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
##
|
|
|
|
# Disable tracing
|
|
|
|
|
1998-01-16 07:13:05 -05:00
|
|
|
def Tracer.off
|
|
|
|
Single.off
|
|
|
|
end
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
##
|
|
|
|
# Register an event handler <code>p</code> which is called everytime a line
|
|
|
|
# in +file_name+ is executed.
|
|
|
|
#
|
|
|
|
# Example:
|
|
|
|
#
|
|
|
|
# Tracer.set_get_line_procs("example.rb", lambda { |line|
|
|
|
|
# puts "line number executed is #{line}"
|
|
|
|
# })
|
|
|
|
|
1999-01-19 23:59:39 -05:00
|
|
|
def Tracer.set_get_line_procs(file_name, p = proc)
|
|
|
|
Single.set_get_line_procs(file_name, p)
|
|
|
|
end
|
1998-01-16 07:13:05 -05:00
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
##
|
|
|
|
# Used to filter unwanted trace output
|
|
|
|
#
|
|
|
|
# Example which only outputs lines of code executed within the Kernel class:
|
|
|
|
#
|
|
|
|
# Tracer.add_filter do |event, file, line, id, binding, klass, *rest|
|
|
|
|
# "Kernel" == klass.to_s
|
|
|
|
# end
|
|
|
|
|
1999-01-19 23:59:39 -05:00
|
|
|
def Tracer.add_filter(p = proc)
|
|
|
|
Single.add_filter(p)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2011-05-17 16:16:23 -04:00
|
|
|
# :stopdoc:
|
2001-10-29 00:07:26 -05:00
|
|
|
SCRIPT_LINES__ = {} unless defined? SCRIPT_LINES__
|
1999-10-15 04:52:18 -04:00
|
|
|
|
2006-02-17 10:40:32 -05:00
|
|
|
if $0 == __FILE__
|
|
|
|
# direct call
|
2009-03-05 22:56:38 -05:00
|
|
|
|
2006-02-17 10:40:32 -05:00
|
|
|
$0 = ARGV[0]
|
|
|
|
ARGV.shift
|
|
|
|
Tracer.on
|
|
|
|
require $0
|
2011-06-29 09:19:59 -04:00
|
|
|
else
|
|
|
|
# call Tracer.on only if required by -r command-line option
|
2012-11-29 03:22:04 -05:00
|
|
|
count = caller.count {|bt| %r%/rubygems/core_ext/kernel_require\.rb:% !~ bt}
|
2011-06-29 09:19:59 -04:00
|
|
|
if (defined?(Gem) and count == 0) or
|
|
|
|
(!defined?(Gem) and count <= 1)
|
|
|
|
Tracer.on
|
|
|
|
end
|
1998-01-16 07:13:05 -05:00
|
|
|
end
|
2011-05-17 16:16:23 -04:00
|
|
|
# :startdoc:
|