diff --git a/logging/adapters/tendermint_log15/convert.go b/logging/adapters/tendermint_log15/convert.go index 52cda465988566abeda50ac6ab28fad5c8a90838..f7be8420866a67a987afb39f84b2e93cea849018 100644 --- a/logging/adapters/tendermint_log15/convert.go +++ b/logging/adapters/tendermint_log15/convert.go @@ -27,7 +27,7 @@ func LogLineToRecord(keyvals ...interface{}) *log15.Record { Lvl: Log15LvlFromString(level), Msg: message, Call: call, - Ctx: append(ctx, structure.CallerKey, call), + Ctx: ctx, KeyNames: log15.RecordKeyNames{ Time: structure.TimeKey, Msg: structure.MessageKey, diff --git a/logging/convention.go b/logging/convention.go index 7a1058532d5722d75e04f242ff44bda742ffbd44..3c75270ac36e65e35f7cc9af14080e282ac873da 100644 --- a/logging/convention.go +++ b/logging/convention.go @@ -31,13 +31,10 @@ func TraceMsg(logger loggers.InfoTraceLogger, message string, keyvals ...interfa Msg(kitlog.LoggerFunc(logger.Trace), message, keyvals...) } -func WithScope(logger loggers.InfoTraceLogger, scopes... string) loggers.InfoTraceLogger { - return logger.With() -} - // Record a structured log line with a message func Msg(logger kitlog.Logger, message string, keyvals ...interface{}) error { - return logger.Log(slice.CopyPrepend(keyvals, structure.MessageKey, message)) + prepended := slice.CopyPrepend(keyvals, structure.MessageKey, message) + return logger.Log(prepended...) } // Record a structured log line with a message and conventional keys diff --git a/logging/loggers/info_trace_logger.go b/logging/loggers/info_trace_logger.go index db2e744cd617862a5c0f69044e4d0923793fd107..6cbdcee6bd9f0aeb2d7965465835f304226eb42a 100644 --- a/logging/loggers/info_trace_logger.go +++ b/logging/loggers/info_trace_logger.go @@ -33,7 +33,7 @@ type InfoTraceLogger interface { // understand or debug the system. Any handled errors or warnings should be // sent to the Info channel (where you may wish to tag them with a suitable // key-value pair to categorise them as such). - Info(keyvals ...interface{}) + Info(keyvals ...interface{}) error // Send an log message to the Trace channel, formed of a sequence of key-value // pairs. Trace messages can be used for any state change in the system that @@ -41,7 +41,7 @@ type InfoTraceLogger interface { // the system or trying to understand the system in detail. If the messages // are very point-like and contain little structure, consider using a metric // instead. - Trace(keyvals ...interface{}) + Trace(keyvals ...interface{}) error // A logging context (see go-kit log's Context). Takes a sequence key values // via With or WithPrefix and ensures future calls to log will have those @@ -107,13 +107,13 @@ func (l *infoTraceLogger) WithPrefix(keyvals ...interface{}) InfoTraceLogger { } } -func (l *infoTraceLogger) Info(keyvals ...interface{}) { +func (l *infoTraceLogger) Info(keyvals ...interface{}) error { // We send Info and Trace log lines down the same pipe to keep them ordered - l.infoLogger.Log(keyvals...) + return l.infoLogger.Log(keyvals...) } -func (l *infoTraceLogger) Trace(keyvals ...interface{}) { - l.traceLogger.Log(keyvals...) +func (l *infoTraceLogger) Trace(keyvals ...interface{}) error { + return l.traceLogger.Log(keyvals...) } // If logged to as a plain kitlog logger presume the message is for Trace diff --git a/logging/loggers/vector_valued_logger.go b/logging/loggers/vector_valued_logger.go index d7f50d760323eb2c94d59830b238d2dabee67bee..b8963db13f61a9e02fdf5273010d9f4910d51009 100644 --- a/logging/loggers/vector_valued_logger.go +++ b/logging/loggers/vector_valued_logger.go @@ -5,7 +5,7 @@ import ( kitlog "github.com/go-kit/kit/log" ) -// Treat duplicate keys +// Treat duplicate key-values as consecutive entries in a vector-valued lookup type vectorValuedLogger struct { logger kitlog.Logger } @@ -13,15 +13,7 @@ type vectorValuedLogger struct { var _ kitlog.Logger = &vectorValuedLogger{} func (vvl *vectorValuedLogger) Log(keyvals ...interface{}) error { - keys, vals := structure.KeyValuesVector(keyvals) - kvs := make([]interface{}, len(keys)*2) - for i := 0; i < len(keys); i++ { - kv := i * 2 - key := keys[i] - kvs[kv] = key - kvs[kv+1] = vals[key] - } - return vvl.logger.Log(kvs...) + return vvl.logger.Log(structure.Vectorise(keyvals)...) } func VectorValuedLogger(logger kitlog.Logger) *vectorValuedLogger { diff --git a/logging/metadata.go b/logging/metadata.go index 1b1f5c2add4af3f280e5742638c0ba840b311114..d645699902e9a6b9a334390a8824c774aac5a4e6 100644 --- a/logging/metadata.go +++ b/logging/metadata.go @@ -24,9 +24,10 @@ var defaultTimestampUTCValuer kitlog.Valuer = func() interface{} { func WithMetadata(infoTraceLogger loggers.InfoTraceLogger) loggers.InfoTraceLogger { return infoTraceLogger.With(structure.TimeKey, defaultTimestampUTCValuer, - structure.CallerKey, kitlog.Caller(infoTraceLoggerCallDepth)) + structure.CallerKey, kitlog.Caller(infoTraceLoggerCallDepth), + "trace", TraceValuer()) } -func CallersValuer() kitlog.Valuer { - return func() interface{} { return stack.Callers() } +func TraceValuer() kitlog.Valuer { + return func() interface{} { return stack.Trace() } } diff --git a/logging/structure/structure.go b/logging/structure/structure.go index 151fda92cbc3f4434a6537905680565c92fc13cb..976332be645eb9ea02442819d80f9c250f7001b2 100644 --- a/logging/structure/structure.go +++ b/logging/structure/structure.go @@ -13,7 +13,7 @@ const ( CallerKey = "caller" // Level name (string) LevelKey = "level" - // Channel name in a multiple channel logging context + // Channel name in a vector channel logging context ChannelKey = "channel" // Log message (string) MessageKey = "message" @@ -58,40 +58,54 @@ func ValuesAndContext(keyvals []interface{}, return vals, context } -type vector []interface{} - -func newVector(vals... interface{}) vector { - return vals -} - -func (v vector) Slice() []interface{} { - return v +// Stateful index that tracks the location of a possible vector value +type vectorValueindex struct { + // Location of the value belonging to a key in output slice + valueIndex int + // Whether or not the value is currently a vector + vector bool } -// Returns the unique keys in keyvals and a map of values where values of -// repeated keys are merged into a slice of those values in the order which they -// appeared -func KeyValuesVector(keyvals []interface{}) ([]interface{}, map[interface{}]interface{}) { - keys := []interface{}{} - vals := make(map[interface{}]interface{}, len(keyvals)/2) +// 'Vectorises' values associated with repeated string keys member by collapsing many values into a single vector value. +// The result is a copy of keyvals where the first occurrence of each matching key and its first value are replaced by +// that key and all of its values in a single slice. +func Vectorise(keyvals []interface{}, vectorKeys ...string) []interface{} { + outputKeyvals := make([]interface{}, 0, len(keyvals)) + // Track the location and vector status of the values in the output + valueIndices := make(map[string]*vectorValueindex, len(vectorKeys)) + elided := 0 for i := 0; i < 2*(len(keyvals)/2); i += 2 { key := keyvals[i] val := keyvals[i+1] - switch oldVal := vals[key].(type) { - case nil: - keys = append(keys, key) - vals[key] = val - case vector: - // if this is, in fact, only the second time we have seen key and the - // first time it had a value of []interface{} then here we are doing the - // wrong thing by appending val. We will end up with - // Slice(..., val) rather than Slice(Slice(...), val) - vals[key] = vector(append(oldVal, val)) - default: - vals[key] = newVector(oldVal, val) + + // Only attempt to vectorise string keys + if k, ok := key.(string); ok { + if valueIndices[k] == nil { + // Record that this key has been seen once + valueIndices[k] = &vectorValueindex{ + valueIndex: i + 1 - elided, + } + // Copy the key-value to output with the single value + outputKeyvals = append(outputKeyvals, key, val) + } else { + // We have seen this key before + vi := valueIndices[k] + if !vi.vector { + // This must be the only second occurrence of the key so now vectorise the value + outputKeyvals[vi.valueIndex] = []interface{}{outputKeyvals[vi.valueIndex]} + vi.vector = true + } + // Grow the vector value + outputKeyvals[vi.valueIndex] = append(outputKeyvals[vi.valueIndex].([]interface{}), val) + // We are now running two more elements behind the input keyvals because we have absorbed this key-value pair + elided += 2 + } + } else { + // Just copy the key-value to the output for non-string keys + outputKeyvals = append(outputKeyvals, key, val) } } - return keys, vals + return outputKeyvals } // Return a single value corresponding to key in keyvals diff --git a/logging/structure/structure_test.go b/logging/structure/structure_test.go index 36f48c521fe6f5992eb6a6e2d921d7b44bdd9029..fde15ff4ae247a02166d91fe7850328c01417e33 100644 --- a/logging/structure/structure_test.go +++ b/logging/structure/structure_test.go @@ -14,13 +14,23 @@ func TestValuesAndContext(t *testing.T) { assert.Equal(t, Slice("dog", 2, "fork", 5), ctx) } -func TestKeyValuesToMap(t *testing.T) { - kvs := Slice("scope", "lawnmower", +func TestVectorise(t *testing.T) { + kvs := Slice( + "scope", "lawnmower", + "hub", "budub", "occupation", "fish brewer", "scope", "hose pipe", - "scope", "rake") - assert.Equal(t, map[interface{}]interface{}{ - "occupation": "fish brewer", - "scope": Slice("lawnmower", "hose pipe", "rake")}, - KeyValuesToMap(kvs)) + "flub", "dub", + "scope", "rake", + "flub", "brub", + ) + + kvsVector := Vectorise(kvs, "occupation", "scope") + assert.Equal(t, Slice( + "scope", Slice("lawnmower", "hose pipe", "rake"), + "hub", "budub", + "occupation", "fish brewer", + "flub", Slice("dub", "brub"), + ), + kvsVector) } diff --git a/util/slice/slice.go b/util/slice/slice.go index 55332d87f5c96aa753f6f0580b306f77385a5134..2c51efd21f89c3478a185d623e54dcc9d4ea3064 100644 --- a/util/slice/slice.go +++ b/util/slice/slice.go @@ -58,7 +58,34 @@ func Delete(slice []interface{}, i int, n int) []interface{} { return append(slice[:i], slice[i+n:]...) } -// +// Delete an element at a specific index and return the contracted list func DeleteAt(slice []interface{}, i int) []interface{} { return Delete(slice, i, 1) } + +// Flatten a slice by a list by splicing any elements of the list that are +// themselves lists into the slice elements to the list in place of slice itself +func Flatten(slice []interface{}) []interface{} { + return DeepFlatten(slice, 1) +} + +// Recursively flattens a list by splicing any sub-lists into their parent until +// depth is reached. If a negative number is passed for depth then it continues +// until no elements of the returned list are lists +func DeepFlatten(slice []interface{}, depth int) []interface{} { + if depth == 0 { + return slice + } + returnSlice := []interface{}{} + + for _, element := range slice { + if s, ok := element.([]interface{}); ok { + returnSlice = append(returnSlice, DeepFlatten(s, depth-1)...) + } else { + returnSlice = append(returnSlice, element) + } + + } + + return returnSlice +} diff --git a/util/slice/slice_test.go b/util/slice/slice_test.go index 4a1f53e71ad0f5c4518e73c1d7b2eaa34ef8abc8..b3d1c9b6a530b1fe050427b3ba41ae8f9f23c388 100644 --- a/util/slice/slice_test.go +++ b/util/slice/slice_test.go @@ -23,14 +23,21 @@ func TestCopyPrepend(t *testing.T) { } func TestConcat(t *testing.T) { - assert.Equal(t, Slice(1,2,3,4,5), Concat(Slice(1,2,3,4,5))) - assert.Equal(t, Slice(1,2,3,4,5), Concat(Slice(1,2,3),Slice(4,5))) - assert.Equal(t, Slice(1,2,3,4,5), Concat(Slice(1),Slice(2,3),Slice(4,5))) + assert.Equal(t, Slice(1, 2, 3, 4, 5), Concat(Slice(1, 2, 3, 4, 5))) + assert.Equal(t, Slice(1, 2, 3, 4, 5), Concat(Slice(1, 2, 3), Slice(4, 5))) + assert.Equal(t, Slice(1, 2, 3, 4, 5), Concat(Slice(1), Slice(2, 3), Slice(4, 5))) assert.Equal(t, EmptySlice(), Concat(nil)) assert.Equal(t, Slice(1), Concat(nil, Slice(), Slice(1))) assert.Equal(t, Slice(1), Concat(Slice(1), Slice(), nil)) } func TestDelete(t *testing.T) { - assert.Equal(t, Slice(1,2,4,5), Delete(Slice(1,2,3,4,5), 2, 1)) -} \ No newline at end of file + assert.Equal(t, Slice(1, 2, 4, 5), Delete(Slice(1, 2, 3, 4, 5), 2, 1)) +} + +func TestDeepFlatten(t *testing.T) { + assert.Equal(t, Flatten(Slice(Slice(1, 2), 3, 4)), Slice(1, 2, 3, 4)) + nestedSlice := Slice(Slice(1, Slice(Slice(2))), Slice(3, 4)) + assert.Equal(t, DeepFlatten(nestedSlice, -1), Slice(1, 2, 3, 4)) + assert.Equal(t, DeepFlatten(nestedSlice, 2), Slice(1, Slice(2), 3, 4)) +}