【Ruby入門】loggerの使い方まとめ

こんにちは！Webコーダー・プログラマーの貝原（@touhicomu）です。

今日は、Rubyのlog、loggerについて解説します。

この記事では、

• log、loggerについて
• log出力レベルとは
• 基本的なlogの出力方法
• ログの出力先指定
• ログレベルの指定方法
• スタックトレースに改行をつけてログ出力
• ログのファイルサイズ指定
• ログのローテーション

という基本的な内容から、

• datetime_formatによる日付フォーマット
• logのフォーマットの指定方法
• loggerシングルトンの例

などの応用的な使い方に関しても学習していきます。

このページで、Rubyのlog、loggerの使い方をよく把握して自分のスキルとしていきましょう！

log、loggerについて

logとは

logとはRubyの実行中に、途中経過や処理結果などテキストファイルに書き込んだものです。

logは主にバグやエラーの解決、デバッグなどに使用され、webアプリの開発などではとりあえずlogを見れば、問題の大方の推測はつくほどの優れものです。

logは例えば、以下のような表示（出力）をします。

# Logfile created on 2017-09-21 11:15:52 +0900 by logger.rb/56815
W, [2017-09-21T11:15:52.517941 #8136]  WARN -- : ログ3
W, [2017-09-21T11:16:49.831474 #26884]  WARN -- : ログ3

以上のように、

• ログを出力した日付
• ログを出力したRubyのプロセス番号（ここでは#8136や#26884）
• ログのレベル（ここではWARN：警告）
• ログメッセージ（ここでは「ログ3」）

などが出力されています。

なお、プロセス番号とは、OSの元で動いているプログラム一つひとつに付番されたIDです。

ログはカスタマイズすることができて、エラーの発生したファイル名や行番号を付与することもできます。

そのため、エラー解決、デバッグなどの指針に役立ちます。

logレベルとは

logにはlogレベルと呼ばれるものがあります。

logレベルによってlogの重要度が変わってき、logレベルによって出力するログを分けたりできます。

logレベルは以下の6種類に分けることができます。

logレベル	意味
UNKNOWN	常にログとして出力される必要がある未知のメッセージ
FATAL	プログラムをクラッシュさせるような制御不可能なエラー
ERROR	エラー
WARN	警告
INFO	一般的な情報
DEBUG	低レベルの情報

上に行くほどログレベルが高いと呼ばれ、より重要な情報を表しているログを表しています。

loggerとは

loggerとは、Rubyからlogを出力するユーティリティです。

log出力に関する様々な便利な機能を搭載しています。

loggerを使用するには、Rubyのファイル冒頭で、以下のように宣言する必要があります。

require 'logger'

まずは基本的な使い方をみていきましょう。

# loggerライブラリを読み込み
require 'logger'

# ログオブジェクトを生成
log = Logger.new('./rubyflie.log')

# 各ログレベルのログメッセージを'/tmp/rubyflie.log'に出力
log.debug('*debug log')
log.info('*info log')
log.warn('*warn log')
log.error('*error log')
log.fatal('*fatal log')
log.unknown('*unknown log')

実行結果（./rubyflie.log）：

# Logfile created on 2017-09-21 10:59:26 +0900 by logger.rb/56815
D, [2017-09-22T10:08:39.414406 #16980] DEBUG -- : *debug log
I, [2017-09-22T10:08:39.414406 #16980]  INFO -- : *info log
W, [2017-09-22T10:08:39.414406 #16980]  WARN -- : *warn log
E, [2017-09-22T10:08:39.414406 #16980] ERROR -- : *error log
F, [2017-09-22T10:08:39.414406 #16980] FATAL -- : *fatal log
A, [2017-09-22T10:08:39.414406 #16980]   ANY -- : *unknown log

以上のように、Logger.newでloggerオブジェクトを作成した後は、loggerのdebug、info、warn、error、fatal、unknownメソッドを使ってログレベルごとに適したフォーマットでログが出力できます。

また、これらの出力のフォーマットはloggerによりカスタマイズできます。

loggerの出力のフォーマットのカスタマイズ方法は、以降の章で解説していきます。

loggerの基本的な使い方

基本的なlogの出力方法

loggerの基本的な使い方を見ていきます。

以下のサンプルコードでは、先頭の方でloggerオブジェクトを生成しています。

その後、テキストファイルを読み込み、テキストファイルの各行を1行ずつ読み込んでいます。

各行の行頭が#で始まっていない場合は、エラーとみなし、loggerオブジェクトを使ってログに出力しています。

エラーでなければ、putsで標準出力に行を表示しています。

require 'logger'

# loggerを生成し、最大ログ出力レベルをLogger::DEBUGに限定
logger = Logger.new('./filescan.log')
#logger.level = Logger::DEBUG

# データファイル"sample.txt"
filename = "sample.txt"

begin

  # データファイル"sample.txt"を行ごとに読み込む（スキャンする）
  File.foreach(filename) do |line|
  
    # 行頭が#で始まっていなければ、エラー
    unless line.start_with?("#")
    
      # エラーをログする
      logger.error("スキャンエラー: #{line.chomp}")
      
    else
      
      # エラーでなければ、標準出力に出力する
      puts line
    end
  end
rescue => err
  
  # 例外が発生した場合は、その旨ログする
  logger.fatal("例外発生： #{err.message}")
  logger.fatal(err)
  
end

実行結果（./filescan.log）：

# Logfile created on 2017-09-21 11:10:32 +0900 by logger.rb/56815
E, [2017-09-22T10:36:31.543668 #11228] ERROR -- : スキャンエラー: Yes, I am a coffee
E, [2017-09-22T10:36:31.544169 #11228] ERROR -- : スキャンエラー: Must done encrypt!

以上のようにログには「スキャンエラー」の文言とともに、エラーとなった行のテキストが書き出されています。

ログレベルはerrorにしています。

ログの出力先指定

ログの出力先を指定することができます。

出力先は主にファイルですが、標準出力（STDOUT）や標準エラー出力（STDERR）なをも指定することができます。

実際のサンプルコードをみていきましょう。

require 'logger'

# 標準出力へのログ
logger1 = Logger.new(STDOUT)
# 標準エラー出力へのログ
logger2 = Logger.new(STDERR)
# ファイルへのログ
logger3 = Logger.new('tofile1.log')

# ファイルへのログ指定方法その２
file = File.open('tofile2.log', File::WRONLY | File::APPEND | File::CREAT)
logger4 = Logger.new(file)

# 各種loggerへ書き込み
logger1.error("ログ1")
logger2.info("ログ2")
logger3.warn("ログ3")
logger4.debug("ログ4")

実行結果（標準出力・標準エラー出力）：

E, [2017-09-22T10:39:15.593142 #10372] ERROR -- : ログ1
I, [2017-09-22T10:39:15.593643 #10372]  INFO -- : ログ2

実行結果（tofile1.log）：

# Logfile created on 2017-09-21 11:15:52 +0900 by logger.rb/56815
W, [2017-09-21T11:15:52.517941 #8136]  WARN -- : ログ3

実行結果（tofile2.log）：

D, [2017-09-22T10:41:28.441136 #10536] DEBUG -- : ログ4

以上のような実行結果になりました。

標準出力と標準エラー出力にもログを出力できています。

標準出力にログを出力する場合は、Logger.newメソッドに「STDOUT」を指定します。

標準エラー出力にログを出力する場合は、Logger.newメソッドに「STDERR」を指定します。

ファイルにログを出力する場合は、Logger.newメソッドにファイル名を指定します。

File.openメソッドで開いたファイルにログを出力する場合は、Logger.newメソッドにそのファイルのオブジェクトを指定します。

なお、File.openメソッドで開いたファイルにログを出力する場合のみ、ログの先頭のヘッダーは出力されません。

ログレベルの指定方法

ログレベルの指定は、loggerオブジェクトのerror、info、warn、debugなどのメソッドを使用することで、ログレベルをそれぞれERROR、INFO、WARN、DEBUGなどを指定したことになります。

また、ログに出力する最大ログレベルを指定することができます。

これの最大ログレベルをプログラムで切り替えられるようにすることで、例えば本番系のシステムとテスト系のシステムで、ログの出力情報の量や質を変更できます。

ログ最大レベルはLoggerのlevelプロパティにLoggerの定数（Logger::WARNなど）を指定することで有効になります。

実際のサンプルコードをみていきましょう。

require 'logger'
# loggerの生成
logger = Logger.new('loglevel.log')

# ログ最大出力レベルをWARNに
# ログの優先度レベルは、DEBUG < INFO < WARN < ERROR < FATAL < UNKNOWN の順になる
logger.level = Logger::WARN

# 各種ログ出力
logger.error("ログ1")
logger.info("ログ2")
logger.warn("ログ3")
logger.debug("ログ4")

実行結果（loglevel.log）：

# Logfile created on 2017-09-21 11:18:31 +0900 by logger.rb/56815
E, [2017-09-21T11:18:31.563299 #27404] ERROR -- : ログ1
W, [2017-09-21T11:18:31.563299 #27404]  WARN -- : ログ3

以上のように、levelにLogger::WARNを指定しました。

ログの優先度レベルは、DEBUG < INFO < WARN < ERROR < FATAL < UNKNOWNの順になるため、上記サンプルコードでは、DEBUGとINFOのログの情報は出力されていません。

また、WARN以上のログレベルであるERRORとWARNのログの情報は出力されています。

スタックトレースに改行をつけてログ出力

ログはデバッグする際に便利な情報です。

ここで、エラーや例外が発生した箇所のスタックトレースをログに出力できれば便利です。

スタックトレースとは、プログラムを実行している時の現在地のメソッド名やローカル変数の情報を、メソッド呼び出しのたびに段を積み上げて（スタックして）保存している情報のことです。

その情報をデバッグ時にプログラムのどのメソッドやローカル変数の情報を得ているか追跡（トレース）しやすいように加工したものを、総称してスタックトレースと言います。

通常、例外のスタックトレースは配列になっています。

そのため、配列のjoinメソッドに"\n"をしていて、配列から"\n"で区切られた文字列に変換します。

例外オブジェクトをerrとすると、スタックトレースは「err.backtrace.join("\n")」で、スタックを1行ごとに改行したテキストになります。

この情報をログに出力してみましょう。

実際のサンプルコードは以下のようになります。

require 'logger'

# loggerを生成し、最大ログ出力レベルをLogger::DEBUGに限定
logger = Logger.new('./filescan2.log')
#logger.level = Logger::DEBUG

# データファイル"sample.txt"
filename = "sample.txt"

begin

  # データファイル"sample.txt"を行ごとに読み込む（スキャンする）
  File.foreach(filename) do |line|
  
    # 行頭が#で始まっていなければ、例外
    unless line.start_with?("#")
    
      # 例外を投げる
      throw
      
    else
      
      # エラーでなければ、標準出力に出力する
      puts line
    end
  end
rescue => err
  
  # スタックトレースに改行をつけてログ出力する
  logger.fatal(err.backtrace.join("\n"))
  
end

実行結果（./filescan2.log）：

# Logfile created on 2017-09-21 11:34:03 +0900 by logger.rb/56815
F, [2017-09-21T11:34:03.013734 #20508] FATAL -- : 
logger_stacktrace.rb:19:in `throw'
logger_stacktrace.rb:19:in `block in <main>'
logger_stacktrace.rb:13:in `foreach'
logger_stacktrace.rb:13:in `<main>'

以上のような実行結果になりました。

ファイル「sample.txt」を1行ごと読み込み、各行が"#"で始まっていなければエラーとして例外を投げています。

例外が投げられると、rescueブロックに処理が移ります。

rescueブロックにて、例外にふくまれるスタックトレースの情報をログに出力しています。

実行結果をみると、スタックトレースの情報を、スタックあたり1行ずつ出力していることがわかります。

これで、エラーの発生箇所がわかりやすくなります。

エラーの発生したファイル名や行番号がわかりますので、デバッグがしやすくなります。

なお、Rubyのrescueについて詳しくは、以下の記事を参照してください。

ログのファイルサイズ指定

ログファイルサイズが大きくなると扱いにくくなります。

そのため、Loggerクラスにはログファイルのサイズを指定できます。

また、指定サイズいっぱいになった場合、古くなったログのファイル名を変更してバックアップとして残すこともできます。

バックアップログファイルも多くなりすぎるとディスク容量を圧迫しますので、何世代まで残すか指定でできます。

指定した世代を超えた世代のバックアップログファイルは自動的に削除されます。

実際のサンプルコードをみてみましょう。

require 'logger'

# 5世代までログを残す
nth = 5

# 1ログファイルあたり10MBまでの容量にする
filesize = 1024 * 10

# 5世代1ログファイルあたり10MBまでのloggerを生成
logger = Logger.new('ruby_size_limit.log', nth, filesize)

以上のように、Loggerのnewメソッドの第2引数に管理する世代、第3引数にログファイルの最大サイズを指定します。

ログのローテーション

前章では、ログのファイルサイズと世代管理の方法を解説しました。

この章では、別の方法でログファイルを管理する方法を解説します。

Loggerのnewメソッドの第2引数に、以下の文字列を渡した場合、期間を決めてログをファイル名変更し、過去のログファイルとします。

文字列	意味
'daily'	1日ごと
'weekly'	1週間ごと
'monthly'	1か月ごと

この期間ごとに順繰りにログファイルをバックアップすることを、ログをローテーションさせると言います。

require 'logger'

# 1日ごとにログをローテーションするloggerを生成
logger1 = Logger.new('daily.log', 'daily')

# 1週間ごとにログをローテーションするloggerを生成
logger2 = Logger.new('weekly.log', 'weekly')

# 1か月ごとにログをローテーションするloggerを生成
logger3 = Logger.new('monthly.log', 'monthly')

以上のように、Loggerのnewメソッドの第2引数に、ローテーションさせる期間の文字列を指定します。

loggerの応用的な使い方

datetime_formatによる日付フォーマット

loggerオブジェクトのログの日時の出力フォーマットは変更できます。

Loggerクラスのdatetime_formatプロパティに、フォーマット付き文字列を設定すれば、カスタマイズが可能です。

なお、datetime_formatに指定する際、以下のキーワードが使用できます。

キーワード	意味
%Y	年
%m	月
%d	日
%H	時
%M	分
%S	秒

なお、Rubyの日付のフォーマットとキーワードについて詳しくは、以下の記事を参照してください。

実際のサンプルコードをみてみましょう。

require 'logger'

logger = Logger.new('date_format.log')

logger.datetime_format = '【%Y-%m-%d (%H:%M:%S)】'

logger.info('ログ情報')

実行結果（date_format.log）：

# Logfile created on 2017-09-21 12:01:56 +0900 by logger.rb/56815
I, [【2017-09-21 (12:01:56)】#6632]  INFO -- : ログ情報

以上のように、datetime_formatプロパティにフォーマット文字列を設定することで、ログの日時の出力フォーマットを変更できました。

logのフォーマットの指定方法

ログ情報は日付以外にも全体のフォーマットを変更可能です。

LoggerクラスのformatterプロパティにProcオブジェクトを渡せば、ログ出力時にProcの引数に下記の値が渡されます。

変数名	意味
severity	ログレベル
datetime	日時
progname	プログラム名
msg	ログメッセージ

これらの値を使って、ログ情報を好きなようにフォーマットすることができます。

実際のサンプルコードをみていきましょう。

require 'logger'

logger = Logger.new('log_format.log')

# ログフォーマットの変更
logger.formatter = proc do |severity, datetime, progname, msg|
  "！#{severity}！【#{datetime}】(#{progname}): #{msg}\n"
end

logger.info('ログ情報')

実行結果（log_format.log）：

# Logfile created on 2017-09-21 12:05:18 +0900 by logger.rb/56815
！INFO！【2017-09-21 12:05:18 +0900】(): ログ情報

以上のような実行結果になりました。

このように、ログを自由なフォーマットで出力することができます。

loggerシングルトンの例

loggerオブジェクトは何個でも生成することができます。

しかし、loggerオブジェクトが増えると、メモリ容量が圧迫されます。

そこで、一つのloggerオブジェクトを生成し、それを使いまわすことでメモリ容量を消費しないようにできます。

デザイン・パターンと呼ばれるオブジェクト指向プログラミングの設計技法のテンプレートの一つである、シングルトン（singleton）・パターンを使ってみます。

シングルトン・パターンは、プログラム全体の中でオブジェクトがただ一つしなかい（シングル）オブジェクトの使用方法です。

実際のサンプルコードをみていきましょう。

require 'logger'

class MyLogger
  @@logger = nil
  def self.getLogger
    if @@logger.nil?
      @@logger = Logger.new('./log_singleton.log')
    end
    return @@logger
  end
end

logger = MyLogger.getLogger
logger.level = Logger::INFO

logger.warn('警告')

実行結果（./log_singleton.log）：

# Logfile created on 2017-09-21 12:21:33 +0900 by logger.rb/56815
W, [2017-09-21T12:21:33.150118 #18128]  WARN -- : 警告

上記サンプルコードでは、まず@@loggerをnil?で初期化しています。

そして、getLoggerが呼ばれた際、@@loggerがnilであればLogger.newメソッドでオブジェクトを生成し、nilでない場合そのまま@@loggerオブジェクトを返しています。

プログラムでは、常にgetLoggerの返値のオブジェクトを使用しています。

プログラム全体では、@@loggerオブジェクトはただ1つです。

その@@logerをプログラ全体で使いまわしています。

これにより、メモリ消費量を抑えることができます。

まとめ

今回はRubyのlogについてついて学習しました！

学習のポイントを振り返ってみましょう！

• logはプログラムのデバッグ用のデータでloggerオブジェクトを使う
• logレベルは複数あり重要度に応じてログレベルを指定する
• スタックトレースをログに出力できる
• ログファイルサイズ、ログローテーションによりログを世代管理できる
• ログの出力フォーマットは日付も含めカスタマイズできる
• loggerはシングルトンクラスを作って管理することもできる

以上の内容を再確認し、ぜひ自分のプログラムに生かし学習を進めてください！