Repository: sirupsen/logrus
Pull request #1072 (2019-11-28 04:21:44)

Fix entry data bleed when using WithContext and WithTime
Creates a copy of the `Data` map when using `WithContext` to create a
child Entry.  Without this, the data map of the parent Entry,
which is exposed in the Entry struct, is shared between a parent
and all children instances.

This can create bugs of shared or overwritten data when a parent
Entry is used to make children in differing contexts, and behaves
differently than `WithField` and its derivatives which does make
a copy of the `Data` map.

Additionally implements the same logic for `WithTime`, for API
consistency in behavior.


Patch:
diff --git a/entry.go b/entry.go
index f24cf8d..7f28ba4 100644
--- a/entry.go
+++ b/entry.go
@@ -103,7 +103,11 @@ func (entry *Entry) WithError(err error) *Entry {
 
 // Add a context to the Entry.
 func (entry *Entry) WithContext(ctx context.Context) *Entry {
-	return &Entry{Logger: entry.Logger, Data: entry.Data, Time: entry.Time, err: entry.err, Context: ctx}
+	dataCopy := make(Fields, len(entry.Data))
+	for k, v := range entry.Data {
+		dataCopy[k] = v
+	}
+	return &Entry{Logger: entry.Logger, Data: dataCopy, Time: entry.Time, err: entry.err, Context: ctx}
 }
 
 // Add a single field to the Entry.
@@ -144,7 +148,11 @@ func (entry *Entry) WithFields(fields Fields) *Entry {
 
 // Overrides the time of the Entry.
 func (entry *Entry) WithTime(t time.Time) *Entry {
-	return &Entry{Logger: entry.Logger, Data: entry.Data, Time: t, err: entry.err, Context: entry.Context}
+	dataCopy := make(Fields, len(entry.Data))
+	for k, v := range entry.Data {
+		dataCopy[k] = v
+	}
+	return &Entry{Logger: entry.Logger, Data: dataCopy, Time: t, err: entry.err, Context: entry.Context}
 }
 
 // getPackageName reduces a fully qualified function name to the package name


Test patch:
diff --git a/entry_test.go b/entry_test.go
index f764085..973091e 100644
--- a/entry_test.go
+++ b/entry_test.go
@@ -47,6 +47,82 @@ func TestEntryWithContext(t *testing.T) {
 	assert.Equal(ctx, entry.WithContext(ctx).Context)
 }
 
+func TestEntryWithContextCopiesData(t *testing.T) {
+	assert := assert.New(t)
+
+	// Initialize a parent Entry object with a key/value set in its Data map
+	logger := New()
+	logger.Out = &bytes.Buffer{}
+	parentEntry := NewEntry(logger).WithField("parentKey", "parentValue")
+
+	// Create two children Entry objects from the parent in different contexts
+	ctx1 := context.WithValue(context.Background(), "foo", "bar")
+	childEntry1 := parentEntry.WithContext(ctx1)
+	assert.Equal(ctx1, childEntry1.Context)
+
+	ctx2 := context.WithValue(context.Background(), "bar", "baz")
+	childEntry2 := parentEntry.WithContext(ctx2)
+	assert.Equal(ctx2, childEntry2.Context)
+	assert.NotEqual(ctx1, ctx2)
+
+	// Ensure that data set in the parent Entry are preserved to both children
+	assert.Equal("parentValue", childEntry1.Data["parentKey"])
+	assert.Equal("parentValue", childEntry2.Data["parentKey"])
+
+	// Modify data stored in the child entry
+	childEntry1.Data["childKey"] = "childValue"
+
+	// Verify that data is successfully stored in the child it was set on
+	val, exists := childEntry1.Data["childKey"]
+	assert.True(exists)
+	assert.Equal("childValue", val)
+
+	// Verify that the data change to child 1 has not affected its sibling
+	val, exists = childEntry2.Data["childKey"]
+	assert.False(exists)
+	assert.Empty(val)
+
+	// Verify that the data change to child 1 has not affected its parent
+	val, exists = parentEntry.Data["childKey"]
+	assert.False(exists)
+	assert.Empty(val)
+}
+
+func TestEntryWithTimeCopiesData(t *testing.T) {
+	assert := assert.New(t)
+
+	// Initialize a parent Entry object with a key/value set in its Data map
+	logger := New()
+	logger.Out = &bytes.Buffer{}
+	parentEntry := NewEntry(logger).WithField("parentKey", "parentValue")
+
+	// Create two children Entry objects from the parent with two different times
+	childEntry1 := parentEntry.WithTime(time.Now().AddDate(0, 0, 1))
+	childEntry2 := parentEntry.WithTime(time.Now().AddDate(0, 0, 2))
+
+	// Ensure that data set in the parent Entry are preserved to both children
+	assert.Equal("parentValue", childEntry1.Data["parentKey"])
+	assert.Equal("parentValue", childEntry2.Data["parentKey"])
+
+	// Modify data stored in the child entry
+	childEntry1.Data["childKey"] = "childValue"
+
+	// Verify that data is successfully stored in the child it was set on
+	val, exists := childEntry1.Data["childKey"]
+	assert.True(exists)
+	assert.Equal("childValue", val)
+
+	// Verify that the data change to child 1 has not affected its sibling
+	val, exists = childEntry2.Data["childKey"]
+	assert.False(exists)
+	assert.Empty(val)
+
+	// Verify that the data change to child 1 has not affected its parent
+	val, exists = parentEntry.Data["childKey"]
+	assert.False(exists)
+	assert.Empty(val)
+}
+
 func TestEntryPanicln(t *testing.T) {
 	errBoom := fmt.Errorf("boom time")