Merge pull request #11 from tendermint/bugfix/multiple-module-keys

Squash module keyvals if multiple keyvals were provided

log/tm_logger.go

@@ -10,7 +10,8 @@ import (
 )
 
 const (
-	msgKey = "_msg" // "_" prefixed to avoid collisions
+	msgKey    = "_msg" // "_" prefixed to avoid collisions
+	moduleKey = "module"
 )
 
 type tmLogger struct {

log/tmfmt_logger.go

@@ -51,13 +51,15 @@ func (l tmfmtLogger) Log(keyvals ...interface{}) error {
 
 	lvl := "none"
 	msg := "unknown"
-	lvlIndex := -1
+	module := "unknown"
-	msgIndex := -1
+
+	// indexes of keys to skip while encoding later
+	excludeIndexes := make([]int, 0)
 
 	for i := 0; i < len(keyvals)-1; i += 2 {
 		// Extract level
 		if keyvals[i] == kitlevel.Key() {
-			lvlIndex = i
+			excludeIndexes = append(excludeIndexes, i)
 			switch keyvals[i+1].(type) {
 			case string:
 				lvl = keyvals[i+1].(string)
@@ -66,18 +68,14 @@ func (l tmfmtLogger) Log(keyvals ...interface{}) error {
 			default:
 				panic(fmt.Sprintf("level value of unknown type %T", keyvals[i+1]))
 			}
-			continue
+			// and message
-		}
+		} else if keyvals[i] == msgKey {
-
+			excludeIndexes = append(excludeIndexes, i)
-		// and message
-		if keyvals[i] == msgKey {
-			msgIndex = i
 			msg = keyvals[i+1].(string)
-			continue
+			// and module (could be multiple keyvals; if such case last keyvalue wins)
-		}
+		} else if keyvals[i] == moduleKey {
-
+			excludeIndexes = append(excludeIndexes, i)
-		if lvlIndex > 0 && msgIndex > 0 { // found all we're looking for
+			module = keyvals[i+1].(string)
-			break
 		}
 	}
 
@@ -90,12 +88,20 @@ func (l tmfmtLogger) Log(keyvals ...interface{}) error {
 	//     D										- first character of the level, uppercase (ASCII only)
 	//     [05-02|11:06:44.322] - our time format (see https://golang.org/src/time/format.go)
 	//     Stopping ...					- message
-	enc.buf.WriteString(fmt.Sprintf("%c[%s] %-44s", lvl[0]-32, time.Now().UTC().Format("01-02|15:04:05.000"), msg))
+	enc.buf.WriteString(fmt.Sprintf("%c[%s] %-44s ", lvl[0]-32, time.Now().UTC().Format("01-02|15:04:05.000"), msg))
 
+	if module != "unknown" {
+		enc.buf.WriteString("module=" + module + " ")
+	}
+
+KeyvalueLoop:
 	for i := 0; i < len(keyvals)-1; i += 2 {
-		if i == lvlIndex || i == msgIndex {
+		for _, j := range excludeIndexes {
-			continue
+			if i == j {
+				continue KeyvalueLoop
+			}
 		}
+
 		if err := enc.EncodeKeyval(keyvals[i], keyvals[i+1]); err != nil {
 			return err
 		}

log/tmfmt_logger_test.go

@@ -44,6 +44,12 @@ func TestTMFmtLogger(t *testing.T) {
 		t.Fatal(err)
 	}
 	assert.Regexp(t, regexp.MustCompile(`N\[.+\] Hello \s+\n$`), buf.String())
+
+	buf.Reset()
+	if err := logger.Log("module", "main", "module", "crypto", "module", "wire"); err != nil {
+		t.Fatal(err)
+	}
+	assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+module=wire\s+\n$`), buf.String())
 }
 
 func BenchmarkTMFmtLoggerSimple(b *testing.B) {