We should all strive to handle all possible errors in our programs and display nice error messages to the users, but one can hardly be sure that nothing will ever go wrong. That’s why I believe we should try to embed a debug mode that users can take advantage of when submitting the issue or solving the problem. Luckily this is very simple thing to do.
First things first I like to add a well known –debug option to the CLI program. In case you use OptionParser from Ruby standard library:
require 'optparse'
options = {}
parser = OptionParser.new do|opts|
opts.banner = "Usage: invoice_printer [options]"
...
opts.on('--debug') do
options[:debug] = true
end
end
Now our users can enable debug mode! That’s of course not so helpful on it’s own. Let’s say we would like to rescue all random exceptions in our program and display the exception’s message in our nice formatted output (to show we are still in control even though everything broke!).
begin
...our program...
rescue => e
STDERR.puts "ERROR: #{e.message}"
exit 1
end
2 things to notice is that we should always end the program with different exit code than 0 to indicate there was an issue. Many people might use it in scripts and ask on the exit code. Similary we should always print what went wrong to the standard error output (puts prints to standard output). Again other people might call our program from their programs and log any failures including the standard error output.
This is already pretty good, but what about our debug mode?
We can leverage our new debug option to show a bit more. For one the obvious thing would be to show the backtrace of the exception:
...
rescue => e
STDERR.puts "ERROR: #{e.message}"
if options[:debug]
STDERR.puts
STDERR.puts e.backtrace
end
exit 1
end
That’s super helpful since we know exactly from where the error come from. Sometimes however that might not be enough and for this reason we can include a logger that logs what’s happening during the whole runtime of the app in case the debug mode is on:
require 'logger'
logger = Logger.new(STDOUT)
logger.level = Logger::WARN
logger.debug("Created logger")
logger.info("Program started")
logger.warn("Nothing to do!")
This logger example from standard library illustrates how to create a logger that would print to standard output based on the specified level. In our example we could setup level of Logger::DEBUG to log everything in case we are running in debug mode and Logger::INFO for regular run. That way we print debug messages only in the debug mode:
...
require 'logger'
logger = Logger.new(STDOUT)
logger.level = options[:debug] ? Logger::DEBUG : Logger::INFO
# Only when running with --debug
logger.debug { "Intermediate result is " + (variable ** 1024).to_s }
# Logs all the time
logger.info "Running smoothly so far"
Notice that I am using logger.debug { } block syntax to avoid potentially expensive operations I might want to do before printing anything.
Wow, nice we are almost done here right? Yes we are, but I will leave you with one more thing(TM).
You can include the following line in your bin/program file:
$stdout.sync = true if options[:debug]
This way you will always get your output from the standard output when it happens. Otherwise the output you are waiting for can be buffered by Ruby and showed much later!
