log

package
v0.6.0 Latest Latest
Warning

This package is not in the latest version of its module.

 Go to latest Published: May 1, 2022 License: MIT Imports: 19 Imported by: 33

README

log: Smart Logging

Build Status Go Reference

Overview

Package log provides a context-based logging API that intelligently selects what to log. The API is designed to be used in conjunction with the context package. The following example shows how to use the API:

package main

import (
        "context"
        "github.com/goadesign/clue/log"
)

func main() {
        ctx := log.Context(context.Background())
        log.Printf(ctx, "hello %s", "world")
        log.Print(ctx, log.KV{"hello", "world"})

        log.Print(ctx,
                log.KV{"example", "log.KV"},
                log.KV{"order", "deterministic"},
                log.KV{"backed_by", "slice"},
        )

        log.Print(ctx, log.Fields{
                "example": "log.Fields",
                "order": "random",
                "backed_by": "map",
        })
}

The example above logs the following messages to stdout (assuming the default formatter):

time=2022-02-22T02:22:02Z level=info msg="hello world"
time=2022-02-22T02:22:02Z level=info hello=world
time=2022-02-22T02:22:02Z level=info example=log.KV order=deterministic backed_by=slice
time=2022-02-22T02:22:02Z level=info order=random backed_by=map example=log.Fields

A typical instantiation of the logger for a Goa service looks like this:

ctx := log.With(log.Context(context.Background()), log.KV{"svc", svcgen.ServiceName})

Where svcgen is the generated Goa service package. This guarantees that all log entries for the service will have the svc key set to the service name.

Buffering

One of the key features of the log package is that it can buffer log messages until an error occurs (and is logged) or the buffer is explicitely flushed. This allows the application to write informative log messages without having to worry about the volume of logs being written.

Specifically any call to the package Info function buffers log messages until the function Fatal, Error or Flush is called. Calls to Print are not buffered. This makes it possible to log specific messages (e.g. request started, request finished, etc.) without having to flush all the buffered messages.

The following example shows how to use the buffering feature:

log.Infof(ctx, "request started")
// ... no log written so far
log.Errorf(ctx, err, "request failed") // flushes all previous log entries

The example above logs the following messages to stdout after the call to Errorf:

time=2022-02-22T02:22:02Z level=info msg="request started"
time=2022-02-22T02:22:04Z level=error msg="request failed"

The time key makes it possible to infer the order of log events in case buffered and non-buffered function calls are mixed. In practice this rarely happens as non buffered log events are typically created by middlewares which log before and after the business logic.

Conditional Buffering

log can also be configured to disable buffering conditionally based on the current context. This makes it possible to force logging when tracing is enabled for the current request for example.

The following example shows how to conditionally disable the buffering feature:

ctx := log.Context(req.Context(), log.WithDisableBuffering(log.IsTracing))
log.Infof(ctx, "request started") // buffering disabled if tracing is enabled

The function given to WithDisableBuffering is called with the current context and should return a boolean indicating whether buffering should be disabled. It is evaluated upon each call to Context and With.

Usage Pattern

Buffering works best in code implementing network request handling (e.g. HTTP or gRPC requests). The context for each request is used to initialize a new logger context for example by using the HTTP middleware or gRPC intereceptors defined in this package (see below). This allows for:

  • Creating request specific buffers thereby naturally limiting how many logs are kept in memory at a given point in time.
  • Evaluating the buffering conditionally based on the request specific context (e.g. to disable buffering for traced requests).
  • Flushing the buffer when the request encounters an error thereby providing useful information about the request.

Structured Logging

The logging function Print, Debug, Info, Error and Fatal each accept a context and a variadic number of key/value pairs. log also makes it possible to build up the log context with a series of key-value pairs via the With function. The following example shows how to leverage structured logging:

ctx := log.Context(context.Background())
ctx := log.With(ctx, log.KV{"key2", "val2"})
log.Print(ctx, log.KV{"hello",  "world 1"})

ctx = log.With(ctx, log.KV{"key3", "val3"})
log.Print(ctx, log.KV{"hello", "world 2"}, log.KV{"key4", "val4"})

The example above logs the following message to stdout (assuming the terminal formatter is being used):

INFO[0000] key2=val2 hello="world 1"
INFO[0000] key2=val2 key3=val3 hello="world 2" key4=val4

Values must be strings, numbers, booleans, nil or a slice of these types.

Log Severity

log supports three log severities: debug, info, and error. By default debug logs are not written to the log output. The following example shows how to enable debug logging:

ctx := log.Context(context.Background())
log.Debugf(ctx, "debug message 1")

ctx := log.Context(ctx, log.WithDebug())
log.Debugf(ctx, "debug message 2")
log.Infof(ctx, "info message")

The example above logs the following messages to stdout:

DEBG[0000] msg="debug message 2"
INFO[0000] msg="info message"

Note that enabling debug logging also disables buffering and causes all future log messages to be written to the log output as demonstrated above.

Log Output

By default log writes log messages to os.Stdout. The following example shows how to change the log output:

ctx := log.Context(context.Background(), log.WithOutput(os.Stderr))
log.Printf(ctx, "hello world")

The example above logs the following message to stderr:

INFO[0000] msg="hello world"

The WithOuput function accepts any type that implements the io.Writer interface.

Log Format

log comes with three predefined log formats and makes it easy to provide custom formatters. The three built-in formats are:

  • FormatText: a plain text format using logfmt
  • FormatTerminal: a format suitable to print logs to colored terminals
  • FormatJSON: a JSON format
Text Format

The text format is the default format used when the application is not running in a terminal.

ctx := log.Context(context.Background(), log.WithFormat(log.FormatText))
log.Printf(ctx, "hello world")

The example above logs the following message:

time=2022-01-09T20:29:45Z level=info msg="hello world"

Where 2022-01-09T20:29:45Z is the current time in UTC.

Terminal Format

The terminal format is the default format used when the application is running in a terminal.

ctx := log.Context(context.Background(), log.WithFormat(log.FormatTerminal))
log.Printf(ctx, "hello world")

The example above logs the following message:

INFO[0000] msg="hello world"

Where 0000 is the number of seconds since the application started. The severity and each key are colored based on the severity (gray for debug entries, blue for info entries and red for errors).

JSON Format

The JSON format prints entries in JSON.

ctx := log.Context(context.Background(), log.WithFormat(log.FormatJSON))
log.Printf(ctx, "hello world")

The example above logs the following message:

{"time":"2022-01-09T20:29:45Z","level":"info","msg":"hello world"}
Custom Formats

The format can be changed by using the WithFormat function as shown above. Any function that accepts a Entry object and returns a slice of bytes can be used as a format function. The following example shows how to use a custom format function:

func formatFunc(entry *log.Entry) []byte {
        return []byte(fmt.Sprintf("%s: %s", entry.Severity, entry.Keyvals[0].V))
}

ctx := log.Context(context.Background(), log.WithFormat(formatFunc))
log.Printf(ctx, "hello world")

The example above logs the following message to stdout:

INFO: hello world

HTTP Middleware

The log package includes a HTTP middleware that initializes the request context with the logger configured in the given context:

check := log.HTTP(ctx)(health.Handler(health.NewChecker(dep1, dep2, ...)))

gRPC Interceptors

The log package also includes both unary and stream gRPC interceptor that initializes the request or stream context with the logger configured in the given context:

grpcsvr := grpc.NewServer(
	grpcmiddleware.WithUnaryServerChain(
		goagrpcmiddleware.UnaryRequestID(),
		log.UnaryServerInterceptor(ctx),
	))

Standard Logger Compatibility

The log package also provides a compatibility layer for the standard log package. The following example shows how to use the standard logger:

ctx := log.Context(context.Background())
logger := log.AsStdLogger(ctx)
logger.Print("hello world")

The compatibility layer supports the following functions:

  • Print
  • Printf
  • Println
  • Fatal
  • Fatalf
  • Fatalln
  • Panic
  • Panicf
  • Panicln

The standard logger adapter uses log.Print under the hood which means that there is no buffering when using these functions.

Goa Request Logging

Loggers created via the log package can be adapted to the Goa middleware.Logger interface. This makes it possible to use this package to configure the logger used by the middlewares (e.g. to print a log message upon receiving a request and sending a response).

ctx := log.Context(context.Background())
logger := log.AsGoaMiddlewareLogger(ctx) // logger implements middleware.Logger

See the AsGoaMiddlewareLogger function for more details on usage.

Documentation

Index

Examples

Constants

View Source 
const DefaultMaxSize = 1024

DefaultMaxSize is the default maximum size of a single log message or value in bytes. It's also the maximum number of elements in a slice value.

Variables

View Source 
var (
	TraceIDKey      = "traceID"
	RequestIDKey    = "requestID"
	MessageKey      = "msg"
	ErrorMessageKey = "err"
	TimestampKey    = "time"
	SeverityKey     = "level"
)
View Source 
var TimestampFormatLayout = time.RFC3339

TimestampFormatLayout is used to set the layout for our TimestampKey (default "time") values. Default format is time.RFC3339.

Functions

func AsGoaMiddlewareLogger added in v0.3.0 

func AsGoaMiddlewareLogger(ctx context.Context) middleware.Logger

AsGoaMiddlewareLogger creates a Goa middleware compatible logger that can be used when configuring Goa HTTP or gRPC servers.

Usage: 

// HTTP server:
import goahttp "goa.design/goa/v3/http"
import httpmdlwr "goa.design/goa/v3/http/middleware"
...
mux := goahttp.NewMuxer()
handler := httpmdlwr.LogContext(log.AsGoaMiddlewareLogger)(mux)

// gRPC server:
import "google.golang.org/grpc"
import grpcmiddleware "github.com/grpc-ecosystem/go-grpc-middleware"
import grpcmdlwr "goa.design/goa/v3/grpc/middleware"
...
srv := grpc.NewServer(
    grpcmiddleware.WithUnaryServerChain(grpcmdlwr.UnaryServerLogContext(log.AsGoaMiddlewareLogger)),
)

func Context 

func Context(ctx context.Context, opts ...LogOption) context.Context

Context initializes a context for logging.

func Debug 

func Debug(ctx context.Context, keyvals ...Fielder)

Debug writes the key/value pairs to the log output if the log context is configured to log debug messages (via WithDebug).

func Debugf added in v0.1.0 

func Debugf(ctx context.Context, format string, v ...interface{})

Debugf sets the key MessageKey (default "msg") and calls Debug. Arguments are handled in the manner of fmt.Printf.

func Error 

func Error(ctx context.Context, err error, keyvals ...Fielder)

Error flushes the log buffer and disables buffering if not already disabled. Error then sets the ErrorMessageKey (default "err") key with the given error and writes the key/value pairs to the log output.

func Errorf added in v0.1.0 

func Errorf(ctx context.Context, err error, format string, v ...interface{})

Errorf sets the key MessageKey (default "msg") and calls Error. Arguments are handled in the manner of fmt.Printf.

Example 
ctx := Context(context.Background())
err := errors.New("error")
Info(ctx, KV{"hello", "world"})
// No output at this point because Info log events are buffered.
// The call to Errorf causes the buffered events to be flushed.
fmt.Println("---")
Errorf(ctx, err, "failure")

Output:

---
time=2022-02-22T17:00:00Z level=info hello=world
time=2022-02-22T17:00:00Z level=error msg=failure err=error

func Fatal added in v0.1.0 

func Fatal(ctx context.Context, err error, keyvals ...Fielder)

Fatal is equivalent to Error followed by a call to os.Exit(1)

func Fatalf added in v0.1.0 

func Fatalf(ctx context.Context, err error, format string, v ...interface{})

Fatalf is equivalent to Errorf followed by a call to os.Exit(1)

func FlushAndDisableBuffering added in v0.1.0 

func FlushAndDisableBuffering(ctx context.Context)

FlushAndDisableBuffering flushes the log entries to the writer and stops buffering the given context.

func FormatJSON 

func FormatJSON(e *Entry) []byte

FormatJSON is a log formatter that prints entries using JSON. Entries are formatted as follows: 

{
  "time": "TIMESTAMP", // UTC timestamp in RFC3339 format
  "level": "SEVERITY", // one of DEBUG, INFO or ERROR
  "key1": "val1",      // entry key/value pairs
  "key2": "val2",
  ...
}

note: the implementation avoids using reflection (and thus the json package) for efficiency.

Output can be customised with log.TimestampKey, log.TimestampFormatLayout, and log.SeverityKey.

func FormatTerminal 

func FormatTerminal(e *Entry) []byte

FormatTerminal is a log formatter that prints entries suitable for terminal that supports colors. It prints entries in the following format: 

SEVERITY[seconds] key=val key=val ...

Where SEVERITY is one of DEBG, INFO or ERRO, seconds is the number of seconds since the application started, message is the log message, and key=val are the entry key/value pairs. The severity and keys are colored according to the severity (gray for debug entries, blue for info entries and red for errors).

func FormatText 

func FormatText(e *Entry) []byte

FormatText is the default log formatter when not running in a terminal, it prints entries using the logfmt format: 

time=TIME level=SEVERITY KEY=VAL KEY=VAL ...

Where TIME is the UTC timestamp in RFC3339 format, SEVERITY is one of "debug", "info" or "error", and KEY=VAL are the entry key/value pairs. Values are quoted and escaped according to the logfmt specification.

Output can be customised with log.TimestampKey, log.TimestampFormatLayout, and log.SeverityKey.

func HTTP 

func HTTP(logCtx context.Context, opts ...HTTPOption) func(http.Handler) http.Handler

HTTP returns a HTTP middleware that initializes the logger context. It panics if logCtx was not initialized with Context.

func Info 

func Info(ctx context.Context, keyvals ...Fielder)

Info writes the key/value pairs to the log buffer or output if buffering is disabled.

func Infof added in v0.1.0 

func Infof(ctx context.Context, format string, v ...interface{})

Infof sets the key MessageKey (default "msg") and calls Info. Arguments are handled in the manner of fmt.Printf.

func IsTerminal 

func IsTerminal() bool

IsTerminal returns true if the process is running in a terminal.

func IsTracing 

func IsTracing(ctx context.Context) bool

IsTracing returns true if the context contains a trace created via the go.opentelemetry.io/otel/trace package. It is the default DisableBufferingFunc used by newly created loggers.

func MustContainLogger added in v0.5.0 

func MustContainLogger(logCtx context.Context)

MustContainLogger will panic if the given context is missing the logger.

It can be used during server initialisation when you have a function or middleware that you want to ensure receives a context with a logger.

func Print 

func Print(ctx context.Context, keyvals ...Fielder)

Print writes the key/value pairs to the log output ignoring buffering.

Example 
ctx := Context(context.Background())
Print(ctx, KV{"hello", "world"})

Output:

time=2022-02-22T17:00:00Z level=info hello=world

func Printf added in v0.1.0 

func Printf(ctx context.Context, format string, v ...interface{})

Printf sets the key MessageKey (default "msg") and calls Print. Arguments are handled in the manner of fmt.Printf.

Example 
ctx := Context(context.Background())
Printf(ctx, "hello %s", "world")

Output:

time=2022-02-22T17:00:00Z level=info msg="hello world"

func StreamServerInterceptor 

func StreamServerInterceptor(logCtx context.Context) grpc.StreamServerInterceptor

StreamServerInterceptor returns a stream interceptor that configures the request context with the logger contained in logCtx. It panics if logCtx was not initialized with Context.

func UnaryServerInterceptor 

func UnaryServerInterceptor(logCtx context.Context) grpc.UnaryServerInterceptor

UnaryServerInterceptor return an interceptor that configured the request context with the logger contained in logCtx. It panics if logCtx was not initialized with Context.

func With 

func With(ctx context.Context, keyvals ...Fielder) context.Context

With creates a copy of the given log context and appends the given key/value pairs to it. Values must be strings, numbers, booleans, nil or a slice of these types.

func WithContext added in v0.5.0 

func WithContext(parentCtx, logCtx context.Context) context.Context

WithContext will inject the second context in the given one.

It is useful when building middleware handlers such as log.HTTP

Types

type DisableBufferingFunc 

type DisableBufferingFunc func(context.Context) bool

DisableBufferingFunc is a function that returns true if the logger should disable buffering for the given context.

type Entry 

type Entry struct {
	Time     time.Time
	Severity Severity
	KeyVals  kvList
}

Log entry

type Fielder added in v0.6.0 

type Fielder interface {
	LogFields() []KV
}

Fielder is an interface that will return a slice of KV

type Fields added in v0.6.0 

type Fields map[string]interface{}

Fields allows to quickly define fields for cases where you are OK with non-deterministic order of the fields

func (Fields) LogFields added in v0.6.0 

func (f Fields) LogFields() []KV

type FormatFunc 

type FormatFunc func(e *Entry) []byte

FormatFunc is a function that formats a log entry.

type HTTPOption added in v0.6.0 

type HTTPOption func(*httpOptions)

HTTPOption is a function that applies a configuration option to log HTTP middleware.

func WithPathFilter added in v0.6.0 

func WithPathFilter(filter *regexp.Regexp) HTTPOption

WithPathFilter adds a path filter to the HTTP middleware. Requests whose path match the filter are not logged. WithPathFilter can be called multiple times to add multiple filters.

type KV added in v0.1.0 

type KV struct {
	K string
	V interface{}
}

KV represents a key/value pair. Values must be strings, numbers, booleans, nil or a slice of these types.

func (KV) LogFields added in v0.6.0 

func (kv KV) LogFields() []KV

type LogOption 

type LogOption func(*options)

LogOption is a function that applies a configuration option to a logger.

func WithDebug 

func WithDebug() LogOption

WithDebug enables debug logging and disables buffering.

func WithDisableBuffering 

func WithDisableBuffering(fn DisableBufferingFunc) LogOption

WithDisableBuffering sets the DisableBufferingFunc called to assess whether buffering should be disabled.

func WithFileLocation added in v0.1.0 

func WithFileLocation() LogOption

WithFileLocation adds the "file" key to each log entry with the parent directory, file and line number of the caller: "file=dir/file.go:123".

func WithFormat 

func WithFormat(fn FormatFunc) LogOption

WithFormat sets the log format.

func WithFunc added in v0.1.0 

func WithFunc(fn func(context.Context) []KV) LogOption

WithFunc sets a key/value pair generator function to be called with every log entry. The generated key/value pairs are added to the log entry.

func WithMaxSize 

func WithMaxSize(n int) LogOption

WithMaxSize sets the maximum size of a single log message or value.

func WithOutput 

func WithOutput(w io.Writer) LogOption

WithOutput sets the log output.

type Severity 

type Severity int

Log severity enum 

const (
	SeverityDebug Severity = iota + 1
	SeverityInfo
	SeverityError
)

func (Severity) Code 

func (l Severity) Code() string

Code returns a 4-character code for the log severity.

func (Severity) Color 

func (l Severity) Color() string

Color returns an escape sequence that colors the output for the given severity.

func (Severity) String 

func (l Severity) String() string

String returns a string representation of the log severity.

type StdLogger added in v0.3.0 

type StdLogger struct {
	// contains filtered or unexported fields
}

StdLogger implements an interface compatible with the stdlib log package.

func AsStdLogger added in v0.3.0 

func AsStdLogger(ctx context.Context) *StdLogger

AsStdLogger adapts a Goa logger to a stdlib compatible logger.

func (*StdLogger) Fatal added in v0.3.0 

func (l *StdLogger) Fatal(v ...interface{})

Fatal is equivalent to l.Print() followed by a call to os.Exit(1).

func (*StdLogger) Fatalf added in v0.3.0 

func (l *StdLogger) Fatalf(format string, v ...interface{})

Fatalf is equivalent to l.Printf() followed by a call to os.Exit(1).

func (*StdLogger) Fatalln added in v0.3.0 

func (l *StdLogger) Fatalln(v ...interface{})

Fatalln is equivalent to l.Println() followed by a call to os.Exit(1).

func (*StdLogger) Panic added in v0.3.0 

func (l *StdLogger) Panic(v ...interface{})

Panic is equivalent to l.Print() followed by a call to panic().

func (*StdLogger) Panicf added in v0.3.0 

func (l *StdLogger) Panicf(format string, v ...interface{})

Panicf is equivalent to l.Printf() followed by a call to panic().

func (*StdLogger) Panicln added in v0.3.0 

func (l *StdLogger) Panicln(v ...interface{})

Panicln is equivalent to l.Println() followed by a call to panic().

func (*StdLogger) Print added in v0.3.0 

func (l *StdLogger) Print(v ...interface{})

Print print to the logger. Arguments are handled in the manner of fmt.Print.

func (*StdLogger) Printf added in v0.3.0 

func (l *StdLogger) Printf(format string, v ...interface{})

Printf prints to the logger. Arguments are handled in the manner of fmt.Printf.

func (*StdLogger) Println added in v0.3.0 

func (l *StdLogger) Println(v ...interface{})

Println prints to the logger. Arguments are handled in the manner of fmt.Println.

Source Files

View all Source files

Jump to

Keyboard shortcuts

? : This menu
/ : Search site
f or F : Jump to
y or Y : Canonical URL
go.dev uses cookies from Google to deliver and enhance the quality of its services and to analyze traffic. Learn more.