Structured Logging Made Easy
Features
- Dependency Free
- Simple and Clean Interface
- Consistent Writer
IOWriter, io.Writer wrapperFileWriter, rotating & effectiveConsoleWriter, colorful & formattingMultiWriter, multiple level dispatchSyslogWriter, syslog server loggingJournalWriter, linux systemd loggingEventlogWriter, windows system eventAsyncWriter, asynchronously writing
- Third-party Logger Interceptor
Logger.Std, (std)logLogger.Grpc, grpclog.LoggerV2Logger.Logr, logr.Logger
- Useful utility function
Goid(), the goroutine id matches stack traceNewXID(), create a tracing idFastrandn(n uint32), fast pseudorandom uint32 in [0,n)IsTerminal(fd uintptr), isatty for golangPrintf(fmt string, a ...interface{}), printf logging
- High Performance
- Significantly faster than all other json loggers.
Interfaces
Logger
// DefaultLogger is the global logger.
var DefaultLogger = Logger{
Level: DebugLevel,
Caller: 0,
TimeField: "",
TimeFormat: "",
Writer: &IOWriter{os.Stderr},
}
// A Logger represents an active logging object that generates lines of JSON output to an io.Writer.
type Logger struct {
// Level defines log levels.
Level Level
// Caller determines if adds the file:line of the "caller" key.
Caller int
// TimeField defines the time filed name in output. It uses "time" in if empty.
TimeField string
// TimeFormat specifies the time format in output. It uses RFC3339 with millisecond if empty.
// If set with `TimeFormatUnix`, `TimeFormatUnixMs`, times are formated as UNIX timestamp.
TimeFormat string
// Writer specifies the writer of output. It uses a wrapped os.Stderr Writer in if empty.
Writer Writer
}
// Writer defines an entry writer interface.
type Writer interface {
WriteEntry(*Entry) (int, error)
}
FileWriter & ConsoleWriter
// FileWriter is an Writer that writes to the specified filename.
type FileWriter struct {
// Filename is the file to write logs to. Backup log files will be retained
// in the same directory.
Filename string
// FileMode represents the file's mode and permission bits. The default
// mode is 0644
FileMode os.FileMode
// MaxSize is the maximum size in bytes of the log file before it gets rotated.
MaxSize int64
// MaxBackups is the maximum number of old log files to retain. The default
// is to retain all old log files
MaxBackups int
// TimeFormat specifies the time format of filename, uses `2006-01-02T15-04-05` as default format.
// If set with `TimeFormatUnix`, `TimeFormatUnixMs`, times are formated as UNIX timestamp.
TimeFormat string
// LocalTime determines if the time used for formatting the timestamps in
// log files is the computer's local time. The default is to use UTC time.
LocalTime bool
// HostName determines if the hostname used for formatting in log files.
HostName bool
// ProcessID determines if the pid used for formatting in log files.
ProcessID bool
// EnsureFolder ensures the file directory creation before writing.
EnsureFolder bool
// Cleaner specifies an optional cleanup function of log backups after rotation,
// if not set, the default behavior is to delete more than MaxBackups log files.
Cleaner func(filename string, maxBackups int, matches []os.FileInfo)
}
// ConsoleWriter parses the JSON input and writes it in a colorized, human-friendly format to Writer.
// IMPORTANT: Don't use ConsoleWriter on critical path of a high concurrency and low latency application.
//
// Default output format:
// {Time} {Level} {Goid} {Caller} > {Message} {Key}={Value} {Key}={Value}
type ConsoleWriter struct {
// ColorOutput determines if used colorized output.
ColorOutput bool
// QuoteString determines if quoting string values.
QuoteString bool
// EndWithMessage determines if output message in the end of line.
EndWithMessage bool
// Writer is the output destination. using os.Stderr if empty.
Writer io.Writer
// Formatter specifies an optional text formatter for creating a customized output,
// If it is set, ColorOutput, QuoteString and EndWithMessage will be ignored.
Formatter func(w io.Writer, args *FormatterArgs) (n int, err error)
}
Note: FileWriter/ConsoleWriter implements log.Writer and io.Writer interfaces both.
Getting Started
Simple Logging Example
A out of box example.
package main
import (
"github.com/phuslu/log"
)
func main() {
log.Info().Str("foo", "bar").Int("number", 42).Msg("hi, phuslog")
log.Info().Msgf("foo=%s number=%d error=%+v", "bar", 42, "an error")
}
// Output:
// {"time":"2020-03-22T09:58:41.828Z","level":"info","foo":"bar","number":42,"message":"hi, phuslog"}
// {"time":"2020-03-22T09:58:41.828Z","level":"info","message":"foo=bar number=42 error=an error"}
Note: By default log writes to
os.Stderr
Customize the configuration and formatting:
To customize logger filed name and format.
log.DefaultLogger = log.Logger{
Level: log.InfoLevel,
Caller: 1,
TimeField: "date",
TimeFormat: "2006-01-02",
Writer: &log.IOWriter{os.Stdout},
}
log.Info().Str("foo", "bar").Msgf("hello %s", "world")
// Output: {"date":"2019-07-04","level":"info","caller":"prog.go:16","foo":"bar","message":"hello world"}
Rotating File Writer
To log to a rotating file, use FileWriter.
package main
import (
"os"
"path/filepath"
"time"
"github.com/phuslu/log"
"github.com/robfig/cron/v3"
)
func main() {
logger := log.Logger{
Level: log.ParseLevel("info"),
Writer: &log.FileWriter{
Filename: "logs/main.log",
FileMode: 0600,
MaxSize: 50 * 1024 * 1024,
Cleaner: func(filename string, maxBackups int, matches []os.FileInfo) {
var dir = filepath.Dir(filename)
var total int64
for i := len(matches) - 1; i >= 0; i-- {
total += matches[i].Size()
if total > 10*1024*1024*1024 {
os.Remove(filepath.Join(dir, matches[i].Name()))
}
}
},
EnsureFolder: true,
LocalTime: false,
},
}
runner := cron.New(cron.WithSeconds(), cron.WithLocation(time.UTC))
runner.AddFunc("0 0 * * * *", func() { logger.Writer.(*log.FileWriter).Rotate() })
go runner.Run()
for {
time.Sleep(time.Second)
logger.Info().Msg("hello world")
}
}
Pretty Console Writer
To log a human-friendly, colorized output, use ConsoleWriter.
if log.IsTerminal(os.Stderr.Fd()) {
log.DefaultLogger = log.Logger{
TimeFormat: "15:04:05",
Caller: 1,
Writer: &log.ConsoleWriter{
ColorOutput: true,
QuoteString: true,
EndWithMessage: true,
},
}
}
log.Debug().Int("everything", 42).Str("foo", "bar").Msg("hello world")
log.Info().Int("everything", 42).Str("foo", "bar").Msg("hello world")
log.Warn().Int("everything", 42).Str("foo", "bar").Msg("hello world")
log.Error().Err(errors.New("an error")).Msg("hello world")
Note: pretty logging also works on windows console
Formatting Console Writer
To log with user-defined format(e.g. glog), using ConsoleWriter.Formatter.
log.DefaultLogger = log.Logger{
Level: log.InfoLevel,
Caller: 1,
TimeFormat: "0102 15:04:05.999999",
Writer: &log.ConsoleWriter{
Formatter: func (w io.Writer, a *log.FormatterArgs) (int, error) {
return fmt.Fprintf(w, "%c%s %s %s] %s\n%s", strings.ToUpper(a.Level)[0],
a.Time, a.Goid, a.Caller, a.Message, a.Stack)
},
},
}
log.Info().Msgf("hello glog %s", "Info")
log.Warn().Msgf("hello glog %s", "Warn")
log.Error().Msgf("hello glog %s", "Error")
// Output:
// I0725 09:59:57.503246 19 console_test.go:183] hello glog Info
// W0725 09:59:57.504247 19 console_test.go:184] hello glog Warn
// E0725 09:59:57.504247 19 console_test.go:185] hello glog Error
Multiple Dispatching Writer
To log to different writers by different levels, use MultiWriter.
log.DefaultLogger.Writer = &log.MultiWriter{
InfoWriter: &log.FileWriter{Filename: "main.INFO", MaxSize: 100<<20},
WarnWriter: &log.FileWriter{Filename: "main.WARNING", MaxSize: 100<<20},
ErrorWriter: &log.FileWriter{Filename: "main.ERROR", MaxSize: 100<<20},
ConsoleWriter: &log.ConsoleWriter{ColorOutput: true},
ConsoleLevel: log.ErrorLevel,
}
log.Info().Int("number", 42).Str("foo", "bar").Msg("a info log")
log.Warn().Int("number", 42).Str("foo", "bar").Msg("a warn log")
log.Error().Int("number", 42).Str("foo", "bar").Msg("a error log")
Multiple Combined Logger:
To logging to different logger as you want, use below idiom.
package main
import (
"github.com/phuslu/log"
)
var logger = struct {
Console log.Logger
Access log.Logger
Data log.Logger
}{
Console: log.Logger{
TimeFormat: "15:04:05",
Caller: 1,
Writer: &log.ConsoleWriter{
ColorOutput: true,
EndWithMessage: true,
},
},
Access: log.Logger{
Level: log.InfoLevel,
Writer: &log.FileWriter{
Filename: "access.log",
MaxSize: 50 * 1024 * 1024,
MaxBackups: 7,
LocalTime: false,
},
},
Data: log.Logger{
Level: log.InfoLevel,
Writer: &log.FileWriter{
Filename: "data.log",
MaxSize: 50 * 1024 * 1024,
MaxBackups: 7,
LocalTime: false,
},
},
}
func main() {
logger.Console.Info().Msgf("hello world")
logger.Access.Log().Msgf("handle request")
logger.Data.Log().Msgf("some data")
}
SyslogWriter & JournalWriter & EventlogWriter
To log to a syslog server, using SyslogWriter.
log.DefaultLogger.Writer = &log.SyslogWriter{
Network : "unixgram", // "tcp"
Address : "/run/systemd/journal/syslog", // "192.168.0.2:601"
Tag : "",
Marker : "@cee:",
Dial : net.Dial,
}
log.Info().Msg("hi")
// Output: <6>Oct 5 16:25:38 [237]: @cee:{"time":"2020-10-05T16:25:38.026Z","level":"info","message":"hi"}
To log to linux systemd journald, using JournalWriter.
log.DefaultLogger.Writer = &log.JournalWriter{}
log.Info().Int("number", 42).Str("foo", "bar").Msg("hello world")
To log to windows system event, using EventlogWriter.
log.DefaultLogger.Writer = &log.EventlogWriter{
Source: ".NET Runtime",
ID: 1000,
}
log.Info().Int("number", 42).Str("foo", "bar").Msg("hello world")
AsyncWriter
To logging asynchronously for performance stability, use AsyncWriter.
logger := log.Logger{
Level: log.InfoLevel,
Writer: &log.AsyncWriter{
ChannelSize: 100,
Writer: &log.FileWriter{
Filename: "main.log",
FileMode: 0600,
MaxSize: 50*1024*1024,
MaxBackups: 7,
LocalTime: false,
},
},
}
logger.Info().Int("number", 42).Str("foo", "bar").Msg("a async info log")
logger.Warn().Int("number", 42).Str("foo", "bar").Msg("a async warn log")
logger.Writer.(io.Closer).Close()
Note: To flush data and quit safely, call
AsyncWriter.Close()explicitly.
StdLog & Logr & Grpc Interceptor
Using wrapped loggers for stdlog/grpc/logr.
package main
import (
stdLog "log"
"github.com/go-logr/logr"
"github.com/phuslu/log"
"google.golang.org/grpc/grpclog"
)
func main() {
ctx := log.NewContext(nil).Str("tag", "hi log").Value()
var stdlog *stdLog.Logger = log.DefaultLogger.Std(log.InfoLevel, ctx, "prefix ", stdLog.LstdFlags)
stdlog.Print("hello from stdlog Print")
stdlog.Println("hello from stdlog Println")
stdlog.Printf("hello from stdlog %s", "Printf")
var grpclog grpclog.LoggerV2 = log.DefaultLogger.Grpc(ctx)
grpclog.Infof("hello %s", "grpclog Infof message")
grpclog.Errorf("hello %s", "grpclog Errorf message")
var logrLog logr.Logger = log.DefaultLogger.Logr(ctx)
logrLog = logrLog.WithName("a_named_logger").WithValues("a_key", "a_value")
logrLog.Info("hello", "foo", "bar", "number", 42)
logrLog.Error(errors.New("this is a error"), "hello", "foo", "bar", "number", 42)
}
User-defined Data Structure
To log with user-defined struct effectively, implements MarshalLogObject.
package main
import (
"github.com/phuslu/log"
)
type User struct {
ID int
Name string
Pass string
}
func (u *User) MarshalLogObject(e *log.Entry) {
e.Int("id", u.ID).Str("name", u.Name).Str("password", "***")
}
func main() {
log.Info().Object("user", &User{1, "neo", "123456"}).Msg("")
log.Info().EmbedObject(&User{2, "john", "abc"}).Msg("")
}
// Output:
// {"time":"2020-07-12T05:03:43.949Z","level":"info","user":{"id":1,"name":"neo","password":"***"}}
// {"time":"2020-07-12T05:03:43.949Z","level":"info","id":2,"name":"john","password":"***"}
Contextual Fields
To add preserved key:value pairs to each entry, use NewContext.
ctx := log.NewContext(nil).Str("ctx_str", "a ctx str").Value()
logger := log.Logger{Level: log.InfoLevel}
logger.Debug().Context(ctx).Int("no0", 0).Msg("zero")
logger.Info().Context(ctx).Int("no1", 1).Msg("first")
logger.Info().Context(ctx).Int("no2", 2).Msg("second")
// Output:
// {"time":"2020-07-12T05:03:43.949Z","level":"info","ctx_str":"a ctx str","no1":1,"message":"first"}
// {"time":"2020-07-12T05:03:43.949Z","level":"info","ctx_str":"a ctx str","no2":2,"message":"second"}
High Performance
A quick and simple benchmark with zap/zerolog, which runs on github actions:
// go test -v -cpu=4 -run=none -bench=. -benchtime=10s -benchmem log_test.go
package main
import (
"io/ioutil"
"testing"
"github.com/phuslu/log"
"github.com/rs/zerolog"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
var fakeMessage = "Test logging, but use a somewhat realistic message length. "
func BenchmarkZap(b *testing.B) {
logger := zap.New(zapcore.NewCore(
zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()),
zapcore.AddSync(ioutil.Discard),
zapcore.InfoLevel,
))
for i := 0; i < b.N; i++ {
logger.Info(fakeMessage, zap.String("foo", "bar"), zap.Int("int", 42))
}
}
func BenchmarkZeroLog(b *testing.B) {
logger := zerolog.New(ioutil.Discard).With().Timestamp().Logger()
for i := 0; i < b.N; i++ {
logger.Info().Str("foo", "bar").Int("int", 42).Msg(fakeMessage)
}
}
func BenchmarkPhusLog(b *testing.B) {
logger := log.Logger{
TimeFormat: "", // uses rfc3339 by default
Writer: log.IOWriter{ioutil.Discard},
}
for i := 0; i < b.N; i++ {
logger.Info().Str("foo", "bar").Int("int", 42).Msg(fakeMessage)
}
}
A Performance result as below, for daily benchmark results see github actions
BenchmarkZap-4 12432787 996 ns/op 128 B/op 1 allocs/op
BenchmarkZeroLog-4 24231926 496 ns/op 0 B/op 0 allocs/op
BenchmarkPhusLog-4 62495569 194 ns/op 0 B/op 0 allocs/op
This library uses the following special techniques to achieve better performance,
- handwriting time formatting
- manual inlining
- unrolled functions
A Real World Example
The example starts a geoip http server which supports change log level dynamically
package main
import (
"encoding/json"
"fmt"
"net"
"net/http"
"os"
"github.com/phuslu/iploc"
"github.com/phuslu/log"
)
type Config struct {
Listen struct {
Tcp string
}
Log struct {
Level string
Maxsize int64
Backups int
}
}
type Handler struct {
Config *Config
AccessLogger log.Logger
}
func (h *Handler) ServeHTTP(rw http.ResponseWriter, req *http.Request) {
reqID := log.NewXID()
remoteIP, _, _ := net.SplitHostPort(req.RemoteAddr)
geo := iploc.Country(net.ParseIP(remoteIP))
h.AccessLogger.Log().
Xid("req_id", reqID).
Str("host", req.Host).
Bytes("geo", geo).
Str("remote_ip", remoteIP).
Str("request_uri", req.RequestURI).
Str("user_agent", req.UserAgent()).
Str("referer", req.Referer()).
Msg("access log")
switch req.RequestURI {
case "/debug", "/info", "/warn", "/error":
log.DefaultLogger.SetLevel(log.ParseLevel(req.RequestURI[1:]))
default:
fmt.Fprintf(rw, `{"req_id":"%s","ip":"%s","geo":"%s"}`, reqID, remoteIP, geo)
}
}
func main() {
config := new(Config)
err := json.Unmarshal([]byte(`{
"listen": {
"tcp": ":8080"
},
"log": {
"level": "debug",
"maxsize": 1073741824,
"backups": 5
}
}`), config)
if err != nil {
log.Fatal().Msgf("json.Unmarshal error: %+v", err)
}
handler := &Handler{
Config: config,
AccessLogger: log.Logger{
Writer: &log.FileWriter{
Filename: "access.log",
MaxSize: config.Log.Maxsize,
MaxBackups: config.Log.Backups,
LocalTime: true,
},
},
}
if log.IsTerminal(os.Stderr.Fd()) {
log.DefaultLogger = log.Logger{
Level: log.ParseLevel(config.Log.Level),
Caller: 1,
TimeFormat: "15:04:05",
Writer: &log.ConsoleWriter{
ColorOutput: true,
EndWithMessage: true,
},
}
handler.AccessLogger = log.DefaultLogger
} else {
log.DefaultLogger = log.Logger{
Level: log.ParseLevel(config.Log.Level),
Writer: &log.FileWriter{
Filename: "main.log",
MaxSize: config.Log.Maxsize,
MaxBackups: config.Log.Backups,
LocalTime: true,
},
}
}
server := &http.Server{
Addr: config.Listen.Tcp,
ErrorLog: log.DefaultLogger.Std(log.ErrorLevel, nil, "", 0),
Handler: handler,
}
log.Fatal().Err(server.ListenAndServe()).Msg("listen failed")
}
Acknowledgment
This log is heavily inspired by zerolog, glog, gjson and lumberjack.
