tfsdklog: Ensure sink logger options are propagated to SDK and provid…

…er root loggers (#58) Reference: #54 Verified via terraform-provider-corner. Previously: ```console $ TF_ACC=1 TF_LOG=WARN go test -count=1 -run='TestAccFrameworkResourceUser$' -v ./internal/frameworkprovider === RUN TestAccFrameworkResourceUser 2022-05-03T14:42:25.505-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.666-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.668-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.668-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.670-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.671-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.671-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.672-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:43.672-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.245-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.247-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.248-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.249-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.249-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.249-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.252-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:48.253-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:52.798-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.552-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.554-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.555-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.555-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.556-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.557-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:42:55.558-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:00.146-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.701-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.703-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.703-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.704-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.705-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.705-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.706-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.707-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:04.707-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:09.252-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.803-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.805-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.806-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.807-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.808-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.808-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.809-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.810-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.811-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:13.811-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.382-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.385-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.385-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.387-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.387-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.387-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.388-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.389-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:18.390-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:22.938-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:25.649-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.199-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.200-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.200-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.203-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.203-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.205-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.206-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.206-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.206-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options 2022-05-03T14:43:30.207-0400 [WARN] sdk: Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options --- PASS: TestAccFrameworkResourceUser (64.75s) PASS ok github.com/hashicorp/terraform-provider-corner/internal/frameworkprovider 65.006s ``` Now: ```console $ TF_ACC=1 TF_LOG=WARN go test -count=1 -run='TestAccFrameworkResourceUser$' -v ./internal/frameworkprovider === RUN TestAccFrameworkResourceUser --- PASS: TestAccFrameworkResourceUser (64.76s) PASS ok github.com/hashicorp/terraform-provider-corner/internal/frameworkprovider 68.569s ```
hashicorp · May 4, 2022 · 0a383c3 · 0a383c3
1 parent 1d1c445
commit 0a383c3
Show file tree

Hide file tree

Showing 5 changed files with 93 additions and 16 deletions.
diff --git a/.changelog/58.txt b/.changelog/58.txt
@@ -0,0 +1,3 @@
+```release-note:bug
+tflog+tfsdklog: Prevented `Unable to create logging subsystem with AdditionalLocationOffset due to missing root logger options` warning logs during acceptance testing
+```
diff --git a/internal/logging/log.go b/internal/logging/log.go
@@ -41,6 +41,12 @@ const (
 	// SinkKey is the loggerKey that will hold the logging sink used for
 	// test frameworks.
 	SinkKey loggerKey = ""
+
+	// SinkOptionsKey is the loggerKey that will hold the sink
+	// logger options when the SDK provider logger is created. This is to
+	// assist creating subsystem loggers, as most options cannot be fetched and
+	// a logger does not provide set methods for these options.
+	SinkOptionsKey loggerKey = "sink-options"
 )
 
 var (

diff --git a/internal/logging/sink.go b/internal/logging/sink.go
@@ -0,0 +1,51 @@
+package logging
+
+import (
+	"context"
+
+	"github.com/hashicorp/go-hclog"
+)
+
+// GetSink returns the sink logger used for writing logs.
+// If no sink logger has been created, it will return nil.
+func GetSink(ctx context.Context) hclog.Logger {
+	logger := ctx.Value(SinkKey)
+	if logger == nil {
+		return nil
+	}
+	return logger.(hclog.Logger)
+}
+
+// GetSinkOptions returns the root logger options used for
+// creating the root SDK logger. If the root logger has not been created or
+// the options are not present, it will return nil.
+func GetSinkOptions(ctx context.Context) *hclog.LoggerOptions {
+	if GetSink(ctx) == nil {
+		return nil
+	}
+
+	loggerOptionsRaw := ctx.Value(SinkOptionsKey)
+
+	if loggerOptionsRaw == nil {
+		return nil
+	}
+
+	loggerOptions, ok := loggerOptionsRaw.(*hclog.LoggerOptions)
+
+	if !ok {
+		return nil
+	}
+
+	return loggerOptions
+}
+
+// SetSink sets `logger` as the sink logger used for writing logs.
+func SetSink(ctx context.Context, logger hclog.Logger) context.Context {
+	return context.WithValue(ctx, SinkKey, logger)
+}
+
+// SetSinkOptions sets `loggerOptions` as the root logger options
+// used for creating the SDK root logger.
+func SetSinkOptions(ctx context.Context, loggerOptions *hclog.LoggerOptions) context.Context {
+	return context.WithValue(ctx, SinkOptionsKey, loggerOptions)
+}
diff --git a/tfsdklog/sdk.go b/tfsdklog/sdk.go
@@ -15,12 +15,21 @@ func NewRootSDKLogger(ctx context.Context, options ...logging.Option) context.Co
 	if opts.Name == "" {
 		opts.Name = logging.DefaultSDKRootLoggerName
 	}
-	if sink := getSink(ctx); sink != nil {
+	if sink := logging.GetSink(ctx); sink != nil {
 		logger := sink.Named(opts.Name)
+		sinkLoggerOptions := logging.GetSinkOptions(ctx)
+		sdkLoggerOptions := hclogutils.LoggerOptionsCopy(sinkLoggerOptions)
+		sdkLoggerOptions.Name = opts.Name
+
 		if opts.Level != hclog.NoLevel {
 			logger.SetLevel(opts.Level)
+			sdkLoggerOptions.Level = opts.Level
 		}
-		return logging.SetSDKRootLogger(ctx, logger)
+
+		ctx = logging.SetSDKRootLogger(ctx, logger)
+		ctx = logging.SetSDKRootLoggerOptions(ctx, sdkLoggerOptions)
+
+		return ctx
 	}
 	if opts.Level == hclog.NoLevel {
 		opts.Level = hclog.Trace
@@ -49,12 +58,21 @@ func NewRootProviderLogger(ctx context.Context, options ...logging.Option) conte
 	if opts.Name == "" {
 		opts.Name = logging.DefaultProviderRootLoggerName
 	}
-	if sink := getSink(ctx); sink != nil {
+	if sink := logging.GetSink(ctx); sink != nil {
 		logger := sink.Named(opts.Name)
+		sinkLoggerOptions := logging.GetSinkOptions(ctx)
+		providerLoggerOptions := hclogutils.LoggerOptionsCopy(sinkLoggerOptions)
+		providerLoggerOptions.Name = opts.Name
+
 		if opts.Level != hclog.NoLevel {
 			logger.SetLevel(opts.Level)
+			providerLoggerOptions.Level = opts.Level
 		}
-		return logging.SetProviderRootLogger(ctx, logger)
+
+		ctx = logging.SetProviderRootLogger(ctx, logger)
+		ctx = logging.SetProviderRootLoggerOptions(ctx, providerLoggerOptions)
+
+		return ctx
 	}
 	if opts.Level == hclog.NoLevel {
 		opts.Level = hclog.Trace

diff --git a/tfsdklog/sink.go b/tfsdklog/sink.go
@@ -57,14 +57,6 @@ var ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "OFF"}
 // Only show invalid log level message once across any number of level lookups.
 var invalidLogLevelMessage sync.Once
 
-func getSink(ctx context.Context) hclog.Logger {
-	logger := ctx.Value(logging.SinkKey)
-	if logger == nil {
-		return nil
-	}
-	return logger.(hclog.Logger)
-}
-
 // RegisterTestSink sets up a logging sink, for use with test frameworks and
 // other cases where plugin logs don't get routed through Terraform. This
 // applies the same filtering and file output behaviors that Terraform does.
@@ -75,10 +67,15 @@ func getSink(ctx context.Context) hclog.Logger {
 // RegisterTestSink must be called prior to any loggers being setup or
 // instantiated.
 func RegisterTestSink(ctx context.Context, t testing.T) context.Context {
-	return context.WithValue(ctx, logging.SinkKey, newSink(t))
+	logger, loggerOptions := newSink(t)
+
+	ctx = logging.SetSink(ctx, logger)
+	ctx = logging.SetSinkOptions(ctx, loggerOptions)
+
+	return ctx
 }
 
-func newSink(t testing.T) hclog.Logger {
+func newSink(t testing.T) (hclog.Logger, *hclog.LoggerOptions) {
 	logOutput := io.Writer(os.Stderr)
 	var json bool
 	var logLevel hclog.Level
@@ -134,12 +131,14 @@ func newSink(t testing.T) hclog.Logger {
 		})
 	}
 
-	return hclog.New(&hclog.LoggerOptions{
+	loggerOptions := &hclog.LoggerOptions{
 		Level:             logLevel,
 		Output:            logOutput,
 		IndependentLevels: true,
 		JSONFormat:        json,
-	})
+	}
+
+	return hclog.New(loggerOptions), loggerOptions
 }
 
 func isValidLogLevel(level string) bool {