BigBinary Blog
We write about Ruby on Rails, React.js, React Native, remote work, open source, engineering and design.
Stack trace or backtrace is a sequential representation of the stack of method calls in a program which gets printed when an exception is raised. It is often used to find out the exact location in a program from where the exception was raised.
Before Ruby 2.5, the printed backtrace contained the exception class and the error message at the top. Next line contained where in the program the exception was raised. Next we got more lines which contained cascaded method calls.
Consider a simple Ruby program.
class DivisionService
attr_reader :a, :b
def initialize(a, b)
@a, @b = a.to_i, b.to_i
end
def divide
puts a / b
end
end
DivisionService.new(ARGV[0], ARGV[1]).divide
Let's execute it using Ruby 2.4.
$ RBENV_VERSION=2.4.0 ruby division_service.rb 5 0
division_service.rb:9:in `/': divided by 0 (ZeroDivisionError)
from division_service.rb:9:in `divide'
from division_service.rb:13:in `<main>'
In the printed backtrace above, the first line shows the location, error message and the exception class name; whereas the subsequent lines shows the caller method names and their locations. Each line in the backtrace above is often considered as a stack frame placed on the call stack.
Most of the times, a backtrace has so many lines that it makes it very difficult to fit the whole backtrace in the visible viewport of the terminal.
Since the backtrace is printed in top to bottom order the meaningful information like error message, exception class and the exact location where the exception was raised is displayed at top of the backtrace. It means developers often need to scroll to the top in the terminal window to find out what went wrong.
Over 4 years ago an issue was created to make printing of backtrace in reverse order configurable.
After much discussion
Nobuyoshi Nakada
made the commit to
print backtrace and error message
in reverse order
only when the error output device (STDERR
)
is a TTY (i.e. a terminal).
Message will not be printed in reverse order
if the original STDERR
is attached to something like a File
object.
Look at the code here
where the check happens
if STDERR
is a TTY
and is unchanged.
Let's execute the same program using Ruby 2.5.
$ RBENV_VERSION=2.5.0 ruby division_service.rb 5 0
Traceback (most recent call last):
2: from division_service.rb:13:in `<main>'
1: from division_service.rb:9:in `divide'
division_service.rb:9:in `/': divided by 0 (ZeroDivisionError)
$
We can notice two new changes in the above backtrace.
This feature makes the debugging convenient when the backtrace size is a quite big and cannot fit in the terminal window. We can easily see the error message without scrolling up now.
Note that,
the Exception#backtrace
attribute
still holds an array of stack frames
like before
in the top to bottom order.
So if we rescue the caught exception and print the backtrace manually
class DivisionService
attr_reader :a, :b
def initialize(a, b)
@a, @b = a.to_i, b.to_i
end
def divide
puts a / b
end
end
begin
DivisionService.new(ARGV[0], ARGV[1]).divide
rescue Exception => e
puts "#{e.class}: #{e.message}"
puts e.backtrace.join("\n")
end
we will get the old behavior.
$ RBENV_VERSION=2.5.0 ruby division_service.rb 5 0
ZeroDivisionError: divided by 0
division_service.rb:9:in `/'
division_service.rb:9:in `divide'
division_service.rb:16:in `<main>'
$
Also,
note that if we assign
STDERR
with a File
object,
thus making it a non-TTY
puts "STDERR is a TTY? [before]: #{$stderr.tty?}"
$stderr = File.new("stderr.log", "w")
$stderr.sync = true
puts "STDERR is a TTY? [after]: #{$stderr.tty?}"
class DivisionService
attr_reader :a, :b
def initialize(a, b)
@a, @b = a.to_i, b.to_i
end
def divide
puts a / b
end
end
DivisionService.new(ARGV[0], ARGV[1]).divide
we can get the old behavior
but the backtrace would be written
to the specified file
and not to STDERR
.
$ RBENV_VERSION=2.5.0 ruby division_service.rb 5 0
STDERR is a TTY? [before]: true
STDERR is a TTY? [after]: false
$ cat stderr.log
division_service.rb:14:in `/': divided by 0 (ZeroDivisionError)
from division_service.rb:14:in `divide'
from division_service.rb:18:in `<main>'
$
This feature has been tagged as experimental feature. What it means is that Ruby team is gathering feedback on this feature.