Golangでログを吐くコツ

  • Author: MURAOKA Taro
  • Date: 2018/12/16
  • golang
  • log

Golangでログを吐く際のコツっていうか気にして欲しいことをまとめます。

この記事は Go Advent Calendar 2018 の16日目の記事です。

Golangでプログラムを書く時にログを吐くの、どうしてますか? 本記事ではログを吐く際のコツというか気にして欲しい事項と、 なぜそうなるのかを解説していきます。

一概に「ログを吐く」と言っても、 ライブラリからログを吐く場合とアプリケーションから吐く場合では 相当に事情が異なります。

TL;DR

  • ライブラリ(パッケージ)を書く時は…
    • まずログを吐かないことを検討しましょう。 error で返してライブラリのユーザーにログへ吐かせるかどうかを選ばせましょう。
    • *log.Logger を使いましょう。 デフォルトは log.Printf に対して吐き(またはそれと同等のログを吐く)、 ライブラリユーザーの設定で任意の *log.Logger に切り替えられるようにしましょう。
    • 自前の Logger インターフェースを定義しましょう。 ロガー構造体ではないことに注意してください。 またデフォルトの実装として *log.Logger を出力先とするものを用意すると良いでしょう。
    • 既存のロギングライブラリを使うのは絶対に止めましょう。 あなたのライブラリの機能を使いたいだけなのに特定のロギングライブラリを強制されるのは、 ライブラリのユーザーにとっては苦痛でしかありません。
  • アプリを書く時は…
    • *log.Logger を使いましょう。
    • 既存のロギングライブラリから必要なものを選びましょう。
    • 自分で必要なロガーを作っちゃえYO!

ライブラリのロギング

あなたが出している そのログ 本当に必要ですか? ライブラリの著者が安心したいがためだけに出していないですか? 将来起こるかもしれないトラブルシューティングのためにログを出力していないですか? ライブラリの大半のユーザーは、ログが出力されたとしてもその意味がわかりません。 当然どのようなアクションが求められているかもわかりません。 つまり そのログ は出すだけ無駄である可能性が高いのです。

ユーザーにとってアクションが必要なログならばむしろ error として返しましょう。 そうすればライブラリのユーザーが単にログに出すのか、 実際にエラーとしてアプリの実行を止めるのか選べます。 将来起こるかもしれないトラブルがあるのならば、 そのようなトラブルが発生しないように設計を見直しましょう。

ライブラリで *log.Logger を使う場合

ライブラリで *log.Logger を使う場合のサンプルコードを示します。 *log.Logger の変数を公開しておきユーザーからの設定を許しています。 ライブラリ内では logf() 関数を通じてログを出力するようにします。

package myawesome

import "log"

var Logger *log.Logger

func logf(format string, v ...interface{}) {
    if Logger == nil {
        log.Printf(format, v...)
        return
    }
    Logger.Printf(format, v...)
}

これを使うアプリ側がロガーを入れ替えたい場合、 次のコードで示すように init() などプログラム実行の早い時点で差し替えます。

package main

import (
    "log"
    "os"
    "github.com/koron/myawesome"
)

func init() {
    myawesome.Logger = log.New(os.Stdout, "myapp", log.LstdFlags)
}

ロガー入れ替え時の排他が気になる場合は、 ロガーの変更を関数化して sync.Mutex などで排他すると良いです。 またログ関数内での if が気になる場合は、 デフォルトのロガーをライブラリ側で用意しても良いです。 以下にその両方を行ったサンプルコードを示します。

package myawesome

import (
    "log"
    "os"
    "sync"
)

var (
    logger  = log.New(os.Stderr, "", log.LstdFlags)
    logMu   sync.Mutex
)

fun SetLogger(l *log.Logger) {
    if l == nil {
        l = log.New(os.Stderr, "", log.LstdFlags)
    }
    logMu.Lock()
    logger = l
    logMu.Unlock()
}

func logf(format string, v ...interface{}) {
    logMu.Lock()
    logger.Printf(format, v...)
    logMu.Unlock()
}

このようにすることで、 ライブラリのユーザーは自分の好きなログ出力先を選べるようになります。

ライブラリで自前の Logger インターフェースを定義する

どうしてもレベル別のログを出力したいなどの特別な要求がある場合には、 ライブラリ側で自前の Logger インターフェース を定義しましょう。 各メソッドのシグネチャはよくあるロギングライブラリに合わせておくと良いでしょう。 加えてデフォルトの実装として *log.Logger へ出力するものを用意すれば、 golang の標準的なログの仕組みに則れて扱いやすくなります。

以下に示すサンプルコードはライブラリが warning と debug レベルのログを出力することを想定しています。 デフォルトの実装では warning のみを *log.Loggerへ出力しています。 前節で示した排他はしていません。 ライブラリのコードはログを出力する際に logger.Warnf() 及び logger.Debugf() を直接呼ぶことを想定しています。

package myawesome

import (
    "log"
    "os"
)

type Logger interface {
    Warnf(string, ...interface{})
    Debugf(string, ...interface{})
}

var logger Logger = &BasicLogger{
    Logger: log.New(os.Stderr, "", log.LstdFlags),
}

func SetLogger(l Logger) {
    logger = l
}

type BasicLogger struct {
    Logger *log.Logger
}

func (bl *BasicLogger) Warnf(format string, v ...interface{}) {
    bl.Logger.Printf(format, v...)
}

func (bl *BasicLogger) Debugf(format string, v ...interface{}) {
    // suppress debug logs
}

このような Logger インターフェースが定義されていれば、 ライブラリのユーザーはアプリの要求に応じて *log.Logger を使うことも それ以外のロギングライブラリを使うことも、 適切なラッパーを容易に書けます。 そんなラッパーの雛形を以下のコードに示します。

package main

import "github.com/koron/myawesome"

func init() {
    myawesome.SetLogger(&appLogger{})
}

type appLogger struct {}

func (l *appLogger) Warnf(format string, v ...interface{}) {
    // TODO: wrap your favorite logger.
}

func (l *appLogger) Debugf(format string, v ...interface{}) {
    // TODO: wrap your favorite logger.
}

既存のロギングライブラリは絶対にNG

ライブラリを書く際に既存のロギングライブラリを使うのは絶対にやめましょう。 あなたのライブラリのユーザーはあなたが提供する機能を使いたいのであって、 あなたが使いたいロギングライブラリを使いたいわけではないのです。

アプリのロギング

ライブラリのロギングに比べてアプリのロギング戦略はシンプルです。

まずは *log.Logger で十分かを検討しましょう。 ローテートなどはOSの標準のものを使うのがもっとも汎用的です。 ログの出力先はコンテナなどでの実行を考えると、 標準出力やエラー出力に出してしまうのがもっとも汎用的と言えます。 それらを考え合わせると案外 *log.Logger で十分というケースも多いのです。

一方で *log.Logger はフォーマットの選択肢やログレベル制御の観点から 不十分である場合も多々あります。 そんな場合は積極的に有名所のロギングライブラリを利用しましょう。 どのロギングライブラリが良いかはそれぞれのアプリの要求がありますから、 本記事では触れません。

仕事だと最近は DevOps などもあり、 アプリのログへの要求が漸進的に変化することも珍しくありません。 要求が変化していく中で、 既存のロギングライブラリでは機能とコスト両面でマッチしなくなる場合もあります。 そんな時は思い切って自分で書いてしまうのもありです。 $GOROOT/log/log.go のコードを見てください。 わずか400行もありません。 これをコピペして必要なコードを追加して要らないところを消してってするだけで、 あなたが必要とする最速ロガーが誕生します。

記事の終わりに

本記事に書いたログに対するネタは、 お仕事でとあるサーバーを書いている際に、 利用している各ライブラリのログを統合してオペレーション的に必要なログに整形する際にえらく苦労したところに端を発しています。 大きく困った点は2つで、 ライブラリが使ってたロギングライブラリが勝手に引数を追加しやがったのと、 そのログ吐かれても…どうして良いかわからなくて困る、というやつでした。 そういうのが将来少しでも減ってくれたらなって思いを込めて記事にしました。

では良い golang ライフを。