m: refactor to use new Component stuff, and make the log logic a bit better

This commit is contained in:
Brian Picciano 2019-06-17 17:56:14 -04:00
parent e741e79acf
commit e91ef01857
3 changed files with 124 additions and 94 deletions

151
m/m.go
View File

@ -1,130 +1,151 @@
// Package m is the glue which holds all the other packages in this project // Package m implements functionality specific to how I like my programs to
// together. While other packages in this project are intended to be able to be // work. It acts as glue between many of the other packages in this framework,
// used separately and largely independently, this package combines them in ways // putting them together in the way I find most useful.
// which I specifically like.
package m package m
import ( import (
"context" "context"
"os" "os"
"os/signal" "os/signal"
"time"
"github.com/mediocregopher/mediocre-go-lib/mcfg" "github.com/mediocregopher/mediocre-go-lib/mcfg"
"github.com/mediocregopher/mediocre-go-lib/mcmp"
"github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/mctx"
"github.com/mediocregopher/mediocre-go-lib/merr" "github.com/mediocregopher/mediocre-go-lib/merr"
"github.com/mediocregopher/mediocre-go-lib/mlog" "github.com/mediocregopher/mediocre-go-lib/mlog"
"github.com/mediocregopher/mediocre-go-lib/mrun" "github.com/mediocregopher/mediocre-go-lib/mrun"
) )
type ctxKey int type cmpKey int
const ( const (
ctxKeyCfgSrc ctxKey = iota cmpKeyCfgSrc cmpKey = iota
ctxKeyInfoLog cmpKeyInfoLog
) )
func debugLog(msg string, ctxs ...context.Context) { func debugLog(cmp *mcmp.Component, msg string, ctxs ...context.Context) {
fn := mlog.Debug level := mlog.DebugLevel
if len(ctxs) > 0 { if len(ctxs) > 0 {
if ok, _ := ctxs[0].Value(ctxKeyInfoLog).(bool); ok { if ok, _ := ctxs[0].Value(cmpKeyInfoLog).(bool); ok {
fn = mlog.Info level = mlog.InfoLevel
} }
} }
fn(msg, ctxs...)
mlog.From(cmp).Log(mlog.Message{
Level: level,
Description: msg,
Contexts: ctxs,
})
} }
// ProcessContext returns a Context which should be used as the root Context // RootComponent returns a Component which should be used as the root Component
// when implementing most processes. // when implementing most programs.
// //
// The returned Context will automatically handle setting up global // The returned Component will automatically handle setting up global
// configuration parameters like "log-level", as well as an http endpoint where // configuration parameters like "log-level", as well as parsing those
// debug information about the running process can be accessed. // and all other parameters when the Init even is triggered on it.
func ProcessContext() context.Context { func RootComponent() *mcmp.Component {
ctx := context.Background() cmp := new(mcmp.Component)
// embed confuration source which should be used into the context. // embed confuration source which should be used into the context.
ctx = context.WithValue(ctx, ctxKeyCfgSrc, mcfg.Source(new(mcfg.SourceCLI))) cmp.SetValue(cmpKeyCfgSrc, mcfg.Source(new(mcfg.SourceCLI)))
// set up log level handling // set up log level handling
logger := mlog.NewLogger() logger := mlog.NewLogger()
ctx = mlog.WithLogger(ctx, logger) mlog.SetLogger(cmp, logger)
ctx, logLevelStr := mcfg.WithString(ctx, "log-level", "info", "Maximum log level which will be printed.")
ctx = mrun.WithStartHook(ctx, func(context.Context) error { // set up parameter parsing
mrun.InitHook(cmp, func(context.Context) error {
src, _ := cmp.Value(cmpKeyCfgSrc).(mcfg.Source)
if src == nil {
return merr.New("Component not sourced from m package", cmp.Context())
} else if err := mcfg.Populate(cmp, src); err != nil {
return merr.Wrap(err, cmp.Context())
}
return nil
})
logLevelStr := mcfg.String(cmp, "log-level",
mcfg.ParamDefault("info"),
mcfg.ParamUsage("Maximum log level which will be printed."))
mrun.InitHook(cmp, func(context.Context) error {
logLevel := mlog.LevelFromString(*logLevelStr) logLevel := mlog.LevelFromString(*logLevelStr)
if logLevel == nil { if logLevel == nil {
ctx := mctx.Annotate(ctx, "log-level", *logLevelStr) return merr.New("invalid log level", cmp.Context(),
return merr.New("invalid log level", ctx) mctx.Annotated("log-level", *logLevelStr))
} }
logger.SetMaxLevel(logLevel) logger.SetMaxLevel(logLevel)
return nil return nil
}) })
return ctx return cmp
} }
// ServiceContext extends ProcessContext so that it better supports long running // RootServiceComponent extends RootComponent so that it better supports long
// processes which are expected to handle requests from outside clients. // running processes which are expected to handle requests from outside clients.
// //
// Additional behavior it adds includes setting up an http endpoint where debug // Additional behavior it adds includes setting up an http endpoint where debug
// information about the running process can be accessed. // information about the running process can be accessed.
func ServiceContext() context.Context { func RootServiceComponent() *mcmp.Component {
ctx := ProcessContext() cmp := RootComponent()
// services expect to use many different configuration sources // services expect to use many different configuration sources
ctx = context.WithValue(ctx, ctxKeyCfgSrc, mcfg.Source(mcfg.Sources{ cmp.SetValue(cmpKeyCfgSrc, mcfg.Source(mcfg.Sources{
new(mcfg.SourceEnv), new(mcfg.SourceEnv),
new(mcfg.SourceCLI), new(mcfg.SourceCLI),
})) }))
// it's useful to show debug entries (from this package specifically) as // it's useful to show debug entries (from this package specifically) as
// info logs for long-running services. // info logs for long-running services.
ctx = context.WithValue(ctx, ctxKeyInfoLog, true) cmp.SetValue(cmpKeyInfoLog, true)
// TODO set up the debug endpoint. // TODO set up the debug endpoint.
return ctx return cmp
} }
// Start performs the work of populating configuration parameters and triggering // MustInit will call mrun.Init on the given Component, which must have been
// the start event. It will return once the Start event has completed running. // created in this package, and exit the process if mrun.Init does not complete
// // successfully.
// This function returns a Context because there are cases where the Context func MustInit(cmp *mcmp.Component) {
// will be modified during Start, such as if WithSubCommand was used. If the ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
// Context was not modified then the passed in Context will be returned. defer cancel()
func Start(ctx context.Context) context.Context {
src, _ := ctx.Value(ctxKeyCfgSrc).(mcfg.Source)
if src == nil {
mlog.Fatal("ctx not sourced from m package", ctx)
}
// no logging should happen before populate, primarily because log-level debugLog(cmp, "initializing")
// hasn't been populated yet, but also because it makes help output on cli if err := mrun.Init(ctx, cmp); err != nil {
// look weird. mlog.From(cmp).Fatal("initialization failed", merr.Context(err))
ctx, err := mcfg.Populate(ctx, src)
if err != nil {
mlog.Fatal("error populating configuration", ctx, merr.Context(err))
} else if err := mrun.Start(ctx); err != nil {
mlog.Fatal("error triggering start event", ctx, merr.Context(err))
} }
debugLog("start hooks completed", ctx) debugLog(cmp, "initialization completed successfully")
return ctx
} }
// StartWaitStop performs the work of populating configuration parameters, // MustShutdown is like MustInit, except that it triggers the Shutdown event on
// triggering the start event, waiting for an interrupt, and then triggering the // the Component.
// stop event. Run will block until the stop event is done. If any errors are func MustShutdown(cmp *mcmp.Component) {
// encountered a fatal is thrown. ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
func StartWaitStop(ctx context.Context) { defer cancel()
ctx = Start(ctx)
debugLog(cmp, "shutting down")
if err := mrun.Shutdown(ctx, cmp); err != nil {
mlog.From(cmp).Fatal("shutdown failed", merr.Context(err))
}
debugLog(cmp, "shutting down completed successfully")
}
// Exec calls MustInit on the given Component, then blocks until an interrupt
// signal is received, then calls MustShutdown on the Component, until finally
// exiting the process.
func Exec(cmp *mcmp.Component) {
MustInit(cmp)
{ {
ch := make(chan os.Signal, 1) ch := make(chan os.Signal, 1)
signal.Notify(ch, os.Interrupt) signal.Notify(ch, os.Interrupt)
s := <-ch s := <-ch
debugLog("signal received, stopping", mctx.Annotate(ctx, "signal", s)) debugLog(cmp, "signal received, stopping", mctx.Annotated("signal", s))
} }
MustShutdown(cmp)
if err := mrun.Stop(ctx); err != nil { debugLog(cmp, "exiting process")
mlog.Fatal("error triggering stop event", ctx, merr.Context(err)) os.Stdout.Sync()
} os.Stderr.Sync()
debugLog("exiting process", ctx) os.Exit(0)
} }

View File

@ -6,47 +6,42 @@ import (
. "testing" . "testing"
"github.com/mediocregopher/mediocre-go-lib/mcfg" "github.com/mediocregopher/mediocre-go-lib/mcfg"
"github.com/mediocregopher/mediocre-go-lib/mctx"
"github.com/mediocregopher/mediocre-go-lib/mlog" "github.com/mediocregopher/mediocre-go-lib/mlog"
"github.com/mediocregopher/mediocre-go-lib/mrun"
"github.com/mediocregopher/mediocre-go-lib/mtest/massert" "github.com/mediocregopher/mediocre-go-lib/mtest/massert"
) )
func TestServiceCtx(t *T) { func TestServiceCtx(t *T) {
t.Run("log-level", func(t *T) { t.Run("log-level", func(t *T) {
ctx := ServiceContext() cmp := RootComponent()
// pull the Logger out of the ctx and set the Handler on it, so we can check // pull the Logger out of the component and set the Handler on it, so we
// the log level // can check the log level
var msgs []mlog.Message var msgs []mlog.Message
logger := mlog.From(ctx) logger := mlog.GetLogger(cmp)
logger.SetHandler(func(msg mlog.Message) error { logger.SetHandler(func(msg mlog.Message) error {
msgs = append(msgs, msg) msgs = append(msgs, msg)
return nil return nil
}) })
mlog.SetLogger(cmp, logger)
// create a child Context before running to ensure it the change propagates // create a child Component before running to ensure it the change propagates
// correctly. // correctly.
ctxA := mctx.NewChild(ctx, "A") cmpA := cmp.Child("A")
ctx = mctx.WithChild(ctx, ctxA)
params := mcfg.ParamValues{{Name: "log-level", Value: json.RawMessage(`"DEBUG"`)}} params := mcfg.ParamValues{{Name: "log-level", Value: json.RawMessage(`"DEBUG"`)}}
if _, err := mcfg.Populate(ctx, params); err != nil { cmp.SetValue(cmpKeyCfgSrc, params)
t.Fatal(err) MustInit(cmp)
} else if err := mrun.Start(ctx); err != nil {
t.Fatal(err)
}
mlog.From(ctxA).Info("foo", ctxA) mlog.From(cmpA).Info("foo")
mlog.From(ctxA).Debug("bar", ctxA) mlog.From(cmpA).Debug("bar")
massert.Require(t, massert.Require(t,
massert.Length(msgs, 2), massert.Length(msgs, 2),
massert.Equal(msgs[0].Level.String(), "INFO"), massert.Equal(msgs[0].Level.String(), "INFO"),
massert.Equal(msgs[0].Description, "foo"), massert.Equal(msgs[0].Description, "foo"),
massert.Equal(msgs[0].Contexts, []context.Context{ctxA}), massert.Equal(msgs[0].Contexts, []context.Context{cmpA.Context()}),
massert.Equal(msgs[1].Level.String(), "DEBUG"), massert.Equal(msgs[1].Level.String(), "DEBUG"),
massert.Equal(msgs[1].Description, "bar"), massert.Equal(msgs[1].Description, "bar"),
massert.Equal(msgs[1].Contexts, []context.Context{ctxA}), massert.Equal(msgs[1].Contexts, []context.Context{cmpA.Context()}),
) )
}) })
} }

View File

@ -11,31 +11,45 @@ type cmpKey int
// retrieved from the Component, or any of its children, using From. // retrieved from the Component, or any of its children, using From.
func SetLogger(cmp *mcmp.Component, l *Logger) { func SetLogger(cmp *mcmp.Component, l *Logger) {
cmp.SetValue(cmpKey(0), l) cmp.SetValue(cmpKey(0), l)
// If the base Logger on this Component gets changed, then the cached Logger
// from From on this Component, and all of its Children, ought to be reset,
// so that any changes can be reflected in their loggers.
var resetFromLogger func(*mcmp.Component)
resetFromLogger = func(cmp *mcmp.Component) {
cmp.SetValue(cmpKey(1), nil)
for _, childCmp := range cmp.Children() {
resetFromLogger(childCmp)
}
}
resetFromLogger(cmp)
} }
// DefaultLogger is an instance of Logger which is returned by From when a // DefaultLogger is an instance of Logger which is returned by From when a
// Logger hasn't been previously set with SetLogger on the passed in Component. // Logger hasn't been previously set with SetLogger on the passed in Component.
var DefaultLogger = NewLogger() var DefaultLogger = NewLogger()
// From returns the Logger which was set on the Component, or one of its // GetLogger returns the Logger which was set on the Component, or on of its
// ancestors, using SetLogger. If no Logger was ever set then DefaultLogger is // ancestors, using SetLogger. If no Logger was ever set then DefaultLogger is
// returned. // returned.
// func GetLogger(cmp *mcmp.Component) *Logger {
// The returned Logger will be modified such that it will implicitly merge the if l, ok := cmp.InheritedValue(cmpKey(0)); ok {
// Contexts of any Message into the given Component's Context. return l.(*Logger)
}
return DefaultLogger
}
// From returns the result from GetLogger, modified so as to automatically add
// some annotations related to the Component itself to all Messages being
// logged.
func From(cmp *mcmp.Component) *Logger { func From(cmp *mcmp.Component) *Logger {
var l *Logger if l, _ := cmp.Value(cmpKey(1)).(*Logger); l != nil {
if l, _ = cmp.Value(cmpKey(1)).(*Logger); l != nil {
return l return l
} else if lInt, ok := cmp.InheritedValue(cmpKey(0)); ok {
l = lInt.(*Logger)
} else {
l = DefaultLogger
} }
// if we're here it means a modified Logger wasn't set on this particular // if we're here it means a modified Logger wasn't set on this particular
// Component, and therefore the current one must be modified. // Component, and therefore the current one must be modified.
l = l.Clone() l := GetLogger(cmp).Clone()
oldHandler := l.Handler() oldHandler := l.Handler()
l.SetHandler(func(msg Message) error { l.SetHandler(func(msg Message) error {
ctx := mctx.MergeAnnotationsInto(cmp.Context(), msg.Contexts...) ctx := mctx.MergeAnnotationsInto(cmp.Context(), msg.Contexts...)