tflog+tfsdklog: Prevent slice/map leaks when setting LoggerOpts (#132)

Reference: #126
Reference: #131

Since the `LoggerOpts` struct contains slice and map fields, it is important to ensure any modifications occur on copies of those slices and maps, otherwise the memory reference can wind up being shared. Consumers should always be able to create a new `context.Context` without worrying about shared data.

This change introduces a `Copy()` method for `LoggerOpts` and implements it for option modifier functions which adjust a map or slice.

Author: bflad

.changes/unreleased/BUG FIXES-20230207-165520.yaml

@@ -0,0 +1,6 @@
+kind: BUG FIXES
+body: 'tflog+tflogsdk: Prevented data race conditions when using SetField and other
+  option functions'
+time: 2023-02-07T16:55:20.433603-05:00
+custom:
+  Issue: "132"

internal/logging/options.go

@@ -157,6 +157,47 @@ type LoggerOpts struct {
 	MaskMessageStrings []string
 }
 
+// Copy creates a duplicate LoggerOpts. This should be used to ensure
+// safe LoggerOpts modification when the LoggerOpts could be saved into a
+// new context.Context.
+func (o LoggerOpts) Copy() LoggerOpts {
+	result := LoggerOpts{
+		AdditionalLocationOffset:     o.AdditionalLocationOffset,
+		Fields:                       make(map[string]any, len(o.Fields)),
+		IncludeLocation:              o.IncludeLocation,
+		IncludeRootFields:            o.IncludeRootFields,
+		IncludeTime:                  o.IncludeTime,
+		Level:                        o.Level,
+		MaskAllFieldValuesRegexes:    make([]*regexp.Regexp, len(o.MaskAllFieldValuesRegexes)),
+		MaskAllFieldValuesStrings:    make([]string, len(o.MaskAllFieldValuesStrings)),
+		MaskFieldValuesWithFieldKeys: make([]string, len(o.MaskFieldValuesWithFieldKeys)),
+		MaskMessageRegexes:           make([]*regexp.Regexp, len(o.MaskMessageRegexes)),
+		MaskMessageStrings:           make([]string, len(o.MaskMessageStrings)),
+		Name:                         o.Name,
+		OmitLogWithFieldKeys:         make([]string, len(o.OmitLogWithFieldKeys)),
+		OmitLogWithMessageRegexes:    make([]*regexp.Regexp, len(o.OmitLogWithMessageRegexes)),
+		OmitLogWithMessageStrings:    make([]string, len(o.OmitLogWithMessageStrings)),
+		Output:                       o.Output,
+	}
+
+	// Copy all slice/map contents to prevent leaking memory references
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	for key, value := range o.Fields {
+		result.Fields[key] = value
+	}
+
+	copy(result.MaskAllFieldValuesRegexes, o.MaskAllFieldValuesRegexes)
+	copy(result.MaskAllFieldValuesStrings, o.MaskAllFieldValuesStrings)
+	copy(result.MaskFieldValuesWithFieldKeys, o.MaskFieldValuesWithFieldKeys)
+	copy(result.MaskMessageRegexes, o.MaskMessageRegexes)
+	copy(result.MaskMessageStrings, o.MaskMessageStrings)
+	copy(result.OmitLogWithFieldKeys, o.OmitLogWithFieldKeys)
+	copy(result.OmitLogWithMessageRegexes, o.OmitLogWithMessageRegexes)
+	copy(result.OmitLogWithMessageStrings, o.OmitLogWithMessageStrings)
+
+	return result
+}
+
 // ApplyLoggerOpts generates a LoggerOpts out of a list of Option
 // implementations. By default, AdditionalLocationOffset is 1, IncludeLocation
 // is true, IncludeTime is true, and Output is os.Stderr.

internal/logging/options_test.go

@@ -0,0 +1,112 @@
+package logging_test
+
+import (
+	"os"
+	"regexp"
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+	"github.com/hashicorp/go-hclog"
+	"github.com/hashicorp/terraform-plugin-log/internal/logging"
+)
+
+func TestLoggerOptsCopy(t *testing.T) {
+	t.Parallel()
+
+	regex1 := regexp.MustCompile("regex1")
+	regex2 := regexp.MustCompile("regex2")
+
+	// Populate all fields.
+	originalLoggerOpts := logging.LoggerOpts{
+		AdditionalLocationOffset:     1,
+		Fields:                       map[string]any{"key1": "value1"},
+		IncludeLocation:              true,
+		IncludeRootFields:            true,
+		IncludeTime:                  true,
+		Level:                        hclog.Error,
+		MaskAllFieldValuesRegexes:    []*regexp.Regexp{regex1},
+		MaskAllFieldValuesStrings:    []string{"string1"},
+		MaskFieldValuesWithFieldKeys: []string{"string1"},
+		MaskMessageRegexes:           []*regexp.Regexp{regex1},
+		MaskMessageStrings:           []string{"string1"},
+		Name:                         "name1",
+		OmitLogWithFieldKeys:         []string{"string1"},
+		OmitLogWithMessageRegexes:    []*regexp.Regexp{regex1},
+		OmitLogWithMessageStrings:    []string{"string1"},
+		Output:                       os.Stdout,
+	}
+
+	// Expected LoggerOpts should exactly match original.
+	expectedLoggerOpts := logging.LoggerOpts{
+		AdditionalLocationOffset:     1,
+		Fields:                       map[string]any{"key1": "value1"},
+		IncludeLocation:              true,
+		IncludeRootFields:            true,
+		IncludeTime:                  true,
+		Level:                        hclog.Error,
+		MaskAllFieldValuesRegexes:    []*regexp.Regexp{regex1},
+		MaskAllFieldValuesStrings:    []string{"string1"},
+		MaskFieldValuesWithFieldKeys: []string{"string1"},
+		MaskMessageRegexes:           []*regexp.Regexp{regex1},
+		MaskMessageStrings:           []string{"string1"},
+		Name:                         "name1",
+		OmitLogWithFieldKeys:         []string{"string1"},
+		OmitLogWithMessageRegexes:    []*regexp.Regexp{regex1},
+		OmitLogWithMessageStrings:    []string{"string1"},
+		Output:                       os.Stdout,
+	}
+
+	// Create a copy before modifying the original LoggerOpts. This will be
+	// checked against the expected LoggerOpts after modifications.
+	copiedLoggerOpts := originalLoggerOpts.Copy()
+
+	// Ensure modifications of original does not effect copy.
+	originalLoggerOpts.AdditionalLocationOffset = 2
+	originalLoggerOpts.Fields["key2"] = "value2"
+	originalLoggerOpts.IncludeLocation = false
+	originalLoggerOpts.IncludeRootFields = false
+	originalLoggerOpts.IncludeTime = false
+	originalLoggerOpts.Level = hclog.Debug
+	originalLoggerOpts.MaskAllFieldValuesRegexes = append(originalLoggerOpts.MaskAllFieldValuesRegexes, regex2)
+	originalLoggerOpts.MaskAllFieldValuesStrings = append(originalLoggerOpts.MaskAllFieldValuesStrings, "string2")
+	originalLoggerOpts.MaskFieldValuesWithFieldKeys = append(originalLoggerOpts.MaskFieldValuesWithFieldKeys, "string2")
+	originalLoggerOpts.MaskMessageRegexes = append(originalLoggerOpts.MaskMessageRegexes, regex2)
+	originalLoggerOpts.MaskMessageStrings = append(originalLoggerOpts.MaskMessageStrings, "string2")
+	originalLoggerOpts.Name = "name2"
+	originalLoggerOpts.OmitLogWithFieldKeys = append(originalLoggerOpts.OmitLogWithFieldKeys, "string2")
+	originalLoggerOpts.OmitLogWithMessageRegexes = append(originalLoggerOpts.OmitLogWithMessageRegexes, regex2)
+	originalLoggerOpts.OmitLogWithMessageStrings = append(originalLoggerOpts.OmitLogWithMessageStrings, "string2")
+	originalLoggerOpts.Output = os.Stderr
+
+	// Prevent go-cmp errors.
+	cmpOpts := []cmp.Option{
+		cmp.Comparer(func(i, j *os.File) bool {
+			if i == nil {
+				return j == nil
+			}
+
+			if j == nil {
+				return false
+			}
+
+			// Simple comparison test is good enough for our purposes.
+			return i.Fd() == j.Fd()
+		}),
+		cmp.Comparer(func(i, j *regexp.Regexp) bool {
+			if i == nil {
+				return j == nil
+			}
+
+			if j == nil {
+				return false
+			}
+
+			// Simple comparison test is good enough for our purposes.
+			return i.String() == j.String()
+		}),
+	}
+
+	if diff := cmp.Diff(copiedLoggerOpts, expectedLoggerOpts, cmpOpts...); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}

tflog/provider.go

@@ -15,7 +15,9 @@ import (
 func SetField(ctx context.Context, key string, value interface{}) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithField(key, value)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithField(key, value)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -152,7 +154,9 @@ func Error(ctx context.Context, msg string, additionalFields ...map[string]inter
 func OmitLogWithFieldKeys(ctx context.Context, keys ...string) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -174,7 +178,9 @@ func OmitLogWithFieldKeys(ctx context.Context, keys ...string) context.Context {
 func OmitLogWithMessageRegexes(ctx context.Context, expressions ...*regexp.Regexp) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithOmitLogWithMessageRegexes(expressions...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithOmitLogWithMessageRegexes(expressions...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -195,7 +201,9 @@ func OmitLogWithMessageRegexes(ctx context.Context, expressions ...*regexp.Regex
 func OmitLogWithMessageStrings(ctx context.Context, matchingStrings ...string) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -217,7 +225,9 @@ func OmitLogWithMessageStrings(ctx context.Context, matchingStrings ...string) c
 func MaskFieldValuesWithFieldKeys(ctx context.Context, keys ...string) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithMaskFieldValuesWithFieldKeys(keys...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithMaskFieldValuesWithFieldKeys(keys...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -241,7 +251,9 @@ func MaskFieldValuesWithFieldKeys(ctx context.Context, keys ...string) context.C
 func MaskAllFieldValuesRegexes(ctx context.Context, expressions ...*regexp.Regexp) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithMaskAllFieldValuesRegexes(expressions...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithMaskAllFieldValuesRegexes(expressions...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -265,7 +277,9 @@ func MaskAllFieldValuesRegexes(ctx context.Context, expressions ...*regexp.Regex
 func MaskAllFieldValuesStrings(ctx context.Context, matchingStrings ...string) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithMaskAllFieldValuesStrings(matchingStrings...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithMaskAllFieldValuesStrings(matchingStrings...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -287,7 +301,9 @@ func MaskAllFieldValuesStrings(ctx context.Context, matchingStrings ...string) c
 func MaskMessageRegexes(ctx context.Context, expressions ...*regexp.Regexp) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithMaskMessageRegexes(expressions...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithMaskMessageRegexes(expressions...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }
@@ -309,7 +325,9 @@ func MaskMessageRegexes(ctx context.Context, expressions ...*regexp.Regexp) cont
 func MaskMessageStrings(ctx context.Context, matchingStrings ...string) context.Context {
 	lOpts := logging.GetProviderRootTFLoggerOpts(ctx)
 
-	lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts)
+	// Copy to prevent slice/map aliasing issues.
+	// Reference: https://github.com/hashicorp/terraform-plugin-log/issues/131
+	lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts.Copy())
 
 	return logging.SetProviderRootTFLoggerOpts(ctx, lOpts)
 }