mediocre-go-lib/mlog/mlog.go
Brian Picciano 15efa4ba3a mlog: refactor to handle certain use cases better, and make KV merging more consistent
Logger is now initialized with its WriteCloser (which can never change
after initialization) and then has its properties modified via method
calls. These method calls return new copies of the Logger, all writing
to the same original WriteCloser still. This allows for doing things
like having a Logger within some entity that has its own KV, for
example.

Also I revamped the merging code a bit, and fixed a precedence
inconsitency in ErrWithKV and CtxWithKV.
2018-05-28 07:53:39 +00:00

382 lines
10 KiB
Go

// Package mlog is a generic logging library. The log methods come in different
// severities: Debug, Info, Warn, Error, and Fatal.
//
// The log methods take in a string describing the error, and a set of key/value
// pairs giving the specific context around the error. The string is intended to
// always be the same no matter what, while the key/value pairs give information
// like which userID the error happened to, or any other relevant contextual
// information.
//
// Examples:
//
// Info("Something important has occurred")
// Error("Could not open file", llog.KV{"filename": filename}, llog.ErrKV(err))
//
package mlog
import (
"bytes"
"fmt"
"io"
"os"
"sort"
"strconv"
"strings"
"sync"
)
// Truncate is a helper function to truncate a string to a given size. It will
// add 3 trailing elipses, so the returned string will be at most size+3
// characters long
func Truncate(s string, size int) string {
if len(s) <= size {
return s
}
return s[:size] + "..."
}
// Level describes the severity of a particular log message, and can be compared
// to the severity of any other Level
type Level interface {
// String gives the string form of the level, e.g. "INFO" or "ERROR"
String() string
// Uint gives an integer indicator of the severity of the level, with zero
// being most severe. If a Level with Uint of zero is logged then the Logger
// implementation provided by this package will exit the process (i.e. zero
// is used as Fatal).
Uint() uint
}
type level struct {
s string
i uint
}
func (l level) String() string {
return l.s
}
func (l level) Uint() uint {
return l.i
}
// All pre-defined log levels
var (
DebugLevel Level = level{s: "DEBUG", i: 40}
InfoLevel Level = level{s: "INFO", i: 30}
WarnLevel Level = level{s: "WARN", i: 20}
ErrorLevel Level = level{s: "ERROR", i: 10}
FatalLevel Level = level{s: "FATAL", i: 0}
)
// LevelFromString parses a string, possibly lowercase, and returns the Level
// identified by it, or an error.
//
// Note that this only works for the Levels pre-defined in this package, if
// you've extended the package to use your own levels you'll have to implement
// your own LevelFromString method.
func LevelFromString(ls string) (Level, error) {
var l Level
switch strings.ToUpper(ls) {
case "DEBUG":
l = DebugLevel
case "INFO":
l = InfoLevel
case "WARN":
l = WarnLevel
case "ERROR":
l = ErrorLevel
case "FATAL":
l = FatalLevel
default:
return nil, fmt.Errorf("unknown log level %q", ls)
}
return l, nil
}
// KVer is used to provide context to a log entry in the form of a dynamic set
// of key/value pairs which can be different for every entry.
//
// Each returned KV should be modifiable.
type KVer interface {
KV() KV
}
// KV is a set of key/value pairs which provides context for a log entry by a
// KVer. KV is itself also a KVer.
type KV map[string]interface{}
// KV implements the KVer method by returning a copy of the KV
func (kv KV) KV() KV {
nkv := make(KV, len(kv))
for k, v := range kv {
nkv[k] = v
}
return nkv
}
// Set returns a copy of the KV being called on with the given key/val set on
// it. The original KV is unaffected
func (kv KV) Set(k string, v interface{}) KV {
nkv := kv.KV()
nkv[k] = v
return nkv
}
// separate from MergeInto because it's convenient to not return a KVer if that
// KVer is going to immediately have KV called on it (and thereby create a copy
// for no reason).
//
// this may take in any amount of nil values, but should never return nil
func mergeInto(kv KVer, kvs ...KVer) KV {
if kv == nil {
kv = KV(nil) // will return empty map when KV is called on it
}
kvm := kv.KV()
for _, kv := range kvs {
if kv == nil {
continue
}
for k, v := range kv.KV() {
kvm[k] = v
}
}
return kvm
}
// separate from Merge because it's convenient to not return a KVer if that KVer
// is going to immediately have KV called on it (and thereby create a copy for
// no reason).
//
// this may take in any amount of nil values, but should never return nil
func merge(kvs ...KVer) KV {
if len(kvs) == 0 {
return KV{}
}
return mergeInto(kvs[0], kvs[1:]...)
}
// Merge takes in multiple KVers and returns a single KVer which is the union of
// all the passed in ones. Key/vals on the rightmost of the set take precedence
// over conflicting ones to the left.
func Merge(kvs ...KVer) KVer {
return merge(kvs...)
}
// MergeInto is a convenience function which acts similarly to Merge.
func MergeInto(kv KVer, kvs ...KVer) KVer {
return mergeInto(kv, kvs...)
}
// Message describes a message to be logged, after having already resolved the
// KVer
type Message struct {
Level
Msg string
KV KV
}
// WriteFn describes a function which formats a single log message and writes it
// to the given io.Writer. If the io.Writer returns an error WriteFn should
// return that error.
type WriteFn func(w io.Writer, msg Message) error
func stringSlice(kv KV) [][2]string {
slice := make([][2]string, 0, len(kv))
for k, v := range kv {
slice = append(slice, [2]string{
k,
strconv.QuoteToGraphic(fmt.Sprint(v)),
})
}
sort.Slice(slice, func(i, j int) bool {
return slice[i][0] < slice[j][0]
})
return slice
}
// DefaultWriteFn is the default implementation of WriteFn.
func DefaultWriteFn(w io.Writer, msg Message) error {
var err error
write := func(s string, args ...interface{}) {
if err == nil {
_, err = fmt.Fprintf(w, s, args...)
}
}
write("~ %s -- %s", msg.Level.String(), msg.Msg)
if len(msg.KV) > 0 {
write(" --")
for _, kve := range stringSlice(msg.KV) {
write(" %s=%s", kve[0], kve[1])
}
}
write("\n")
return err
}
type msg struct {
buf *bytes.Buffer
msg Message
}
// Logger wraps a WriteFn and an io.WriteCloser such that logging calls on the
// Logger will use them (in a thread-safe manner) to write out log messages.
type Logger struct {
wc io.WriteCloser
wfn WriteFn
maxLevel uint
kv KV
msgBufPool *sync.Pool
msgCh chan msg
testMsgWrittenCh chan struct{} // only initialized/used in tests
}
// NewLogger initializes and returns a new instance of Logger which will write
// to the given WriteCloser.
func NewLogger(wc io.WriteCloser) *Logger {
l := &Logger{
wc: wc,
wfn: DefaultWriteFn,
msgBufPool: &sync.Pool{
New: func() interface{} {
return new(bytes.Buffer)
},
},
msgCh: make(chan msg, 1024),
maxLevel: InfoLevel.Uint(),
}
go l.spin()
return l
}
func (l *Logger) cp() *Logger {
l2 := *l
return &l2
}
func (l *Logger) spin() {
for msg := range l.msgCh {
if _, err := io.Copy(l.wc, msg.buf); err != nil {
go l.Error("error writing to Logger's WriteCloser", ErrKV(err))
}
l.msgBufPool.Put(msg.buf)
if l.testMsgWrittenCh != nil {
l.testMsgWrittenCh <- struct{}{}
}
if msg.msg.Level.Uint() == 0 {
l.wc.Close()
os.Exit(1)
}
}
l.wc.Close()
}
// WithMaxLevelUint returns a copy of the Logger with its max logging level set
// to the given uint. The Logger will not log any messages with a higher
// Level.Uint value.
func (l *Logger) WithMaxLevelUint(i uint) *Logger {
l = l.cp()
l.maxLevel = i
return l
}
// WithMaxLevel returns a copy of the Logger with its max Level set to the given
// one. The Logger will not log any messages with a higher Level.Uint value.
func (l *Logger) WithMaxLevel(lvl Level) *Logger {
return l.WithMaxLevelUint(lvl.Uint())
}
// WithWriteFn returns a copy of the Logger which will use the given WriteFn
// to format and write Messages to the Logger's WriteCloser. This does not
// affect the WriteFn of the original Logger, and both can be used at the same
// time.
func (l *Logger) WithWriteFn(wfn WriteFn) *Logger {
l = l.cp()
l.wfn = wfn
return l
}
// WithKV returns a copy of Logger which will implicitly use the KVers for all
// log messages.
func (l *Logger) WithKV(kvs ...KVer) *Logger {
l = l.cp()
l.kv = mergeInto(l.kv, kvs...)
return l
}
// Stop stops and cleans up any running go-routines and resources held by the
// Logger, allowing it to be garbage-collected. The Logger should not be used
// after Stop is called
func (l *Logger) Stop() {
close(l.msgCh)
}
// Log can be used to manually log a message of some custom defined Level. kvs
// will be Merge'd automatically. If the Level is a fatal (Uint() == 0) then
// calling this will never return, and the process will have os.Exit(1) called.
func (l *Logger) Log(lvl Level, msgStr string, kvs ...KVer) {
if l.maxLevel < lvl.Uint() {
return
}
m := Message{Level: lvl, Msg: msgStr, KV: mergeInto(l.kv, kvs...)}
buf := l.msgBufPool.Get().(*bytes.Buffer)
buf.Reset()
if err := l.wfn(buf, m); err != nil {
// TODO welp, hopefully this doesn't infinite loop
l.Log(ErrorLevel, "Logger could not write to WriteCloser", ErrKV(err))
return
}
l.msgCh <- msg{buf: buf, msg: m}
// if a Fatal is logged then we're merely waiting here for spin to call
// os.Exit, and this go-routine shouldn't be allowed to continue
if lvl.Uint() == 0 {
select {}
}
}
// Debug logs a DebugLevel message, merging the KVers together first
func (l *Logger) Debug(msg string, kvs ...KVer) {
l.Log(DebugLevel, msg, kvs...)
}
// Info logs a InfoLevel message, merging the KVers together first
func (l *Logger) Info(msg string, kvs ...KVer) {
l.Log(InfoLevel, msg, kvs...)
}
// Warn logs a WarnLevel message, merging the KVers together first
func (l *Logger) Warn(msg string, kvs ...KVer) {
l.Log(WarnLevel, msg, kvs...)
}
// Error logs a ErrorLevel message, merging the KVers together first
func (l *Logger) Error(msg string, kvs ...KVer) {
l.Log(ErrorLevel, msg, kvs...)
}
// Fatal logs a FatalLevel message, merging the KVers together first. A Fatal
// message automatically stops the process with an os.Exit(1)
func (l *Logger) Fatal(msg string, kvs ...KVer) {
l.Log(FatalLevel, msg, kvs...)
}
// DefaultLogger is a Logger using the default configuration (which will log to
// stderr). The Debug, Info, Warn, etc... methods from DefaultLogger are exposed
// as global functions for convenience. Because Logger is not truly initialized
// till the first time it is called any of DefaultLogger's fields may be
// modified before using one of the Debug, Info, Warn, etc... global functions.
var (
DefaultLogger = NewLogger(os.Stderr)
Debug = DefaultLogger.Debug
Info = DefaultLogger.Info
Warn = DefaultLogger.Warn
Error = DefaultLogger.Error
Fatal = DefaultLogger.Fatal
)