tflog+tfsdklog: Added WithRootFields() function (#60)

Reference: #59

Author: bflad

.changelog/60.txt

@@ -0,0 +1,7 @@
+```release-note:enhancement
+tflog: Added `WithRootFields()` function, which can copy root logger fields to a new subsystem logger during `NewSubsystem()`
+```
+
+```release-note:enhancement
+tfsdklog: Added `WithRootFields()` function, which can copy root logger fields to a new subsystem logger during `NewSubsystem()`
+```

internal/logging/options.go

@@ -39,6 +39,11 @@ type LoggerOpts struct {
 	// tfsdklog; providers and SDKs should always include the time logs
 	// were written as part of the log.
 	IncludeTime bool
+
+	// IncludeRootFields indicates whether a new subsystem logger should
+	// copy existing fields from the root logger. This is only performed
+	// at the time of new subsystem creation.
+	IncludeRootFields bool
 }
 
 // ApplyLoggerOpts generates a LoggerOpts out of a list of Option
@@ -81,6 +86,15 @@ func WithOutput(output io.Writer) Option {
 	}
 }
 
+// WithRootFields enables the copying of root logger fields to a new subsystem
+// logger during creation.
+func WithRootFields() Option {
+	return func(l LoggerOpts) LoggerOpts {
+		l.IncludeRootFields = true
+		return l
+	}
+}
+
 // WithoutLocation disables the location included with logging statements. It
 // should only ever be used to make log output deterministic when testing
 // terraform-plugin-log.

tflog/options.go

@@ -43,6 +43,12 @@ func WithLevel(level hclog.Level) logging.Option {
 	}
 }
 
+// WithRootFields enables the copying of root logger fields to a new subsystem
+// logger during creation.
+func WithRootFields() logging.Option {
+	return logging.WithRootFields()
+}
+
 // WithoutLocation returns an option that disables including the location of
 // the log line in the log output, which is on by default. This has no effect
 // when used with NewSubsystem.

tflog/options_test.go

@@ -120,3 +120,82 @@ func TestWithAdditionalLocationOffset(t *testing.T) {
 		})
 	}
 }
+
+func TestWithRootFields(t *testing.T) {
+	t.Parallel()
+
+	testCases := map[string]struct {
+		logMessage      string
+		rootFields      map[string]interface{}
+		subsystemFields map[string]interface{}
+		expectedOutput  []map[string]interface{}
+	}{
+		"no-root-log-fields": {
+			subsystemFields: map[string]interface{}{
+				"test-subsystem-key": "test-subsystem-value",
+			},
+			logMessage: "test message",
+			expectedOutput: []map[string]interface{}{
+				{
+					"@level":             hclog.Trace.String(),
+					"@message":           "test message",
+					"@module":            testSubsystemModule,
+					"test-subsystem-key": "test-subsystem-value",
+				},
+			},
+		},
+		"with-root-log-fields": {
+			subsystemFields: map[string]interface{}{
+				"test-subsystem-key": "test-subsystem-value",
+			},
+			logMessage: "test message",
+			rootFields: map[string]interface{}{
+				"test-root-key": "test-root-value",
+			},
+			expectedOutput: []map[string]interface{}{
+				{
+					"@level":             hclog.Trace.String(),
+					"@message":           "test message",
+					"@module":            testSubsystemModule,
+					"test-root-key":      "test-root-value",
+					"test-subsystem-key": "test-subsystem-value",
+				},
+			},
+		},
+	}
+
+	for name, testCase := range testCases {
+		name, testCase := name, testCase
+
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			var outputBuffer bytes.Buffer
+
+			ctx := context.Background()
+			ctx = loggertest.ProviderRoot(ctx, &outputBuffer)
+
+			for key, value := range testCase.rootFields {
+				ctx = tflog.With(ctx, key, value)
+			}
+
+			ctx = tflog.NewSubsystem(ctx, testSubsystem, tflog.WithRootFields())
+
+			for key, value := range testCase.subsystemFields {
+				ctx = tflog.SubsystemWith(ctx, testSubsystem, key, value)
+			}
+
+			tflog.SubsystemTrace(ctx, testSubsystem, testCase.logMessage)
+
+			got, err := loggertest.MultilineJSONDecode(&outputBuffer)
+
+			if err != nil {
+				t.Fatalf("unable to read multiple line JSON: %s", err)
+			}
+
+			if diff := cmp.Diff(testCase.expectedOutput, got); diff != "" {
+				t.Errorf("unexpected output difference: %s", diff)
+			}
+		})
+	}
+}

tflog/subsystem.go

@@ -63,7 +63,13 @@ func NewSubsystem(ctx context.Context, subsystem string, options ...logging.Opti
 		subLoggerOptions.Level = opts.Level
 	}
 
-	return logging.SetProviderSubsystemLogger(ctx, subsystem, hclog.New(subLoggerOptions))
+	subLogger := hclog.New(subLoggerOptions)
+
+	if opts.IncludeRootFields {
+		subLogger = subLogger.With(logger.ImpliedArgs()...)
+	}
+
+	return logging.SetProviderSubsystemLogger(ctx, subsystem, subLogger)
 }
 
 // SubsystemWith returns a new context.Context that has a modified logger for

tfsdklog/options.go

@@ -53,6 +53,12 @@ func WithLevel(level hclog.Level) logging.Option {
 	}
 }
 
+// WithRootFields enables the copying of root logger fields to a new subsystem
+// logger during creation.
+func WithRootFields() logging.Option {
+	return logging.WithRootFields()
+}
+
 // WithoutLocation returns an option that disables including the location of
 // the log line in the log output, which is on by default. This has no effect
 // when used with NewSubsystem.

tfsdklog/options_test.go

@@ -120,3 +120,82 @@ func TestWithAdditionalLocationOffset(t *testing.T) {
 		})
 	}
 }
+
+func TestWithRootFields(t *testing.T) {
+	t.Parallel()
+
+	testCases := map[string]struct {
+		logMessage      string
+		rootFields      map[string]interface{}
+		subsystemFields map[string]interface{}
+		expectedOutput  []map[string]interface{}
+	}{
+		"no-root-log-fields": {
+			subsystemFields: map[string]interface{}{
+				"test-subsystem-key": "test-subsystem-value",
+			},
+			logMessage: "test message",
+			expectedOutput: []map[string]interface{}{
+				{
+					"@level":             hclog.Trace.String(),
+					"@message":           "test message",
+					"@module":            testSubsystemModule,
+					"test-subsystem-key": "test-subsystem-value",
+				},
+			},
+		},
+		"with-root-log-fields": {
+			subsystemFields: map[string]interface{}{
+				"test-subsystem-key": "test-subsystem-value",
+			},
+			logMessage: "test message",
+			rootFields: map[string]interface{}{
+				"test-root-key": "test-root-value",
+			},
+			expectedOutput: []map[string]interface{}{
+				{
+					"@level":             hclog.Trace.String(),
+					"@message":           "test message",
+					"@module":            testSubsystemModule,
+					"test-root-key":      "test-root-value",
+					"test-subsystem-key": "test-subsystem-value",
+				},
+			},
+		},
+	}
+
+	for name, testCase := range testCases {
+		name, testCase := name, testCase
+
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			var outputBuffer bytes.Buffer
+
+			ctx := context.Background()
+			ctx = loggertest.SDKRoot(ctx, &outputBuffer)
+
+			for key, value := range testCase.rootFields {
+				ctx = tfsdklog.With(ctx, key, value)
+			}
+
+			ctx = tfsdklog.NewSubsystem(ctx, testSubsystem, tfsdklog.WithRootFields())
+
+			for key, value := range testCase.subsystemFields {
+				ctx = tfsdklog.SubsystemWith(ctx, testSubsystem, key, value)
+			}
+
+			tfsdklog.SubsystemTrace(ctx, testSubsystem, testCase.logMessage)
+
+			got, err := loggertest.MultilineJSONDecode(&outputBuffer)
+
+			if err != nil {
+				t.Fatalf("unable to read multiple line JSON: %s", err)
+			}
+
+			if diff := cmp.Diff(testCase.expectedOutput, got); diff != "" {
+				t.Errorf("unexpected output difference: %s", diff)
+			}
+		})
+	}
+}

tfsdklog/subsystem.go

@@ -63,7 +63,13 @@ func NewSubsystem(ctx context.Context, subsystem string, options ...logging.Opti
 		subLoggerOptions.Level = opts.Level
 	}
 
-	return logging.SetSDKSubsystemLogger(ctx, subsystem, hclog.New(subLoggerOptions))
+	subLogger := hclog.New(subLoggerOptions)
+
+	if opts.IncludeRootFields {
+		subLogger = subLogger.With(logger.ImpliedArgs()...)
+	}
+
+	return logging.SetSDKSubsystemLogger(ctx, subsystem, subLogger)
 }
 
 // SubsystemWith returns a new context.Context that has a modified logger for