Log パッケージで遊ぶ
今回は Go 言語の標準パッケージに含まれる log
について。
log
パッケージは,名前の通り,ログ出力を行うパッケージである。
例えば以下のように書ける。
package main
import (
"log"
)
func main() {
log.Println("Hello, World")
}
これを実行すると以下のフォーマットで標準エラー出力に出力される。
2009/11/10 23:00:00 Hello, World
Log パッケージの中身
具体的に log
パッケージを見てみよう。
// A Logger represents an active logging object that generates lines of
// output to an io.Writer. Each logging operation makes a single call to
// the Writer's Write method. A Logger can be used simultaneously from
// multiple goroutines; it guarantees to serialize access to the Writer.
type Logger struct {
mu sync.Mutex // ensures atomic writes; protects the following fields
prefix string // prefix to write at beginning of each line
flag int // properties
out io.Writer // destination for output
buf []byte // for accumulating text to write
}
// Printf calls l.Output to print to the logger.
// Arguments are handled in the manner of fmt.Printf.
func (l *Logger) Printf(format string, v ...interface{}) {
l.Output(2, fmt.Sprintf(format, v...))
}
// Output writes the output for a logging event. The string s contains
// the text to print after the prefix specified by the flags of the
// Logger. A newline is appended if the last character of s is not
// already a newline. Calldepth is used to recover the PC and is
// provided for generality, although at the moment on all pre-defined
// paths it will be 2.
func (l *Logger) Output(calldepth int, s string) error {
now := time.Now() // get this early.
var file string
var line int
l.mu.Lock()
defer l.mu.Unlock()
if l.flag&(Lshortfile|Llongfile) != 0 {
// Release lock while getting caller info - it's expensive.
l.mu.Unlock()
var ok bool
_, file, line, ok = runtime.Caller(calldepth)
if !ok {
file = "???"
line = 0
}
l.mu.Lock()
}
l.buf = l.buf[:0]
l.formatHeader(&l.buf, now, file, line)
l.buf = append(l.buf, s...)
if len(s) == 0 || s[len(s)-1] != '\n' {
l.buf = append(l.buf, '\n')
}
_, err := l.out.Write(l.buf)
return err
}
ログ出力時は log
.Logger
内部のバッファを使って整形するため,複数の goroutine から非同期に呼ばれる可能性を考慮し, sync
.Mutex
を使って排他的に処理している。
Log のカスタマイズ
log
パッケージではログの出力先や出力フォーマットをある程度カスタマイズできる。
たとえば,こんな感じ。
package main
import (
"log"
"os"
)
func main() {
log.SetFlags(log.LstdFlags | log.Lmicroseconds | log.Lshortfile)
log.SetOutput(os.Stdout)
log.SetPrefix("[Hello] ")
log.Println("Hello, World")
}
この場合,以下の形式で標準出力に出力される。
[Hello] 2009/11/10 23:00:00.000000 main.go:13: Hello, World
また log
.New()
関数で新たな log
.Logger
インスタンスを作成することもできる。
package main
import (
"log"
"os"
)
func main() {
l := log.New(os.Stdout, "[Hello] ", log.LstdFlags|log.Lmicroseconds|log.Lshortfile)
l.Println("Hello, World")
}
このコードのログ出力は先ほどと同じになる。
出力レベルとフィルタリング
log
パッケージの欠点は出力のフィルタリングができないことである。
ログメッセージ毎に ERROR, WARN, INFO, DEBUG といった出力レベルの設定を行い,あらかじめ指定したレベル以下のメッセージについてはフィルタリングできる仕掛けが欲しいところである。
サードパーティーではフィルタリング機能を持つ logger が色々あるが,せっかく log
パッケージが「できる子」なんだから,なるべく生かした形で実装を考えてみる。
フィルタリング付き Writer
まずは,出力時にフィルタリングを行う Writer を考えてみる。 有り難いことに既にこの機能を持ったパッケージが存在する。
これは log
.Logger
インスタンスにセットする Writer をラップしてフィルタリング機能を付加するものである。
こんな感じで使うらしい。
package main
import (
"log"
"os"
"github.com/hashicorp/logutils"
)
func main() {
filter := &logutils.LevelFilter{
Levels: []logutils.LogLevel{"DEBUG", "WARN", "ERROR"},
MinLevel: logutils.LogLevel("WARN"),
Writer: os.Stderr,
}
log.SetOutput(filter)
log.Print("[DEBUG] Debugging") // this will not print
log.Print("[WARN] Warning") // this will
log.Print("[ERROR] Erroring") // and so will this
log.Print("Message I haven't updated") // and so will this
}
これを実行するとこんな感じになる。
2009/11/10 23:00:00 [WARN] Warning
2009/11/10 23:00:00 [ERROR] Erroring
2009/11/10 23:00:00 Message I haven't updated
あらかじめキーワード("DEBUG"
など)を決めておいて,ログ出力する文字列にこのキーワードを埋め込むことで出力レベルの設定とフィルタリングを行うようだ。
実際には埋め込むキーワードの typo を防ぐために何らかの仕掛けを作る必要があると思うが,とてもシンプルな作りなので,気軽に導入できそうである。
Logger に渡す前にフィルタリングする
hashicorp/logutils は Writer への書き込み時にフィルタリングを行うものだったが,別のアプローチで log
.Logger
に渡す前にフィルタリングすることを考えてみる。
というわけで作ってみた。
logf
.Logger
はこんな感じで log
.Logger
インスタンス(へのポインタ)を内部に持つ。
//Logger is logger class
type Logger struct {
lg *log.Logger // logger
mu sync.Mutex // ensures atomic writes; protects the following fields
flag int // properties
min Level
}
実際の出力はこんな感じにしてみた。
//Output writes the output for a logging event.
func (l *Logger) Output(lv Level, calldepth int, s string) error {
if lv >= l.min {
if (l.flag & Llevel) != 0 {
return l.lg.Output(calldepth, fmt.Sprintf("[%v] %s", lv, s))
}
return l.lg.Output(calldepth, s)
}
return nil
}
出力レベルのチェック時に排他処理を行っていないが,値の参照だけで状態を変えるわけではないので,まぁいいかなと。
これを使ってログ出力のコードを書いてみる。
package main
import (
"os"
"github.com/spiegel-im-spiegel/logf"
)
func main() {
logf.SetOutput(os.Stdout)
logf.SetMinLevel(logf.WARN)
logf.Debug("Debugging") // this will not print
logf.Print("Information") // this will not print
logf.Warn("Warning") // this will
logf.Error("Erroring") // and so will this
}
これを実行するとこんな感じになる。
2009/11/10 23:00:00 [WARN] Warning
2009/11/10 23:00:00 [ERROR] Erroring
んー。 杜撰なコードだが,取り敢えずこんな感じかな。
【追記】ログファイルの分割とローテーション
もうひとつ log
パッケージにない機能としてログファイルの分割とローテーション機能がある。
たとえば Apache HTTP Server の rotatelogs のような機能があると便利である。
と思って探したらありましたよ。
rotatelogs
パッケージと先ほどの logf
パッケージを組み合わせれば,こんな感じに書ける。
package main
import (
rotatelogs "github.com/lestrrat-go/file-rotatelogs"
"github.com/spiegel-im-spiegel/logf"
)
func main() {
logf.SetMinLevel(logf.WARN)
rl, err := rotatelogs.New("./log.%Y%m%d%H%M.txt")
if err != nil {
logf.Fatal(err)
return
}
logf.SetOutput(rl)
logf.Debug("Debugging") // this will not print
logf.Print("Information") // this will not print
logf.Warn("Warning") // this will
logf.Error("Erroring") // and so will this
}
よーし,うむうむ,よーし。
ブックマーク
構造化ログ
- rs/zerolog: Zero Allocation JSON Logger : JSON 形式でログを吐く。おススメ
- hnakamur/ltsvlog: a minimalist LTSV logging library in Go : LTSV 形式でログを吐く
その他
- golangでlogを標準出力とテキストファイルの2箇所の出力する - Qiita
- Goのバッチで統計を取得するAPIを用意しておくと便利 - Qiita
- ええっ!? 文字列で書くの!? ログレベル付きロガーhashicorp/logutilsのご紹介 - Qiita
- 標準出力に表示をしながらファイルにも保存して、かつローテーションもする - Qiita
- GitHub - spf13/jWalterWeatherman: So you always leave a note
参考図書
- プログラミング言語Go (ADDISON-WESLEY PROFESSIONAL COMPUTING SERIES)
- Alan A.A. Donovan (著), Brian W. Kernighan (著), 柴田 芳樹 (翻訳)
- 丸善出版 2016-06-20
- 単行本(ソフトカバー)
- 4621300253 (ASIN), 9784621300251 (EAN), 4621300253 (ISBN), 9784621300251 (ISBN)
- 評価
著者のひとりは(あの「バイブル」とも呼ばれる)通称 “K&R” の K のほうである。この本は Go 言語の教科書と言ってもいいだろう。
-
lestrrat-go/file-rotatelogs パッケージは Perl の File::RotateLogs から Go 言語へのポーティングのようだ。 ↩︎