log15

README

log15

Package log15 provides an opinionated, simple toolkit for best-practice logging in Go (golang) that is both human and machine readable. It is modeled after the Go standard library's io and net/http packages and is an alternative to the standard library's log package.

Features

• A simple, easy-to-understand API
• Promotes structured logging by encouraging use of key/value pairs
• Child loggers which inherit and add their own private context
• Lazy evaluation of expensive operations
• Simple Handler interface allowing for construction of flexible, custom logging configurations with a tiny API.
• Color terminal support
• Built-in support for logging to files, streams, syslog, and the network
• Support for forking records to multiple handlers, buffering records for output, failing over from failed handler writes, + more

Versioning

The API of the master branch of log15 should always be considered unstable. If you want to rely on a stable API, you must vendor the library.

Importing

import log "github.com/turingchain2020/turingchain/common/log/log15"

Examples

// all loggers can have key/value context
srvlog := log.New("module", "app/server")

// all log messages can have key/value context
srvlog.Warn("abnormal conn rate", "rate", curRate, "low", lowRate, "high", highRate)

// child loggers with inherited context
connlog := srvlog.New("raddr", c.RemoteAddr())
connlog.Info("connection open")

// lazy evaluation
connlog.Debug("ping remote", "latency", log.Lazy{pingRemote})

// flexible configuration
srvlog.SetHandler(log.MultiHandler(
    log.StreamHandler(os.Stderr, log.LogfmtFormat()),
    log.LvlFilterHandler(
        log.LvlError,
        log.Must.FileHandler("errors.json", log.JsonFormat()))))

Will result in output that looks like this:

WARN[06-17|21:58:10] abnormal conn rate                       module=app/server rate=0.500 low=0.100 high=0.800
INFO[06-17|21:58:10] connection open                          module=app/server raddr=10.0.0.1

Breaking API Changes

The following commits broke API stability. This reference is intended to help you understand the consequences of updating to a newer version of log15.

• 57a084d014d4150152b19e4e531399a7145d1540 - Added a Get() method to the Logger interface to retrieve the current handler
• 93404652ee366648fa622b64d1e2b67d75a3094a - Record field Call changed to stack.Call with switch to github.com/go-stack/stack
• a5e7613673c73281f58e15a87d2cf0cf111e8152 - Restored syslog.Priority argument to the SyslogXxx handler constructors

FAQ

The varargs style is brittle and error prone! Can I have type safety please?

Yes. Use log.Ctx:

srvlog := log.New(log.Ctx{"module": "app/server"})
srvlog.Warn("abnormal conn rate", log.Ctx{"rate": curRate, "low": lowRate, "high": highRate})

Regenerating the CONTRIBUTORS file

go get -u github.com/kevinburke/write_mailmap
write_mailmap > CONTRIBUTORS

License

Apache

Documentation

Overview

Package log15 provides an opinionated, simple toolkit for best-practice logging that is both human and machine readable. It is modeled after the standard library's io and net/http packages.

This package enforces you to only log key/value pairs. Keys must be strings. Values may be any type that you like. The default output format is logfmt, but you may also choose to use JSON instead if that suits you. Here's how you log:

log.Info("page accessed", "path", r.URL.Path, "user_id", user.id)

This will output a line that looks like:

lvl=info t=2014-05-02T16:07:23-0700 msg="page accessed" path=/org/71/profile user_id=9

Getting Started

To get started, you'll want to import the library:

import log "github.com/turingchain2020/turingchain/common/log/log15"

Now you're ready to start logging:

func main() {
    log.Info("Program starting", "args", os.Args())
}

Convention

Because recording a human-meaningful message is common and good practice, the first argument to every logging method is the value to the *implicit* key 'msg'.

Additionally, the level you choose for a message will be automatically added with the key 'lvl', and so will the current timestamp with key 't'.

You may supply any additional context as a set of key/value pairs to the logging function. log15 allows you to favor terseness, ordering, and speed over safety. This is a reasonable tradeoff for logging functions. You don't need to explicitly state keys/values, log15 understands that they alternate in the variadic argument list:

log.Warn("size out of bounds", "low", lowBound, "high", highBound, "val", val)

If you really do favor your type-safety, you may choose to pass a log.Ctx instead:

log.Warn("size out of bounds", log.Ctx{"low": lowBound, "high": highBound, "val": val})

Context loggers

Frequently, you want to add context to a logger so that you can track actions associated with it. An http request is a good example. You can easily create new loggers that have context that is automatically included with each log line:

requestlogger := log.New("path", r.URL.Path)

// later
requestlogger.Debug("db txn commit", "duration", txnTimer.Finish())

This will output a log line that includes the path context that is attached to the logger:

lvl=dbug t=2014-05-02T16:07:23-0700 path=/repo/12/add_hook msg="db txn commit" duration=0.12

Handlers

The Handler interface defines where log lines are printed to and how they are formated. Handler is a single interface that is inspired by net/http's handler interface:

type Handler interface {
    Log(r *Record) error
}

Handlers can filter records, format them, or dispatch to multiple other Handlers. This package implements a number of Handlers for common logging patterns that are easily composed to create flexible, custom logging structures.

Here's an example handler that prints logfmt output to Stdout:

handler := log.StreamHandler(os.Stdout, log.LogfmtFormat())

Here's an example handler that defers to two other handlers. One handler only prints records from the rpc package in logfmt to standard out. The other prints records at Error level or above in JSON formatted output to the file /var/log/service.json

handler := log.MultiHandler(
    log.LvlFilterHandler(log.LvlError, log.Must.FileHandler("/var/log/service.json", log.JSONFormat())),
    log.MatchFilterHandler("pkg", "app/rpc" log.StdoutHandler())
)

Logging File Names and Line Numbers

This package implements three Handlers that add debugging information to the context, CallerFileHandler, CallerFuncHandler and CallerStackHandler. Here's an example that adds the source file and line number of each logging call to the context.

h := log.CallerFileHandler(log.StdoutHandler)
log.Root().SetHandler(h)
...
log.Error("open file", "err", err)

This will output a line that looks like:

lvl=eror t=2014-05-02T16:07:23-0700 msg="open file" err="file not found" caller=data.go:42

Here's an example that logs the call stack rather than just the call site.

h := log.CallerStackHandler("%+v", log.StdoutHandler)
log.Root().SetHandler(h)
...
log.Error("open file", "err", err)

This will output a line that looks like:

lvl=eror t=2014-05-02T16:07:23-0700 msg="open file" err="file not found" stack="[pkg/data.go:42 pkg/cmd/main.go]"

The "%+v" format instructs the handler to include the path of the source file relative to the compile time GOPATH. The github.com/go-stack/stack package documents the full list of formatting verbs and modifiers available.

Custom Handlers

The Handler interface is so simple that it's also trivial to write your own. Let's create an example handler which tries to write to one handler, but if that fails it falls back to writing to another handler and includes the error that it encountered when trying to write to the primary. This might be useful when trying to log over a network socket, but if that fails you want to log those records to a file on disk.

type BackupHandler struct {
    Primary Handler
    Secondary Handler
}

func (h *BackupHandler) Log (r *Record) error {
    err := h.Primary.Log(r)
    if err != nil {
        r.Ctx = append(ctx, "primary_err", err)
        return h.Secondary.Log(r)
    }
    return nil
}

This pattern is so useful that a generic version that handles an arbitrary number of Handlers is included as part of this library called FailoverHandler.

Logging Expensive Operations

Sometimes, you want to log values that are extremely expensive to compute, but you don't want to pay the price of computing them if you haven't turned up your logging level to a high level of detail.

This package provides a simple type to annotate a logging operation that you want to be evaluated lazily, just when it is about to be logged, so that it would not be evaluated if an upstream Handler filters it out. Just wrap any function which takes no arguments with the log.Lazy type. For example:

func factorRSAKey() (factors []int) {
    // return the factors of a very large number
}

log.Debug("factors", log.Lazy{factorRSAKey})

If this message is not logged for any reason (like logging at the Error level), then factorRSAKey is never evaluated.

Dynamic context values

The same log.Lazy mechanism can be used to attach context to a logger which you want to be evaluated when the message is logged, but not when the logger is created. For example, let's imagine a game where you have Player objects:

type Player struct {
    name string
    alive bool
    log.Logger
}

You always want to log a player's name and whether they're alive or dead, so when you create the player object, you might do:

p := &Player{name: name, alive: true}
p.Logger = log.New("name", p.name, "alive", p.alive)

Only now, even after a player has died, the logger will still report they are alive because the logging context is evaluated when the logger was created. By using the Lazy wrapper, we can defer the evaluation of whether the player is alive or not to each log message, so that the log records will reflect the player's current state no matter when the log message is written:

p := &Player{name: name, alive: true}
isAlive := func() bool { return p.alive }
player.Logger = log.New("name", p.name, "alive", log.Lazy{isAlive})

Terminal Format

If log15 detects that stdout is a terminal, it will configure the default handler for it (which is log.StdoutHandler) to use TerminalFormat. This format logs records nicely for your terminal, including color-coded output based on log level.

Error Handling

Becasuse log15 allows you to step around the type system, there are a few ways you can specify invalid arguments to the logging functions. You could, for example, wrap something that is not a zero-argument function with log.Lazy or pass a context key that is not a string. Since logging libraries are typically the mechanism by which errors are reported, it would be onerous for the logging functions to return errors. Instead, log15 handles errors by making these guarantees to you:

- Any log record containing an error will still be printed with the error explained to you as part of the log record.

- Any log record containing an error will include the context key LOG15_ERROR, enabling you to easily (and if you like, automatically) detect if any of your logging calls are passing bad values.

Understanding this, you might wonder why the Handler interface can return an error value in its Log method. Handlers are encouraged to return errors only if they fail to write their log records out to an external source like if the syslog daemon is not responding. This allows the construction of useful handlers which cope with those failures like the FailoverHandler.

Library Use

log15 is intended to be useful for library authors as a way to provide configurable logging to users of their library. Best practice for use in a library is to always disable all output for your logger by default and to provide a public Logger instance that consumers of your library can configure. Like so:

package yourlib

import "github.com/turingchain2020/turingchain/common/log/log15"

var Log = log.New()

func init() {
    Log.SetHandler(log.DiscardHandler())
}

Users of your library may then enable it if they like:

import "github.com/turingchain2020/turingchain/common/log/log15"
import "example.com/yourlib"

func main() {
    handler := // custom handler setup
    yourlib.Log.SetHandler(handler)
}

Best practices attaching logger context

The ability to attach context to a logger is a powerful one. Where should you do it and why? I favor embedding a Logger directly into any persistent object in my application and adding unique, tracing context keys to it. For instance, imagine I am writing a web browser:

type Tab struct {
    url string
    render *RenderingContext
    // ...

    Logger
}

func NewTab(url string) *Tab {
    return &Tab {
        // ...
        url: url,

        Logger: log.New("url", url),
    }
}

When a new tab is created, I assign a logger to it with the url of the tab as context so it can easily be traced through the logs. Now, whenever we perform any operation with the tab, we'll log with its embedded logger and it will include the tab title automatically:

tab.Debug("moved position", "idx", tab.idx)

There's only one problem. What if the tab url changes? We could use log.Lazy to make sure the current url is always written, but that would mean that we couldn't trace a tab's full lifetime through our logs after the user navigate to a new URL.

Instead, think about what values to attach to your loggers the same way you think about what to use as a key in a SQL database schema. If it's possible to use a natural key that is unique for the lifetime of the object, do so. But otherwise, log15's ext package has a handy RandId function to let you generate what you might call "surrogate keys" They're just random hex identifiers to use for tracing. Back to our Tab example, we would prefer to set up our Logger like so:

import logext "github.com/turingchain2020/turingchain/common/log/log15/ext"

t := &Tab {
    // ...
    url: url,
}

t.Logger = log.New("id", logext.RandId(8), "url", log.Lazy{t.getUrl})
return t

Now we'll have a unique traceable identifier even across loading new urls, but we'll still be able to see the tab's current url in the log messages.

Must

For all Handler functions which can return an error, there is a version of that function which will return no error but panics on failure. They are all available on the Must object. For example:

log.Must.FileHandler("/path", log.JSONFormat)
log.Must.NetHandler("tcp", ":1234", log.JSONFormat)

Inspiration and Credit

All of the following excellent projects inspired the design of this library:

code.google.com/p/log4go

github.com/op/go-logging

github.com/technoweenie/grohl

github.com/Sirupsen/logrus

github.com/kr/logfmt

github.com/spacemonkeygo/spacelog

golang's stdlib, notably io and net/http

The Name

https://xkcd.com/927/

Index

• Variables
• func Crit(msg string, ctx ...interface{})
• func Debug(msg string, ctx ...interface{})
• func Error(msg string, ctx ...interface{})
• func Info(msg string, ctx ...interface{})
• func Warn(msg string, ctx ...interface{})
• type Ctx
• type Format
  • func FormatFunc(f func(*Record) []byte) Format
  • func JSONFormat() Format
  • func JSONFormatEx(pretty, lineSeparated bool) Format
  • func LogfmtFormat() Format
  • func TerminalFormat() Format
• type Handler
  • func BufferedHandler(bufSize int, h Handler) Handler
  • func CallerFileHandler(h Handler) Handler
  • func CallerFuncHandler(h Handler) Handler
  • func CallerStackHandler(format string, h Handler) Handler
  • func ChannelHandler(recs chan<- *Record, maxLevel int) Handler
  • func DiscardHandler() Handler
  • func FailoverHandler(hs ...Handler) Handler
  • func FileHandler(path string, fmtr Format) (Handler, error)
  • func FilterHandler(fn func(r *Record) bool, h Handler) Handler
  • func FuncHandler(maxLevel int, fn func(r *Record) error) Handler
  • func LazyHandler(h Handler) Handler
  • func LvlFilterHandler(maxLvl Lvl, h Handler) Handler
  • func MatchFilterHandler(key string, value interface{}, h Handler) Handler
  • func MultiHandler(hs ...Handler) Handler
  • func NetHandler(network, addr string, fmtr Format) (Handler, error)
  • func StreamHandler(wr io.Writer, fmtr Format) Handler
  • func SyncHandler(h Handler) Handler
  • func SyslogHandler(priority syslog.Priority, tag string, fmtr Format) (Handler, error)
  • func SyslogNetHandler(net, addr string, priority syslog.Priority, tag string, fmtr Format) (Handler, error)
• type Lazy
• type Logger
  • func New(ctx ...interface{}) Logger
  • func Root() Logger
• type Lvl
  • func LvlFromString(lvlString string) (Lvl, error)
  • func (l Lvl) String() string
• type Record
• type RecordKeyNames

Variables

var (
	StdoutHandler = StreamHandler(os.Stdout, LogfmtFormat())
	StderrHandler = StreamHandler(os.Stderr, LogfmtFormat())
)

Predefined handlers

var Must muster

Must object provides the following Handler creation functions which instead of returning an error parameter only return a Handler and panic on failure: FileHandler, NetHandler, SyslogHandler, SyslogNetHandler

Functions

func Crit

func Crit(msg string, ctx ...interface{})

Crit is a convenient alias for Root().Crit

func Debug

func Debug(msg string, ctx ...interface{})

Debug is a convenient alias for Root().Debug

func Error

func Error(msg string, ctx ...interface{})

Error is a convenient alias for Root().Error

func Info

func Info(msg string, ctx ...interface{})

Info is a convenient alias for Root().Info

func Warn

func Warn(msg string, ctx ...interface{})

Warn is a convenient alias for Root().Warn

Types

type Ctx

type Ctx map[string]interface{}

Ctx is a map of key/value pairs to pass as context to a log function Use this only if you really need greater safety around the arguments you pass to the logging functions.

type Format

type Format interface {
	Format(r *Record) []byte
}

Format is the interface implemented by StreamHandler formatters.

func FormatFunc

func FormatFunc(f func(*Record) []byte) Format

FormatFunc returns a new Format object which uses the given function to perform record formatting.

func JSONFormat

func JSONFormat() Format

JSONFormat formats log records as JSON objects separated by newlines. It is the equivalent of JSONFormatEx(false, true).

func JSONFormatEx

func JSONFormatEx(pretty, lineSeparated bool) Format

JSONFormatEx formats log records as JSON objects. If pretty is true, records will be pretty-printed. If lineSeparated is true, records will be logged with a new line between each record.

func LogfmtFormat

func LogfmtFormat() Format

LogfmtFormat prints records in logfmt format, an easy machine-parseable but human-readable format for key/value pairs.

For more details see: http://godoc.org/github.com/kr/logfmt

func TerminalFormat

func TerminalFormat() Format

TerminalFormat formats log records optimized for human readability on a terminal with color-coded level output and terser human friendly timestamp. This format should only be used for interactive programs or while developing.

[TIME] [LEVEL] MESAGE key=value key=value ...

Example:

[May 16 20:58:45] [DBUG] remove route ns=haproxy addr=127.0.0.1:50002

type Handler

type Handler interface {
	Log(r *Record) error
	MaxLevel() int
	SetMaxLevel(int)
}

Handler interface defines where and how log records are written. A logger prints its log records by writing to a Handler. Handlers are composable, providing you great flexibility in combining them to achieve the logging structure that suits your applications.

func BufferedHandler

func BufferedHandler(bufSize int, h Handler) Handler

BufferedHandler writes all records to a buffered channel of the given size which flushes into the wrapped handler whenever it is available for writing. Since these writes happen asynchronously, all writes to a BufferedHandler never return an error and any errors from the wrapped handler are ignored.

func CallerFileHandler

func CallerFileHandler(h Handler) Handler

CallerFileHandler returns a Handler that adds the line number and file of the calling function to the context with key "caller".

func CallerFuncHandler

func CallerFuncHandler(h Handler) Handler

CallerFuncHandler returns a Handler that adds the calling function name to the context with key "fn".

func CallerStackHandler

func CallerStackHandler(format string, h Handler) Handler

CallerStackHandler returns a Handler that adds a stack trace to the context with key "stack". The stack trace is formated as a space separated list of call sites inside matching []'s. The most recent call site is listed first. Each call site is formatted according to format. See the documentation of package github.com/go-stack/stack for the list of supported formats.

func ChannelHandler

func ChannelHandler(recs chan<- *Record, maxLevel int) Handler

ChannelHandler writes all records to the given channel. It blocks if the channel is full. Useful for async processing of log messages, it's used by BufferedHandler.

func DiscardHandler

func DiscardHandler() Handler

DiscardHandler reports success for all writes but does nothing. It is useful for dynamically disabling logging at runtime via a Logger's SetHandler method.

func FailoverHandler

func FailoverHandler(hs ...Handler) Handler

FailoverHandler writes all log records to the first handler specified, but will failover and write to the second handler if the first handler has failed, and so on for all handlers specified. For example you might want to log to a network socket, but failover to writing to a file if the network fails, and then to standard out if the file write fails:

log.FailoverHandler(
    log.Must.NetHandler("tcp", ":9090", log.JSONFormat()),
    log.Must.FileHandler("/var/log/app.log", log.LogfmtFormat()),
    log.StdoutHandler)

All writes that do not go to the first handler will add context with keys of the form "failover_err_{idx}" which explain the error encountered while trying to write to the handlers before them in the list.

func FileHandler

func FileHandler(path string, fmtr Format) (Handler, error)

FileHandler returns a handler which writes log records to the give file using the given format. If the path already exists, FileHandler will append to the given file. If it does not, FileHandler will create the file with mode 0644.

func FilterHandler

func FilterHandler(fn func(r *Record) bool, h Handler) Handler

FilterHandler returns a Handler that only writes records to the wrapped Handler if the given function evaluates true. For example, to only log records where the 'err' key is not nil:

logger.SetHandler(FilterHandler(func(r *Record) bool {
    for i := 0; i < len(r.Ctx); i += 2 {
        if r.Ctx[i] == "err" {
            return r.Ctx[i+1] != nil
        }
    }
    return false
}, h))

func FuncHandler

func FuncHandler(maxLevel int, fn func(r *Record) error) Handler

FuncHandler returns a Handler that logs records with the given function.

func LazyHandler

func LazyHandler(h Handler) Handler

LazyHandler writes all values to the wrapped handler after evaluating any lazy functions in the record's context. It is already wrapped around StreamHandler and SyslogHandler in this library, you'll only need it if you write your own Handler.

func LvlFilterHandler

func LvlFilterHandler(maxLvl Lvl, h Handler) Handler

LvlFilterHandler returns a Handler that only writes records which are less than the given verbosity level to the wrapped Handler. For example, to only log Error/Crit records:

log.LvlFilterHandler(log.LvlError, log.StdoutHandler)

func MatchFilterHandler

func MatchFilterHandler(key string, value interface{}, h Handler) Handler

MatchFilterHandler returns a Handler that only writes records to the wrapped Handler if the given key in the logged context matches the value. For example, to only log records from your ui package:

log.MatchFilterHandler("pkg", "app/ui", log.StdoutHandler)

func MultiHandler

func MultiHandler(hs ...Handler) Handler

MultiHandler ...

func NetHandler

func NetHandler(network, addr string, fmtr Format) (Handler, error)

NetHandler opens a socket to the given address and writes records over the connection.

func StreamHandler

func StreamHandler(wr io.Writer, fmtr Format) Handler

StreamHandler writes log records to an io.Writer with the given format. StreamHandler can be used to easily begin writing log records to other outputs.

StreamHandler wraps itself with LazyHandler and SyncHandler to evaluate Lazy objects and perform safe concurrent writes.

func SyncHandler

func SyncHandler(h Handler) Handler

SyncHandler can be wrapped around a handler to guarantee that only a single Log operation can proceed at a time. It's necessary for thread-safe concurrent writes.

func SyslogHandler

func SyslogHandler(priority syslog.Priority, tag string, fmtr Format) (Handler, error)

SyslogHandler opens a connection to the system syslog daemon by calling syslog.New and writes all records to it.

func SyslogNetHandler

func SyslogNetHandler(net, addr string, priority syslog.Priority, tag string, fmtr Format) (Handler, error)

SyslogNetHandler opens a connection to a log daemon over the network and writes all log records to it.

type Lazy

type Lazy struct {
	Fn interface{}
}

Lazy allows you to defer calculation of a logged value that is expensive to compute until it is certain that it must be evaluated with the given filters.

Lazy may also be used in conjunction with a Logger's New() function to generate a child logger which always reports the current value of changing state.

You may wrap any function which takes no arguments to Lazy. It may return any number of values of any type.

type Logger

type Logger interface {
	// New returns a new Logger that has this logger's context plus the given context
	New(ctx ...interface{}) Logger

	// GetHandler gets the handler associated with the logger.
	GetHandler() Handler

	// SetHandler updates the logger to write records to the specified handler.
	SetHandler(h Handler)

	// Log a message at the given level with context key/value pairs
	Debug(msg string, ctx ...interface{})
	Info(msg string, ctx ...interface{})
	Warn(msg string, ctx ...interface{})
	Error(msg string, ctx ...interface{})
	Crit(msg string, ctx ...interface{})
	SetMaxLevel(int)
}

A Logger writes key/value pairs to a Handler

func New

func New(ctx ...interface{}) Logger

New returns a new logger with the given context. New is a convenient alias for Root().New

func Root

func Root() Logger

Root returns the root logger

type Lvl

type Lvl int

Lvl is a type for predefined log levels.

const (
	LvlCrit Lvl = iota
	LvlError
	LvlWarn
	LvlInfo
	LvlDebug
)

List of predefined log Levels

func LvlFromString

func LvlFromString(lvlString string) (Lvl, error)

LvlFromString returns the appropriate Lvl from a string name. Useful for parsing command line args and configuration files.

func (Lvl) String

func (l Lvl) String() string

Returns the name of a Lvl

type Record

type Record struct {
	Time     time.Time
	Lvl      Lvl
	Msg      string
	Ctx      []interface{}
	Call     stack.Call
	KeyNames RecordKeyNames
}

A Record is what a Logger asks its handler to write

type RecordKeyNames

type RecordKeyNames struct {
	Time string
	Msg  string
	Lvl  string
}

RecordKeyNames are the predefined names of the log props used by the Logger interface.