From 20c6f950913b1c881ba18850ba7f4a161bfc44bd Mon Sep 17 00:00:00 2001 From: Brian Picciano Date: Wed, 30 Jan 2019 16:06:24 -0500 Subject: [PATCH] mlog: refactor to use Clone/Set instead of With pattern, implement CtxSetAll --- cmd/totp-proxy/main.go | 4 ++- mhttp/mhttp.go | 4 ++- mhttp/mhttp_test.go | 5 ++- mlog/ctx.go | 74 ++++++++++++++++++++++++------------------ mlog/ctx_test.go | 23 ++++++++++++- mlog/mlog.go | 70 +++++++++++++++++++-------------------- mlog/mlog_test.go | 13 +++++--- mnet/mnet.go | 3 +- mnet/mnet_test.go | 5 ++- 9 files changed, 123 insertions(+), 78 deletions(-) diff --git a/cmd/totp-proxy/main.go b/cmd/totp-proxy/main.go index ad5bf8a..c2a6032 100644 --- a/cmd/totp-proxy/main.go +++ b/cmd/totp-proxy/main.go @@ -60,7 +60,9 @@ func main() { }) authHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - authLogger := logger.WithKV(mlog.CtxKV(r.Context())) + // TODO mlog.FromHTTP? + authLogger := logger.Clone() + authLogger.SetKV(mlog.CtxKV(r.Context())) unauthorized := func() { w.Header().Add("WWW-Authenticate", "Basic") diff --git a/mhttp/mhttp.go b/mhttp/mhttp.go index d6dc288..96ebf5f 100644 --- a/mhttp/mhttp.go +++ b/mhttp/mhttp.go @@ -28,7 +28,9 @@ func MListenAndServe(ctx mctx.Context, h http.Handler) *http.Server { ctx = mctx.ChildOf(ctx, "http") listener := mnet.MListen(ctx, "tcp", "") listener.NoCloseOnStop = true // http.Server.Shutdown will do this - logger := mlog.From(ctx).WithKV(listener) + + logger := mlog.From(ctx) + logger.SetKV(listener) srv := http.Server{Handler: h} mrun.OnStart(ctx, func(mctx.Context) error { diff --git a/mhttp/mhttp_test.go b/mhttp/mhttp_test.go index fa7fda2..85edc8c 100644 --- a/mhttp/mhttp_test.go +++ b/mhttp/mhttp_test.go @@ -15,8 +15,11 @@ import ( ) func TestMListenAndServe(t *T) { + // TODO mtest.NewCtx ctx := mctx.ChildOf(mctx.New(), "test") - mlog.CtxSet(ctx, mlog.From(ctx).WithMaxLevel(mlog.DebugLevel)) + logger := mlog.From(ctx) + logger.SetMaxLevel(mlog.DebugLevel) + mlog.CtxSet(ctx, logger) h := http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { io.Copy(rw, r.Body) diff --git a/mlog/ctx.go b/mlog/ctx.go index f4880b8..e601f1d 100644 --- a/mlog/ctx.go +++ b/mlog/ctx.go @@ -21,6 +21,24 @@ func CtxSet(ctx mctx.Context, l *Logger) { }) } +// CtxSetAll traverses the given Context's children, breadth-first. It calls the +// callback for each Context which has a Logger set on it, replacing that Logger +// with the returned one. +// +// This is useful, for example, when changing the log level of all Loggers in an +// app. +func CtxSetAll(ctx mctx.Context, callback func(mctx.Context, *Logger) *Logger) { + mctx.BreadthFirstVisit(ctx, func(ctx mctx.Context) bool { + mctx.GetSetMutableValue(ctx, false, ctxKey(0), func(i interface{}) interface{} { + if i == nil { + return nil + } + return callback(ctx, i.(*Logger)) + }) + return true + }) +} + type ctxPathStringer struct { str Stringer pathStr string @@ -39,39 +57,31 @@ func (cp ctxPathStringer) String() string { // Context parent's Logger. If the parent hasn't had From called on it its // parent will be queried instead, and so on. func From(ctx mctx.Context) *Logger { - var from func(mctx.Context) *Logger - from = func(ctx mctx.Context) *Logger { - return mctx.GetSetMutableValue(ctx, true, ctxKey(0), func(interface{}) interface{} { + return mctx.GetSetMutableValue(ctx, true, ctxKey(0), func(interface{}) interface{} { + ctxPath := mctx.Path(ctx) + if len(ctxPath) == 0 { + // we're at the root node and it doesn't have a Logger set, use + // the default + return NewLogger() + } - ctxPath := mctx.Path(ctx) - if len(ctxPath) == 0 { - // we're at the root node and it doesn't have a Logger set, use - // the default - return NewLogger() - } + // set up child's logger + pathStr := "/" + path.Join(ctxPath...) - // set up child's logger - pathStr := "/" - if len(ctxPath) > 0 { - pathStr += path.Join(ctxPath...) - } - - parentL := from(mctx.Parent(ctx)) - prevH := parentL.Handler() - return parentL.WithHandler(func(msg Message) error { - // if the Description is already a ctxPathStringer it can be - // assumed this Message was passed in from a child Logger. - if _, ok := msg.Description.(ctxPathStringer); !ok { - msg.Description = ctxPathStringer{ - str: msg.Description, - pathStr: pathStr, - } + parentL := From(mctx.Parent(ctx)) + parentH := parentL.Handler() + thisL := parentL.Clone() + thisL.SetHandler(func(msg Message) error { + // if the Description is already a ctxPathStringer it can be + // assumed this Message was passed in from a child Logger. + if _, ok := msg.Description.(ctxPathStringer); !ok { + msg.Description = ctxPathStringer{ + str: msg.Description, + pathStr: pathStr, } - return prevH(msg) - }) - - }).(*Logger) - } - - return from(ctx) + } + return parentH(msg) + }) + return thisL + }).(*Logger) } diff --git a/mlog/ctx_test.go b/mlog/ctx_test.go index 90eb0f2..7dba374 100644 --- a/mlog/ctx_test.go +++ b/mlog/ctx_test.go @@ -14,7 +14,8 @@ func TestContextStuff(t *T) { ctx1b := mctx.ChildOf(ctx1, "b") var descrs []string - l := NewLogger().WithHandler(func(msg Message) error { + l := NewLogger() + l.SetHandler(func(msg Message) error { descrs = append(descrs, msg.Description.String()) return nil }) @@ -23,6 +24,7 @@ func TestContextStuff(t *T) { From(ctx1a).Info("ctx1a") From(ctx1).Info("ctx1") From(ctx).Info("ctx") + From(ctx1b).Debug("ctx1b (shouldn't show up)") From(ctx1b).Info("ctx1b") ctx2 := mctx.ChildOf(ctx, "2") @@ -36,4 +38,23 @@ func TestContextStuff(t *T) { massert.Equal(descrs[3], "(/1/b) ctx1b"), massert.Equal(descrs[4], "(/2) ctx2"), )) + + // use CtxSetAll to change all MaxLevels in-place + ctx2L := From(ctx2) + CtxSetAll(ctx, func(_ mctx.Context, l *Logger) *Logger { + l.SetMaxLevel(DebugLevel) + return l + }) + + descrs = descrs[:0] + From(ctx).Info("ctx") + From(ctx).Debug("ctx debug") + ctx2L.Debug("ctx2L debug") + + massert.Fatal(t, massert.All( + massert.Len(descrs, 3), + massert.Equal(descrs[0], "ctx"), + massert.Equal(descrs[1], "ctx debug"), + massert.Equal(descrs[2], "(/2) ctx2L debug"), + )) } diff --git a/mlog/mlog.go b/mlog/mlog.go index 5c1eb5e..9570ded 100644 --- a/mlog/mlog.go +++ b/mlog/mlog.go @@ -264,9 +264,10 @@ func DefaultHandler() Handler { } // Logger directs Messages to an internal Handler and provides convenient -// methods for creating and modifying its own behavior. +// methods for creating and modifying its own behavior. All methods are +// thread-safe. type Logger struct { - w io.Writer + l *sync.RWMutex h Handler maxLevel uint kv KVer @@ -278,54 +279,50 @@ type Logger struct { // to the DefaultHandler. func NewLogger() *Logger { return &Logger{ + l: new(sync.RWMutex), h: DefaultHandler(), maxLevel: InfoLevel.Uint(), } } -// Handler returns the Handler currently in use by the Logger. -func (l *Logger) Handler() Handler { - return l.h -} - -func (l *Logger) clone() *Logger { +// Clone returns an identical instance of the Logger which can be modified +// independently of the original. +func (l *Logger) Clone() *Logger { l2 := *l + l2.l = new(sync.RWMutex) return &l2 } -// WithMaxLevelUint returns a copy of the Logger which will not log any messages -// with a higher Level.Uint value than the one given. The returned Logger is -// identical in all other aspects. -func (l *Logger) WithMaxLevelUint(i uint) *Logger { - l = l.clone() - l.maxLevel = i - return l +// SetMaxLevel sets the Logger to not log any messages with a higher Level.Uint +// value than of the one given. +func (l *Logger) SetMaxLevel(lvl Level) { + l.l.Lock() + defer l.l.Unlock() + l.maxLevel = lvl.Uint() } -// WithMaxLevel returns a copy of the Logger which will not log any messages -// with a higher Level.Uint value than of the Level given. The returned Logger -// is identical in all other aspects. -func (l *Logger) WithMaxLevel(lvl Level) *Logger { - return l.WithMaxLevelUint(lvl.Uint()) -} - -// WithHandler returns a copy of the Logger which will use the given Handler in -// order to process messages. The returned Logger is identical in all other -// aspects. -func (l *Logger) WithHandler(h Handler) *Logger { - l = l.clone() +// SetHandler sets the Logger to use the given Handler in order to process +// Messages. +func (l *Logger) SetHandler(h Handler) { + l.l.Lock() + defer l.l.Unlock() l.h = h - return l } -// WithKV returns a copy of the Logger which will use the merging of the given -// KVers as a base KVer for all log messages. If the original Logger already had -// a base KVer (via a previous WithKV call) then this set will be merged onto -// that one. -func (l *Logger) WithKV(kvs ...KVer) *Logger { - l = l.clone() +// Handler returns the Handler currently in use by the Logger. +func (l *Logger) Handler() Handler { + l.l.RLock() + defer l.l.RUnlock() + return l.h +} + +// SetKV sets the Logger to use the merging of the given KVers as a base KVer +// for all Messages. If the Logger already had a base KVer (via a previous SetKV +// call) then this set will be merged onto that one. +func (l *Logger) SetKV(kvs ...KVer) { + l.l.Lock() + defer l.l.Unlock() l.kv = MergeInto(l.kv, kvs...) - return l } // Log can be used to manually log a message of some custom defined Level. @@ -333,6 +330,9 @@ func (l *Logger) WithKV(kvs ...KVer) *Logger { // 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(msg Message) { + l.l.RLock() + defer l.l.RUnlock() + if l.maxLevel < msg.Level.Uint() { return } diff --git a/mlog/mlog_test.go b/mlog/mlog_test.go index 3bd8d7a..0c5c0ec 100644 --- a/mlog/mlog_test.go +++ b/mlog/mlog_test.go @@ -41,7 +41,8 @@ func TestLogger(t *T) { return DefaultFormat(buf, msg) } - l := NewLogger().WithHandler(h) + l := NewLogger() + l.SetHandler(h) l.testMsgWrittenCh = make(chan struct{}, 10) assertOut := func(expected string) massert.Assertion { @@ -68,7 +69,7 @@ func TestLogger(t *T) { assertOut("~ ERROR -- buz\n"), )) - l = l.WithMaxLevel(WarnLevel) + l.SetMaxLevel(WarnLevel) l.Debug("foo") l.Info("bar") l.Warn("baz") @@ -78,8 +79,9 @@ func TestLogger(t *T) { assertOut("~ ERROR -- buz -- a=\"b\"\n"), )) - l2 := l.WithMaxLevel(InfoLevel) - l2 = l2.WithHandler(func(msg Message) error { + l2 := l.Clone() + l2.SetMaxLevel(InfoLevel) + l2.SetHandler(func(msg Message) error { msg.Description = String(strings.ToUpper(msg.Description.String())) return h(msg) }) @@ -92,7 +94,8 @@ func TestLogger(t *T) { assertOut("~ ERROR -- buz\n"), )) - l3 := l2.WithKV(KV{"a": 1}) + l3 := l2.Clone() + l3.SetKV(KV{"a": 1}) l3.Info("foo", KV{"b": 2}) l3.Info("bar", KV{"a": 2, "b": 3}) massert.Fatal(t, massert.All( diff --git a/mnet/mnet.go b/mnet/mnet.go index c602823..577f705 100644 --- a/mnet/mnet.go +++ b/mnet/mnet.go @@ -38,7 +38,8 @@ func MListen(ctx mctx.Context, network, defaultAddr string) *MListener { addr := mcfg.String(ctx, "listen-addr", defaultAddr, network+" address to listen on in format [host]:port. If port is 0 then a random one will be chosen") l := new(MListener) - l.log = mlog.From(ctx).WithKV(l) + l.log = mlog.From(ctx) + l.log.SetKV(l) mrun.OnStart(ctx, func(mctx.Context) error { var err error diff --git a/mnet/mnet_test.go b/mnet/mnet_test.go index 91f241b..5c50389 100644 --- a/mnet/mnet_test.go +++ b/mnet/mnet_test.go @@ -39,8 +39,11 @@ func TestIsReservedIP(t *T) { } func TestMListen(t *T) { + // TODO mtest.NewCtx ctx := mctx.ChildOf(mctx.New(), "test") - mlog.CtxSet(ctx, mlog.From(ctx).WithMaxLevel(mlog.DebugLevel)) + logger := mlog.From(ctx) + logger.SetMaxLevel(mlog.DebugLevel) + mlog.CtxSet(ctx, logger) l := MListen(ctx, "", "") if err := mcfg.Populate(ctx, nil); err != nil {