log.Printlnとfmt.Printlnの違いについてまとめる
[到達していたい状態]
- logパッケージについての理解を深める
- fmtパッケージについての理解を深める
- log.Printlnとfmt.Printlnの違いを人に説明できる
- logがもっと良いやり方がないかを探す
[やること]
- 公式ドキュメントを読む
- コードを書く
logパッケージ
logパッケージは、シンプルなロギングパッケージを実装しています。Loggerという型を定義しており、
出力をフォーマットするためのメソッドを備えています。また、ヘルパー関数Print[f|ln]、Fatal[f|ln]、Panic[f|ln]からアクセスできる定義済みの「標準」ロガーがあり、ロガーは手動で作成するより簡単に使用できます。そのロガーは、標準エラーに書き込み、各ログメッセージの日付と時刻を表示します。印刷されるメッセージが改行で終わらない場合、ロガーは改行を追加します。Fatal関数は、ログメッセージを書き込んだ後、os.Exit(1)を呼び出します。パニック関数は、ログメッセージを書き込んだ後、panicを呼び出します。
なるほど。めちゃくちゃシンプルだな。ログレベルとかもない。
ロガーは標準エラー出力に対して書き込むのか
fmtパッケージ
fmtパッケージは、Cのprintfとscanfに類似した関数で、フォーマットされたI/Oを実装しています。フォーマットの「動詞」はCのものを継承していますが、よりシンプルになっています。
今更深ぼるほどでもないけど、一応引用しておく
log.Printlnとfmt.Printlnの違い
出力結果が結構違う。
log.Printlnの場合、エラーが出た年月日と時間の情報が付与されている。
あと、fmt.Printlnは標準出力に対して出力される。log.Printlnは標準エラー出力に対して出力される。
package main
import (
"errors"
"fmt"
"log"
)
var ErrFoo = fmt.Errorf("foo")
var ErrBar = errors.New("bar")
func main() {
err := doSomething()
if err != nil {
log.Println(err) // => 2023/06/16 01:55:22 foo
fmt.Println(err) // => foo
}
}
func doSomething() error {
return ErrFoo
}
参考記事
ログレベル
ついでにログレベルについても調べてみた。
ログレベルとは、ログの緊急度を表すレベルのこと。
代表的なログライブラリのLog4jには以下の6つのログレベルが定義されている。
レベル | 概要 | 説明 | 運用時の対応 |
---|---|---|---|
FATAL | 致命的なエラー | プログラムの異常終了を伴うようなもの。コンソール等に即時出力することを想定 | 即時対応が必要 |
ERROR | エラー | 予期しないその他の実行時エラー。コンソール等に即時出力することを想定 | 営業時間内のみ対応 |
WARN | 警告 | 廃要素となったAPIの使用、APIの不適切な使用、エラーに近い事象など、実行時に生じた異常とは言い切れないが正常とも異なる何らかの予期しない問題。コンソール等に即時出力することを想定 | 次回リリースまでに対応 |
INFO | 情報 | 実行時の何らかの注目すべき事象(開始や終了など)。コンソール等に即時出力することを想定。従ってメッセージ内容は簡潔に止めるべき | 対応不要 |
DEBUG | デバッグ情報 | システムの動作状況に関する詳細な情報。コンソールではなくログ上にだけ出力することを想定 | 出力しない |
TRACE | トレース情報 | デバッグ情報よりも更に詳細な情報。コンソールではなくログ上にだけ出力することを想定 | 出力しない |
ちなみに最近出たGoの標準ログパッケージのslogには以下のログレベルが定義されている。
レベルが大きいほどより深刻なイベントを意味するそう。
type Level int
const (
LevelDebug Level = -4
LevelInfo Level = 0
LevelWarn Level = 4
LevelError Level = 8
)
参考記事
slogパッケージについて深ぼる
slogパッケージとは、構造化ロギングパッケージである。slogのsはおそらくStructured(構造化)のsである。
logパッケージとslogパッケージを比較したときの、slogパッケージのメリット
- 構造化ログとログレベルを提供している
- Zapのようにパフォーマンスにも重点をおいている
- logrのようにロギングライブラリのためのインタフェースを提供
- 既存のロギングライブラリを置き換えるものではない
- 既存のロギングライブラリに親しみが無いユーザでも扱える
- JSONなどの機械処理しやすい形式にログを出力できるようになっている。
1.21からslogが使えるのか。brewではgo 1.20. 5までしかアップデートできないからしばらく使えないそう。そしたらzapを使うか
Zap
Zapもslogと似ていて、構造体でログ情報を出力できるライブラリである。
logパッケージとZapパッケージを比較したときの、Zapパッケージのメリット
- パフォーマンスにも重点をおいている
- ロギング時間、ログレベル、ロギングした行、メッセージと構造化されたメッセージを表示できる
- 構造体のフィールドのvalueの型が設定しやすい
package main
import (
"errors"
"fmt"
"log"
"os"
"time"
"github.com/joho/godotenv"
"go.uber.org/zap"
)
var ErrFoo = fmt.Errorf("foo")
var ErrBar = errors.New("bar")
func main() {
err := doSomething()
if err != nil {
log.Println(err) // => 2023/06/16 01:55:22 foo
fmt.Println(err) // => foo
err := godotenv.Load(fmt.Sprintf("../env/%s.env", os.Getenv("GO_ENV")))
if err != nil {
logger := GetLogger()
logger.Info("Hello zap", zap.Error(err), zap.Time("logged_at", time.Now()))
}
logger := GetLogger()
// ロギング時間、ログレベル、ロギングした行、メッセージと構造かされたメッセージが表示される
// zap.Stringやzap.Timeは構造体のフィールドを定義している。
// StringとかTimeとかは、valueの型を表している。
logger.Info("Hello zap", zap.String("key", "value"), zap.Time("now", time.Now()))
// => 2023-06-21T00:01:13.019+0900 INFO cmd/main.go:22 Hello zap {"key": "value", "now": "2023-06-21T00:01:13.019+0900"}
// Warn以降スタックトレースもついてくる
logger.Warn("Hello zap", zap.String("key", "value"), zap.Time("now", time.Now()))
// => 2023-06-21T00:10:02.403+0900 WARN cmd/main.go:26 Hello zap {"key": "value", "now": "2023-06-21T00:10:02.403+0900"}
// main.main
// /Users/yuuki_haga/repos/go/go-sandbox/cmd/main.go:26
// runtime.main
// /usr/local/go/src/runtime/proc.go:250
p := os.Getenv("DB_PORT")
fmt.Println(p)
}
}
func doSomething() error {
return ErrFoo
}
// 開発環境と本番環境で分ける
// dev用はconsole形式で出力
// prd用はjson形式で出力
func GetLogger() *zap.Logger {
var logger *zap.Logger
if os.Getenv("GO_ENV") == "prod" {
logger, _ = zap.NewProduction()
} else {
logger, _ = zap.NewDevelopment()
}
return logger
}
開発環境だとコンソール形式で出力される
本番環境ではjson形式で出力される
➜ cmd GO_ENV=dev go run .
2023/06/21 01:01:38 foo
foo
2023-06-21T01:01:38.488+0900 INFO cmd/main.go:34 Hello zap {"key": "value", "now": "2023-06-21T01:01:38.488+0900"}
2023-06-21T01:01:38.488+0900 WARN cmd/main.go:38 Hello zap {"key": "value", "now": "2023-06-21T01:01:38.488+0900"}
main.main
/Users/yuuki_haga/repos/go/go-sandbox/cmd/main.go:38
runtime.main
/usr/local/go/src/runtime/proc.go:250
3306
➜ cmd GO_ENV=prod go run .
2023/06/21 01:01:49 foo
foo
{"level":"info","ts":1687276909.364863,"caller":"cmd/main.go:34","msg":"Hello zap","key":"value","now":1687276909.3648598}
{"level":"warn","ts":1687276909.364956,"caller":"cmd/main.go:38","msg":"Hello zap","key":"value","now":1687276909.364956}
3300
ディレクトリ構成
➜ go-sandbox tree
.
├── cmd
│ ├── foo.txt
│ └── main.go
├── env
│ ├── dev.env
│ └── prod.env
├── go.mod
└── go.sum
Zapが提供しているログレベル
Zapでは以下のログレベルが提供されている
Warnからスタックトレースも出力される。DPanic以降、開発・本番でパニックが起こる。
Level | Description |
---|---|
Fatal | Fatalレベルのメッセージを出力。デフォルトではスタックトレースも出力。その後ステータスコード1でプロセスを終了 |
Panic | Panicレベルのメッセージを出力。デフォルトではスタックトレースも出力。その後Panic |
DPanic | DPanicレベルのメッセージを出力。デフォルトではスタックトレースも出力。Devモードの場合、その後Panic |
Error | Errorレベルのメッセージを出力。デフォルトではスタックトレースも出力 |
Warn | Warnレベルのメッセージを出力。デフォルトではスタックトレースも出力 |
Info | Infoレベルのメッセージを出力 |
Debug | Debugレベルのメッセージを出力 |
道中で調べたこと
アロケーション
アロケーションとは、プログラムが使用するメモリ領域を OS などが確保して、使用可能にすることを指す場合が多いです。
スタックトレース
スタックトレースとは、実行中のプログラムがエラーを起こした時に、その直前まで実行していた関数やメソッドの履歴を表示すること