tfsdklog: Introduce outside context level checks for logging functions (

#149)

Reference: hashicorp/terraform-plugin-framework#721

This change introduces log level checks outside the `context.Context` of a request to improve the performance of logging functions when logs would not be emitted at the configured level. Almost exclusively, logging levels are not expected to change during provider (and therefore SDK) runtime since they are environment variable driven. Even if they did, this level check will either immediately constrict logging to match an updated higher level or cause additional `context.Context` reads with an updated lower level, which is no different than the current behavior.

The following benchmark was ran prior to the introduction of the level checks and mutexes:

```
BenchmarkSubsystemTraceDisabled-10            4616656               258.0 ns/op
BenchmarkSubsystemTraceEnabled-10              936865              1138 ns/op
```

After the addition of level checks and mutexes:

```
BenchmarkSubsystemTraceDisabled-10           86043471                13.78 ns/op
BenchmarkSubsystemTraceEnabled-10              906649              1137 ns/op
```

This enhancement could also be considered for provider loggers, however SDK logging tends to be more prevalent in practice, so this only targets the `tfsdklog` package handling.

.changes/unreleased/ENHANCEMENTS-20230418-201952.yaml

@@ -0,0 +1,6 @@
+kind: ENHANCEMENTS
+body: 'tfsdklog: Improved logging performance 20x when logs would be skipped due to
+  logging level'
+time: 2023-04-18T20:19:52.460485-04:00
+custom:
+  Issue: "149"

tfsdklog/levels.go

@@ -0,0 +1,81 @@
+package tfsdklog
+
+import (
+	"sync"
+
+	"github.com/hashicorp/go-hclog"
+)
+
+var (
+	// rootLevel stores the effective level of the root SDK logger during
+	// NewRootSDKLogger where the value is deterministically chosen based on
+	// environment variables, etc. This call generally happens with each new
+	// provider RPC request. If the environment variable values changed during
+	// runtime between calls, then inflight provider requests checking this
+	// value would receive the most up-to-date value which would potentially
+	// differ with the actual in-context logger level. This tradeoff would only
+	// effect the inflight requests and should not be an overall performance
+	// concern in the case of this level causing more context checks until the
+	// request is over.
+	rootLevel hclog.Level = hclog.NoLevel
+
+	// rootLevelMutex is a read-write mutex that protects rootLevel from
+	// triggering the data race detector.
+	rootLevelMutex = sync.RWMutex{}
+
+	// subsystemLevels stores the effective level of all subsystem SDK loggers
+	// during NewSubsystem where the value is deterministically chosen based on
+	// environment variables, etc. This call generally happens with each new
+	// provider RPC request. If the environment variable values changed during
+	// runtime between calls, then inflight provider requests checking this
+	// value would receive the most up-to-date value which would potentially
+	// differ with the actual in-context logger level. This tradeoff would only
+	// effect the inflight requests and should not be an overall performance
+	// concern in the case of this level causing more context checks until the
+	// request is over.
+	subsystemLevels map[string]hclog.Level = make(map[string]hclog.Level)
+
+	// subsystemLevelsMutex is a read-write mutex that protects the
+	// subsystemLevels map from concurrent read and write panics.
+	subsystemLevelsMutex = sync.RWMutex{}
+)
+
+// subsystemWouldLog returns true if the subsystem SDK logger would emit a log
+// at the given level. This is performed outside the context-based logger for
+// performance.
+func subsystemWouldLog(subsystem string, level hclog.Level) bool {
+	subsystemLevelsMutex.RLock()
+
+	setLevel, ok := subsystemLevels[subsystem]
+
+	subsystemLevelsMutex.RUnlock()
+
+	if !ok {
+		return false
+	}
+
+	return wouldLog(setLevel, level)
+}
+
+// rootWouldLog returns true if the root SDK logger would emit a log at the
+// given level. This is performed outside the context-based logger for
+// performance.
+func rootWouldLog(level hclog.Level) bool {
+	rootLevelMutex.RLock()
+
+	setLevel := rootLevel
+
+	rootLevelMutex.RUnlock()
+
+	return wouldLog(setLevel, level)
+}
+
+// wouldLog returns true if the set level would emit a log at the given
+// level. This is performed outside the context-based logger for performance.
+func wouldLog(setLevel, checkLevel hclog.Level) bool {
+	if checkLevel == hclog.Off {
+		return false
+	}
+
+	return checkLevel >= setLevel
+}