From 2c88e342dbfed3492c8c7a782279dcdfb902207f Mon Sep 17 00:00:00 2001 From: Brian Tiger Chow Date: Sat, 15 Nov 2014 16:08:11 -0800 Subject: [PATCH] feat(elog) implement event logger a wrapper around the util.Logger metadata is loggable License: MIT Signed-off-by: Brian Tiger Chow --- cmd/ipfs2/main.go | 4 +- util/elog/context.go | 35 +++++++++++++++ util/elog/context_test.go | 44 +++++++++++++++++++ util/elog/log.go | 75 ++++++++++++++++++++++++++++++++ util/elog/metadata.go | 87 ++++++++++++++++++++++++++++++++++++++ util/elog/metadata_test.go | 48 +++++++++++++++++++++ 6 files changed, 292 insertions(+), 1 deletion(-) create mode 100644 util/elog/context.go create mode 100644 util/elog/context_test.go create mode 100644 util/elog/log.go create mode 100644 util/elog/metadata.go create mode 100644 util/elog/metadata_test.go diff --git a/cmd/ipfs2/main.go b/cmd/ipfs2/main.go index 58ab8020e..ca474c911 100644 --- a/cmd/ipfs2/main.go +++ b/cmd/ipfs2/main.go @@ -9,6 +9,7 @@ import ( "runtime/pprof" "syscall" + // TODO rm direct reference to go-logging logging "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/go-logging" ma "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/go-multiaddr" manet "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/go-multiaddr/net" @@ -22,10 +23,11 @@ import ( updates "github.com/jbenet/go-ipfs/updates" u "github.com/jbenet/go-ipfs/util" "github.com/jbenet/go-ipfs/util/debugerror" + elog "github.com/jbenet/go-ipfs/util/elog" ) // log is the command logger -var log = u.Logger("cmd/ipfs") +var log = elog.Logger("cmd/ipfs") // signal to output help var errHelpRequested = errors.New("Help Requested") diff --git a/util/elog/context.go b/util/elog/context.go new file mode 100644 index 000000000..92e80ce89 --- /dev/null +++ b/util/elog/context.go @@ -0,0 +1,35 @@ +package elog + +import ( + "errors" + + "github.com/jbenet/go-ipfs/Godeps/_workspace/src/code.google.com/p/go.net/context" +) + +type key int + +const metadataKey key = 0 + +func ContextWithMetadata(ctx context.Context, l Loggable) context.Context { + existing, err := MetadataFromContext(ctx) + if err != nil { + // context does not contain meta. just set the new metadata + child := context.WithValue(ctx, metadataKey, l.Loggable()) + return child + } + + merged := DeepMerge(existing, l.Loggable()) + child := context.WithValue(ctx, metadataKey, merged) + return child +} + +func MetadataFromContext(ctx context.Context) (Metadata, error) { + value := ctx.Value(metadataKey) + if value != nil { + metadata, ok := value.(Metadata) + if ok { + return metadata, nil + } + } + return nil, errors.New("context contains no metadata") +} diff --git a/util/elog/context_test.go b/util/elog/context_test.go new file mode 100644 index 000000000..c973a104b --- /dev/null +++ b/util/elog/context_test.go @@ -0,0 +1,44 @@ +package elog + +import ( + "testing" + + "github.com/jbenet/go-ipfs/Godeps/_workspace/src/code.google.com/p/go.net/context" +) + +func TestContextContainsMetadata(t *testing.T) { + t.Parallel() + + m := Metadata{"foo": "bar"} + ctx := ContextWithMetadata(context.Background(), m) + got, err := MetadataFromContext(ctx) + if err != nil { + t.Fatal(err) + } + + _, exists := got["foo"] + if !exists { + t.Fail() + } +} + +func TestContextWithPreexistingMetadata(t *testing.T) { + t.Parallel() + + ctx := ContextWithMetadata(context.Background(), Metadata{"hello": "world"}) + ctx = ContextWithMetadata(ctx, Metadata{"goodbye": "earth"}) + + got, err := MetadataFromContext(ctx) + if err != nil { + t.Fatal(err) + } + + _, exists := got["hello"] + if !exists { + t.Fatal("original key not present") + } + _, exists = got["goodbye"] + if !exists { + t.Fatal("new key not present") + } +} diff --git a/util/elog/log.go b/util/elog/log.go new file mode 100644 index 000000000..dbe1914a0 --- /dev/null +++ b/util/elog/log.go @@ -0,0 +1,75 @@ +package elog + +import ( + "github.com/jbenet/go-ipfs/Godeps/_workspace/src/code.google.com/p/go.net/context" + logging "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/go-logging" + "github.com/jbenet/go-ipfs/util" +) + +var eloggers = map[string]*logging.Logger{} + +func init() { + SetupLogging() +} + +type EventLogger interface { + StandardLogger + Event(ctx context.Context, event string, m ...Metadata) +} + +type StandardLogger interface { + Critical(args ...interface{}) + Criticalf(format string, args ...interface{}) + Debug(args ...interface{}) + Debugf(format string, args ...interface{}) + Error(args ...interface{}) + Errorf(format string, args ...interface{}) + Fatal(args ...interface{}) + Fatalf(format string, args ...interface{}) + Info(args ...interface{}) + Infof(format string, args ...interface{}) + Notice(args ...interface{}) + Noticef(format string, args ...interface{}) + Panic(args ...interface{}) + Panicf(format string, args ...interface{}) + Warning(args ...interface{}) + Warningf(format string, args ...interface{}) +} + +// Logger retrieves a particular event logger +func Logger(system string) EventLogger { + return &eventLogger{util.Logger(system)} +} + +// eventLogger implements the EventLogger and wraps a go-logging Logger +type eventLogger struct { + *logging.Logger +} + +func (el *eventLogger) Event(ctx context.Context, event string, metadata ...Metadata) { + existing, err := MetadataFromContext(ctx) + if err != nil { + existing = Metadata{} + } + accum := existing + for _, datum := range metadata { + accum = DeepMerge(accum, datum) + } + accum["event"] = event + + str, err := accum.JsonString() + if err != nil { + return + } + el.Logger.Info(str) +} + +// SetupLogging will initialize the logger backend and set the flags. +func SetupLogging() { + // fmt := logging.DefaultFormatter + + // f, err := os.Create("events.ipfslog") + // if err != nil { + // panic("failed to open file for event logger") + // } +} diff --git a/util/elog/metadata.go b/util/elog/metadata.go new file mode 100644 index 000000000..22c8b2a2a --- /dev/null +++ b/util/elog/metadata.go @@ -0,0 +1,87 @@ +package elog + +import ( + "encoding/json" + "errors" + "reflect" + + "github.com/jbenet/go-ipfs/Godeps/_workspace/src/code.google.com/p/go-uuid/uuid" +) + +// Metadata is a convenience type for generic maps +type Metadata map[string]interface{} + +// Loggable describes objects that can be marshalled into Metadata for logging +type Loggable interface { + Loggable() Metadata +} + +// UniqueEvent returns a Metadata with the string key and UUID value +func UniqueEvent(key string) Metadata { + return Metadata{ + key: uuid.New(), + } +} + +// DeepMerge merges the second Metadata parameter into the first. +// Nested Metadata are merged recursively. Primitives are over-written. +func DeepMerge(b, a Metadata) Metadata { + out := Metadata{} + for k, v := range b { + out[k] = v + } + for k, v := range a { + + maybe, err := Metadatify(v) + if err != nil { + // if the new value is not meta. just overwrite the dest vaue + out[k] = v + continue + } + + // it is meta. What about dest? + outv, exists := out[k] + if !exists { + // the new value is meta, but there's no dest value. just write it + out[k] = v + continue + } + + outMetadataValue, err := Metadatify(outv) + if err != nil { + // the new value is meta and there's a dest value, but the dest + // value isn't meta. just overwrite + out[k] = v + continue + } + + // both are meta. merge them. + out[k] = DeepMerge(outMetadataValue, maybe) + } + return out +} + +// Loggable implements the Loggable interface +func (m Metadata) Loggable() Metadata { + // NB: method defined on value to avoid de-referencing nil Metadata + return m +} + +func (m Metadata) JsonString() (string, error) { + // NB: method defined on value + b, err := json.Marshal(m) + return string(b), err +} + +// Metadatify converts maps into Metadata +func Metadatify(i interface{}) (Metadata, error) { + value := reflect.ValueOf(i) + if value.Kind() == reflect.Map { + m := map[string]interface{}{} + for _, k := range value.MapKeys() { + m[k.String()] = value.MapIndex(k).Interface() + } + return Metadata(m), nil + } + return nil, errors.New("is not a map") +} diff --git a/util/elog/metadata_test.go b/util/elog/metadata_test.go new file mode 100644 index 000000000..2abfc6d7e --- /dev/null +++ b/util/elog/metadata_test.go @@ -0,0 +1,48 @@ +package elog + +import "testing" + +func TestOverwrite(t *testing.T) { + t.Parallel() + + under := Metadata{ + "a": Metadata{ + "b": Metadata{ + "c": Metadata{ + "d": "the original value", + "other": "SURVIVE", + }, + }, + }, + } + over := Metadata{ + "a": Metadata{ + "b": Metadata{ + "c": Metadata{ + "d": "a new value", + }, + }, + }, + } + + out := DeepMerge(under, over) + + dval := out["a"].(Metadata)["b"].(Metadata)["c"].(Metadata)["d"].(string) + if dval != "a new value" { + t.Fatal(dval) + } + surv := out["a"].(Metadata)["b"].(Metadata)["c"].(Metadata)["other"].(string) + if surv != "SURVIVE" { + t.Fatal(surv) + } +} + +func TestMarshalJSON(t *testing.T) { + bs, _ := Metadata{"a": "b"}.JsonString() + t.Log(bs) +} + +func TestMetadataIsLoggable(t *testing.T) { + func(l Loggable) { + }(Metadata{}) +}