witchcraft-go-logging

witchcraft-go-logging is a Go implementation of the Witchcraft logging specification. It provides an API that can be used for logging along with several implementations and adapters.

Implementations wrap existing Go logging libraries in order to implement the wlog interface. We currently provide

• zap via wlog-zap
• zerolog via wlog-zerolog
• glog via wlog-glog
• wlog-tmpl for rendering structured logging using human-friendly templates.

Adapters wrap the witchcraft-go-logging logger implementations (svc1log, ev2log, req2log, etc) to allow interoperability with other Go logging interfaces. We currently provide

• svc1zap wraps a svc1log.Logger to provide a zap Logger.

Architecture

witchcraft-go-logging defines versioned logger interfaces for specific logger types (service.1 loggers, request.2 loggers, etc.) and provides implementations of those interfaces. The logger packages define functions for instantiating these loggers and often provide functions for creating parameters for the loggers and for storing and retrieving loggers from a context.Context.

The loggers are implemented using abstractions defined in the wlog package -- specifically, wlog.LogEntry, wlog.Logger and wlog.LeveledLogger.

wlog.LogEntry is an interface that represents a log entry, and offers functions for appending typed key-value pairs to an entry. It also provides an ObjectValue function which can append values of arbitrary types.

The wlog.Logger interface defines the Log(params ...Param) function, where a Param is a functional parameter that typically operates on a wlog.LogEntry by calling set functions on it. Conceptually, the Log function applies all of the append operations specified by the Param arguments to an internal wlog.LogEntry object and outputs the result.

The wlog.LeveledLogger is similar to the wlog.Logger interface, but rather than having a Log function it declares functions for logging at specific levels with a message (Debug(msg string, params ...Param), Info(msg string, params ...Param), etc.) and defines a SetLevel(level LogLevel) function that can be used to configure the level of the logger.

The wlog.LoggerCreator and wlog.LevelLoggerCreator function types (defined as type LoggerCreator func(w io.Writer) Logger and type LeveledLoggerCreator func(w io.Writer, level LogLevel) LeveledLogger, respectively) define signatures for creating a wlog.Logger or wlog.LeveledLogger given the required parameters.

The specific logger types define an instantiation function that takes in one of the logger creator types defined above as an argument and instantiates a typed logger that is backed by the logger implementation returned by the creator. For example, metric1log defines func NewFromCreator(w io.Writer, creator wlog.LoggerCreator) Logger, which creates a new metric.1 logger using the provided creator function that writes to the specified output. Logger types also define an instantiation function that does not require specifying a creator -- these functions use the logger creator supplied by the globally defined default logger instead. For example, metric1log defines func New(w io.Writer) Logger.

Set the default logger provider

In the canonical usage pattern for loggers, loggers are instantiated using the version of the function that does not specify a logger implementation -- for example, metric1log.New(w io.Writer) Logger.

These functions use the wlog.DefaultLoggerProvider() function to get the logger creator required to instantiate the logger. This function returns a wlog.LoggerProvider, which is defined as:

type LoggerProvider interface {
	NewLogger(w io.Writer) Logger
	NewLeveledLogger(w io.Writer, level LogLevel) LeveledLogger
}

The default implementation of wlog.DefaultLoggerProvider() returns a logger that outputs a warning that states that the default logger provider has not been set. For example, running the program:

package main

import (
	"os"

	"github.com/palantir/witchcraft-go-logging/wlog"
	"github.com/palantir/witchcraft-go-logging/wlog/svclog/svc1log"
)

func main() {
	logger := svc1log.New(os.Stdout, wlog.InfoLevel)
	logger.Info("Hello")
}

Results in the following output to STDOUT:

[WARNING] Logging operation that uses the default logger provider was performed without specifying a logger provider implementation. To see logger output, set the global logger provider implementation using wlog.SetDefaultLoggerProvider or by importing an implementation. This warning can be disabled by setting the global logger provider to be the noop logger provider using wlog.SetDefaultLoggerProvider(wlog.NewNoopLoggerProvider()).

The global logger provider should always be set by the top-level program (the main package), so if this warning is output it indicates that the top-level program should set a global logger implementation.

Most logger implementations have a package that contains an init() function that sets the global logger provider to be the implementation's provider. This allows an underscore import to set the logger provider. For example, the following sets the default logger provider to be a provider backed by zap:

package main

import (
	"os"

	"github.com/palantir/witchcraft-go-logging/wlog"
	"github.com/palantir/witchcraft-go-logging/wlog/svclog/svc1log"
	// import wlog-zap to set zap as the default logger provider
	_ "github.com/palantir/witchcraft-go-logging/wlog-zap"
)

func main() {
	logger := svc1log.New(os.Stdout, wlog.InfoLevel)
	logger.Info("Hello")
}

Running this program results in the following output to STDOUT:

{"level":"INFO","time":"2018-12-01T05:25:28.856348Z","message":"Hello","type":"service.1"}

It is also possible to set the default logger provider explicitly using the SetDefaultLoggerProvider(provider LoggerProvider) function in wlog. For example, the following program also uses wlog-zap as the default logger provider, but does so by calling wlog.SetDefaultLoggerProvider(wlogzap.LoggerProvider()) rather than using an import:

package main

import (
	"os"

	"github.com/palantir/witchcraft-go-logging/wlog"
	"github.com/palantir/witchcraft-go-logging/wlog-zap"
	"github.com/palantir/witchcraft-go-logging/wlog/svclog/svc1log"
)

func main() {
	wlog.SetDefaultLoggerProvider(wlogzap.LoggerProvider())
	logger := svc1log.New(os.Stdout, wlog.InfoLevel)
	logger.Info("Hello")
}

Setting the default logger provider to a no-op logger disables all output of loggers created using the default logger provider. This can be done by calling wlog.SetDefaultLoggerProvider(wlog.NewNoopLoggerProvider()).

Using loggers in code

Creating loggers and making them available in code

Each logger defines creation functions that typically take the io.Writer to which the logger output should be written as an argument. There are typically 2 versions of a logger creation function: one that is explicitly provided with the logger implementation that should be used to create the logger, and another which uses the default logger provider (as determined at runtime) to create the logger. In most cases, loggers are created using the function that uses the default logger provider (this makes it easier to set the default logger provider once to change all implementation).

Loggers are typically created by the top-level program (the program with a main package) and made available to other code using some mechanism such as setting it in an exported package variable, passing it as an argument or setting it in the contexts provided to program logic. This is a general issue common to all logging frameworks, and witchcraft-go-logging does not take an explicit stance on the correct approach.

Packages that are written as libraries typically do not instantiate loggers themselves -- they either accept the required loggers as arguments or have a context parameter and require that the expected loggers be set in the context.

Using contexts to propagate loggers

Most logger packages define functions that can be used to set and retrieve the logger from a context. For example, the svc1log package defines WithLogger and FromContext functions that can be used to set a logger on a context and retrieve a logger from a context, respectively.

If a FromContext function is called on a context that does not have the logger set, it creates a default logger that is returned instead. This ensures that the function will not return nil. However, this situation is usually indicative of a programming error -- the consuming API expected a logger to be set on a context, but it was not (this implicit API dependency is a commonly expressed concern about using storing loggers in contexts). As such, the default implementation of the logger returned in this situation is configured to write to STDERR, and writes a warning about this situation (followed by the actual logger output). The logger returned by the FromContext function when no logger is present in the context is configurable, so if this default behavior is not desirable it can be changed -- for example, one may return a noop logger to quietly suppress output or return nil to force a panic in this situation.

One advantage of using loggers stored in contexts is the ability to decorate them with parameters so that subsequent calls use the provided parameters. For example, consider the following series of calls starting with UpdateService:

func UpdateService(ctx context.Context, serviceID string) {
	ctx = svc1log.WithLoggerParams(ctx, svc1log.SafeParam("serviceId", serviceID))
	for _, currProcessID := range processIDs {
		updateProcess(ctx, currProcessID)
	}
}

func updateProcess(ctx context.Context, processID string) {
	ctx = svc1log.WithLoggerParams(ctx, svc1log.SafeParam("processId", processID))
	updateValue(ctx, processVals[processID], "timestamp", time.Now().String())
}

func updateValue(ctx context.Context, vals map[string]string, key, newValue string) {
	prevValue := vals[key]
	vals[key] = newValue
	svc1log.FromContext(ctx).Debug("Updating value", svc1log.SafeParam("prevValue", prevValue), svc1log.SafeParam("newValue", newValue))
}

In this series of calls, each function creates a new context that decorates its service logger with the provided parameter. This has the result that, when updateValue performs its debug logging, the serviceId and processId parameters that were added in the previous calls will be included in the logger output.

Updating audit logger category definitions

Audit logger category definitions come from 2 different places:

• Conjure objects generated from the audit-api Conjure definition
• Generated Go code that defines the request and result fields and translates an AuditCategoryV2 object to an audit parameter

The Conjure objects come from the Conjure definitions, while the generated Go code is based on Java code that defines audit categories.

In order to update audit logger category definitions, it is necessary to update the Conjure definition and to generate the Go code from the latest Java code.

Updating the Conjure definition

Audit logger categories are defined by the "audit-api" Conjure definition. The Conjure definition is published internally. The definition can be updated in this repository by following these steps:

1. Obtain the latest version of the Conjure definition (the .conjure.json file)
2. Remove the existing definition from the conjure/defs directory
3. Place the new definition in the conjure/defs directory
4. Update the Conjure definition in the godel/config/conjure-plugin.yml file to point to the new definition
5. Run ./godelw conjure to generate the code for the new definition

Updating the generated Go code

The generated Go code is based on the Java code in the AuditCategoryConfiguration.java in the foundry-audit project. This is an internal project. The generated go code can be updated as follows:

1. Obtain the latest version of the Java code and note the path to the "AuditCategoryConfiguration.java" file
2. Run the [category_transform.go](wlog/auditlog/audit3log/internal/category_transform.go) file as a main program with the path to the "AuditCategoryConfiguration.java" as the argument. The working directory should be the wlog/auditlog/audit3log/internal directory.

This will generate the "categories.go" file. Note that the generator logic assumes that the definitions in the Java code are written in a particular manner -- if the format or definition of the definitions in the Java code changes, the generator must be updated to handle the new format.

Active TODOs

• Improve testing loggers that produce non-JSON output (glog)
• Port over more tests for audit logs

License

This project is made available under the Apache 2.0 License.