Merge pull request #89 from Sirupsen/fix-logrus-double-fields

Fix JSON formatter prefixing old msg/time/level fields

formatter.go

@@ -26,19 +26,19 @@ type Formatter interface {
 //
 // It's not exported because it's still using Data in an opinionated way. It's to
 // avoid code duplication between the two default formatters.
-func prefixFieldClashes(entry *Entry) {
-	_, ok := entry.Data["time"]
+func prefixFieldClashes(data Fields) {
+	_, ok := data["time"]
 	if ok {
-		entry.Data["fields.time"] = entry.Data["time"]
+		data["fields.time"] = data["time"]
 	}
 
-	_, ok = entry.Data["msg"]
+	_, ok = data["msg"]
 	if ok {
-		entry.Data["fields.msg"] = entry.Data["msg"]
+		data["fields.msg"] = data["msg"]
 	}
 
-	_, ok = entry.Data["level"]
+	_, ok = data["level"]
 	if ok {
-		entry.Data["fields.level"] = entry.Data["level"]
+		data["fields.level"] = data["level"]
 	}
 }

json_formatter.go

@@ -9,12 +9,16 @@ import (
 type JSONFormatter struct{}
 
 func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
-	prefixFieldClashes(entry)
-	entry.Data["time"] = entry.Time.Format(time.RFC3339)
-	entry.Data["msg"] = entry.Message
-	entry.Data["level"] = entry.Level.String()
+	data := make(Fields, len(entry.Data)+3)
+	for k, v := range entry.Data {
+		data[k] = v
+	}
+	prefixFieldClashes(data)
+	data["time"] = entry.Time.Format(time.RFC3339)
+	data["msg"] = entry.Message
+	data["level"] = entry.Level.String()
 
-	serialized, err := json.Marshal(entry.Data)
+	serialized, err := json.Marshal(data)
 	if err != nil {
 		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
 	}

logrus_test.go

@@ -204,6 +204,38 @@ func TestDefaultFieldsAreNotPrefixed(t *testing.T) {
 	})
 }
 
+func TestDoubleLoggingDoesntPrefixPreviousFields(t *testing.T) {
+
+	var buffer bytes.Buffer
+	var fields Fields
+
+	logger := New()
+	logger.Out = &buffer
+	logger.Formatter = new(JSONFormatter)
+
+	llog := logger.WithField("context", "eating raw fish")
+
+	llog.Info("looks delicious")
+
+	err := json.Unmarshal(buffer.Bytes(), &fields)
+	assert.NoError(t, err, "should have decoded first message")
+	assert.Len(t, fields, 4, "should only have msg/time/level/context fields")
+	assert.Equal(t, fields["msg"], "looks delicious")
+	assert.Equal(t, fields["context"], "eating raw fish")
+
+	buffer.Reset()
+
+	llog.Warn("omg it is!")
+
+	err = json.Unmarshal(buffer.Bytes(), &fields)
+	assert.NoError(t, err, "should have decoded second message")
+	assert.Len(t, fields, 4, "should only have msg/time/level/context fields")
+	assert.Equal(t, fields["msg"], "omg it is!")
+	assert.Equal(t, fields["context"], "eating raw fish")
+	assert.Nil(t, fields["fields.msg"], "should not have prefixed previous `msg` entry")
+
+}
+
 func TestConvertLevelToString(t *testing.T) {
 	assert.Equal(t, "debug", DebugLevel.String())
 	assert.Equal(t, "info", InfoLevel.String())

text_formatter.go

@@ -46,7 +46,7 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
 
 	b := &bytes.Buffer{}
 
-	prefixFieldClashes(entry)
+	prefixFieldClashes(entry.Data)
 
 	isColored := (f.ForceColors || isTerminal) && !f.DisableColors