デバッグモードを使う

Rubyにはグローバル変数$DEBUGが定義されている。これは、Rubyインタプリタに--debugオプションを渡すか、コード$DEBUGをtrueにすることで有効になる。

loggerを使う

Ruby標準ライブラリのLoggerを使って、ログデータをファイルまたは別のストリームに出力する。
ログレベルはFATAL,ERROR,WARN,INFO,DEBUGの５段階。
require 'logger'

log = Logger.new(STDOUT)
#log.level = Logger::ERROR
#log.level = Logger::FATAL
#log.level = Logger::WARN
#log.level = Logger::INFO
log.level = Logger::DEBUG

log.error("Error!!");
log.fatal("Fatal!!");
log.debug("Created logger")
log.info("Program started");
log.warn("Nothing to do!");

出力

E, [2008-09-25T21:37:18.168000 #5664] ERROR -- : Error!!
F, [2008-09-25T21:37:18.168000 #5664] FATAL -- : Fatal!!
D, [2008-09-25T21:37:18.168000 #5664] DEBUG -- : Created logger
I, [2008-09-25T21:37:18.168000 #5664]  INFO -- : Program started
W, [2008-09-25T21:37:18.178000 #5664]  WARN -- : Nothing to do!

Loggerは期間あるいはファイルサイズを元にrotateしてログファイルを交換することもできる。

Logger.new('logfile.log', 'monthly') #月ごとにログファイルを交換 他にdaily, weeklyが指定できる。
Logger.new('logfile.log', 5, 100 * 1024 * 1024) #100MBのログを5つまで保持する
Logger.new('logfile.log', 0, 100 * 1024 * 1024) #100MBでログファイルを交換
datetime_formatを変更することで日付フォーマットを変更できる。
log = Logger.new(STDOUT)
log.datetime_format = "%Y-%m-%d %H:%M:%S"

さらに、Logger::Formatterのcallをオーバーライドすれば、さらに出力を変更できる。

Kernel#callerでコールスタックを調べる。

Kernel#callerによって呼び出し元のメソッドを調べることができる。
class ClassA
	def ClassA.some_methodA
		ClassB.some_methodB
	end
end

class ClassB
	def ClassB.some_methodB
		ClassC.do_action
	end
end

class ClassC
	def ClassC.do_action
		puts 'show trace back'
		caller.each do |c|
			puts c
		end
	end
end

ClassA.some_methodA

出力
show trace back
trace_back.rb:9:in `some_methodB'
trace_back.rb:3:in `some_methodA'
trace_back.rb:22

Breakpointライブラリを使用する

メソッドbreakpointを実行すると、irbの対話型のRubyセッションに切り替わります。

require 'breakpoint'

$KCODE ='sjis'
class Foo
	def initialize(init_val)
		@instance_var = init_val
	end
	def bar
		test_var = @instance_var
		puts 'before break'
		breakpoint
		puts 'after break'
		puts "test_var: #{test_var}, @instance_var: #{@instance_var}"
	end
end

f = Foo.new('start')
f.bar

プロファイリング機能を使用する

アプリケーションにRubyプロファイラをインクルードすると、rubyはアプリケーション終了後に標準エラー出力にレポートを出力する。

require 'profile'

total=0
('a'..'zz').each do |seq|
	['a', 'b', 'c'].each do |i|
		if seq.index(i)
			total += 1
			break
		end
	end
end
puts "Total: #{total}"


出力

Total: 150
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 48.00     0.12      0.12      702     0.17     0.27  Array#each
 24.00     0.18      0.06     1952     0.03     0.03  String#index
 24.00     0.24      0.06        1    60.00   250.00  Range#each
  4.00     0.25      0.01      150     0.07     0.07  Fixnum#+
  0.00     0.25      0.00        1     0.00     0.00  String#<=>
  0.00     0.25      0.00      702     0.00     0.00  String#succ
  0.00     0.25      0.00        1     0.00     0.00  Kernel.puts
  0.00     0.25      0.00        2     0.00     0.00  IO#write
  0.00     0.25      0.00        1     0.00     0.00  Fixnum#to_s
  0.00     0.25      0.00        1     0.00   250.00  #toplevel

プロファイラは最も時間のかかるメソッドからリストアップする。