技術ブログ

defer 文を使ったロギング処理

author: yterajimadate: 2016-08-30tags: golang

購入したまま放置してしまっていた プログラミング言語Go をようやく読み終わりました。機能を考えればできるけれど言われないと思いつかない, ような使い方が書かれていて良かったです。

その中で defer 文を使ったロギング処理について使えそうな処理方法があったのでまとめてみます。

defer 文の特徴

defer 文に渡された関数は処理が完了した時点で実行されます。例えば HTTP レスポンス Body を closeし忘れないように defer を使います。

var fetch = func(URL string) ([]byte, error) {
    var body []byte

    res, err := http.Get(URL)
    if err != nil {
      return body, err
    }
    defer res.Body.Close()

    return ioutil.ReadAll(res.Body)
}

ロギングに使う

プログラミング言語Goサンプル: trace

このサンプルでは defer 文を使って実行終了時にログを書き出します。この方法を使うと処理途中でエラーが発生して return するような場合にも defer は実行されるのでログの書き出し漏れが防げます。終了する度に必ず関数を呼び出す, というのも手ですが重複するコードの行数が増えてしまうので芳しくありません。

このサンプルコードの場合, 特定のメッセージをログに残すことしかできませんが, このアイデアを用いてメソッドを使うと上手くログが取れるようです。

構造体とメソッドを使った例

The Go Palyground

import (
    "log"
    "time"
)

func main() {
    h := hoge{id: 100, start: time.Now()}
    defer h.trace()()

    time.Sleep(time.Second * 1)
    h.msg = "completed!!"
    h.end = time.Now()
}

type hoge struct {
    id    int
    start time.Time
    end   time.Time
    msg   string
}

func (h *hoge) trace() func() {
    log.Printf("start id:%d time:%s pointer:%p", h.id, h.start, h)
    return func() {
      log.Printf("complete id:%d exec:%s msg:%s time:%s pointer:%p", h.id, time.Since(h.start), h.msg, h.end, h)
    }
}

構造体にログに必要なフィールドを用意しておいて, defer が実行される前に必要な情報を与えるとログに書き出すことができるようです。これであれば特定のエラー時にメッセージ内容を変更したり, デバッグ情報を追加することができます。

(ここまでやるなら直接ログ用の関数を呼び出した方が早い?)