In writing some shell scripts in ruby, I decided that I needed to be able to debug (trace) the lines that were being executed. I even ran across a closed StackOverflow question looking for the same thing.
code=ARGF.readlines.grep_v(/^$/)
eval code.map { |c| %Q|puts "+ #{c.gsub("\"", "\\"").strip}"| }.zip(code).join($/)
After playing around with one of the other answers (see above), I ended up taking a different tactic to try and figure out how to debug the scripts. (By the way, the above code breaks if you have line breaks in a single statement, like the following contrived example):
y = 2
+ 4
The important search term here is “trace”, or Tracer to be exact.
Take the following example:
bind = binding
p bind
bind.local_variable_set(:bind, 2)
p bind
p binding.local_variables
bind = binding
p eval("bind", bind)
if 2 > 3
puts 2
else
puts 3
end
if true
puts "looks like the if true is compiled out"
end
if you run the above (contained in a filename binding.rb) using ruby -r tracer binding.rb then you get the following:
#0:/home/tpowell/.rbenv/versions/2.5.5/lib/ruby/2.5.0/rubygems/core_ext/kernel_require.rb:59:Kernel:<: return gem_original_require(path)
#0:binding.rb:1::-: bind = binding
#0:binding.rb:2::-: p bind
#<Binding:0x000055fe6879cd38>
#0:binding.rb:4::-: bind.local_variable_set(:bind, 2)
#0:binding.rb:6::-: p bind
2
#0:binding.rb:8::-: p binding.local_variables
[:bind]
#0:binding.rb:10::-: bind = binding
#0:binding.rb:12::-: p eval("bind", bind)
#0:binding.rb:10::-: bind = binding
#<Binding:0x000055fe68835718>
#0:binding.rb:14::-: if 2 > 3
#0:binding.rb:17::-: puts 3
3
#0:binding.rb:22::-: puts "looks like the if true is compiled out"
looks like the if true is compiled out
One interesting difference between how ruby -r tracer works from set -x is that the ruby tracer appears skips evaluating the if true at all. The above runs were against ruby 2.5.5. Looking at 3.0.0 (and as far back as 2.6.x), I only get the output of the script:
#<Binding:0x000055af54e0c730>
2
[:bind]
#<Binding:0x000055af54e0c050>
3
looks like the if true is compiled out
Looking at Tracer, it’s using set_trace_func under the hood:
set_trace_func proc { |event, file, line, id, binding, classname|
printf "%8s %s:%-2d %10s %8s\n", event, file, line, id, classname
}
Adding that in the 2.6.x+ world returns:
c-return binding.rb:1 set_trace_func Kernel
line binding.rb:5
c-call binding.rb:5 binding Kernel
c-return binding.rb:5 binding Kernel
line binding.rb:6
c-call binding.rb:6 p Kernel
c-call binding.rb:6 inspect Kernel
c-return binding.rb:6 inspect Kernel
.
.
.
That output can be filtered by the event type , but the lines of code themselves aren’t output and apparently set_trace_func was apparently obsoleted as of 2.1.10. TracePoint is the updated way to accomplish this:
trace = TracePoint.new(:line) do |tp|
p tp
end
trace.enable
.
.
.
But we still have the same problem:
#<TracePoint:line@binding_trace_point.rb:8>
#<TracePoint:line@binding_trace_point.rb:9>
#<Binding:0x00005652f2a125e8>
#<TracePoint:line@binding_trace_point.rb:11>
#<TracePoint:line@binding_trace_point.rb:13>
2
#<TracePoint:line@binding_trace_point.rb:15>
[:trace, :bind]
A crude solution I’ve found around this is to read the line from the file mentioned in the TracePoint from within the block (and this apparently doesn’t end up with a stack overflow).
trace = TracePoint.new(:line) do |tp|
puts "+ #{File.open(tp.path) { |f| f.each_line.to_a[tp.lineno-1] }}"
end
trace.enable
.
.
.
Which produces a somewhat set -x output:
+ bind = binding
+ p bind
#<Binding:0x000055ef6c9d9f70>
+ bind.local_variable_set(:bind, 2)
+ p bind
2
+ p binding.local_variables
[:trace, :bind]
+ bind = binding
+ p eval("bind", bind)
+ bind = binding
#<Binding:0x000055ef6c8321b8>
+ if 2 > 3
+ if 3 > 2
+ puts 3
3
+ puts "looks like the if true is compiled out"
looks like the if true is compiled out