Skip to content

fortio/log

Repository files navigation

codecov

Log

Fortio's log is simple logger built on top of go's default one with additional opinionated levels similar to glog but simpler to use and configure.

It's been used for many years for Fortio's org Fortio project and more (under fortio.org/fortio/log package) but split out recently for standalone use, with the "flag pollution" limited (as a library it doesn't include the flags, you configure it using apis).

// On a cli tool (avoids file name and line numbers, stack traces on log.Fatalf etc)
log.SetDefaultsForClientTools()
log.LoggerStaticFlagSetup() // adds -loglevel flag to configure
// Or on a server type, import fortio.org/dflag, then:
dflag.LoggerFlagSetup()

// Then, printf style leveled logging:
log.Debugf(...) // Debug level
log.LogVf(...)  // Verbose level
log.Infof(...)  // Info/default level
log.Warnf(...)  // Warning level
log.Errf(...)   // Error level
log.Critf(...)  // Critical level (always logged even if level is set to max)
log.Fatalf(...) // Fatal level - program will panic/exit

// for http servers there is also
// access log type including user-agent, forwarded ip/proto (behind load balancer case),
// TLS crypto used and CN of peer certificate if any.
log.LogRequest(r, "some info")

// Structured logging with attributes
log.S(log.Info, "msg", log.Attr("key1", value1)...)

See the Config object for options like whether to include line number and file name of caller or not etc

New since 1.4 server logging (as used in fortio.org/scli for instance) is now structured (JSON), client logging (as setup by fortio.org/cli remains as before.

One can also revert server to not be JSON through config.

In JSON mode the output looks like this

{"ts":1683504169.239557,"level":"info","file":"logger.go","line":221,"msg":"Log level is now 1 Verbose (was 2 Info"}

Which can be converted to JSONEntry but is also a fixed, optimized format (ie ts is always first etc)

The timestamp ts is in seconds.microseconds since epoch (golang UnixMicro() split into seconds part before decimal and microseconds after)

Since 1.8 the Go Routine ID is present in JSON (r field) or colorized log output (for multi threaded server types).

Optional additional KeyValue pairs can be added to the base structure using the new log.S or passed to log.LogRequest using log.Any and log.Str. Note that numbers, as well as arrays of any type and maps of string keys to any type are supported (but more expensive to serialize recursively).

If console output is detected (and ConsoleColor is true, which is the default) or if ForceColor is set, colorized output similar to logc will be done instead of JSON. levelsDemo/levels.go produces the following output:

When output is redirected, JSON output:

{"ts":1689986143.463329,"level":"dbug","r":1,"file":"levels.go","line":16,"msg":"This is a debug message ending with backslash \\"}
{"ts":1689986143.463374,"level":"trace","r":1,"file":"levels.go","line":17,"msg":"This is a verbose message"}
{"ts":1689986143.463378,"level":"info","r":1,"msg":"This an always printed, file:line omitted message"}
{"ts":1689986143.463382,"level":"info","r":1,"file":"levels.go","line":19,"msg":"This is an info message with no attributes but with \"quotes\"..."}
{"ts":1689986143.463389,"level":"info","r":1,"file":"levels.go","line":20,"msg":"This is multi line\n\tstructured info message with 3 attributes","attr1":"value1","attr2":42,"attr3":"\"quoted\nvalue\""}
{"ts":1689986143.463396,"level":"warn","r":1,"file":"levels.go","line":22,"msg":"This is a warning message"}
{"ts":1689986143.4634,"level":"err","r":1,"file":"levels.go","line":23,"msg":"This is an error message"}
{"ts":1689986143.463403,"level":"crit","r":1,"file":"levels.go","line":24,"msg":"This is a critical message"}
{"ts":1689986143.463406,"level":"fatal","r":1,"file":"levels.go","line":25,"msg":"This is a fatal message"}
This is a non-JSON output, will get prefixed with a exclamation point with logc

When on console:

Example console color output

JSON formatted logs can also be converted back to text later/after capture and similarly colorized using fortio.org/logc

The log.Colors can be used by callers and they'll be empty string when not in color mode, and the ansi escape codes otherwise.

HTTP request/response logging

LogAndCall() combines LogRequest and LogResponse for a light middleware recording what happens during serving of a request (both incoming and outgoing attributes).

For instance (most attributes elided for brevity, also logs client cert and TLSInfo if applicable)

{"level":"info","msg":"test-log-and-call2","method":"GET","url":"/tea","status":418,"size":5,"microsec":100042}

Config

You can either use fortio.org/cli or fortio.org/scli (or dflags) for configuration using flags (or dynamic flags and config map) or use the environment variables:

LOGGER_LOG_PREFIX=' '
LOGGER_LOG_FILE_AND_LINE=false
LOGGER_FATAL_PANICS=false
LOGGER_JSON=false
LOGGER_NO_TIMESTAMP=false
LOGGER_CONSOLE_COLOR=true
LOGGER_FORCE_COLOR=false
LOGGER_GOROUTINE_ID=false
LOGGER_COMBINE_REQUEST_AND_RESPONSE=true
LOGGER_LEVEL='Info'

Small binaries

If you're never logging http requests/responses, use -tags no_http (or -tags no_net) to exclude the http/https logging utilities (which pulls in a lot of dependencies because of net/http init).

If you never need to JSON log complex structures/types that have a special json.Marshaler then you can use -tags no_net,no_json for the smallest executables

(see make size-check)