Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Is there an equivalent of shell scripting's xtrace option for Ruby?

Tags:

ruby

When debugging shell scripts, I find it helpful to run with xtrace on:

-x    xtrace        Print commands  and  parameter
                    assignments when they are exe-
                    cuted, preceded by  the  value
                    of PS4.

For instance:

$ set -x
$ s='Say again?'
+ s='Say again?'

# Other commands that might mess with the value of $s

$ echo $s
+ echo Say 'again?'
Say again?

I know that Ruby has interactive debuggers such as pry and byebug, but I'm looking for something that will be easy to turn on for logging automated scripts.

I did find an xtrace gem, but it has something to do with a PHP format.

I also see there is a Tracer class and a TracePoint class which do seem to provide a way to print statements as they are executed. But I haven't found any way to print the value of variables (rather than just the variable name):

$ ruby -r tracer trace.rb 
#0:/usr/local/Cellar/ruby/2.4.1_1/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:Kernel:<:       return gem_original_require(path)
#0:trace.rb:1::-: s='Say again?'
#0:trace.rb:2::-: puts s
Say again?

I'd like to have the penultimate line read:

#0:trace.rb:2::-: puts 'Say again?'

Is this possible? Or is there a better way with Ruby?

like image 658
Kathryn Avatar asked Nov 07 '22 22:11

Kathryn


1 Answers

I was able to build a module that more or less does what I'm looking for:

require 'pry'

=begin
  We are always one line behind because the value of assignment comes
  _after_ the trace is called. Without this, every assignment would look
  like:

      x = 1 #=> {:x=>nil}

   It would be nice if the trace happened after assignment, but what can 
  you do?  
=end 

module Xtrace
  # Only run the trace on the main file, not on require'd files.
  # Possible room for expansion later.
  @files = {$0 => Pry::Code.from_file($0)}

  def Xtrace.print_trace
    if @prev_line then
      if @files[@path] then
        line = @files[@path].around(@prev_line, 0).chomp

        # When calling a method, don't make it look like it's being defined.
        line.gsub!(/^\s*def\s*\b/, '') if @event == :call

        values = []
        @bind.local_variables.each do |v|
          values << {v => @bind.local_variable_get(v)} if line =~ /\b#{v}\b/
        end
        STDERR.printf "%5s: %s", @prev_line, line
        STDERR.printf " #=> %s", values.join(', ') unless values.empty?
        STDERR.printf "\n"
      end
    end
  end

  @xtrace = TracePoint.trace(:line, :call) do |tp|
    tp.disable 
    @bind=tp.binding
    Xtrace.print_trace

    # Other than the binding, everything we need to print comes from the
    # previous trace call.
    @prev_line = tp.lineno
    @event=tp.event
    @path=tp.path
    tp.enable
  end    

  # Need to print the trace one last time after the last line of code. 
  at_exit do
    # It doesn't matter what we do in this last line. Any statement works.
    # Also, it's a bit inconvenient that the disable command is itself traced.
    @xtrace.disable
  end
end

If you put it in a file named xtrace.rb and put in in your library load path, you can begin tracing by adding require 'xtrace'. It prints the line number of each line and method call executed, the actual code and the values of any local variable in the line. For a simple factorial function, the output might look like:

    3: def factorial(n)
    8: puts factorial(3)
    3: factorial(n) #=> {:n=>3}
    4:   return 1 if n <= 1 #=> {:n=>3}
    5:   return n*factorial(n-1) #=> {:n=>2}
    3: factorial(n) #=> {:n=>2}
    4:   return 1 if n <= 1 #=> {:n=>2}
    5:   return n*factorial(n-1) #=> {:n=>1}
    3: factorial(n) #=> {:n=>1}
    4:   return 1 if n <= 1
6

For the moment, it only looks at local variables. It also only traces the executed file and not any loaded files. There's no way to enable or disable traces just yet. The trace begins when you require the module and ends when the execution does. Trace output goes to STDERR and the format is hardcoded.

If you use this module, watch out that you don't leak sensitive information such as passwords, API keys or PII.

like image 108
Kathryn Avatar answered Nov 15 '22 12:11

Kathryn