Closed12

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を呼び出します。

なるほど。めちゃくちゃシンプルだな。ログレベルとかもない。
ロガーは標準エラー出力に対して書き込むのか
https://pkg.go.dev/log

ハガユウキハガユウキ

fmtパッケージ

fmtパッケージは、Cのprintfとscanfに類似した関数で、フォーマットされたI/Oを実装しています。フォーマットの「動詞」はCのものを継承していますが、よりシンプルになっています。

今更深ぼるほどでもないけど、一応引用しておく
https://pkg.go.dev/fmt

ハガユウキハガユウキ

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
}

参考記事

https://tsujitaku50.hatenablog.com/entry/2017/05/01/190250

ハガユウキハガユウキ

ログレベル

ついでにログレベルについても調べてみた。
ログレベルとは、ログの緊急度を表すレベルのこと。
代表的なログライブラリの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
)

参考記事

https://qiita.com/nanasess/items/350e59b29cceb2f122b3
https://ja.wikipedia.org/wiki/Log4j#.E3.83.AD.E3.82.B0.E3.83.AC.E3.83.99.E3.83.AB
https://pkg.go.dev/golang.org/x/exp/slog#Level
https://qiita.com/ryokky59/items/19fa212d1898dcb4bcfd

ハガユウキハガユウキ

slogパッケージについて深ぼる

slogパッケージとは、構造化ロギングパッケージである。slogのsはおそらくStructured(構造化)のsである。

logパッケージとslogパッケージを比較したときの、slogパッケージのメリット

  • 構造化ログとログレベルを提供している
  • Zapのようにパフォーマンスにも重点をおいている
  • logrのようにロギングライブラリのためのインタフェースを提供
  • 既存のロギングライブラリを置き換えるものではない
  • 既存のロギングライブラリに親しみが無いユーザでも扱える
  • JSONなどの機械処理しやすい形式にログを出力できるようになっている。
ハガユウキハガユウキ

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
}

https://qiita.com/emonuh/items/28dbee9bf2fe51d28153
https://github.com/uber-go/zap

ハガユウキハガユウキ

開発環境だとコンソール形式で出力される
本番環境では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レベルのメッセージを出力

https://pkg.go.dev/go.uber.org/zap@v1.24.0/zapcore#Level

ハガユウキハガユウキ

道中で調べたこと

アロケーション

アロケーションとは、プログラムが使用するメモリ領域を OS などが確保して、使用可能にすることを指す場合が多いです。

https://programming-place.net/ppp/contents/glossary/a/allocation.html

スタックトレース

スタックトレースとは、実行中のプログラムがエラーを起こした時に、その直前まで実行していた関数やメソッドの履歴を表示すること
https://qiita.com/tsukasaI/items/8e093d0898578dabe3fb

このスクラップは2023/06/21にクローズされました