From e1e52db208914e49746b2486469fa024ed0aa9e7 Mon Sep 17 00:00:00 2001 From: Brian Picciano Date: Sat, 9 Feb 2019 14:08:30 -0500 Subject: [PATCH] refactor everything to use context's annotation system, making some significant changes to annotations themselves along the way --- README.md | 7 + TODO | 2 + cmd/totp-proxy/main.go | 31 ++-- m/m.go | 27 +-- m/m_test.go | 11 +- mcfg/cli.go | 5 +- mcfg/cli_test.go | 10 +- mcfg/env.go | 3 +- mcfg/mcfg.go | 2 +- mcfg/mcfg_test.go | 12 +- mcfg/param.go | 143 ++++++++------- mcfg/source_test.go | 14 +- mcrypto/pair.go | 15 +- mcrypto/secret.go | 5 +- mcrypto/sig.go | 13 +- mcrypto/uuid.go | 5 +- mctx/annotate.go | 305 ++++++++++++++++++++++++++----- mctx/annotate_test.go | 75 +++++--- mctx/ctx.go | 17 +- mctx/stack.go | 94 ++++++++++ {merr => mctx}/stack_test.go | 14 +- mdb/mbigquery/bigquery.go | 45 ++--- mdb/mbigtable/bigtable.go | 62 +++---- mdb/mbigtable/bigtable_test.go | 6 +- mdb/mdatastore/datastore.go | 34 ++-- mdb/mdatastore/datastore_test.go | 6 +- mdb/mdb.go | 27 +-- mdb/mpubsub/pubsub.go | 87 ++++----- mdb/mpubsub/pubsub_test.go | 12 +- merr/kv.go | 120 ------------ merr/kv_test.go | 98 ---------- merr/merr.go | 191 +++++++++++-------- merr/merr_test.go | 71 +++++-- merr/stack.go | 85 --------- mhttp/mhttp.go | 31 ++-- mhttp/mhttp_test.go | 4 +- mlog/ctx.go | 53 +++--- mlog/ctx_test.go | 67 ------- mlog/errctx.go | 30 --- mlog/errctx_test.go | 44 ----- mlog/mlog.go | 246 +++++-------------------- mlog/mlog_test.go | 163 +++-------------- mnet/mnet.go | 55 +++--- mnet/mnet_test.go | 6 +- mrun/hook.go | 44 ++--- mrun/hook_test.go | 14 +- mrun/mrun.go | 8 +- mrun/mrun_test.go | 20 +- mtest/mtest.go | 18 +- mtest/mtest_test.go | 6 +- 50 files changed, 1080 insertions(+), 1383 deletions(-) create mode 100644 TODO create mode 100644 mctx/stack.go rename {merr => mctx}/stack_test.go (78%) delete mode 100644 merr/kv.go delete mode 100644 merr/kv_test.go delete mode 100644 merr/stack.go delete mode 100644 mlog/ctx_test.go delete mode 100644 mlog/errctx.go delete mode 100644 mlog/errctx_test.go diff --git a/README.md b/README.md index 6bdc6e3..ef5ffac 100644 --- a/README.md +++ b/README.md @@ -27,8 +27,15 @@ Everything here are guidelines, not actual rules. * https://github.com/golang/go/wiki/CodeReviewComments +* Package names may be abbreviations of a concept, but types, functions, and + methods should all be full words. + * When deciding if a package should initialize a struct as a value or pointer, a good rule is: If it's used as an immutable value it should be a value, otherwise it's a pointer. Even if the immutable value implementation has internal caching, locks, etc..., that can be hidden as pointers inside the struct, but the struct itself can remain a value type. + +* A function which takes in a `context.Context` and returns a modified copy of + that same `context.Context` should have a name prefixed with `With`, e.g. + `WithValue` or `WithLogger`. Exceptions like `Annotate` do exist. diff --git a/TODO b/TODO new file mode 100644 index 0000000..6de66ce --- /dev/null +++ b/TODO @@ -0,0 +1,2 @@ +- read through all docs, especially package docs, make sure they make sense +- write examples diff --git a/cmd/totp-proxy/main.go b/cmd/totp-proxy/main.go index 6326740..f85c313 100644 --- a/cmd/totp-proxy/main.go +++ b/cmd/totp-proxy/main.go @@ -20,6 +20,7 @@ import ( "github.com/mediocregopher/mediocre-go-lib/m" "github.com/mediocregopher/mediocre-go-lib/mcfg" "github.com/mediocregopher/mediocre-go-lib/mcrypto" + "github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/mhttp" "github.com/mediocregopher/mediocre-go-lib/mlog" "github.com/mediocregopher/mediocre-go-lib/mrand" @@ -29,27 +30,27 @@ import ( ) func main() { - ctx := m.NewServiceCtx() - ctx, cookieName := mcfg.String(ctx, "cookie-name", "_totp_proxy", "String to use as the name for cookies") - ctx, cookieTimeout := mcfg.Duration(ctx, "cookie-timeout", mtime.Duration{1 * time.Hour}, "Timeout for cookies") + ctx := m.ServiceContext() + ctx, cookieName := mcfg.WithString(ctx, "cookie-name", "_totp_proxy", "String to use as the name for cookies") + ctx, cookieTimeout := mcfg.WithDuration(ctx, "cookie-timeout", mtime.Duration{1 * time.Hour}, "Timeout for cookies") var userSecrets map[string]string - ctx = mcfg.RequiredJSON(ctx, "users", &userSecrets, "JSON object which maps usernames to their TOTP secret strings") + ctx = mcfg.WithRequiredJSON(ctx, "users", &userSecrets, "JSON object which maps usernames to their TOTP secret strings") var secret mcrypto.Secret - ctx, secretStr := mcfg.String(ctx, "secret", "", "String used to sign authentication tokens. If one isn't given a new one will be generated on each startup, invalidating all previous tokens.") - ctx = mrun.OnStart(ctx, func(context.Context) error { + ctx, secretStr := mcfg.WithString(ctx, "secret", "", "String used to sign authentication tokens. If one isn't given a new one will be generated on each startup, invalidating all previous tokens.") + ctx = mrun.WithStartHook(ctx, func(context.Context) error { if *secretStr == "" { *secretStr = mrand.Hex(32) } - mlog.Info(ctx, "generating secret") + mlog.Info("generating secret", ctx) secret = mcrypto.NewSecret([]byte(*secretStr)) return nil }) proxyHandler := new(struct{ http.Handler }) - ctx, proxyURL := mcfg.RequiredString(ctx, "dst-url", "URL to proxy requests to. Only the scheme and host should be set.") - ctx = mrun.OnStart(ctx, func(context.Context) error { + ctx, proxyURL := mcfg.WithRequiredString(ctx, "dst-url", "URL to proxy requests to. Only the scheme and host should be set.") + ctx = mrun.WithStartHook(ctx, func(context.Context) error { u, err := url.Parse(*proxyURL) if err != nil { return err @@ -60,7 +61,6 @@ func main() { authHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { // TODO mlog.FromHTTP? - // TODO annotate this ctx ctx := r.Context() unauthorized := func() { @@ -79,7 +79,8 @@ func main() { } if cookie, _ := r.Cookie(*cookieName); cookie != nil { - mlog.Debug(ctx, "authenticating with cookie", mlog.KV{"cookie": cookie.String()}) + mlog.Debug("authenticating with cookie", + mctx.Annotate(ctx, "cookie", cookie.String())) var sig mcrypto.Signature if err := sig.UnmarshalText([]byte(cookie.Value)); err == nil { err := mcrypto.VerifyString(secret, sig, "") @@ -91,10 +92,8 @@ func main() { } if user, pass, ok := r.BasicAuth(); ok && pass != "" { - mlog.Debug(ctx, "authenticating with user/pass", mlog.KV{ - "user": user, - "pass": pass, - }) + mlog.Debug("authenticating with user", + mctx.Annotate(ctx, "user", user)) if userSecret, ok := userSecrets[user]; ok { if totp.Validate(pass, userSecret) { authorized() @@ -106,6 +105,6 @@ func main() { unauthorized() }) - ctx, _ = mhttp.MListenAndServe(ctx, authHandler) + ctx, _ = mhttp.WithListeningServer(ctx, authHandler) m.Run(ctx) } diff --git a/m/m.go b/m/m.go index c50675f..992b6c2 100644 --- a/m/m.go +++ b/m/m.go @@ -6,10 +6,12 @@ package m import ( "context" + "log" "os" "os/signal" "github.com/mediocregopher/mediocre-go-lib/mcfg" + "github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/merr" "github.com/mediocregopher/mediocre-go-lib/mlog" "github.com/mediocregopher/mediocre-go-lib/mrun" @@ -24,25 +26,26 @@ func CfgSource() mcfg.Source { } } -// NewServiceCtx returns a Context which should be used as the root Context when -// creating long running services, such as an RPC service or database. +// ServiceContext returns a Context which should be used as the root Context +// when creating long running services, such as an RPC service or database. // // The returned Context will automatically handle setting up global // configuration parameters like "log-level", as well as an http endpoint where // debug information about the running process can be accessed. // // TODO set up the debug endpoint. -func NewServiceCtx() context.Context { +func ServiceContext() context.Context { ctx := context.Background() // set up log level handling logger := mlog.NewLogger() - ctx = mlog.Set(ctx, logger) - ctx, logLevelStr := mcfg.String(ctx, "log-level", "info", "Maximum log level which will be printed.") - ctx = mrun.OnStart(ctx, func(context.Context) error { + ctx = mlog.WithLogger(ctx, logger) + ctx, logLevelStr := mcfg.WithString(ctx, "log-level", "info", "Maximum log level which will be printed.") + ctx = mrun.WithStartHook(ctx, func(context.Context) error { logLevel := mlog.LevelFromString(*logLevelStr) + log.Printf("setting log level to %v", logLevel) if logLevel == nil { - return merr.New("invalid log level", "log-level", *logLevelStr) + return merr.New(ctx, "invalid log level", "log-level", *logLevelStr) } logger.SetMaxLevel(logLevel) return nil @@ -58,20 +61,20 @@ func NewServiceCtx() context.Context { func Run(ctx context.Context) { log := mlog.From(ctx) if err := mcfg.Populate(ctx, CfgSource()); err != nil { - log.Fatal(ctx, "error populating configuration", merr.KV(err)) + log.Fatal("error populating configuration", ctx, merr.Context(err)) } else if err := mrun.Start(ctx); err != nil { - log.Fatal(ctx, "error triggering start event", merr.KV(err)) + log.Fatal("error triggering start event", ctx, merr.Context(err)) } { ch := make(chan os.Signal, 1) signal.Notify(ch, os.Interrupt) s := <-ch - log.Info(ctx, "signal received, stopping", mlog.KV{"signal": s}) + log.Info("signal received, stopping", mctx.Annotate(ctx, "signal", s)) } if err := mrun.Stop(ctx); err != nil { - log.Fatal(ctx, "error triggering stop event", merr.KV(err)) + log.Fatal("error triggering stop event", ctx, merr.Context(err)) } - log.Info(ctx, "exiting process") + log.Info("exiting process", ctx) } diff --git a/m/m_test.go b/m/m_test.go index ad6d84a..47eb4b9 100644 --- a/m/m_test.go +++ b/m/m_test.go @@ -1,6 +1,7 @@ package m import ( + "context" "encoding/json" . "testing" @@ -13,7 +14,7 @@ import ( func TestServiceCtx(t *T) { t.Run("log-level", func(t *T) { - ctx := NewServiceCtx() + ctx := ServiceContext() // pull the Logger out of the ctx and set the Handler on it, so we can check // the log level @@ -36,16 +37,16 @@ func TestServiceCtx(t *T) { t.Fatal(err) } - mlog.From(ctxA).Info(ctxA, "foo") - mlog.From(ctxA).Debug(ctxA, "bar") + mlog.From(ctxA).Info("foo", ctxA) + mlog.From(ctxA).Debug("bar", ctxA) massert.Fatal(t, massert.All( massert.Len(msgs, 2), massert.Equal(msgs[0].Level.String(), "INFO"), massert.Equal(msgs[0].Description, "foo"), - massert.Equal(msgs[0].Context, ctxA), + massert.Equal(msgs[0].Contexts, []context.Context{ctxA}), massert.Equal(msgs[1].Level.String(), "DEBUG"), massert.Equal(msgs[1].Description, "bar"), - massert.Equal(msgs[1].Context, ctxA), + massert.Equal(msgs[1].Contexts, []context.Context{ctxA}), )) }) } diff --git a/mcfg/cli.go b/mcfg/cli.go index bd0d9ad..807734a 100644 --- a/mcfg/cli.go +++ b/mcfg/cli.go @@ -1,6 +1,7 @@ package mcfg import ( + "context" "fmt" "io" "os" @@ -89,7 +90,7 @@ func (cli SourceCLI) Parse(params []Param) ([]ParamValue, error) { break } if !pvOk { - return nil, merr.New("unexpected config parameter", "param", arg) + return nil, merr.New(context.Background(), "unexpected config parameter", "param", arg) } } @@ -120,7 +121,7 @@ func (cli SourceCLI) Parse(params []Param) ([]ParamValue, error) { pvStrValOk = false } if pvOk && !pvStrValOk { - return nil, merr.New("param expected a value", "param", key) + return nil, merr.New(p.Context, "param expected a value", "param", key) } return pvs, nil } diff --git a/mcfg/cli_test.go b/mcfg/cli_test.go index 892f7a2..7d48709 100644 --- a/mcfg/cli_test.go +++ b/mcfg/cli_test.go @@ -15,11 +15,11 @@ import ( func TestSourceCLIHelp(t *T) { ctx := context.Background() - ctx, _ = Int(ctx, "foo", 5, "Test int param ") // trailing space should be trimmed - ctx, _ = Bool(ctx, "bar", "Test bool param.") - ctx, _ = String(ctx, "baz", "baz", "Test string param") - ctx, _ = RequiredString(ctx, "baz2", "") - ctx, _ = RequiredString(ctx, "baz3", "") + ctx, _ = WithInt(ctx, "foo", 5, "Test int param ") // trailing space should be trimmed + ctx, _ = WithBool(ctx, "bar", "Test bool param.") + ctx, _ = WithString(ctx, "baz", "baz", "Test string param") + ctx, _ = WithRequiredString(ctx, "baz2", "") + ctx, _ = WithRequiredString(ctx, "baz3", "") src := SourceCLI{} buf := new(bytes.Buffer) diff --git a/mcfg/env.go b/mcfg/env.go index f1ab14b..73dd92c 100644 --- a/mcfg/env.go +++ b/mcfg/env.go @@ -1,6 +1,7 @@ package mcfg import ( + "context" "os" "strings" @@ -58,7 +59,7 @@ func (env SourceEnv) Parse(params []Param) ([]ParamValue, error) { for _, kv := range kvs { split := strings.SplitN(kv, "=", 2) if len(split) != 2 { - return nil, merr.New("malformed environment key/value pair", "kv", kv) + return nil, merr.New(context.Background(), "malformed environment key/value pair", "kv", kv) } k, v := split[0], split[1] if p, ok := pM[k]; ok { diff --git a/mcfg/mcfg.go b/mcfg/mcfg.go index 1a23479..ff7321f 100644 --- a/mcfg/mcfg.go +++ b/mcfg/mcfg.go @@ -110,7 +110,7 @@ func populate(params []Param, src Source) error { if !p.Required { continue } else if _, ok := pvM[hash]; !ok { - return merr.New("required parameter is not set", + return merr.New(p.Context, "required parameter is not set", "param", paramFullName(mctx.Path(p.Context), p.Name)) } } diff --git a/mcfg/mcfg_test.go b/mcfg/mcfg_test.go index 9ad6df1..9c3e6be 100644 --- a/mcfg/mcfg_test.go +++ b/mcfg/mcfg_test.go @@ -11,10 +11,10 @@ import ( func TestPopulate(t *T) { { ctx := context.Background() - ctx, a := Int(ctx, "a", 0, "") + ctx, a := WithInt(ctx, "a", 0, "") ctxChild := mctx.NewChild(ctx, "foo") - ctxChild, b := Int(ctxChild, "b", 0, "") - ctxChild, c := Int(ctxChild, "c", 0, "") + ctxChild, b := WithInt(ctxChild, "b", 0, "") + ctxChild, c := WithInt(ctxChild, "c", 0, "") ctx = mctx.WithChild(ctx, ctxChild) err := Populate(ctx, SourceCLI{ @@ -28,10 +28,10 @@ func TestPopulate(t *T) { { // test that required params are enforced ctx := context.Background() - ctx, a := Int(ctx, "a", 0, "") + ctx, a := WithInt(ctx, "a", 0, "") ctxChild := mctx.NewChild(ctx, "foo") - ctxChild, b := Int(ctxChild, "b", 0, "") - ctxChild, c := RequiredInt(ctxChild, "c", "") + ctxChild, b := WithInt(ctxChild, "b", 0, "") + ctxChild, c := WithRequiredInt(ctxChild, "c", "") ctx = mctx.WithChild(ctx, ctxChild) err := Populate(ctx, SourceCLI{ diff --git a/mcfg/param.go b/mcfg/param.go index b0223ce..d3a34b9 100644 --- a/mcfg/param.go +++ b/mcfg/param.go @@ -45,7 +45,7 @@ type Param struct { Into interface{} // The Context this Param was added to. NOTE that this will be automatically - // filled in by MustAdd when the Param is added to the Context. + // filled in by WithParam when the Param is added to the Context. Context context.Context } @@ -74,9 +74,9 @@ func getParam(ctx context.Context, name string) (Param, bool) { return param, ok } -// MustAdd returns a Context with the given Param added to it. It will panic if -// a Param with the same Name already exists in the Context. -func MustAdd(ctx context.Context, param Param) context.Context { +// WithParam returns a Context with the given Param added to it. It will panic +// if a Param with the same Name already exists in the Context. +func WithParam(ctx context.Context, param Param) context.Context { param.Name = strings.ToLower(param.Name) param.Context = ctx @@ -99,113 +99,114 @@ func getLocalParams(ctx context.Context) []Param { return params } -// Int64 returns an *int64 which will be populated once Populate is run on the -// returned Context. -func Int64(ctx context.Context, name string, defaultVal int64, usage string) (context.Context, *int64) { +// WithInt64 returns an *int64 which will be populated once Populate is run on +// the returned Context. +func WithInt64(ctx context.Context, name string, defaultVal int64, usage string) (context.Context, *int64) { i := defaultVal - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, Into: &i}) + ctx = WithParam(ctx, Param{Name: name, Usage: usage, Into: &i}) return ctx, &i } -// RequiredInt64 returns an *int64 which will be populated once Populate is run -// on the returned Context, and which must be supplied by a configuration -// Source. -func RequiredInt64(ctx context.Context, name string, usage string) (context.Context, *int64) { - var i int64 - ctx = MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, Into: &i}) - return ctx, &i -} - -// Int returns an *int which will be populated once Populate is run on the -// returned Context. -func Int(ctx context.Context, name string, defaultVal int, usage string) (context.Context, *int) { - i := defaultVal - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, Into: &i}) - return ctx, &i -} - -// RequiredInt returns an *int which will be populated once Populate is run on -// the returned Context, and which must be supplied by a configuration Source. -func RequiredInt(ctx context.Context, name string, usage string) (context.Context, *int) { - var i int - ctx = MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, Into: &i}) - return ctx, &i -} - -// String returns a *string which will be populated once Populate is run on the -// returned Context. -func String(ctx context.Context, name, defaultVal, usage string) (context.Context, *string) { - s := defaultVal - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, IsString: true, Into: &s}) - return ctx, &s -} - -// RequiredString returns a *string which will be populated once Populate is +// WithRequiredInt64 returns an *int64 which will be populated once Populate is // run on the returned Context, and which must be supplied by a configuration // Source. -func RequiredString(ctx context.Context, name, usage string) (context.Context, *string) { - var s string - ctx = MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, IsString: true, Into: &s}) +func WithRequiredInt64(ctx context.Context, name string, usage string) (context.Context, *int64) { + var i int64 + ctx = WithParam(ctx, Param{Name: name, Required: true, Usage: usage, Into: &i}) + return ctx, &i +} + +// WithInt returns an *int which will be populated once Populate is run on the +// returned Context. +func WithInt(ctx context.Context, name string, defaultVal int, usage string) (context.Context, *int) { + i := defaultVal + ctx = WithParam(ctx, Param{Name: name, Usage: usage, Into: &i}) + return ctx, &i +} + +// WithRequiredInt returns an *int which will be populated once Populate is run +// on the returned Context, and which must be supplied by a configuration +// Source. +func WithRequiredInt(ctx context.Context, name string, usage string) (context.Context, *int) { + var i int + ctx = WithParam(ctx, Param{Name: name, Required: true, Usage: usage, Into: &i}) + return ctx, &i +} + +// WithString returns a *string which will be populated once Populate is run on +// the returned Context. +func WithString(ctx context.Context, name, defaultVal, usage string) (context.Context, *string) { + s := defaultVal + ctx = WithParam(ctx, Param{Name: name, Usage: usage, IsString: true, Into: &s}) return ctx, &s } -// Bool returns a *bool which will be populated once Populate is run on the +// WithRequiredString returns a *string which will be populated once Populate is +// run on the returned Context, and which must be supplied by a configuration +// Source. +func WithRequiredString(ctx context.Context, name, usage string) (context.Context, *string) { + var s string + ctx = WithParam(ctx, Param{Name: name, Required: true, Usage: usage, IsString: true, Into: &s}) + return ctx, &s +} + +// WithBool returns a *bool which will be populated once Populate is run on the // returned Context, and which defaults to false if unconfigured. // // The default behavior of all Sources is that a boolean parameter will be set // to true unless the value is "", 0, or false. In the case of the CLI Source // the value will also be true when the parameter is used with no value at all, // as would be expected. -func Bool(ctx context.Context, name, usage string) (context.Context, *bool) { +func WithBool(ctx context.Context, name, usage string) (context.Context, *bool) { var b bool - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, IsBool: true, Into: &b}) + ctx = WithParam(ctx, Param{Name: name, Usage: usage, IsBool: true, Into: &b}) return ctx, &b } -// TS returns an *mtime.TS which will be populated once Populate is run on the -// returned Context. -func TS(ctx context.Context, name string, defaultVal mtime.TS, usage string) (context.Context, *mtime.TS) { +// WithTS returns an *mtime.TS which will be populated once Populate is run on +// the returned Context. +func WithTS(ctx context.Context, name string, defaultVal mtime.TS, usage string) (context.Context, *mtime.TS) { t := defaultVal - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, Into: &t}) + ctx = WithParam(ctx, Param{Name: name, Usage: usage, Into: &t}) return ctx, &t } -// RequiredTS returns an *mtime.TS which will be populated once Populate is run -// on the returned Context, and which must be supplied by a configuration +// WithRequiredTS returns an *mtime.TS which will be populated once Populate is +// run on the returned Context, and which must be supplied by a configuration // Source. -func RequiredTS(ctx context.Context, name, usage string) (context.Context, *mtime.TS) { +func WithRequiredTS(ctx context.Context, name, usage string) (context.Context, *mtime.TS) { var t mtime.TS - ctx = MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, Into: &t}) + ctx = WithParam(ctx, Param{Name: name, Required: true, Usage: usage, Into: &t}) return ctx, &t } -// Duration returns an *mtime.Duration which will be populated once Populate is -// run on the returned Context. -func Duration(ctx context.Context, name string, defaultVal mtime.Duration, usage string) (context.Context, *mtime.Duration) { +// WithDuration returns an *mtime.Duration which will be populated once Populate +// is run on the returned Context. +func WithDuration(ctx context.Context, name string, defaultVal mtime.Duration, usage string) (context.Context, *mtime.Duration) { d := defaultVal - ctx = MustAdd(ctx, Param{Name: name, Usage: usage, IsString: true, Into: &d}) + ctx = WithParam(ctx, Param{Name: name, Usage: usage, IsString: true, Into: &d}) return ctx, &d } -// RequiredDuration returns an *mtime.Duration which will be populated once +// WithRequiredDuration returns an *mtime.Duration which will be populated once // Populate is run on the returned Context, and which must be supplied by a // configuration Source. -func RequiredDuration(ctx context.Context, name string, defaultVal mtime.Duration, usage string) (context.Context, *mtime.Duration) { +func WithRequiredDuration(ctx context.Context, name string, defaultVal mtime.Duration, usage string) (context.Context, *mtime.Duration) { var d mtime.Duration - ctx = MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, IsString: true, Into: &d}) + ctx = WithParam(ctx, Param{Name: name, Required: true, Usage: usage, IsString: true, Into: &d}) return ctx, &d } -// JSON reads the parameter value as a JSON value and unmarshals it into the +// WithJSON reads the parameter value as a JSON value and unmarshals it into the // given interface{} (which should be a pointer). The receiver (into) is also // used to determine the default value. -func JSON(ctx context.Context, name string, into interface{}, usage string) context.Context { - return MustAdd(ctx, Param{Name: name, Usage: usage, Into: into}) +func WithJSON(ctx context.Context, name string, into interface{}, usage string) context.Context { + return WithParam(ctx, Param{Name: name, Usage: usage, Into: into}) } -// RequiredJSON reads the parameter value as a JSON value and unmarshals it into -// the given interface{} (which should be a pointer). The value must be supplied -// by a configuration Source. -func RequiredJSON(ctx context.Context, name string, into interface{}, usage string) context.Context { - return MustAdd(ctx, Param{Name: name, Required: true, Usage: usage, Into: into}) +// WithRequiredJSON reads the parameter value as a JSON value and unmarshals it +// into the given interface{} (which should be a pointer). The value must be +// supplied by a configuration Source. +func WithRequiredJSON(ctx context.Context, name string, into interface{}, usage string) context.Context { + return WithParam(ctx, Param{Name: name, Required: true, Usage: usage, Into: into}) } diff --git a/mcfg/source_test.go b/mcfg/source_test.go index b3ad605..db31e07 100644 --- a/mcfg/source_test.go +++ b/mcfg/source_test.go @@ -116,7 +116,7 @@ func (scs srcCommonState) applyCtxAndPV(p srcCommonParams) srcCommonState { // the Sources don't actually care about the other fields of Param, // those are only used by Populate once it has all ParamValues together } - *thisCtx = MustAdd(*thisCtx, ctxP) + *thisCtx = WithParam(*thisCtx, ctxP) ctxP, _ = getParam(*thisCtx, ctxP.Name) // get it back out to get any added fields if !p.unset { @@ -155,9 +155,9 @@ func (scs srcCommonState) assert(s Source) error { func TestSources(t *T) { ctx := context.Background() - ctx, a := RequiredInt(ctx, "a", "") - ctx, b := RequiredInt(ctx, "b", "") - ctx, c := RequiredInt(ctx, "c", "") + ctx, a := WithRequiredInt(ctx, "a", "") + ctx, b := WithRequiredInt(ctx, "b", "") + ctx, c := WithRequiredInt(ctx, "c", "") err := Populate(ctx, Sources{ SourceCLI{Args: []string{"--a=1", "--b=666"}}, @@ -173,10 +173,10 @@ func TestSources(t *T) { func TestSourceParamValues(t *T) { ctx := context.Background() - ctx, a := RequiredInt(ctx, "a", "") + ctx, a := WithRequiredInt(ctx, "a", "") foo := mctx.NewChild(ctx, "foo") - foo, b := RequiredString(foo, "b", "") - foo, c := Bool(foo, "c", "") + foo, b := WithRequiredString(foo, "b", "") + foo, c := WithBool(foo, "c", "") ctx = mctx.WithChild(ctx, foo) err := Populate(ctx, ParamValues{ diff --git a/mcrypto/pair.go b/mcrypto/pair.go index 26648b5..dd2e40c 100644 --- a/mcrypto/pair.go +++ b/mcrypto/pair.go @@ -1,6 +1,7 @@ package mcrypto import ( + "context" "crypto" "crypto/rand" "crypto/rsa" @@ -58,7 +59,7 @@ func (pk PublicKey) verify(s Signature, r io.Reader) error { return err } if err := rsa.VerifyPSS(&pk.PublicKey, crypto.SHA256, h.Sum(nil), s.sig, nil); err != nil { - return merr.WithValue(ErrInvalidSig, "sig", s, true) + return merr.Wrap(context.Background(), ErrInvalidSig, "sig", s) } return nil } @@ -88,12 +89,12 @@ func (pk *PublicKey) UnmarshalText(b []byte) error { str := string(b) strEnc, ok := stripPrefix(str, pubKeyV0) if !ok || len(strEnc) <= hex.EncodedLen(8) { - return merr.WithValue(errMalformedPublicKey, "pubKeyStr", str, true) + return merr.Wrap(context.Background(), errMalformedPublicKey, "pubKeyStr", str) } b, err := hex.DecodeString(strEnc) if err != nil { - return merr.WithValue(err, "pubKeyStr", str, true) + return merr.Wrap(context.Background(), err, "pubKeyStr", str) } pk.E = int(binary.BigEndian.Uint64(b)) @@ -184,17 +185,17 @@ func (pk *PrivateKey) UnmarshalText(b []byte) error { str := string(b) strEnc, ok := stripPrefix(str, privKeyV0) if !ok { - return merr.Wrap(errMalformedPrivateKey) + return merr.Wrap(context.Background(), errMalformedPrivateKey) } b, err := hex.DecodeString(strEnc) if err != nil { - return merr.Wrap(errMalformedPrivateKey) + return merr.Wrap(context.Background(), errMalformedPrivateKey) } e, n := binary.Uvarint(b) if n <= 0 { - return merr.Wrap(errMalformedPrivateKey) + return merr.Wrap(context.Background(), errMalformedPrivateKey) } pk.PublicKey.E = int(e) b = b[n:] @@ -205,7 +206,7 @@ func (pk *PrivateKey) UnmarshalText(b []byte) error { } l, n := binary.Uvarint(b) if n <= 0 { - err = merr.Wrap(errMalformedPrivateKey) + err = merr.Wrap(context.Background(), errMalformedPrivateKey) } b = b[n:] i := new(big.Int) diff --git a/mcrypto/secret.go b/mcrypto/secret.go index 156e12f..76e3736 100644 --- a/mcrypto/secret.go +++ b/mcrypto/secret.go @@ -1,6 +1,7 @@ package mcrypto import ( + "context" "crypto/hmac" "crypto/rand" "crypto/sha256" @@ -76,9 +77,9 @@ func (s Secret) sign(r io.Reader) (Signature, error) { func (s Secret) verify(sig Signature, r io.Reader) error { sigB, err := s.signRaw(r, uint8(len(sig.sig)), sig.salt, sig.t) if err != nil { - return merr.WithValue(err, "sig", sig, true) + return merr.Wrap(context.Background(), err, "sig", sig) } else if !hmac.Equal(sigB, sig.sig) { - return merr.WithValue(ErrInvalidSig, "sig", sig, true) + return merr.Wrap(context.Background(), ErrInvalidSig, "sig", sig) } return nil } diff --git a/mcrypto/sig.go b/mcrypto/sig.go index 553ab96..8d0bdf9 100644 --- a/mcrypto/sig.go +++ b/mcrypto/sig.go @@ -2,6 +2,7 @@ package mcrypto import ( "bytes" + "context" "encoding/binary" "encoding/hex" "encoding/json" @@ -66,12 +67,12 @@ func (s *Signature) UnmarshalText(b []byte) error { str := string(b) strEnc, ok := stripPrefix(str, sigV0) if !ok || len(strEnc) < hex.EncodedLen(10) { - return merr.WithValue(errMalformedSig, "sigStr", str, true) + return merr.Wrap(context.Background(), errMalformedSig, "sigStr", str) } b, err := hex.DecodeString(strEnc) if err != nil { - return merr.WithValue(err, "sigStr", str, true) + return merr.Wrap(context.Background(), err, "sigStr", str) } unixNano, b := int64(binary.BigEndian.Uint64(b[:8])), b[8:] @@ -81,7 +82,7 @@ func (s *Signature) UnmarshalText(b []byte) error { if err != nil { return nil } else if len(b) < 1+int(b[0]) { - err = merr.WithValue(errMalformedSig, "sigStr", str, true) + err = merr.Wrap(context.Background(), errMalformedSig, "sigStr", str) return nil } out := b[1 : 1+b[0]] @@ -161,7 +162,7 @@ func SignString(s Signer, in string) Signature { // Verify reads all data from the io.Reader and uses the Verifier to verify that // the Signature is for that data. // -// Returns any errors from io.Reader, or ErrInvalidSig (use merry.Is(err, +// Returns any errors from io.Reader, or ErrInvalidSig (use merr.Equal(err, // mcrypto.ErrInvalidSig) to check). func Verify(v Verifier, s Signature, r io.Reader) error { return v.verify(s, r) @@ -170,7 +171,7 @@ func Verify(v Verifier, s Signature, r io.Reader) error { // VerifyBytes uses the Verifier to verify that the Signature is for the given // []bytes. // -// Returns ErrInvalidSig (use merry.Is(err, mcrypto.ErrInvalidSig) to check). +// Returns ErrInvalidSig (use merr.Equal(err, mcrypto.ErrInvalidSig) to check). func VerifyBytes(v Verifier, s Signature, b []byte) error { return v.verify(s, bytes.NewBuffer(b)) } @@ -178,7 +179,7 @@ func VerifyBytes(v Verifier, s Signature, b []byte) error { // VerifyString uses the Verifier to verify that the Signature is for the given // string. // -// Returns ErrInvalidSig (use merry.Is(err, mcrypto.ErrInvalidSig) to check). +// Returns ErrInvalidSig (use merr.Equal(err, mcrypto.ErrInvalidSig) to check). func VerifyString(v Verifier, s Signature, in string) error { return VerifyBytes(v, s, []byte(in)) } diff --git a/mcrypto/uuid.go b/mcrypto/uuid.go index f898899..ebe3a94 100644 --- a/mcrypto/uuid.go +++ b/mcrypto/uuid.go @@ -2,6 +2,7 @@ package mcrypto import ( "bytes" + "context" "crypto/rand" "encoding/binary" "encoding/hex" @@ -68,11 +69,11 @@ func (u *UUID) UnmarshalText(b []byte) error { str := string(b) strEnc, ok := stripPrefix(str, uuidV0) if !ok || len(strEnc) != hex.EncodedLen(16) { - return merr.WithValue(errMalformedUUID, "uuidStr", str, true) + return merr.Wrap(context.Background(), errMalformedUUID, "uuidStr", str) } b, err := hex.DecodeString(strEnc) if err != nil { - return merr.WithValue(err, "uuidStr", str, true) + return merr.Wrap(context.Background(), err, "uuidStr", str) } u.b = b return nil diff --git a/mctx/annotate.go b/mctx/annotate.go index b2d72e9..8cad9df 100644 --- a/mctx/annotate.go +++ b/mctx/annotate.go @@ -3,69 +3,284 @@ package mctx import ( "context" "fmt" + "sort" + "strings" ) -type annotateKey struct { - userKey interface{} +// Annotation describes the annotation of a key/value pair made on a Context via +// the Annotate call. The Path field is the Path of the Context on which the +// call was made. +type Annotation struct { + Key, Value interface{} + Path []string } +type annotation struct { + Annotation + root, prev *annotation +} + +type annotationKey int + // Annotate takes in one or more key/value pairs (kvs' length must be even) and // returns a Context carrying them. Annotations only exist on the local level, // i.e. a child and parent share different annotation namespaces. +// +// NOTE that annotations are preserved across NewChild calls, but are keyed +// based on the passed in key _and_ the Context's Path. func Annotate(ctx context.Context, kvs ...interface{}) context.Context { - for i := 0; i < len(kvs); i += 2 { - ctx = WithLocalValue(ctx, annotateKey{kvs[i]}, kvs[i+1]) + if len(kvs)%2 > 0 { + panic("kvs being passed to mctx.Annotate must have an even number of elements") + } else if len(kvs) == 0 { + return ctx } + + // if multiple annotations are passed in here it's not actually necessary to + // create an intermediate Context for each one, so keep curr outside and + // only use it later + var curr, root *annotation + prev, _ := ctx.Value(annotationKey(0)).(*annotation) + if prev != nil { + root = prev.root + } + path := Path(ctx) + for i := 0; i < len(kvs); i += 2 { + curr = &annotation{ + Annotation: Annotation{ + Key: kvs[i], Value: kvs[i+1], + Path: path, + }, + prev: prev, + } + if root == nil { + root = curr + } + curr.root = curr + prev = curr + } + + ctx = context.WithValue(ctx, annotationKey(0), curr) return ctx } -// Annotations describes a set of keys/values which were set on a Context (but -// not its parents or children) using Annotate. -type Annotations [][2]interface{} +// AnnotationSet describes a set of unique Annotation values which were +// retrieved off a Context via the Annotations function. An AnnotationSet has a +// couple methods on it to aid in post-processing. +type AnnotationSet []Annotation -// LocalAnnotations returns all key/value pairs which have been set via Annotate -// on this Context (but not its parent or children). If a key was set twice then -// only the most recent value is included. The returned order is -// non-deterministic. -func LocalAnnotations(ctx context.Context) Annotations { - var annotations Annotations - localValuesIter(ctx, func(key, val interface{}) { - aKey, ok := key.(annotateKey) - if !ok { - return +// Annotations returns all Annotation values which have been set via Annotate on +// this Context. If a key was set twice then only the most recent value is +// included. +func Annotations(ctx context.Context) AnnotationSet { + a, _ := ctx.Value(annotationKey(0)).(*annotation) + if a == nil { + return nil + } + type mKey struct { + pathHash string + key interface{} + } + m := map[mKey]bool{} + + var aa AnnotationSet + for { + if a == nil { + break } - annotations = append(annotations, [2]interface{}{aKey.userKey, val}) - }) - return annotations + + k := mKey{pathHash: pathHash(a.Path), key: a.Key} + if m[k] { + a = a.prev + continue + } + + aa = append(aa, a.Annotation) + m[k] = true + a = a.prev + } + return aa } -// StringMap formats each of the key/value pairs into strings using fmt.Sprint. -// If any two keys format to the same string, then type information will be -// prefaced to each one. -func (aa Annotations) StringMap() map[string]string { - keyTypes := make(map[string]interface{}, len(aa)) - keyVals := map[string]string{} - setKey := func(k, v interface{}) { - kStr := fmt.Sprint(k) - oldType := keyTypes[kStr] - if oldType == nil { - keyTypes[kStr] = k - keyVals[kStr] = fmt.Sprint(v) - return +// StringMapByPath is similar to StringMap, but it first maps each annotation +// datum by its path. +func (aa AnnotationSet) StringMapByPath() map[string]map[string]string { + type mKey struct { + str string + path string + typ string + } + m := map[mKey][]Annotation{} + for _, a := range aa { + k := mKey{ + str: fmt.Sprint(a.Key), + path: "/" + strings.Join(a.Path, "/"), } - - // check if oldKey is in kvm, if so it needs to be moved to account for - // its type info - if oldV, ok := keyVals[kStr]; ok { - delete(keyVals, kStr) - keyVals[fmt.Sprintf("%T(%s)", oldType, kStr)] = oldV - } - - keyVals[fmt.Sprintf("%T(%s)", k, kStr)] = fmt.Sprint(v) + m[k] = append(m[k], a) } - for _, kv := range aa { - setKey(kv[0], kv[1]) + nextK := func(k mKey, a Annotation) mKey { + if k.typ == "" { + k.typ = fmt.Sprintf("%T", a.Key) + } else { + panic(fmt.Sprintf("mKey %#v is somehow conflicting with another", k)) + } + return k } - return keyVals + + for { + var any bool + for k, annotations := range m { + if len(annotations) == 1 { + continue + } + any = true + for _, a := range annotations { + k2 := nextK(k, a) + m[k2] = append(m[k2], a) + } + delete(m, k) + } + if !any { + break + } + } + + outM := map[string]map[string]string{} + for k, annotations := range m { + a := annotations[0] + if outM[k.path] == nil { + outM[k.path] = map[string]string{} + } + kStr := k.str + if k.typ != "" { + kStr += "(" + k.typ + ")" + } + outM[k.path][kStr] = fmt.Sprint(a.Value) + } + return outM +} + +// StringMap formats each of the Annotations into strings using fmt.Sprint. If +// any two keys format to the same string, then path information will be +// prefaced to each one. If they still format to the same string, then type +// information will be prefaced to each one. +func (aa AnnotationSet) StringMap() map[string]string { + type mKey struct { + str string + path string + typ string + } + m := map[mKey][]Annotation{} + for _, a := range aa { + k := mKey{str: fmt.Sprint(a.Key)} + m[k] = append(m[k], a) + } + + nextK := func(k mKey, a Annotation) mKey { + if k.path == "" { + k.path = "/" + strings.Join(a.Path, "/") + } else if k.typ == "" { + k.typ = fmt.Sprintf("%T", a.Key) + } else { + panic(fmt.Sprintf("mKey %#v is somehow conflicting with another", k)) + } + return k + } + + for { + var any bool + for k, annotations := range m { + if len(annotations) == 1 { + continue + } + any = true + for _, a := range annotations { + k2 := nextK(k, a) + m[k2] = append(m[k2], a) + } + delete(m, k) + } + if !any { + break + } + } + + outM := map[string]string{} + for k, annotations := range m { + a := annotations[0] + kStr := k.str + if k.path != "" { + kStr += "(" + k.path + ")" + } + if k.typ != "" { + kStr += "(" + k.typ + ")" + } + outM[kStr] = fmt.Sprint(a.Value) + } + return outM +} + +// StringSlice is like StringMap but it returns a slice of key/value tuples +// rather than a map. If sorted is true then the slice will be sorted by key in +// ascending order. +func (aa AnnotationSet) StringSlice(sorted bool) [][2]string { + m := aa.StringMap() + slice := make([][2]string, 0, len(m)) + for k, v := range m { + slice = append(slice, [2]string{k, v}) + } + if sorted { + sort.Slice(slice, func(i, j int) bool { + return slice[i][0] < slice[j][0] + }) + } + return slice +} + +func mergeAnnotations(ctxA, ctxB context.Context) context.Context { + annotationA, _ := ctxA.Value(annotationKey(0)).(*annotation) + annotationB, _ := ctxB.Value(annotationKey(0)).(*annotation) + if annotationB == nil { + return ctxA + } else if annotationA == nil { + return context.WithValue(ctxA, annotationKey(0), annotationB) + } + + var headA, currA *annotation + currB := annotationB + for { + if currB == nil { + break + } + + prevA := &annotation{ + Annotation: currB.Annotation, + root: annotationA.root, + } + if currA != nil { + currA.prev = prevA + } + currA, currB = prevA, currB.prev + if headA == nil { + headA = currA + } + } + + currA.prev = annotationA + return context.WithValue(ctxA, annotationKey(0), headA) +} + +// MergeAnnotations sequentially merges the annotation data of the passed in +// Contexts into the first passed in one. Data from a Context overwrites +// overlapping data on all passed in Contexts to the left of it. All other +// aspects of the first Context remain the same, and that Context is returned +// with the new set of Annotation data. +// +// NOTE this will panic if no Contexts are passed in. +func MergeAnnotations(ctxs ...context.Context) context.Context { + ctxA := ctxs[0] + for _, ctxB := range ctxs[1:] { + ctxA = mergeAnnotations(ctxA, ctxB) + } + return ctxA } diff --git a/mctx/annotate_test.go b/mctx/annotate_test.go index 3db3c04..acff519 100644 --- a/mctx/annotate_test.go +++ b/mctx/annotate_test.go @@ -13,42 +13,73 @@ func TestAnnotate(t *T) { parent = Annotate(parent, "b", "bar") child := NewChild(parent, "child") + child = Annotate(child, "a", "Foo") child = Annotate(child, "a", "FOO") child = Annotate(child, "c", "BAZ") parent = WithChild(parent, child) - parentAnnotations := LocalAnnotations(parent) - childAnnotations := LocalAnnotations(child) + parentAnnotations := Annotations(parent) + childAnnotations := Annotations(child) massert.Fatal(t, massert.All( massert.Len(parentAnnotations, 2), - massert.Has(parentAnnotations, [2]interface{}{"a", "foo"}), - massert.Has(parentAnnotations, [2]interface{}{"b", "bar"}), - massert.Len(childAnnotations, 2), - massert.Has(childAnnotations, [2]interface{}{"a", "FOO"}), - massert.Has(childAnnotations, [2]interface{}{"c", "BAZ"}), + massert.Has(parentAnnotations, Annotation{Key: "a", Value: "foo"}), + massert.Has(parentAnnotations, Annotation{Key: "b", Value: "bar"}), + + massert.Len(childAnnotations, 4), + massert.Has(childAnnotations, Annotation{Key: "a", Value: "foo"}), + massert.Has(childAnnotations, Annotation{Key: "b", Value: "bar"}), + massert.Has(childAnnotations, + Annotation{Key: "a", Path: []string{"child"}, Value: "FOO"}), + massert.Has(childAnnotations, + Annotation{Key: "c", Path: []string{"child"}, Value: "BAZ"}), )) } -func TestAnnotationsStingMap(t *T) { +func TestAnnotationsStringMap(t *T) { type A int type B int - aa := Annotations{ - {"foo", "bar"}, - {"1", "one"}, - {1, 1}, - {0, 0}, - {A(0), 0}, - {B(0), 0}, + aa := AnnotationSet{ + {Key: 0, Path: nil, Value: "zero"}, + {Key: 1, Path: nil, Value: "one"}, + {Key: 1, Path: []string{"foo"}, Value: "ONE"}, + {Key: A(2), Path: []string{"foo"}, Value: "two"}, + {Key: B(2), Path: []string{"foo"}, Value: "TWO"}, } + massert.Fatal(t, massert.All( + massert.Equal(map[string]string{ + "0": "zero", + "1(/)": "one", + "1(/foo)": "ONE", + "2(/foo)(mctx.A)": "two", + "2(/foo)(mctx.B)": "TWO", + }, aa.StringMap()), + massert.Equal(map[string]map[string]string{ + "/": { + "0": "zero", + "1": "one", + }, + "/foo": { + "1": "ONE", + "2(mctx.A)": "two", + "2(mctx.B)": "TWO", + }, + }, aa.StringMapByPath()), + )) +} + +func TestMergeAnnotations(t *T) { + ctxA := Annotate(context.Background(), 0, "zero", 1, "one") + ctxA = Annotate(ctxA, 0, "ZERO") + ctxB := Annotate(context.Background(), 2, "two") + ctxB = Annotate(ctxB, 1, "ONE", 2, "TWO") + + ctx := MergeAnnotations(ctxA, ctxB) err := massert.Equal(map[string]string{ - "foo": "bar", - "string(1)": "one", - "int(1)": "1", - "int(0)": "0", - "mctx.A(0)": "0", - "mctx.B(0)": "0", - }, aa.StringMap()).Assert() + "0": "ZERO", + "1": "ONE", + "2": "TWO", + }, Annotations(ctx).StringMap()).Assert() if err != nil { t.Fatal(err) } diff --git a/mctx/ctx.go b/mctx/ctx.go index 304163f..ac5003e 100644 --- a/mctx/ctx.go +++ b/mctx/ctx.go @@ -11,17 +11,13 @@ package mctx import ( "context" + "crypto/sha256" + "encoding/hex" "fmt" ) //////////////////////////////////////////////////////////////////////////////// -// New returns a new context which can be used as the root context for all -// purposes in this framework. -//func New() Context { -// return &context{Context: goctx.Background()} -//} - type ancestryKey int // 0 -> children, 1 -> parent, 2 -> path const ( @@ -97,6 +93,14 @@ func pathCP(ctx context.Context) []string { return outPath } +func pathHash(path []string) string { + pathHash := sha256.New() + for _, pathEl := range path { + fmt.Fprintf(pathHash, "%q.", pathEl) + } + return hex.EncodeToString(pathHash.Sum(nil)) +} + // Name returns the name this Context was generated with via NewChild, or false // if this Context was not generated via NewChild. func Name(ctx context.Context) (string, bool) { @@ -119,6 +123,7 @@ func NewChild(parent context.Context, name string) context.Context { } childPath := append(pathCP(parent), name) + child := withoutLocalValues(parent) child = context.WithValue(child, ancestryKeyChildren, nil) // unset children child = context.WithValue(child, ancestryKeyChildrenMap, nil) // unset children diff --git a/mctx/stack.go b/mctx/stack.go new file mode 100644 index 0000000..37bd4a9 --- /dev/null +++ b/mctx/stack.go @@ -0,0 +1,94 @@ +package mctx + +import ( + "context" + "fmt" + "path/filepath" + "runtime" + "strings" + "text/tabwriter" +) + +// MaxStackSize indicates the maximum number of stack frames which will be +// stored when embedding stack traces in errors. +var MaxStackSize = 50 + +type ctxStackKey int + +// Stacktrace represents a stack trace at a particular point in execution. +type Stacktrace struct { + frames []uintptr +} + +// Frame returns the first frame in the stack. +func (s Stacktrace) Frame() runtime.Frame { + if len(s.frames) == 0 { + panic("cannot call Frame on empty stack") + } + + frame, _ := runtime.CallersFrames([]uintptr(s.frames)).Next() + return frame +} + +// Frames returns all runtime.Frame instances for this stack. +func (s Stacktrace) Frames() []runtime.Frame { + if len(s.frames) == 0 { + return nil + } + + out := make([]runtime.Frame, 0, len(s.frames)) + frames := runtime.CallersFrames([]uintptr(s.frames)) + for { + frame, more := frames.Next() + out = append(out, frame) + if !more { + break + } + } + return out +} + +// String returns a string representing the top-most frame of the stack. +func (s Stacktrace) String() string { + if len(s.frames) == 0 { + return "" + } + frame := s.Frame() + file, dir := filepath.Base(frame.File), filepath.Dir(frame.File) + dir = filepath.Base(dir) // only want the first dirname, ie the pkg name + return fmt.Sprintf("%s/%s:%d", dir, file, frame.Line) +} + +// FullString returns the full stack trace. +func (s Stacktrace) FullString() string { + sb := new(strings.Builder) + tw := tabwriter.NewWriter(sb, 0, 4, 4, ' ', 0) + for _, frame := range s.Frames() { + file := fmt.Sprintf("%s:%d", frame.File, frame.Line) + fmt.Fprintf(tw, "%s\t%s\n", file, frame.Function) + } + if err := tw.Flush(); err != nil { + panic(err) + } + return sb.String() +} + +// WithStack returns a Context with the current stacktrace embedded in it (as a +// Stacktrace type). If skip is non-zero it will skip that many frames from the +// top of the stack. The frame containing the WithStack call itself is always +// excluded. +func WithStack(ctx context.Context, skip int) context.Context { + stackSlice := make([]uintptr, MaxStackSize) + // incr skip once for WithStack, and once for runtime.Callers + l := runtime.Callers(skip+2, stackSlice) + stack := Stacktrace{frames: stackSlice[:l]} + + return context.WithValue(ctx, ctxStackKey(0), stack) +} + +// Stack returns the Stacktrace instance which was embedded by WithStack, or false if +// none ever was. +func Stack(ctx context.Context) (Stacktrace, bool) { + stack, ok := ctx.Value(ctxStackKey(0)).(Stacktrace) + return stack, ok +} diff --git a/merr/stack_test.go b/mctx/stack_test.go similarity index 78% rename from merr/stack_test.go rename to mctx/stack_test.go index 5491942..cea617b 100644 --- a/merr/stack_test.go +++ b/mctx/stack_test.go @@ -1,6 +1,7 @@ -package merr +package mctx import ( + "context" "strings" . "testing" @@ -8,8 +9,9 @@ import ( ) func TestStack(t *T) { - foo := New("foo") - fooStack := GetStack(foo) + foo := WithStack(context.Background(), 0) + fooStack, ok := Stack(foo) + massert.Fatal(t, massert.Equal(true, ok)) // test Frame frame := fooStack.Frame() @@ -25,13 +27,13 @@ func TestStack(t *T) { massert.Equal(true, strings.Contains(frames[0].File, "stack_test.go")), massert.Equal(true, strings.Contains(frames[0].Function, "TestStack")), ), - "fooStack.String():\n%s", fooStack.String(), + "fooStack.FullString():\n%s", fooStack.FullString(), )) // test that WithStack works and can be used to skip frames inner := func() { bar := WithStack(foo, 1) - barStack := GetStack(bar) + barStack, _ := Stack(bar) frames := barStack.Frames() massert.Fatal(t, massert.Comment( massert.All( @@ -39,7 +41,7 @@ func TestStack(t *T) { massert.Equal(true, strings.Contains(frames[0].File, "stack_test.go")), massert.Equal(true, strings.Contains(frames[0].Function, "TestStack")), ), - "barStack.String():\n%s", barStack.String(), + "barStack.FullString():\n%s", barStack.FullString(), )) } inner() diff --git a/mdb/mbigquery/bigquery.go b/mdb/mbigquery/bigquery.go index 153fb57..64ad3b4 100644 --- a/mdb/mbigquery/bigquery.go +++ b/mdb/mbigquery/bigquery.go @@ -42,43 +42,37 @@ type BigQuery struct { tableUploaders map[[2]string]*bigquery.Uploader } -// MNew returns a BigQuery instance which will be initialized and configured -// when the start event is triggered on the returned (see mrun.Start). The -// BigQuery instance will have Close called on it when the stop event is -// triggered on the returned Context (see mrun.Stop). +// WithBigQuery returns a BigQuery instance which will be initialized and +// configured when the start event is triggered on the returned (see +// mrun.Start). The BigQuery instance will have Close called on it when the stop +// event is triggered on the returned Context (see mrun.Stop). // // gce is optional and can be passed in if there's an existing gce object which // should be used, otherwise a new one will be created with mdb.MGCE. -func MNew(ctx context.Context, gce *mdb.GCE) (context.Context, *BigQuery) { +func WithBigQuery(parent context.Context, gce *mdb.GCE) (context.Context, *BigQuery) { + ctx := mctx.NewChild(parent, "mbigquery") if gce == nil { - ctx, gce = mdb.MGCE(ctx, "") + ctx, gce = mdb.WithGCE(ctx, "") } bq := &BigQuery{ gce: gce, tables: map[[2]string]*bigquery.Table{}, tableUploaders: map[[2]string]*bigquery.Uploader{}, - ctx: mctx.NewChild(ctx, "bigquery"), } - // TODO the equivalent functionality as here will be added with annotations - // bq.log.SetKV(bq) - - bq.ctx = mrun.OnStart(bq.ctx, func(innerCtx context.Context) error { - mlog.Info(bq.ctx, "connecting to bigquery") + ctx = mrun.WithStartHook(ctx, func(innerCtx context.Context) error { + bq.ctx = mctx.MergeAnnotations(bq.ctx, bq.gce.Context()) + mlog.Info("connecting to bigquery", bq.ctx) var err error bq.Client, err = bigquery.NewClient(innerCtx, bq.gce.Project, bq.gce.ClientOptions()...) - return merr.WithKV(err, bq.KV()) + return merr.Wrap(bq.ctx, err) }) - bq.ctx = mrun.OnStop(bq.ctx, func(context.Context) error { + ctx = mrun.WithStopHook(ctx, func(context.Context) error { return bq.Client.Close() }) - return mctx.WithChild(ctx, bq.ctx), bq -} - -// KV implements the mlog.KVer interface. -func (bq *BigQuery) KV() map[string]interface{} { - return bq.gce.KV() + bq.ctx = ctx + return mctx.WithChild(parent, ctx), bq } // Table initializes and returns the table instance with the given dataset and @@ -100,17 +94,18 @@ func (bq *BigQuery) Table( return table, bq.tableUploaders[key], nil } - kv := mlog.KV{"bigQueryDataset": dataset, "bigQueryTable": tableName} - mlog.Debug(bq.ctx, "creating/grabbing table", kv) + ctx = mctx.MergeAnnotations(ctx, bq.ctx) + ctx = mctx.Annotate(ctx, "dataset", dataset, "table", tableName) + mlog.Debug("creating/grabbing table", bq.ctx) schema, err := bigquery.InferSchema(schemaObj) if err != nil { - return nil, nil, merr.WithKV(err, bq.KV(), kv.KV()) + return nil, nil, merr.Wrap(ctx, err) } ds := bq.Dataset(dataset) if err := ds.Create(ctx, nil); err != nil && !isErrAlreadyExists(err) { - return nil, nil, merr.WithKV(err, bq.KV(), kv.KV()) + return nil, nil, merr.Wrap(ctx, err) } table := ds.Table(tableName) @@ -119,7 +114,7 @@ func (bq *BigQuery) Table( Schema: schema, } if err := table.Create(ctx, meta); err != nil && !isErrAlreadyExists(err) { - return nil, nil, merr.WithKV(err, bq.KV(), kv.KV()) + return nil, nil, merr.Wrap(ctx, err) } uploader := table.Uploader() diff --git a/mdb/mbigtable/bigtable.go b/mdb/mbigtable/bigtable.go index 420b62e..c858ca1 100644 --- a/mdb/mbigtable/bigtable.go +++ b/mdb/mbigtable/bigtable.go @@ -31,61 +31,56 @@ type Bigtable struct { ctx context.Context } -// MNew returns a Bigtable instance which will be initialized and configured -// when the start event is triggered on the returned Context (see mrun.Start). -// The Bigtable instance will have Close called on it when the stop event is -// triggered on the returned Context (see mrun.Stop). +// WithBigTable returns a Bigtable instance which will be initialized and +// configured when the start event is triggered on the returned Context (see +// mrun.Start). The Bigtable instance will have Close called on it when the +// stop event is triggered on the returned Context (see mrun.Stop). // // gce is optional and can be passed in if there's an existing gce object which // should be used, otherwise a new one will be created with mdb.MGCE. // // defaultInstance can be given as the instance name to use as the default // parameter value. If empty the parameter will be required to be set. -func MNew(ctx context.Context, gce *mdb.GCE, defaultInstance string) (context.Context, *Bigtable) { +func WithBigTable(parent context.Context, gce *mdb.GCE, defaultInstance string) (context.Context, *Bigtable) { + ctx := mctx.NewChild(parent, "bigtable") if gce == nil { - ctx, gce = mdb.MGCE(ctx, "") + ctx, gce = mdb.WithGCE(ctx, "") } bt := &Bigtable{ gce: gce, - ctx: mctx.NewChild(ctx, "bigtable"), } - // TODO the equivalent functionality as here will be added with annotations - // bt.log.SetKV(bt) - var inst *string { const name, descr = "instance", "name of the bigtable instance in the project to connect to" if defaultInstance != "" { - bt.ctx, inst = mcfg.String(bt.ctx, name, defaultInstance, descr) + ctx, inst = mcfg.WithString(ctx, name, defaultInstance, descr) } else { - bt.ctx, inst = mcfg.RequiredString(bt.ctx, name, descr) + ctx, inst = mcfg.WithRequiredString(ctx, name, descr) } } - bt.ctx = mrun.OnStart(bt.ctx, func(innerCtx context.Context) error { + ctx = mrun.WithStartHook(ctx, func(innerCtx context.Context) error { bt.Instance = *inst - mlog.Info(bt.ctx, "connecting to bigtable", bt) + + bt.ctx = mctx.MergeAnnotations(bt.ctx, bt.gce.Context()) + bt.ctx = mctx.Annotate(bt.ctx, "instance", bt.Instance) + + mlog.Info("connecting to bigtable", bt.ctx) var err error bt.Client, err = bigtable.NewClient( innerCtx, bt.gce.Project, bt.Instance, bt.gce.ClientOptions()..., ) - return merr.WithKV(err, bt.KV()) + return merr.Wrap(bt.ctx, err) }) - bt.ctx = mrun.OnStop(bt.ctx, func(context.Context) error { + ctx = mrun.WithStopHook(ctx, func(context.Context) error { return bt.Client.Close() }) - return mctx.WithChild(ctx, bt.ctx), bt -} - -// KV implements the mlog.KVer interface. -func (bt *Bigtable) KV() map[string]interface{} { - kv := bt.gce.KV() - kv["bigtableInstance"] = bt.Instance - return kv + bt.ctx = ctx + return mctx.WithChild(parent, ctx), bt } // EnsureTable ensures that the given table exists and has (at least) the given @@ -93,28 +88,29 @@ func (bt *Bigtable) KV() map[string]interface{} { // // This method requires admin privileges on the bigtable instance. func (bt *Bigtable) EnsureTable(ctx context.Context, name string, colFams ...string) error { - kv := mlog.KV{"bigtableTable": name} - mlog.Info(bt.ctx, "ensuring table", kv) + ctx = mctx.MergeAnnotations(ctx, bt.ctx) + ctx = mctx.Annotate(ctx, "table", name) + mlog.Info("ensuring table", ctx) - mlog.Debug(bt.ctx, "creating admin client", kv) + mlog.Debug("creating admin client", ctx) adminClient, err := bigtable.NewAdminClient(ctx, bt.gce.Project, bt.Instance) if err != nil { - return merr.WithKV(err, bt.KV(), kv.KV()) + return merr.Wrap(ctx, err) } defer adminClient.Close() - mlog.Debug(bt.ctx, "creating bigtable table (if needed)", kv) + mlog.Debug("creating bigtable table (if needed)", ctx) err = adminClient.CreateTable(ctx, name) if err != nil && !isErrAlreadyExists(err) { - return merr.WithKV(err, bt.KV(), kv.KV()) + return merr.Wrap(ctx, err) } for _, colFam := range colFams { - kv := kv.Set("family", colFam) - mlog.Debug(bt.ctx, "creating bigtable column family (if needed)", kv) + ctx := mctx.Annotate(ctx, "family", colFam) + mlog.Debug("creating bigtable column family (if needed)", ctx) err := adminClient.CreateColumnFamily(ctx, name, colFam) if err != nil && !isErrAlreadyExists(err) { - return merr.WithKV(err, bt.KV(), kv.KV()) + return merr.Wrap(ctx, err) } } diff --git a/mdb/mbigtable/bigtable_test.go b/mdb/mbigtable/bigtable_test.go index ad1427c..36c4417 100644 --- a/mdb/mbigtable/bigtable_test.go +++ b/mdb/mbigtable/bigtable_test.go @@ -11,9 +11,9 @@ import ( ) func TestBasic(t *T) { - ctx := mtest.NewCtx() - ctx = mtest.SetEnv(ctx, "GCE_PROJECT", "testProject") - ctx, bt := MNew(ctx, nil, "testInstance") + ctx := mtest.Context() + ctx = mtest.WithEnv(ctx, "BIGTABLE_GCE_PROJECT", "testProject") + ctx, bt := WithBigTable(ctx, nil, "testInstance") mtest.Run(ctx, t, func() { tableName := "test-" + mrand.Hex(8) diff --git a/mdb/mdatastore/datastore.go b/mdb/mdatastore/datastore.go index c150796..1a74e9f 100644 --- a/mdb/mdatastore/datastore.go +++ b/mdb/mdatastore/datastore.go @@ -22,39 +22,33 @@ type Datastore struct { ctx context.Context } -// MNew returns a Datastore instance which will be initialized and configured -// when the start event is triggered on the returned Context (see mrun.Start). -// The Datastore instance will have Close called on it when the stop event is -// triggered on the returned Context (see mrun.Stop). +// WithDatastore returns a Datastore instance which will be initialized and +// configured when the start event is triggered on the returned Context (see +// mrun.Start). The Datastore instance will have Close called on it when the +// stop event is triggered on the returned Context (see mrun.Stop). // // gce is optional and can be passed in if there's an existing gce object which // should be used, otherwise a new one will be created with mdb.MGCE. -func MNew(ctx context.Context, gce *mdb.GCE) (context.Context, *Datastore) { +func WithDatastore(parent context.Context, gce *mdb.GCE) (context.Context, *Datastore) { + ctx := mctx.NewChild(parent, "datastore") if gce == nil { - ctx, gce = mdb.MGCE(ctx, "") + ctx, gce = mdb.WithGCE(ctx, "") } ds := &Datastore{ gce: gce, - ctx: mctx.NewChild(ctx, "datastore"), } - // TODO the equivalent functionality as here will be added with annotations - // ds.log.SetKV(ds) - - ds.ctx = mrun.OnStart(ds.ctx, func(innerCtx context.Context) error { - mlog.Info(ds.ctx, "connecting to datastore") + ctx = mrun.WithStartHook(ctx, func(innerCtx context.Context) error { + ds.ctx = mctx.MergeAnnotations(ds.ctx, ds.gce.Context()) + mlog.Info("connecting to datastore", ds.ctx) var err error ds.Client, err = datastore.NewClient(innerCtx, ds.gce.Project, ds.gce.ClientOptions()...) - return merr.WithKV(err, ds.KV()) + return merr.Wrap(ds.ctx, err) }) - ds.ctx = mrun.OnStop(ds.ctx, func(context.Context) error { + ctx = mrun.WithStopHook(ctx, func(context.Context) error { return ds.Client.Close() }) - return mctx.WithChild(ctx, ds.ctx), ds -} - -// KV implements the mlog.KVer interface. -func (ds *Datastore) KV() map[string]interface{} { - return ds.gce.KV() + ds.ctx = ctx + return mctx.WithChild(parent, ctx), ds } diff --git a/mdb/mdatastore/datastore_test.go b/mdb/mdatastore/datastore_test.go index c6b8270..759b0b1 100644 --- a/mdb/mdatastore/datastore_test.go +++ b/mdb/mdatastore/datastore_test.go @@ -11,9 +11,9 @@ import ( // Requires datastore emulator to be running func TestBasic(t *T) { - ctx := mtest.NewCtx() - ctx = mtest.SetEnv(ctx, "GCE_PROJECT", "test") - ctx, ds := MNew(ctx, nil) + ctx := mtest.Context() + ctx = mtest.WithEnv(ctx, "DATASTORE_GCE_PROJECT", "test") + ctx, ds := WithDatastore(ctx, nil) mtest.Run(ctx, t, func() { name := mrand.Hex(8) key := datastore.NameKey("testKind", name, nil) diff --git a/mdb/mdb.go b/mdb/mdb.go index a148984..5a5283e 100644 --- a/mdb/mdb.go +++ b/mdb/mdb.go @@ -7,7 +7,6 @@ import ( "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/mrun" "google.golang.org/api/option" ) @@ -15,32 +14,36 @@ import ( // GCE wraps configuration parameters commonly used for interacting with GCE // services. type GCE struct { + ctx context.Context Project string CredFile string } -// MGCE returns a GCE instance which will be initialized and configured when the -// start event is triggered on the returned Context (see mrun.Start). +// WithGCE returns a GCE instance which will be initialized and configured when +// the start event is triggered on the returned Context (see mrun.Start). // defaultProject is used as the default value for the mcfg parameter this // function creates. -func MGCE(parent context.Context, defaultProject string) (context.Context, *GCE) { +func WithGCE(parent context.Context, defaultProject string) (context.Context, *GCE) { ctx := mctx.NewChild(parent, "gce") - ctx, credFile := mcfg.String(ctx, "cred-file", "", "Path to GCE credientials JSON file, if any") + ctx, credFile := mcfg.WithString(ctx, "cred-file", "", "Path to GCE credientials JSON file, if any") var project *string const projectUsage = "Name of GCE project to use" if defaultProject == "" { - ctx, project = mcfg.RequiredString(ctx, "project", projectUsage) + ctx, project = mcfg.WithRequiredString(ctx, "project", projectUsage) } else { - ctx, project = mcfg.String(ctx, "project", defaultProject, projectUsage) + ctx, project = mcfg.WithString(ctx, "project", defaultProject, projectUsage) } var gce GCE - ctx = mrun.OnStart(ctx, func(context.Context) error { + ctx = mrun.WithStartHook(ctx, func(context.Context) error { gce.Project = *project gce.CredFile = *credFile + gce.ctx = mctx.Annotate(ctx, "project", gce.Project) return nil }) + + gce.ctx = ctx return mctx.WithChild(parent, ctx), &gce } @@ -54,9 +57,7 @@ func (gce *GCE) ClientOptions() []option.ClientOption { return opts } -// KV implements the mlog.KVer interface. -func (gce *GCE) KV() map[string]interface{} { - return mlog.KV{ - "gceProject": gce.Project, - } +// Context returns the annotated Context from this instance's initialization. +func (gce *GCE) Context() context.Context { + return gce.ctx } diff --git a/mdb/mpubsub/pubsub.go b/mdb/mpubsub/pubsub.go index 64c06c1..c63fefc 100644 --- a/mdb/mpubsub/pubsub.go +++ b/mdb/mpubsub/pubsub.go @@ -4,7 +4,6 @@ package mpubsub import ( "context" - "errors" "sync" "time" @@ -41,45 +40,40 @@ type PubSub struct { ctx context.Context } -// MNew returns a PubSub instance which will be initialized and configured when -// the start event is triggered on the returned Context (see mrun.Start). The -// PubSub instance will have Close called on it when the stop event is triggered -// on the returned Context(see mrun.Stop). +// WithPubSub returns a PubSub instance which will be initialized and configured +// when the start event is triggered on the returned Context (see mrun.Start). +// The PubSub instance will have Close called on it when the stop event is +// triggered on the returned Context(see mrun.Stop). // // gce is optional and can be passed in if there's an existing gce object which // should be used, otherwise a new one will be created with mdb.MGCE. -func MNew(ctx context.Context, gce *mdb.GCE) (context.Context, *PubSub) { +func WithPubSub(parent context.Context, gce *mdb.GCE) (context.Context, *PubSub) { + ctx := mctx.NewChild(parent, "pubsub") if gce == nil { - ctx, gce = mdb.MGCE(ctx, "") + ctx, gce = mdb.WithGCE(ctx, "") } ps := &PubSub{ gce: gce, - ctx: mctx.NewChild(ctx, "pubsub"), } - // TODO the equivalent functionality as here will be added with annotations - // ps.log.SetKV(ps) - - ps.ctx = mrun.OnStart(ps.ctx, func(innerCtx context.Context) error { - mlog.Info(ps.ctx, "connecting to pubsub") + ctx = mrun.WithStartHook(ctx, func(innerCtx context.Context) error { + ps.ctx = mctx.MergeAnnotations(ps.ctx, ps.gce.Context()) + mlog.Info("connecting to pubsub", ps.ctx) var err error ps.Client, err = pubsub.NewClient(innerCtx, ps.gce.Project, ps.gce.ClientOptions()...) - return merr.WithKV(err, ps.KV()) + return merr.Wrap(ps.ctx, err) }) - ps.ctx = mrun.OnStop(ps.ctx, func(context.Context) error { + ctx = mrun.WithStopHook(ctx, func(context.Context) error { return ps.Client.Close() }) - return mctx.WithChild(ctx, ps.ctx), ps -} - -// KV implements the mlog.KVer interface -func (ps *PubSub) KV() map[string]interface{} { - return ps.gce.KV() + ps.ctx = ctx + return mctx.WithChild(parent, ctx), ps } // Topic provides methods around a particular topic in PubSub type Topic struct { + ctx context.Context ps *PubSub topic *pubsub.Topic name string @@ -88,6 +82,7 @@ type Topic struct { // Topic returns, after potentially creating, a topic of the given name func (ps *PubSub) Topic(ctx context.Context, name string, create bool) (*Topic, error) { t := &Topic{ + ctx: mctx.Annotate(ps.ctx, "topicName", name), ps: ps, name: name, } @@ -98,38 +93,31 @@ func (ps *PubSub) Topic(ctx context.Context, name string, create bool) (*Topic, if isErrAlreadyExists(err) { t.topic = ps.Client.Topic(name) } else if err != nil { - return nil, merr.WithKV(err, t.KV()) + return nil, merr.Wrap(ctx, merr.Wrap(t.ctx, err)) } } else { t.topic = ps.Client.Topic(name) - if exists, err := t.topic.Exists(ctx); err != nil { - return nil, merr.WithKV(err, t.KV()) + if exists, err := t.topic.Exists(t.ctx); err != nil { + return nil, merr.Wrap(ctx, merr.Wrap(t.ctx, err)) } else if !exists { - err := merr.New("topic dne") - return nil, merr.WithKV(err, t.KV()) + return nil, merr.Wrap(ctx, merr.New(t.ctx, "topic dne")) } } return t, nil } -// KV implements the mlog.KVer interface -func (t *Topic) KV() map[string]interface{} { - kv := t.ps.KV() - kv["topicName"] = t.name - return kv -} - // Publish publishes a message with the given data as its body to the Topic func (t *Topic) Publish(ctx context.Context, data []byte) error { _, err := t.topic.Publish(ctx, &Message{Data: data}).Get(ctx) if err != nil { - return merr.WithKV(err, t.KV()) + return merr.Wrap(ctx, merr.Wrap(t.ctx, err)) } return nil } // Subscription provides methods around a subscription to a topic in PubSub type Subscription struct { + ctx context.Context topic *Topic sub *pubsub.Subscription name string @@ -143,6 +131,7 @@ type Subscription struct { func (t *Topic) Subscription(ctx context.Context, name string, create bool) (*Subscription, error) { name = t.name + "_" + name s := &Subscription{ + ctx: mctx.Annotate(t.ctx, "subName", name), topic: t, name: name, } @@ -155,27 +144,19 @@ func (t *Topic) Subscription(ctx context.Context, name string, create bool) (*Su if isErrAlreadyExists(err) { s.sub = t.ps.Subscription(name) } else if err != nil { - return nil, merr.WithKV(err, s.KV()) + return nil, merr.Wrap(ctx, merr.Wrap(s.ctx, err)) } } else { s.sub = t.ps.Subscription(name) if exists, err := s.sub.Exists(ctx); err != nil { - return nil, merr.WithKV(err, s.KV()) + return nil, merr.Wrap(ctx, merr.Wrap(s.ctx, err)) } else if !exists { - err := merr.New("sub dne") - return nil, merr.WithKV(err, s.KV()) + return nil, merr.Wrap(ctx, merr.New(s.ctx, "sub dne")) } } return s, nil } -// KV implements the mlog.KVer interface -func (s *Subscription) KV() map[string]interface{} { - kv := s.topic.KV() - kv["subName"] = s.name - return kv -} - // ConsumerFunc is a function which messages being consumed will be passed. The // returned boolean and returned error are independent. If the bool is false the // message will be returned to the queue for retrying later. If an error is @@ -221,12 +202,14 @@ func (s *Subscription) Consume(ctx context.Context, fn ConsumerFunc, opts Consum octx := oldctx.Context(ctx) for { err := s.sub.Receive(octx, func(octx oldctx.Context, msg *Message) { - innerCtx, cancel := oldctx.WithTimeout(octx, opts.Timeout) + innerOCtx, cancel := oldctx.WithTimeout(octx, opts.Timeout) defer cancel() + innerCtx := context.Context(innerOCtx) - ok, err := fn(context.Context(innerCtx), msg) + ok, err := fn(innerCtx, msg) if err != nil { - mlog.Warn(s.topic.ps.ctx, "error consuming pubsub message", s, merr.KV(err)) + mlog.Warn("error consuming pubsub message", + s.ctx, ctx, innerCtx, merr.Context(err)) } if ok { @@ -238,7 +221,8 @@ func (s *Subscription) Consume(ctx context.Context, fn ConsumerFunc, opts Consum if octx.Err() == context.Canceled || err == nil { return } else if err != nil { - mlog.Warn(s.topic.ps.ctx, "error consuming from pubsub", s, merr.KV(err)) + mlog.Warn("error consuming from pubsub", + s.ctx, ctx, merr.Context(err)) time.Sleep(1 * time.Second) } } @@ -331,7 +315,8 @@ func (s *Subscription) BatchConsume( } ret, err := fn(thisCtx, msgs) if err != nil { - mlog.Warn(s.topic.ps.ctx, "error consuming pubsub batch messages", s, merr.KV(err)) + mlog.Warn("error consuming pubsub batch messages", + s.ctx, merr.Context(err)) } for i := range thisGroup { thisGroup[i].retCh <- ret // retCh is buffered @@ -365,7 +350,7 @@ func (s *Subscription) BatchConsume( case ret := <-retCh: return ret, nil case <-ctx.Done(): - return false, errors.New("reading from batch grouping process timed out") + return false, merr.Wrap(ctx, merr.New(s.ctx, "reading from batch grouping process timed out")) } }, opts) diff --git a/mdb/mpubsub/pubsub_test.go b/mdb/mpubsub/pubsub_test.go index af0feb1..d2327ea 100644 --- a/mdb/mpubsub/pubsub_test.go +++ b/mdb/mpubsub/pubsub_test.go @@ -13,9 +13,9 @@ import ( // this requires the pubsub emulator to be running func TestPubSub(t *T) { - ctx := mtest.NewCtx() - ctx = mtest.SetEnv(ctx, "GCE_PROJECT", "test") - ctx, ps := MNew(ctx, nil) + ctx := mtest.Context() + ctx = mtest.WithEnv(ctx, "PUBSUB_GCE_PROJECT", "test") + ctx, ps := WithPubSub(ctx, nil) mtest.Run(ctx, t, func() { topicName := "testTopic_" + mrand.Hex(8) ctx := context.Background() @@ -47,9 +47,9 @@ func TestPubSub(t *T) { } func TestBatchPubSub(t *T) { - ctx := mtest.NewCtx() - ctx = mtest.SetEnv(ctx, "GCE_PROJECT", "test") - ctx, ps := MNew(ctx, nil) + ctx := mtest.Context() + ctx = mtest.WithEnv(ctx, "PUBSUB_GCE_PROJECT", "test") + ctx, ps := WithPubSub(ctx, nil) mtest.Run(ctx, t, func() { topicName := "testBatchTopic_" + mrand.Hex(8) diff --git a/merr/kv.go b/merr/kv.go deleted file mode 100644 index a5ec63f..0000000 --- a/merr/kv.go +++ /dev/null @@ -1,120 +0,0 @@ -package merr - -import ( - "fmt" - "path/filepath" -) - -// WithValue returns a copy of the original error, automatically wrapping it if -// the error is not from merr (see Wrap). The returned error has a value set on -// with for the given key. -// -// visible determines whether or not the value is visible in the output of -// Error. -func WithValue(e error, k, v interface{}, visible bool) error { - if e == nil { - return nil - } - er := wrap(e, true, 1) - er.attr[k] = val{val: v, visible: visible} - return er -} - -// GetValue returns the value embedded in the error for the given key, or nil if -// the error isn't from this package or doesn't have that key embedded. -func GetValue(e error, k interface{}) interface{} { - if e == nil { - return nil - } - return wrap(e, false, -1).attr[k].val -} - -//////////////////////////////////////////////////////////////////////////////// - -// not really used for attributes, but w/e -const attrKeyErr attrKey = "err" -const attrKeyErrSrc attrKey = "errSrc" - -// KVer implements the mlog.KVer interface. This is defined here to avoid this -// package needing to actually import mlog. -type KVer struct { - kv map[string]interface{} -} - -// KV implements the mlog.KVer interface. -func (kv KVer) KV() map[string]interface{} { - return kv.kv -} - -// KV returns a KVer which contains all visible values embedded in the error, as -// well as the original error string itself. Keys will be turned into strings -// using the fmt.Sprint function. -// -// If any keys conflict then their type information will be included as part of -// the key. -func KV(e error) KVer { - if e == nil { - return KVer{} - } - - er := wrap(e, false, 1) - kvm := make(map[string]interface{}, len(er.attr)+1) - - keys := map[string]interface{}{} // in this case the value is the raw key - setKey := func(k, v interface{}) { - kStr := fmt.Sprint(k) - oldKey := keys[kStr] - if oldKey == nil { - keys[kStr] = k - kvm[kStr] = v - return - } - - // check if oldKey is in kvm, if so it needs to be moved to account for - // its type info - if oldV, ok := kvm[kStr]; ok { - delete(kvm, kStr) - kvm[fmt.Sprintf("%T(%s)", oldKey, kStr)] = oldV - } - - kvm[fmt.Sprintf("%T(%s)", k, kStr)] = v - } - - setKey(attrKeyErr, er.err.Error()) - for k, v := range er.attr { - if !v.visible { - continue - } - - stack, ok := v.val.(Stack) - if !ok { - setKey(k, v.val) - continue - } - - // compress the stack trace to just be the top-most frame - frame := stack.Frame() - file, dir := filepath.Base(frame.File), filepath.Dir(frame.File) - dir = filepath.Base(dir) // only want the first dirname, ie the pkg name - setKey(attrKeyErrSrc, fmt.Sprintf("%s/%s:%d", dir, file, frame.Line)) - } - - return KVer{kvm} -} - -type kvKey string - -// WithKV embeds key/value pairs into an error, just like WithValue, but it does -// so via one or more passed in maps -func WithKV(e error, kvMaps ...map[string]interface{}) error { - if e == nil { - return nil - } - er := wrap(e, true, 1) - for _, kvMap := range kvMaps { - for k, v := range kvMap { - er.attr[kvKey(k)] = val{val: v, visible: true} - } - } - return er -} diff --git a/merr/kv_test.go b/merr/kv_test.go deleted file mode 100644 index 7738598..0000000 --- a/merr/kv_test.go +++ /dev/null @@ -1,98 +0,0 @@ -package merr - -import ( - "strings" - . "testing" - - "github.com/mediocregopher/mediocre-go-lib/mtest/massert" -) - -func TestKV(t *T) { - massert.Fatal(t, massert.All( - massert.Nil(WithValue(nil, "foo", "bar", true)), - massert.Nil(WithValue(nil, "foo", "bar", false)), - massert.Nil(GetValue(nil, "foo")), - massert.Len(KV(nil).KV(), 0), - )) - - er := New("foo", "bar", "baz") - kv := KV(er).KV() - massert.Fatal(t, massert.Comment( - massert.All( - massert.Len(kv, 3), - massert.Equal("foo", kv["err"]), - massert.Equal("baz", kv["bar"]), - massert.Equal(true, - strings.HasPrefix(kv["errSrc"].(string), "merr/kv_test.go:")), - ), - "kv: %#v", kv, - )) - - type A string - type B string - type C string - - er = WithValue(er, "invisible", "you can't see me", false) - er = WithValue(er, A("k"), "1", true) - kv = KV(er).KV() - massert.Fatal(t, massert.Comment( - massert.All( - massert.Len(kv, 4), - massert.Equal("foo", kv["err"]), - massert.Equal("baz", kv["bar"]), - massert.Equal(true, - strings.HasPrefix(kv["errSrc"].(string), "merr/kv_test.go:")), - massert.Equal("1", kv["k"]), - ), - "kv: %#v", kv, - )) - - er = WithValue(er, B("k"), "2", true) - kv = KV(er).KV() - massert.Fatal(t, massert.Comment( - massert.All( - massert.Len(kv, 5), - massert.Equal("foo", kv["err"]), - massert.Equal("baz", kv["bar"]), - massert.Equal(true, - strings.HasPrefix(kv["errSrc"].(string), "merr/kv_test.go:")), - massert.Equal("1", kv["merr.A(k)"]), - massert.Equal("2", kv["merr.B(k)"]), - ), - "kv: %#v", kv, - )) - - er = WithValue(er, C("k"), "3", true) - kv = KV(er).KV() - massert.Fatal(t, massert.Comment( - massert.All( - massert.Len(kv, 6), - massert.Equal("foo", kv["err"]), - massert.Equal("baz", kv["bar"]), - massert.Equal(true, - strings.HasPrefix(kv["errSrc"].(string), "merr/kv_test.go:")), - massert.Equal("1", kv["merr.A(k)"]), - massert.Equal("2", kv["merr.B(k)"]), - massert.Equal("3", kv["merr.C(k)"]), - ), - "kv: %#v", kv, - )) - - er = WithKV(er, map[string]interface{}{"D": 4, "k": 5}) - kv = KV(er).KV() - massert.Fatal(t, massert.Comment( - massert.All( - massert.Len(kv, 8), - massert.Equal("foo", kv["err"]), - massert.Equal("baz", kv["bar"]), - massert.Equal(true, - strings.HasPrefix(kv["errSrc"].(string), "merr/kv_test.go:")), - massert.Equal("1", kv["merr.A(k)"]), - massert.Equal("2", kv["merr.B(k)"]), - massert.Equal("3", kv["merr.C(k)"]), - massert.Equal(4, kv["D"]), - massert.Equal(5, kv["merr.kvKey(k)"]), - ), - "kv: %#v", kv, - )) -} diff --git a/merr/merr.go b/merr/merr.go index f585e21..0fb1175 100644 --- a/merr/merr.go +++ b/merr/merr.go @@ -9,11 +9,12 @@ package merr import ( + "context" "errors" - "fmt" - "sort" "strings" "sync" + + "github.com/mediocregopher/mediocre-go-lib/mctx" ) var strBuilderPool = sync.Pool{ @@ -27,114 +28,158 @@ func putStrBuilder(sb *strings.Builder) { //////////////////////////////////////////////////////////////////////////////// -type val struct { - visible bool - val interface{} -} - -func (v val) String() string { - return fmt.Sprint(v.val) -} - type err struct { err error - attr map[interface{}]val + attr map[interface{}]interface{} } // attr keys internal to this package -type attrKey string +type attrKey int -func wrap(e error, cp bool, skip int) *err { +const ( + attrKeyCtx attrKey = iota +) + +func wrap(e error, cp bool) *err { if e == nil { return nil } er, ok := e.(*err) if !ok { - er := &err{err: e, attr: map[interface{}]val{}} - if skip >= 0 { - setStack(er, skip+1) - } - return er + return &err{err: e} } else if !cp { return er } er2 := &err{ err: er.err, - attr: make(map[interface{}]val, len(er.attr)), + attr: make(map[interface{}]interface{}, len(er.attr)), } for k, v := range er.attr { er2.attr[k] = v } - if _, ok := er2.attr[attrKeyStack]; !ok && skip >= 0 { - setStack(er, skip+1) - } return er2 } -// Wrap takes in an error and returns one wrapping it in merr's inner type, -// which embeds information like the stack trace. -func Wrap(e error) error { - return wrap(e, false, 1) +// Base takes in an error and checks if it is merr's internal error type. If it +// is then the underlying error which is being wrapped is returned. If it's not +// then the passed in error is returned as-is. +func Base(e error) error { + if er, ok := e.(*err); ok { + return er.err + } + return e } -// New returns a new error with the given string as its error string. New -// automatically wraps the error in merr's inner type, which embeds information -// like the stack trace. -// -// For convenience, visible key/values may be passed into New at this point. For -// example, the following two are equivalent: -// -// merr.WithValue(merr.New("foo"), "bar", "baz", true) -// merr.New("foo", "bar", "baz") -// -func New(str string, kvs ...interface{}) error { - if len(kvs)%2 != 0 { - panic("key passed in without corresponding value") +// WithValue returns a copy of the original error, automatically wrapping it if +// the error is not from merr (see Wrap). The returned error has an attribute +// value set on it for the given key. +func WithValue(e error, k, v interface{}) error { + if e == nil { + return nil } - err := wrap(errors.New(str), false, 1) - for i := 0; i < len(kvs); i += 2 { - err.attr[kvs[i]] = val{ - visible: true, - val: kvs[i+1], - } + er := wrap(e, true) + if er.attr == nil { + er.attr = map[interface{}]interface{}{} } - return err + er.attr[k] = v + return er } -func (er *err) visibleAttrs() [][2]string { - out := make([][2]string, 0, len(er.attr)) - for k, v := range er.attr { - if !v.visible { - continue - } - out = append(out, [2]string{ - strings.Trim(fmt.Sprintf("%q", k), `"`), - fmt.Sprint(v.val), - }) +// Value returns the value embedded in the error for the given key, or nil if +// the error isn't from this package or doesn't have that key embedded. +func Value(e error, k interface{}) interface{} { + if e == nil { + return nil + } + return wrap(e, false).attr[k] +} + +// WrapSkip is like Wrap but also allows for skipping extra stack frames when +// embedding the stack into the error. +func WrapSkip(ctx context.Context, e error, skip int, kvs ...interface{}) error { + prevCtx, _ := Value(e, attrKeyCtx).(context.Context) + if prevCtx != nil { + ctx = mctx.MergeAnnotations(prevCtx, ctx) } - sort.Slice(out, func(i, j int) bool { - return out[i][0] < out[j][0] - }) + if _, ok := mctx.Stack(ctx); !ok { + ctx = mctx.WithStack(ctx, skip+1) + } + if len(kvs) > 0 { + ctx = mctx.Annotate(ctx, kvs...) + } - return out + return WithValue(e, attrKeyCtx, ctx) +} + +// Wrap takes in an error and returns one which wraps it in merr's inner type, +// embedding the given Context (which can later be retrieved by Ctx) at the same +// time. +// +// For convenience, extra annotation information can be passed in here as well +// via the kvs argument. See mctx.Annotate for more information. +// +// This function automatically embeds stack information into the Context as it's +// being stored, using mctx.WithStack, unless the error already has stack +// information in it. +func Wrap(ctx context.Context, e error, kvs ...interface{}) error { + return WrapSkip(ctx, e, 1, kvs...) +} + +// New is a shortcut for: +// merr.Wrap(ctx, errors.New(str), kvs...) +func New(ctx context.Context, str string, kvs ...interface{}) error { + return WrapSkip(ctx, errors.New(str), 1, kvs...) +} + +// TODO it would be more convenient in a lot of cases if New and Wrap took in a +// list of Contexts. + +type annotateKey string + +func ctx(e error) context.Context { + ctx, _ := Value(e, attrKeyCtx).(context.Context) + if ctx == nil { + ctx = context.Background() + } + + if stack, ok := mctx.Stack(ctx); ok { + ctx = mctx.Annotate(ctx, annotateKey("errLoc"), stack.String()) + } + return ctx +} + +// Context returns the Context embedded in this error from the last call to Wrap +// or New. If none is embedded this uses context.Background(). +// +// The returned Context will have annotated on it (see mctx.Annotate) the +// underlying error's string (as returned by Error()) and the stack location in +// the Context. Stack locations are automatically added by New and Wrap via +// mctx.WithStack. +// +// If this error is nil this returns context.Background(). +func Context(e error) context.Context { + if e == nil { + return context.Background() + } + ctx := ctx(e) + ctx = mctx.Annotate(ctx, annotateKey("err"), Base(e).Error()) + return ctx } func (er *err) Error() string { - visAttrs := er.visibleAttrs() - if len(visAttrs) == 0 { - return er.err.Error() - } + ctx := ctx(er) sb := strBuilderPool.Get().(*strings.Builder) defer putStrBuilder(sb) - sb.WriteString(strings.TrimSpace(er.err.Error())) - for _, attr := range visAttrs { - k, v := strings.TrimSpace(attr[0]), strings.TrimSpace(attr[1]) + + annotations := mctx.Annotations(ctx).StringSlice(true) + for _, kve := range annotations { + k, v := strings.TrimSpace(kve[0]), strings.TrimSpace(kve[1]) sb.WriteString("\n\t* ") sb.WriteString(k) sb.WriteString(": ") @@ -154,16 +199,6 @@ func (er *err) Error() string { return sb.String() } -// Base takes in an error and checks if it is merr's internal error type. If it -// is then the underlying error which is being wrapped is returned. If it's not -// then the passed in error is returned as-is. -func Base(e error) error { - if er, ok := e.(*err); ok { - return er.err - } - return e -} - // Equal is a shortcut for Base(e1) == Base(e2). func Equal(e1, e2 error) bool { return Base(e1) == Base(e2) diff --git a/merr/merr_test.go b/merr/merr_test.go index 6077004..84f9abb 100644 --- a/merr/merr_test.go +++ b/merr/merr_test.go @@ -1,35 +1,33 @@ package merr import ( + "context" "errors" . "testing" + "github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/mtest/massert" ) func TestError(t *T) { - er := &err{ - err: errors.New("foo"), - attr: map[interface{}]val{ - "a": val{val: "aaa aaa\n", visible: true}, - "b": val{val: "invisible"}, - "c": val{val: "ccc\nccc\n", visible: true}, - "d\t": val{val: "weird key but ok", visible: true}, - }, - } - str := er.Error() + e := New(context.Background(), "foo", + "a", "aaa aaa\n", + "c", "ccc\nccc\n", + "d\t", "weird key but ok", + ) exp := `foo * a: aaa aaa * c: ccc ccc - * d\t: weird key but ok` - massert.Fatal(t, massert.Equal(exp, str)) + * d: weird key but ok + * errLoc: merr/merr_test.go:13` + massert.Fatal(t, massert.Equal(exp, e.Error())) } func TestBase(t *T) { errFoo, errBar := errors.New("foo"), errors.New("bar") - erFoo := Wrap(errFoo) + erFoo := Wrap(context.Background(), errFoo) massert.Fatal(t, massert.All( massert.Nil(Base(nil)), massert.Equal(errFoo, Base(erFoo)), @@ -40,3 +38,50 @@ func TestBase(t *T) { massert.Equal(false, Equal(errBar, erFoo)), )) } + +func TestValue(t *T) { + massert.Fatal(t, massert.All( + massert.Nil(WithValue(nil, "foo", "bar")), + massert.Nil(Value(nil, "foo")), + )) + + e1 := New(context.Background(), "foo") + e1 = WithValue(e1, "a", "A") + e2 := WithValue(errors.New("bar"), "a", "A") + massert.Fatal(t, massert.All( + massert.Equal("A", Value(e1, "a")), + massert.Equal("A", Value(e2, "a")), + )) + + e3 := WithValue(e2, "a", "AAA") + massert.Fatal(t, massert.All( + massert.Equal("A", Value(e1, "a")), + massert.Equal("A", Value(e2, "a")), + massert.Equal("AAA", Value(e3, "a")), + )) +} + +func mkErr(ctx context.Context, err error) error { + return Wrap(ctx, err) // it's important that this is line 65 +} + +func TestCtx(t *T) { + ctxA := mctx.Annotate(context.Background(), "0", "ZERO", "1", "one") + ctxB := mctx.Annotate(context.Background(), "1", "ONE", "2", "TWO") + + // use mkErr so that it's easy to test that the stack info isn't overwritten + // when Wrap is called with ctxB. + e := mkErr(ctxA, errors.New("hello")) + e = Wrap(ctxB, e) + + err := massert.Equal(map[string]string{ + "0": "ZERO", + "1": "ONE", + "2": "TWO", + "err": "hello", + "errLoc": "merr/merr_test.go:65", + }, mctx.Annotations(Context(e)).StringMap()).Assert() + if err != nil { + t.Fatal(err) + } +} diff --git a/merr/stack.go b/merr/stack.go deleted file mode 100644 index e97ed9a..0000000 --- a/merr/stack.go +++ /dev/null @@ -1,85 +0,0 @@ -package merr - -import ( - "fmt" - "runtime" - "strings" - "text/tabwriter" -) - -// MaxStackSize indicates the maximum number of stack frames which will be -// stored when embedding stack traces in errors. -var MaxStackSize = 50 - -const attrKeyStack attrKey = "stack" - -// Stack represents a stack trace at a particular point in execution. -type Stack []uintptr - -// Frame returns the first frame in the stack. -func (s Stack) Frame() runtime.Frame { - if len(s) == 0 { - panic("cannot call Frame on empty stack") - } - - frame, _ := runtime.CallersFrames([]uintptr(s)).Next() - return frame -} - -// Frames returns all runtime.Frame instances for this stack. -func (s Stack) Frames() []runtime.Frame { - if len(s) == 0 { - return nil - } - - out := make([]runtime.Frame, 0, len(s)) - frames := runtime.CallersFrames([]uintptr(s)) - for { - frame, more := frames.Next() - out = append(out, frame) - if !more { - break - } - } - return out -} - -// String returns the full stack trace. -func (s Stack) String() string { - sb := strBuilderPool.Get().(*strings.Builder) - defer putStrBuilder(sb) - tw := tabwriter.NewWriter(sb, 0, 4, 4, ' ', 0) - for _, frame := range s.Frames() { - file := fmt.Sprintf("%s:%d", frame.File, frame.Line) - fmt.Fprintf(tw, "%s\t%s\n", file, frame.Function) - } - if err := tw.Flush(); err != nil { - panic(err) - } - return sb.String() -} - -func setStack(er *err, skip int) { - stackSlice := make([]uintptr, MaxStackSize) - // incr skip once for setStack, and once for runtime.Callers - l := runtime.Callers(skip+2, stackSlice) - er.attr[attrKeyStack] = val{val: Stack(stackSlice[:l]), visible: true} -} - -// WithStack returns a copy of the original error, automatically wrapping it if -// the error is not from merr (see Wrap). The returned error has the embedded -// stacktrace set to the frame calling this function. -// -// skip can be used to exclude that many frames from the top of the stack. -func WithStack(e error, skip int) error { - er := wrap(e, true, -1) - setStack(er, skip+1) - return er -} - -// GetStack returns the Stack which was embedded in the error, if the error is -// from this package. If not then nil is returned. -func GetStack(e error) Stack { - stack, _ := wrap(e, false, -1).attr[attrKeyStack].val.(Stack) - return stack -} diff --git a/mhttp/mhttp.go b/mhttp/mhttp.go index 64c50ce..2766060 100644 --- a/mhttp/mhttp.go +++ b/mhttp/mhttp.go @@ -17,13 +17,13 @@ import ( "github.com/mediocregopher/mediocre-go-lib/mrun" ) -// MServer is returned by MListenAndServe and simply wraps an *http.Server. -type MServer struct { +// Server is returned by WithListeningServer and simply wraps an *http.Server. +type Server struct { *http.Server ctx context.Context } -// MListenAndServe returns an http.Server which will be initialized and have +// WithListeningServer returns a *Server which will be initialized and have // ListenAndServe called on it (asynchronously) when the start event is // triggered on the returned Context (see mrun.Start). The Server will have // Shutdown called on it when the stop event is triggered on the returned @@ -31,25 +31,22 @@ type MServer struct { // // This function automatically handles setting up configuration parameters via // mcfg. The default listen address is ":0". -func MListenAndServe(ctx context.Context, h http.Handler) (context.Context, *MServer) { - srv := &MServer{ +func WithListeningServer(ctx context.Context, h http.Handler) (context.Context, *Server) { + srv := &Server{ Server: &http.Server{Handler: h}, ctx: mctx.NewChild(ctx, "http"), } - var listener *mnet.MListener - srv.ctx, listener = mnet.MListen(srv.ctx, "tcp", "") + var listener *mnet.Listener + srv.ctx, listener = mnet.WithListener(srv.ctx, "tcp", "") listener.NoCloseOnStop = true // http.Server.Shutdown will do this - // TODO the equivalent functionality as here will be added with annotations - //logger := mlog.From(ctx) - //logger.SetKV(listener) - - srv.ctx = mrun.OnStart(srv.ctx, func(context.Context) error { + srv.ctx = mrun.WithStartHook(srv.ctx, func(context.Context) error { srv.Addr = listener.Addr().String() - srv.ctx = mrun.Thread(srv.ctx, func() error { - if err := srv.Serve(listener); err != http.ErrServerClosed { - mlog.Error(srv.ctx, "error serving listener", merr.KV(err)) + srv.ctx = mrun.WithThread(srv.ctx, func() error { + mlog.Info("serving requests", srv.ctx) + if err := srv.Serve(listener); !merr.Equal(err, http.ErrServerClosed) { + mlog.Error("error serving listener", srv.ctx, merr.Context(err)) return err } return nil @@ -57,8 +54,8 @@ func MListenAndServe(ctx context.Context, h http.Handler) (context.Context, *MSe return nil }) - srv.ctx = mrun.OnStop(srv.ctx, func(innerCtx context.Context) error { - mlog.Info(srv.ctx, "shutting down server") + srv.ctx = mrun.WithStopHook(srv.ctx, func(innerCtx context.Context) error { + mlog.Info("shutting down server", srv.ctx) if err := srv.Shutdown(innerCtx); err != nil { return err } diff --git a/mhttp/mhttp_test.go b/mhttp/mhttp_test.go index 1574d9b..5db0aad 100644 --- a/mhttp/mhttp_test.go +++ b/mhttp/mhttp_test.go @@ -13,9 +13,9 @@ import ( ) func TestMListenAndServe(t *T) { - ctx := mtest.NewCtx() + ctx := mtest.Context() - ctx, srv := MListenAndServe(ctx, http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { + ctx, srv := WithListeningServer(ctx, 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 20a9bb2..8d07a80 100644 --- a/mlog/ctx.go +++ b/mlog/ctx.go @@ -1,53 +1,58 @@ package mlog -import "context" +import ( + "context" +) type ctxKey int -// Set returns the Context with the Logger carried by it. -func Set(ctx context.Context, l *Logger) context.Context { +// WithLogger returns the Context with the Logger carried by it. +func WithLogger(ctx context.Context, l *Logger) context.Context { return context.WithValue(ctx, ctxKey(0), l) } // DefaultLogger is an instance of Logger which is returned by From when a -// Logger hasn't been previously Set on the Context passed in. +// Logger hasn't been previously WithLogger on the Contexts passed in. var DefaultLogger = NewLogger() -// From returns the Logger carried by this Context, or DefaultLogger if none is -// being carried. -func From(ctx context.Context) *Logger { - if l, _ := ctx.Value(ctxKey(0)).(*Logger); l != nil { - return l +// From looks at each context and returns the Logger from the first Context +// which carries one via a WithLogger call. If none carry a Logger than +// DefaultLogger is returned. +func From(ctxs ...context.Context) *Logger { + for _, ctx := range ctxs { + if l, _ := ctx.Value(ctxKey(0)).(*Logger); l != nil { + return l + } } return DefaultLogger } // Debug is a shortcut for -// mlog.From(ctx).Debug(ctx, descr, kvs...) -func Debug(ctx context.Context, descr string, kvs ...KVer) { - From(ctx).Debug(ctx, descr, kvs...) +// mlog.From(ctxs...).Debug(desc, ctxs...) +func Debug(descr string, ctxs ...context.Context) { + From(ctxs...).Debug(descr, ctxs...) } // Info is a shortcut for -// mlog.From(ctx).Info(ctx, descr, kvs...) -func Info(ctx context.Context, descr string, kvs ...KVer) { - From(ctx).Info(ctx, descr, kvs...) +// mlog.From(ctxs...).Info(desc, ctxs...) +func Info(descr string, ctxs ...context.Context) { + From(ctxs...).Info(descr, ctxs...) } // Warn is a shortcut for -// mlog.From(ctx).Warn(ctx, descr, kvs...) -func Warn(ctx context.Context, descr string, kvs ...KVer) { - From(ctx).Warn(ctx, descr, kvs...) +// mlog.From(ctxs...).Warn(desc, ctxs...) +func Warn(descr string, ctxs ...context.Context) { + From(ctxs...).Warn(descr, ctxs...) } // Error is a shortcut for -// mlog.From(ctx).Error(ctx, descr, kvs...) -func Error(ctx context.Context, descr string, kvs ...KVer) { - From(ctx).Error(ctx, descr, kvs...) +// mlog.From(ctxs...).Error(desc, ctxs...) +func Error(descr string, ctxs ...context.Context) { + From(ctxs...).Error(descr, ctxs...) } // Fatal is a shortcut for -// mlog.From(ctx).Fatal(ctx, descr, kvs...) -func Fatal(ctx context.Context, descr string, kvs ...KVer) { - From(ctx).Fatal(ctx, descr, kvs...) +// mlog.From(ctxs...).Fatal(desc, ctxs...) +func Fatal(descr string, ctxs ...context.Context) { + From(ctxs...).Fatal(descr, ctxs...) } diff --git a/mlog/ctx_test.go b/mlog/ctx_test.go deleted file mode 100644 index 24fd446..0000000 --- a/mlog/ctx_test.go +++ /dev/null @@ -1,67 +0,0 @@ -package mlog - -import ( - "bytes" - "context" - "strings" - . "testing" - - "github.com/mediocregopher/mediocre-go-lib/mctx" - "github.com/mediocregopher/mediocre-go-lib/mtest/massert" -) - -func TestContextLogging(t *T) { - - var lines []string - l := NewLogger() - l.SetHandler(func(msg Message) error { - buf := new(bytes.Buffer) - if err := DefaultFormat(buf, msg); err != nil { - t.Fatal(err) - } - lines = append(lines, strings.TrimSuffix(buf.String(), "\n")) - return nil - }) - - ctx := Set(context.Background(), l) - ctx1 := mctx.NewChild(ctx, "1") - ctx1a := mctx.NewChild(ctx1, "a") - ctx1b := mctx.NewChild(ctx1, "b") - ctx1 = mctx.WithChild(ctx1, ctx1a) - ctx1 = mctx.WithChild(ctx1, ctx1b) - ctx = mctx.WithChild(ctx, ctx1) - - From(ctx).Info(ctx1a, "ctx1a") - From(ctx).Info(ctx1, "ctx1") - From(ctx).Info(ctx, "ctx") - From(ctx).Debug(ctx1b, "ctx1b (shouldn't show up)") - From(ctx).Info(ctx1b, "ctx1b") - - ctx2 := mctx.NewChild(ctx, "2") - ctx = mctx.WithChild(ctx, ctx2) - From(ctx2).Info(ctx2, "ctx2") - - massert.Fatal(t, massert.All( - massert.Len(lines, 5), - massert.Equal(lines[0], "~ INFO -- (/1/a) ctx1a"), - massert.Equal(lines[1], "~ INFO -- (/1) ctx1"), - massert.Equal(lines[2], "~ INFO -- ctx"), - massert.Equal(lines[3], "~ INFO -- (/1/b) ctx1b"), - massert.Equal(lines[4], "~ INFO -- (/2) ctx2"), - )) - - // changing MaxLevel on ctx's Logger should change it for all - From(ctx).SetMaxLevel(DebugLevel) - - lines = lines[:0] - From(ctx).Info(ctx, "ctx") - From(ctx).Debug(ctx, "ctx debug") - From(ctx2).Debug(ctx2, "ctx2 debug") - - massert.Fatal(t, massert.All( - massert.Len(lines, 3), - massert.Equal(lines[0], "~ INFO -- ctx"), - massert.Equal(lines[1], "~ DEBUG -- ctx debug"), - massert.Equal(lines[2], "~ DEBUG -- (/2) ctx2 debug"), - )) -} diff --git a/mlog/errctx.go b/mlog/errctx.go deleted file mode 100644 index db256b4..0000000 --- a/mlog/errctx.go +++ /dev/null @@ -1,30 +0,0 @@ -package mlog - -import ( - "context" -) - -type kvKey int - -// CtxWithKV embeds a KV into a Context, returning a new Context instance. If -// the Context already has a KV embedded in it then the returned error will have -// the merging of the two, with the given KVs taking precedence. -func CtxWithKV(ctx context.Context, kvs ...KVer) context.Context { - existingKV := ctx.Value(kvKey(0)) - var kv KV - if existingKV != nil { - kv = mergeInto(existingKV.(KV), kvs...) - } else { - kv = Merge(kvs...).KV() - } - return context.WithValue(ctx, kvKey(0), kv) -} - -// CtxKV returns a copy of the KV embedded in the Context by CtxWithKV -func CtxKV(ctx context.Context) KVer { - kv := ctx.Value(kvKey(0)) - if kv == nil { - return KV{} - } - return kv.(KV) -} diff --git a/mlog/errctx_test.go b/mlog/errctx_test.go deleted file mode 100644 index 670a7c6..0000000 --- a/mlog/errctx_test.go +++ /dev/null @@ -1,44 +0,0 @@ -package mlog - -import ( - "context" - . "testing" - - "github.com/mediocregopher/mediocre-go-lib/mtest/massert" -) - -func TestCtxKV(t *T) { - ctx := context.Background() - massert.Fatal(t, massert.Equal(KV{}, CtxKV(ctx))) - - kv := KV{"a": "a"} - ctx2 := CtxWithKV(ctx, kv) - massert.Fatal(t, massert.All( - massert.Equal(KV{}, CtxKV(ctx)), - massert.Equal(KV{"a": "a"}, CtxKV(ctx2)), - )) - - // changing the kv now shouldn't do anything - kv["a"] = "b" - massert.Fatal(t, massert.All( - massert.Equal(KV{}, CtxKV(ctx)), - massert.Equal(KV{"a": "a"}, CtxKV(ctx2)), - )) - - // a new CtxWithKV shouldn't affect the previous one - ctx3 := CtxWithKV(ctx2, KV{"b": "b"}) - massert.Fatal(t, massert.All( - massert.Equal(KV{}, CtxKV(ctx)), - massert.Equal(KV{"a": "a"}, CtxKV(ctx2)), - massert.Equal(KV{"a": "a", "b": "b"}, CtxKV(ctx3)), - )) - - // make sure precedence works - ctx4 := CtxWithKV(ctx3, KV{"b": "bb"}) - massert.Fatal(t, massert.All( - massert.Equal(KV{}, CtxKV(ctx)), - massert.Equal(KV{"a": "a"}, CtxKV(ctx2)), - massert.Equal(KV{"a": "a", "b": "b"}, CtxKV(ctx3)), - massert.Equal(KV{"a": "a", "b": "bb"}, CtxKV(ctx4)), - )) -} diff --git a/mlog/mlog.go b/mlog/mlog.go index cac1f01..f5141e2 100644 --- a/mlog/mlog.go +++ b/mlog/mlog.go @@ -1,28 +1,17 @@ // 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: -// -// log := mlog.NewLogger() -// log.Info("Something important has occurred") -// log.Error("Could not open file", mlog.KV{"filename": filename}, merr.KV(err)) +// The log methods take in a message string and a Context. The Context can be +// loaded with additional annotations which will be included in the log entry as +// well (see mctx package). // package mlog import ( - "bufio" "context" - "fmt" + "encoding/json" "io" "os" - "sort" - "strconv" "strings" "sync" @@ -99,134 +88,12 @@ func LevelFromString(s string) Level { //////////////////////////////////////////////////////////////////////////////// -// 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. -// -// The returned map is read-only, and may be nil. -type KVer interface { - KV() map[string]interface{} -} - -// KVerFunc is a function which implements the KVer interface by calling itself. -type KVerFunc func() map[string]interface{} - -// KV implements the KVer interface by calling the KVerFunc itself. -func (kvf KVerFunc) KV() map[string]interface{} { - return kvf() -} - -// KV is a KVer which returns a copy of itself when KV is called. -type KV map[string]interface{} - -// KV implements the KVer method by returning a copy of itself. -func (kv KV) KV() map[string]interface{} { - return map[string]interface{}(kv) -} - -// 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 { - kvm := make(map[string]interface{}, len(kv)+1) - copyM(kvm, kv.KV()) - kvm[k] = v - return KV(kvm) -} - -// returns a key/value map which should not be written to. saves a map-cloning -// if KVer is a KV -func readOnlyKVM(kver KVer) map[string]interface{} { - if kver == nil { - return map[string]interface{}(nil) - } else if kv, ok := kver.(KV); ok { - return map[string]interface{}(kv) - } - return kver.KV() -} - -func copyM(dst, src map[string]interface{}) { - for k, v := range src { - dst[k] = v - } -} - -// this may take in any amount of nil values, but should never return nil -func mergeInto(kv KVer, kvs ...KVer) map[string]interface{} { - kvm := map[string]interface{}{} - if kv != nil { - copyM(kvm, kv.KV()) - } - for _, innerKV := range kvs { - if innerKV == nil { - continue - } - copyM(kvm, innerKV.KV()) - } - return kvm -} - -type merger struct { - base KVer - rest []KVer -} - -// 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. -// -// The KVer returned will call KV() on each of the passed in KVers every time -// its KV method is called. -func Merge(kvs ...KVer) KVer { - if len(kvs) == 0 { - return merger{} - } - return merger{base: kvs[0], rest: kvs[1:]} -} - -// MergeInto is a convenience function which acts similarly to Merge. -func MergeInto(kv KVer, kvs ...KVer) KVer { - return merger{base: kv, rest: kvs} -} - -func (m merger) KV() map[string]interface{} { - return mergeInto(m.base, m.rest...) -} - -// Prefix prefixes all keys returned from the given KVer with the given prefix -// string. -func Prefix(kv KVer, prefix string) KVer { - return KVerFunc(func() map[string]interface{} { - kvm := readOnlyKVM(kv) - newKVM := make(map[string]interface{}, len(kvm)) - for k, v := range kvm { - newKVM[prefix+k] = v - } - return newKVM - }) -} - -//////////////////////////////////////////////////////////////////////////////// - // Message describes a message to be logged, after having already resolved the // KVer type Message struct { - context.Context Level Description string - KVer -} - -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 + Contexts []context.Context } // Handler is a function which can process Messages in some way. @@ -235,47 +102,39 @@ func stringSlice(kv KV) [][2]string { // Handler if necessary. type Handler func(msg Message) error -// DefaultFormat formats and writes the Message to the given Writer using mlog's -// default format. -func DefaultFormat(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 -- ", msg.Level.String()) - if path := mctx.Path(msg.Context); len(path) > 0 { - write("(%s) ", "/"+strings.Join(path, "/")) - } - write("%s", msg.Description) - if msg.KVer != nil { - if kv := msg.KV(); len(kv) > 0 { - write(" --") - for _, kve := range stringSlice(kv) { - write(" %s=%s", kve[0], kve[1]) - } - } - } - write("\n") - return err +// MessageJSON is the type used to encode Messages to JSON in DefaultHandler +type MessageJSON struct { + Level string `json:"level"` + Description string `json:"descr"` + + // path -> key -> value + Annotations map[string]map[string]string `json:"annotations,omitempty"` } // DefaultHandler initializes and returns a Handler which will write all // messages to os.Stderr in a thread-safe way. This is the Handler which // NewLogger will use automatically. func DefaultHandler() Handler { + return defaultHandler(os.Stderr) +} + +func defaultHandler(out io.Writer) Handler { l := new(sync.Mutex) - bw := bufio.NewWriter(os.Stderr) + enc := json.NewEncoder(out) return func(msg Message) error { l.Lock() defer l.Unlock() - err := DefaultFormat(bw, msg) - if err == nil { - err = bw.Flush() + msgJSON := MessageJSON{ + Level: msg.Level.String(), + Description: msg.Description, } - return err + if len(msg.Contexts) > 0 { + ctx := mctx.MergeAnnotations(msg.Contexts...) + msgJSON.Annotations = mctx.Annotations(ctx).StringMapByPath() + } + + return enc.Encode(msgJSON) } } @@ -286,7 +145,6 @@ type Logger struct { l *sync.RWMutex h Handler maxLevel uint - kv KVer testMsgWrittenCh chan struct{} // only initialized/used in tests } @@ -332,15 +190,6 @@ func (l *Logger) Handler() Handler { 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...) -} - // Log can be used to manually log a message of some custom defined Level. // // If the Level is a fatal (Uint() == 0) then calling this will never return, @@ -353,12 +202,8 @@ func (l *Logger) Log(msg Message) { return } - if l.kv != nil { - msg.KVer = MergeInto(l.kv, msg.KVer) - } - if err := l.h(msg); err != nil { - go l.Error(context.Background(), "Logger.Handler returned error", merr.KV(err)) + go l.Error("Logger.Handler returned error", merr.Context(err)) return } @@ -371,37 +216,36 @@ func (l *Logger) Log(msg Message) { } } -func mkMsg(ctx context.Context, lvl Level, descr string, kvs ...KVer) Message { +func mkMsg(lvl Level, descr string, ctxs ...context.Context) Message { return Message{ - Context: ctx, Level: lvl, Description: descr, - KVer: Merge(kvs...), + Contexts: ctxs, } } -// Debug logs a DebugLevel message, merging the KVers together first -func (l *Logger) Debug(ctx context.Context, descr string, kvs ...KVer) { - l.Log(mkMsg(ctx, DebugLevel, descr, kvs...)) +// Debug logs a DebugLevel message. +func (l *Logger) Debug(descr string, ctxs ...context.Context) { + l.Log(mkMsg(DebugLevel, descr, ctxs...)) } -// Info logs a InfoLevel message, merging the KVers together first -func (l *Logger) Info(ctx context.Context, descr string, kvs ...KVer) { - l.Log(mkMsg(ctx, InfoLevel, descr, kvs...)) +// Info logs a InfoLevel message. +func (l *Logger) Info(descr string, ctxs ...context.Context) { + l.Log(mkMsg(InfoLevel, descr, ctxs...)) } -// Warn logs a WarnLevel message, merging the KVers together first -func (l *Logger) Warn(ctx context.Context, descr string, kvs ...KVer) { - l.Log(mkMsg(ctx, WarnLevel, descr, kvs...)) +// Warn logs a WarnLevel message. +func (l *Logger) Warn(descr string, ctxs ...context.Context) { + l.Log(mkMsg(WarnLevel, descr, ctxs...)) } -// Error logs a ErrorLevel message, merging the KVers together first -func (l *Logger) Error(ctx context.Context, descr string, kvs ...KVer) { - l.Log(mkMsg(ctx, ErrorLevel, descr, kvs...)) +// Error logs a ErrorLevel message. +func (l *Logger) Error(descr string, ctxs ...context.Context) { + l.Log(mkMsg(ErrorLevel, descr, ctxs...)) } -// 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(ctx context.Context, descr string, kvs ...KVer) { - l.Log(mkMsg(ctx, FatalLevel, descr, kvs...)) +// Fatal logs a FatalLevel message. A Fatal message automatically stops the +// process with an os.Exit(1) +func (l *Logger) Fatal(descr string, ctxs ...context.Context) { + l.Log(mkMsg(FatalLevel, descr, ctxs...)) } diff --git a/mlog/mlog_test.go b/mlog/mlog_test.go index 4065de4..427bc6d 100644 --- a/mlog/mlog_test.go +++ b/mlog/mlog_test.go @@ -3,11 +3,11 @@ package mlog import ( "bytes" "context" - "regexp" "strings" . "testing" "time" + "github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/mtest/massert" ) @@ -19,29 +19,9 @@ func TestTruncate(t *T) { )) } -func TestKV(t *T) { - var kv KV - massert.Fatal(t, massert.All( - massert.Nil(kv.KV()), - massert.Len(kv.KV(), 0), - )) - - // test that the Set method returns a copy - kv = KV{"foo": "a"} - kv2 := kv.Set("bar", "wat") - kv["bur"] = "ok" - massert.Fatal(t, massert.All( - massert.Equal(KV{"foo": "a", "bur": "ok"}, kv), - massert.Equal(KV{"foo": "a", "bar": "wat"}, kv2), - )) -} - func TestLogger(t *T) { - ctx := context.Background() buf := new(bytes.Buffer) - h := func(msg Message) error { - return DefaultFormat(buf, msg) - } + h := defaultHandler(buf) l := NewLogger() l.SetHandler(h) @@ -56,29 +36,31 @@ func TestLogger(t *T) { out, err := buf.ReadString('\n') return massert.All( massert.Nil(err), - massert.Equal(expected, out), + massert.Equal(expected, strings.TrimSpace(out)), ) } // Default max level should be INFO - l.Debug(ctx, "foo") - l.Info(ctx, "bar") - l.Warn(ctx, "baz") - l.Error(ctx, "buz") + l.Debug("foo") + l.Info("bar") + l.Warn("baz") + l.Error("buz") massert.Fatal(t, massert.All( - assertOut("~ INFO -- bar\n"), - assertOut("~ WARN -- baz\n"), - assertOut("~ ERROR -- buz\n"), + assertOut(`{"level":"INFO","descr":"bar"}`), + assertOut(`{"level":"WARN","descr":"baz"}`), + assertOut(`{"level":"ERROR","descr":"buz"}`), )) + ctx := context.Background() + l.SetMaxLevel(WarnLevel) - l.Debug(ctx, "foo") - l.Info(ctx, "bar") - l.Warn(ctx, "baz") - l.Error(ctx, "buz", KV{"a": "b"}) + l.Debug("foo") + l.Info("bar") + l.Warn("baz") + l.Error("buz", mctx.Annotate(ctx, "a", "b", "c", "d")) massert.Fatal(t, massert.All( - assertOut("~ WARN -- baz\n"), - assertOut("~ ERROR -- buz -- a=\"b\"\n"), + assertOut(`{"level":"WARN","descr":"baz"}`), + assertOut(`{"level":"ERROR","descr":"buz","annotations":{"/":{"a":"b","c":"d"}}}`), )) l2 := l.Clone() @@ -87,109 +69,12 @@ func TestLogger(t *T) { msg.Description = strings.ToUpper(msg.Description) return h(msg) }) - l2.Info(ctx, "bar") - l2.Warn(ctx, "baz") - l.Error(ctx, "buz") + l2.Info("bar") + l2.Warn("baz") + l.Error("buz") massert.Fatal(t, massert.All( - assertOut("~ INFO -- BAR\n"), - assertOut("~ WARN -- BAZ\n"), - assertOut("~ ERROR -- buz\n"), - )) - - l3 := l2.Clone() - l3.SetKV(KV{"a": 1}) - l3.Info(ctx, "foo", KV{"b": 2}) - l3.Info(ctx, "bar", KV{"a": 2, "b": 3}) - massert.Fatal(t, massert.All( - assertOut("~ INFO -- FOO -- a=\"1\" b=\"2\"\n"), - assertOut("~ INFO -- BAR -- a=\"2\" b=\"3\"\n"), - )) - -} - -func TestDefaultFormat(t *T) { - assertFormat := func(postfix string, msg Message) massert.Assertion { - expectedRegex := regexp.MustCompile(`^~ ` + postfix + `\n$`) - buf := bytes.NewBuffer(make([]byte, 0, 128)) - writeErr := DefaultFormat(buf, msg) - line, err := buf.ReadString('\n') - return massert.Comment( - massert.All( - massert.Nil(writeErr), - massert.Nil(err), - massert.Equal(true, expectedRegex.MatchString(line)), - ), - "line:%q", line, - ) - } - - msg := Message{ - Context: context.Background(), - Level: InfoLevel, - Description: "this is a test", - } - massert.Fatal(t, assertFormat("INFO -- this is a test", msg)) - - msg.KVer = KV{} - massert.Fatal(t, assertFormat("INFO -- this is a test", msg)) - - msg.KVer = KV{"foo": "a"} - massert.Fatal(t, assertFormat("INFO -- this is a test -- foo=\"a\"", msg)) - - msg.KVer = KV{"foo": "a", "bar": "b"} - massert.Fatal(t, - assertFormat("INFO -- this is a test -- bar=\"b\" foo=\"a\"", msg)) -} - -func TestMerge(t *T) { - assertMerge := func(exp KV, kvs ...KVer) massert.Assertion { - return massert.Equal(exp.KV(), Merge(kvs...).KV()) - } - - massert.Fatal(t, massert.All( - assertMerge(KV{}), - assertMerge(KV{}, nil), - assertMerge(KV{}, nil, nil), - - assertMerge(KV{"a": "a"}, KV{"a": "a"}), - assertMerge(KV{"a": "a"}, nil, KV{"a": "a"}), - assertMerge(KV{"a": "a"}, KV{"a": "a"}, nil), - - assertMerge( - KV{"a": "a", "b": "b"}, - KV{"a": "a"}, KV{"b": "b"}, - ), - assertMerge( - KV{"a": "a", "b": "b"}, - KV{"a": "a"}, KV{"b": "b"}, - ), - assertMerge( - KV{"a": "b"}, - KV{"a": "a"}, KV{"a": "b"}, - ), - )) - - // Merge should _not_ call KV() on the inner KVers until the outer one is - // called. - { - kv := KV{"a": "a"} - mergedKV := Merge(kv) - kv["a"] = "b" - massert.Fatal(t, massert.All( - massert.Equal(KV{"a": "b"}, kv), - massert.Equal(map[string]interface{}{"a": "b"}, kv.KV()), - massert.Equal(map[string]interface{}{"a": "b"}, mergedKV.KV()), - )) - } -} - -func TestPrefix(t *T) { - kv := KV{"foo": "bar"} - prefixKV := Prefix(kv, "aa") - - massert.Fatal(t, massert.All( - massert.Equal(map[string]interface{}{"foo": "bar"}, kv.KV()), - massert.Equal(map[string]interface{}{"aafoo": "bar"}, prefixKV.KV()), - massert.Equal(map[string]interface{}{"foo": "bar"}, kv.KV()), + assertOut(`{"level":"INFO","descr":"BAR"}`), + assertOut(`{"level":"WARN","descr":"BAZ"}`), + assertOut(`{"level":"ERROR","descr":"buz"}`), )) } diff --git a/mnet/mnet.go b/mnet/mnet.go index bb0aa05..fec7fdc 100644 --- a/mnet/mnet.go +++ b/mnet/mnet.go @@ -8,13 +8,13 @@ import ( "strings" "github.com/mediocregopher/mediocre-go-lib/mcfg" - "github.com/mediocregopher/mediocre-go-lib/merr" + "github.com/mediocregopher/mediocre-go-lib/mctx" "github.com/mediocregopher/mediocre-go-lib/mlog" "github.com/mediocregopher/mediocre-go-lib/mrun" ) -// MListener is returned by MListen and simply wraps a net.Listener. -type MListener struct { +// Listener is returned by WithListen and simply wraps a net.Listener. +type Listener struct { net.Listener ctx context.Context @@ -23,13 +23,13 @@ type MListener struct { NoCloseOnStop bool } -// MListen returns an MListener which will be initialized when the start event -// is triggered on the returned Context (see mrun.Start), and closed when the -// stop event is triggered on the returned Context (see mrun.Stop). +// WithListener returns a Listener which will be initialized when the start +// event is triggered on the returned Context (see mrun.Start), and closed when +// the stop event is triggered on the returned Context (see mrun.Stop). // // network defaults to "tcp" if empty. defaultAddr defaults to ":0" if empty, // and will be configurable via mcfg. -func MListen(ctx context.Context, network, defaultAddr string) (context.Context, *MListener) { +func WithListener(ctx context.Context, network, defaultAddr string) (context.Context, *Listener) { if network == "" { network = "tcp" } @@ -37,59 +37,52 @@ func MListen(ctx context.Context, network, defaultAddr string) (context.Context, defaultAddr = ":0" } - l := new(MListener) + l := &Listener{ + ctx: mctx.NewChild(ctx, "net"), + } - // TODO the equivalent functionality as here will be added with annotations - //l.log = mlog.From(ctx) - //l.log.SetKV(l) - - ctx, addr := mcfg.String(ctx, "listen-addr", defaultAddr, strings.ToUpper(network)+" address to listen on in format [host]:port. If port is 0 then a random one will be chosen") - ctx = mrun.OnStart(ctx, func(context.Context) error { + var addr *string + l.ctx, addr = mcfg.WithString(l.ctx, "listen-addr", defaultAddr, strings.ToUpper(network)+" address to listen on in format [host]:port. If port is 0 then a random one will be chosen") + l.ctx = mrun.WithStartHook(l.ctx, func(context.Context) error { var err error if l.Listener, err = net.Listen(network, *addr); err != nil { return err } - mlog.Info(l.ctx, "listening") + l.ctx = mctx.Annotate(l.ctx, "addr", l.Addr().String()) + mlog.Info("listening", l.ctx) return nil }) // TODO track connections and wait for them to complete before shutting // down? - ctx = mrun.OnStop(ctx, func(context.Context) error { + l.ctx = mrun.WithStopHook(l.ctx, func(context.Context) error { if l.NoCloseOnStop { return nil } - mlog.Info(l.ctx, "stopping listener") + mlog.Info("stopping listener", l.ctx) return l.Close() }) - l.ctx = ctx - return ctx, l + return mctx.WithChild(ctx, l.ctx), l } // Accept wraps a call to Accept on the underlying net.Listener, providing debug // logging. -func (l *MListener) Accept() (net.Conn, error) { +func (l *Listener) Accept() (net.Conn, error) { conn, err := l.Listener.Accept() if err != nil { return conn, err } - mlog.Debug(l.ctx, "connection accepted", mlog.KV{"remoteAddr": conn.RemoteAddr()}) + mlog.Debug("connection accepted", + mctx.Annotate(l.ctx, "remoteAddr", conn.RemoteAddr().String())) return conn, nil } // Close wraps a call to Close on the underlying net.Listener, providing debug // logging. -func (l *MListener) Close() error { - mlog.Debug(l.ctx, "listener closing") - err := l.Listener.Close() - mlog.Debug(l.ctx, "listener closed", merr.KV(err)) - return err -} - -// KV implements the mlog.KVer interface. -func (l *MListener) KV() map[string]interface{} { - return map[string]interface{}{"addr": l.Addr().String()} +func (l *Listener) Close() error { + mlog.Info("listener closing", l.ctx) + return l.Listener.Close() } //////////////////////////////////////////////////////////////////////////////// diff --git a/mnet/mnet_test.go b/mnet/mnet_test.go index b9b9b7e..e2942fb 100644 --- a/mnet/mnet_test.go +++ b/mnet/mnet_test.go @@ -35,9 +35,9 @@ func TestIsReservedIP(t *T) { )) } -func TestMListen(t *T) { - ctx := mtest.NewCtx() - ctx, l := MListen(ctx, "", "") +func TestWithListener(t *T) { + ctx := mtest.Context() + ctx, l := WithListener(ctx, "", "") mtest.Run(ctx, t, func() { go func() { conn, err := net.Dial("tcp", l.Addr().String()) diff --git a/mrun/hook.go b/mrun/hook.go index 2087c4c..2e38374 100644 --- a/mrun/hook.go +++ b/mrun/hook.go @@ -7,7 +7,7 @@ import ( ) // Hook describes a function which can be registered to trigger on an event via -// the RegisterHook function. +// the WithHook function. type Hook func(context.Context) error type ctxKey int @@ -65,12 +65,12 @@ func getHookEls(ctx context.Context, userKey interface{}) ([]hookEl, int, int) { return hookEls, len(children), lastNumHooks } -// RegisterHook registers a Hook under a typed key. The Hook will be called when +// WithHook registers a Hook under a typed key. The Hook will be called when // TriggerHooks is called with that same key. Multiple Hooks can be registered // for the same key, and will be called sequentially when triggered. // // Hooks will be called with whatever Context is passed into TriggerHooks. -func RegisterHook(ctx context.Context, key interface{}, hook Hook) context.Context { +func WithHook(ctx context.Context, key interface{}, hook Hook) context.Context { hookEls, numChildren, numHooks := getHookEls(ctx, key) hookEls = append(hookEls, hookEl{hook: hook}) @@ -100,9 +100,9 @@ func triggerHooks(ctx context.Context, userKey interface{}, next func([]hookEl) return nil } -// TriggerHooks causes all Hooks registered with RegisterHook on the Context -// (and its predecessors) under the given key to be called in the order they -// were registered. +// TriggerHooks causes all Hooks registered with WithHook on the Context (and +// its predecessors) under the given key to be called in the order they were +// registered. // // If any Hook returns an error no further Hooks will be called and that error // will be returned. @@ -113,15 +113,15 @@ func triggerHooks(ctx context.Context, userKey interface{}, next func([]hookEl) // // // parent context has hookA registered // ctx := context.Background() -// ctx = RegisterHook(ctx, 0, hookA) +// ctx = WithHook(ctx, 0, hookA) // // // child context has hookB registered // childCtx := mctx.NewChild(ctx, "child") -// childCtx = RegisterHook(childCtx, 0, hookB) +// childCtx = WithHook(childCtx, 0, hookB) // ctx = mctx.WithChild(ctx, childCtx) // needed to link childCtx to ctx // // // parent context has another Hook, hookC, registered -// ctx = RegisterHook(ctx, 0, hookC) +// ctx = WithHook(ctx, 0, hookC) // // // The Hooks will be triggered in the order: hookA, hookB, then hookC // err := TriggerHooks(ctx, 0) @@ -148,33 +148,33 @@ const ( stop ) -// OnStart registers the given Hook to run when Start is called. This is a -// special case of RegisterHook. +// WithStartHook registers the given Hook to run when Start is called. This is a +// special case of WithHook. // // As a convention Hooks running on the start event should block only as long as // it takes to ensure that whatever is running can do so successfully. For // short-lived tasks this isn't a problem, but long-lived tasks (e.g. a web // server) will want to use the Hook only to initialize, and spawn off a // go-routine to do their actual work. Long-lived tasks should set themselves up -// to stop on the stop event (see OnStop). -func OnStart(ctx context.Context, hook Hook) context.Context { - return RegisterHook(ctx, start, hook) +// to stop on the stop event (see WithStopHook). +func WithStartHook(ctx context.Context, hook Hook) context.Context { + return WithHook(ctx, start, hook) } -// Start runs all Hooks registered using OnStart. This is a special case of -// TriggerHooks. +// Start runs all Hooks registered using WithStartHook. This is a special case +// of TriggerHooks. func Start(ctx context.Context) error { return TriggerHooks(ctx, start) } -// OnStop registers the given Hook to run when Stop is called. This is a special -// case of RegisterHook. -func OnStop(ctx context.Context, hook Hook) context.Context { - return RegisterHook(ctx, stop, hook) +// WithStopHook registers the given Hook to run when Stop is called. This is a +// special case of WithHook. +func WithStopHook(ctx context.Context, hook Hook) context.Context { + return WithHook(ctx, stop, hook) } -// Stop runs all Hooks registered using OnStop in the reverse order in which -// they were registered. This is a special case of TriggerHooks. +// Stop runs all Hooks registered using WithStopHook in the reverse order in +// which they were registered. This is a special case of TriggerHooks. func Stop(ctx context.Context) error { return TriggerHooksReverse(ctx, stop) } diff --git a/mrun/hook_test.go b/mrun/hook_test.go index c679b7f..ef6d9f3 100644 --- a/mrun/hook_test.go +++ b/mrun/hook_test.go @@ -18,20 +18,20 @@ func TestHooks(t *T) { } ctx := context.Background() - ctx = RegisterHook(ctx, 0, mkHook(1)) - ctx = RegisterHook(ctx, 0, mkHook(2)) + ctx = WithHook(ctx, 0, mkHook(1)) + ctx = WithHook(ctx, 0, mkHook(2)) ctxA := mctx.NewChild(ctx, "a") - ctxA = RegisterHook(ctxA, 0, mkHook(3)) - ctxA = RegisterHook(ctxA, 999, mkHook(999)) // different key + ctxA = WithHook(ctxA, 0, mkHook(3)) + ctxA = WithHook(ctxA, 999, mkHook(999)) // different key ctx = mctx.WithChild(ctx, ctxA) - ctx = RegisterHook(ctx, 0, mkHook(4)) + ctx = WithHook(ctx, 0, mkHook(4)) ctxB := mctx.NewChild(ctx, "b") - ctxB = RegisterHook(ctxB, 0, mkHook(5)) + ctxB = WithHook(ctxB, 0, mkHook(5)) ctxB1 := mctx.NewChild(ctxB, "1") - ctxB1 = RegisterHook(ctxB1, 0, mkHook(6)) + ctxB1 = WithHook(ctxB1, 0, mkHook(6)) ctxB = mctx.WithChild(ctxB, ctxB1) ctx = mctx.WithChild(ctx, ctxB) diff --git a/mrun/mrun.go b/mrun/mrun.go index feb0ec1..d5c44c4 100644 --- a/mrun/mrun.go +++ b/mrun/mrun.go @@ -36,10 +36,10 @@ func (fe *futureErr) set(err error) { type threadCtxKey int -// Thread spawns a go-routine which executes the given function. The returned -// Context tracks this go-routine, which can then be passed into the Wait -// function to block until the spawned go-routine returns. -func Thread(ctx context.Context, fn func() error) context.Context { +// WithThread spawns a go-routine which executes the given function. The +// returned Context tracks this go-routine, which can then be passed into the +// Wait function to block until the spawned go-routine returns. +func WithThread(ctx context.Context, fn func() error) context.Context { futErr := newFutureErr() oldFutErrs, _ := ctx.Value(threadCtxKey(0)).([]*futureErr) futErrs := make([]*futureErr, len(oldFutErrs), len(oldFutErrs)+1) diff --git a/mrun/mrun_test.go b/mrun/mrun_test.go index 2d4102d..164dc62 100644 --- a/mrun/mrun_test.go +++ b/mrun/mrun_test.go @@ -30,7 +30,7 @@ func TestThreadWait(t *T) { t.Run("noBlock", func(t *T) { t.Run("noErr", func(t *T) { ctx := context.Background() - ctx = Thread(ctx, func() error { return nil }) + ctx = WithThread(ctx, func() error { return nil }) if err := Wait(ctx, nil); err != nil { t.Fatal(err) } @@ -38,7 +38,7 @@ func TestThreadWait(t *T) { t.Run("err", func(t *T) { ctx := context.Background() - ctx = Thread(ctx, func() error { return testErr }) + ctx = WithThread(ctx, func() error { return testErr }) if err := Wait(ctx, nil); err != testErr { t.Fatalf("should have got test error, got: %v", err) } @@ -48,7 +48,7 @@ func TestThreadWait(t *T) { t.Run("block", func(t *T) { t.Run("noErr", func(t *T) { ctx := context.Background() - ctx = Thread(ctx, func() error { + ctx = WithThread(ctx, func() error { time.Sleep(1 * time.Second) return nil }) @@ -59,7 +59,7 @@ func TestThreadWait(t *T) { t.Run("err", func(t *T) { ctx := context.Background() - ctx = Thread(ctx, func() error { + ctx = WithThread(ctx, func() error { time.Sleep(1 * time.Second) return testErr }) @@ -70,7 +70,7 @@ func TestThreadWait(t *T) { t.Run("canceled", func(t *T) { ctx := context.Background() - ctx = Thread(ctx, func() error { + ctx = WithThread(ctx, func() error { time.Sleep(5 * time.Second) return testErr }) @@ -90,7 +90,7 @@ func TestThreadWait(t *T) { t.Run("noBlock", func(t *T) { t.Run("noErr", func(t *T) { ctx, childCtx := ctxWithChild() - childCtx = Thread(childCtx, func() error { return nil }) + childCtx = WithThread(childCtx, func() error { return nil }) ctx = mctx.WithChild(ctx, childCtx) if err := Wait(ctx, nil); err != nil { t.Fatal(err) @@ -99,7 +99,7 @@ func TestThreadWait(t *T) { t.Run("err", func(t *T) { ctx, childCtx := ctxWithChild() - childCtx = Thread(childCtx, func() error { return testErr }) + childCtx = WithThread(childCtx, func() error { return testErr }) ctx = mctx.WithChild(ctx, childCtx) if err := Wait(ctx, nil); err != testErr { t.Fatalf("should have got test error, got: %v", err) @@ -110,7 +110,7 @@ func TestThreadWait(t *T) { t.Run("block", func(t *T) { t.Run("noErr", func(t *T) { ctx, childCtx := ctxWithChild() - childCtx = Thread(childCtx, func() error { + childCtx = WithThread(childCtx, func() error { time.Sleep(1 * time.Second) return nil }) @@ -122,7 +122,7 @@ func TestThreadWait(t *T) { t.Run("err", func(t *T) { ctx, childCtx := ctxWithChild() - childCtx = Thread(childCtx, func() error { + childCtx = WithThread(childCtx, func() error { time.Sleep(1 * time.Second) return testErr }) @@ -134,7 +134,7 @@ func TestThreadWait(t *T) { t.Run("canceled", func(t *T) { ctx, childCtx := ctxWithChild() - childCtx = Thread(childCtx, func() error { + childCtx = WithThread(childCtx, func() error { time.Sleep(5 * time.Second) return testErr }) diff --git a/mtest/mtest.go b/mtest/mtest.go index 4543b28..5126a54 100644 --- a/mtest/mtest.go +++ b/mtest/mtest.go @@ -12,18 +12,18 @@ import ( type envCtxKey int -// NewCtx creates and returns a root Context suitable for testing. -func NewCtx() context.Context { +// Context creates and returns a root Context suitable for testing. +func Context() context.Context { ctx := context.Background() logger := mlog.NewLogger() logger.SetMaxLevel(mlog.DebugLevel) - return mlog.Set(ctx, logger) + return mlog.WithLogger(ctx, logger) } -// SetEnv sets the given environment variable on the given Context, such that it -// will be used as if it was a real environment variable when the Run function -// from this package is called. -func SetEnv(ctx context.Context, key, val string) context.Context { +// WithEnv sets the given environment variable on the given Context, such that +// it will be used as if it was a real environment variable when the Run +// function from this package is called. +func WithEnv(ctx context.Context, key, val string) context.Context { prevEnv, _ := ctx.Value(envCtxKey(0)).([][2]string) env := make([][2]string, len(prevEnv), len(prevEnv)+1) copy(env, prevEnv) @@ -33,7 +33,7 @@ func SetEnv(ctx context.Context, key, val string) context.Context { // Run performs the following using the given Context: // -// - Calls mcfg.Populate using any variables set by SetEnv. +// - Calls mcfg.Populate using any variables set by WithEnv. // // - Calls mrun.Start // @@ -42,7 +42,7 @@ func SetEnv(ctx context.Context, key, val string) context.Context { // - Calls mrun.Stop // // The intention is that Run is used within a test on a Context created via -// NewCtx, after any setup functions have been called (e.g. mnet.MListen). +// NewCtx, after any setup functions have been called (e.g. mnet.WithListener). func Run(ctx context.Context, t *testing.T, body func()) { envTups, _ := ctx.Value(envCtxKey(0)).([][2]string) env := make([]string, 0, len(envTups)) diff --git a/mtest/mtest_test.go b/mtest/mtest_test.go index 473ecdc..bc0211c 100644 --- a/mtest/mtest_test.go +++ b/mtest/mtest_test.go @@ -7,9 +7,9 @@ import ( ) func TestRun(t *T) { - ctx := NewCtx() - ctx, arg := mcfg.RequiredString(ctx, "arg", "Required by this test") - ctx = SetEnv(ctx, "ARG", "foo") + ctx := Context() + ctx, arg := mcfg.WithRequiredString(ctx, "arg", "Required by this test") + ctx = WithEnv(ctx, "ARG", "foo") Run(ctx, t, func() { if *arg != "foo" { t.Fatalf(`arg not set to "foo", is set to %q`, *arg)