ch13

l := log.New(os.Stdout, "example: ", log.Lshortfile)
l.Print("logging to standard output")

Output:

example: log_test.go:12: logging to standard output

lDebug := log.New(os.Stdout, "DEBUG: ", log.Lshortfile)
logFile := new(bytes.Buffer)
w := SustainedMultiWriter(logFile, lDebug.Writer())
lError := log.New(w, "ERROR: ", log.Lshortfile)

fmt.Println("standard output:")
lError.Print("cannot communicate with the database")
lDebug.Print("you cannot hum while holding your nose")

fmt.Print("\nlog file contents:\n", logFile.String())

Output:

standard output:
ERROR: log_test.go:43: cannot communicate with the database
DEBUG: log_test.go:44: you cannot hum while holding your nose

log file contents:
ERROR: log_test.go:43: cannot communicate with the database

logFile := new(bytes.Buffer)
w := SustainedMultiWriter(os.Stdout, logFile)
l := log.New(w, "example: ", log.Lshortfile|log.Lmsgprefix)

fmt.Println("standard output:")
l.Print("Canada is south of Detroit")

fmt.Print("\nlog file contents:\n", logFile.String())

Output:

standard output:
log_test.go:24: example: Canada is south of Detroit

log file contents:
log_test.go:24: example: Canada is south of Detroit

package main

import (
	"io"
	"io/ioutil"
	"net"
	"net/http"
	"net/http/httptest"
	"os"

	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
)

type wideResponseWriter struct {
	http.ResponseWriter
	length, status int
}

func (w *wideResponseWriter) WriteHeader(status int) {
	w.ResponseWriter.WriteHeader(status)
	w.status = status
}

func (w *wideResponseWriter) Write(b []byte) (int, error) {
	n, err := w.ResponseWriter.Write(b)
	w.length += n

	if w.status == 0 {
		// 200 OK inferred on first Write if status is not yet set
		w.status = http.StatusOK
	}

	return n, err
}

func WideEventLog(logger *zap.Logger, next http.Handler) http.Handler {
	return http.HandlerFunc(
		func(w http.ResponseWriter, r *http.Request) {
			wideWriter := &wideResponseWriter{ResponseWriter: w}

			next.ServeHTTP(wideWriter, r)

			addr, _, _ := net.SplitHostPort(r.RemoteAddr)
			logger.Info("example wide event",
				zap.Int("status_code", wideWriter.status),
				zap.Int("response_length", wideWriter.length),
				zap.Int64("content_length", r.ContentLength),
				zap.String("method", r.Method),
				zap.String("proto", r.Proto),
				zap.String("remote_addr", addr),
				zap.String("uri", r.RequestURI),
				zap.String("user_agent", r.UserAgent()),
			)
		},
	)
}

func main() {
	zl := zap.New(
		zapcore.NewCore(
			zapcore.NewJSONEncoder(encoderCfg),
			zapcore.Lock(os.Stdout),
			zapcore.DebugLevel,
		),
	)
	defer func() { _ = zl.Sync() }()

	ts := httptest.NewServer(
		WideEventLog(zl, http.HandlerFunc(
			func(w http.ResponseWriter, r *http.Request) {
				defer func(r io.ReadCloser) {
					_, _ = io.Copy(ioutil.Discard, r)
					_ = r.Close()
				}(r.Body)
				_, _ = w.Write([]byte("Hello!"))
			},
		)),
	)
	defer ts.Close()

	resp, err := http.Get(ts.URL + "/test")
	if err != nil {
		zl.Fatal(err.Error())
	}
	_ = resp.Body.Close()

}

Output:

{"level":"info","msg":"example wide event","status_code":200,"response_length":6,"content_length":0,"method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1","uri":"/test","user_agent":"Go-http-client/1.1"}

zl := zap.New(
	zapcore.NewCore(
		zapcore.NewConsoleEncoder(encoderCfg),
		zapcore.Lock(os.Stdout),
		zapcore.InfoLevel,
	),
)
defer func() { _ = zl.Sync() }()

console := zl.Named("[console]")
console.Info("this is logged by the logger")
console.Debug("this is below the logger's threshold and won't log")
console.Error("this is also logged by the logger")

Output:

info	[console]	this is logged by the logger
error	[console]	this is also logged by the logger

tempDir, err := ioutil.TempDir("", "")
if err != nil {
	log.Fatal(err)
}
defer func() { _ = os.RemoveAll(tempDir) }()

debugLevelFile := filepath.Join(tempDir, "level.debug")
atomicLevel := zap.NewAtomicLevel()

zl := zap.New(
	zapcore.NewCore(
		zapcore.NewJSONEncoder(encoderCfg),
		zapcore.Lock(os.Stdout),
		atomicLevel,
	),
)
defer func() { _ = zl.Sync() }()

watcher, err := fsnotify.NewWatcher()
if err != nil {
	log.Fatal(err)
}
defer func() { _ = watcher.Close() }()

err = watcher.Add(tempDir)
if err != nil {
	log.Fatal(err)
}

ready := make(chan struct{})
go func() {
	defer close(ready)

	originalLevel := atomicLevel.Level()

	for {
		select {
		case event, ok := <-watcher.Events:
			if !ok {
				return
			}
			if event.Name == debugLevelFile {
				switch {
				case event.Op&fsnotify.Create == fsnotify.Create:
					atomicLevel.SetLevel(zapcore.DebugLevel)
					ready <- struct{}{}
				case event.Op&fsnotify.Remove == fsnotify.Remove:
					atomicLevel.SetLevel(originalLevel)
					ready <- struct{}{}
				}
			}
		case err, ok := <-watcher.Errors:
			if !ok {
				return
			}
			zl.Error(err.Error())
		}
	}
}()

zl.Debug("this is below the logger's threshold")

// Touch the debug level file.
df, err := os.Create(debugLevelFile)
if err != nil {
	log.Fatal(err)
}
err = df.Close()
if err != nil {
	log.Fatal(err)
}
<-ready

zl.Debug("this is now at the logger's threshold")

err = os.Remove(debugLevelFile)
if err != nil {
	log.Fatal(err)
}
<-ready

zl.Debug("this is below the logger's threshold again")
zl.Info("this is at the logger's current threshold")

Output:

{"level":"debug","msg":"this is now at the logger's threshold"}
{"level":"info","msg":"this is at the logger's current threshold"}

logFile := new(bytes.Buffer)
zl := zap.New(
	zapcore.NewCore(
		zapcore.NewJSONEncoder(encoderCfg),
		zapcore.Lock(zapcore.AddSync(logFile)),
		zapcore.InfoLevel,
	),
)
defer func() { _ = zl.Sync() }()

zl.Debug("this is below the logger's threshold and won't log")
zl.Error("this is logged by the logger")

zl = zl.WithOptions(
	zap.WrapCore(
		func(c zapcore.Core) zapcore.Core {
			ucEncoderCfg := encoderCfg
			ucEncoderCfg.EncodeLevel = zapcore.CapitalLevelEncoder
			return zapcore.NewTee(
				c,
				zapcore.NewCore(
					zapcore.NewConsoleEncoder(ucEncoderCfg),
					zapcore.Lock(os.Stdout),
					zapcore.DebugLevel,
				),
			)
		},
	),
)

fmt.Println("standard output:")
zl.Debug("this is only logged as console encoding")
zl.Info("this is logged as console encoding and JSON")

fmt.Print("\nlog file contents:\n", logFile.String())

Output:

standard output:
DEBUG	this is only logged as console encoding
INFO	this is logged as console encoding and JSON

log file contents:
{"level":"error","msg":"this is logged by the logger"}
{"level":"info","msg":"this is logged as console encoding and JSON"}

zl := zap.New(
	zapcore.NewCore(
		zapcore.NewJSONEncoder(encoderCfg),
		zapcore.Lock(os.Stdout),
		zapcore.DebugLevel,
	),
	zap.AddCaller(),
	zap.Fields(
		zap.String("version", runtime.Version()),
	),
)
defer func() { _ = zl.Sync() }()

example := zl.Named("example")
example.Debug("test debug message")
example.Info("test info message")

Output:

{"level":"debug","name":"example","caller":"ch13/zap_test.go:49","msg":"test debug message","version":"go1.20.1"}
{"level":"info","name":"example","caller":"ch13/zap_test.go:50","msg":"test info message","version":"go1.20.1"}

zl := zap.New(
	zapcore.NewSamplerWithOptions(
		zapcore.NewCore(
			zapcore.NewJSONEncoder(encoderCfg),
			zapcore.Lock(os.Stdout),
			zapcore.DebugLevel,
		),
		time.Second, 1, 3,
	),
)
defer func() { _ = zl.Sync() }()

for i := 0; i < 10; i++ {
	if i == 5 {
		time.Sleep(time.Second)
	}
	zl.Debug(fmt.Sprintf("%d", i))
	zl.Debug("debug message")
}

Output:

{"level":"debug","msg":"0"}
{"level":"debug","msg":"debug message"}
{"level":"debug","msg":"1"}
{"level":"debug","msg":"2"}
{"level":"debug","msg":"3"}
{"level":"debug","msg":"debug message"}
{"level":"debug","msg":"4"}
{"level":"debug","msg":"5"}
{"level":"debug","msg":"debug message"}
{"level":"debug","msg":"6"}
{"level":"debug","msg":"7"}
{"level":"debug","msg":"8"}
{"level":"debug","msg":"debug message"}
{"level":"debug","msg":"9"}