tflog+tfsdklog: Change final variadic function parameter in logging f…

…unctions to ...map[string]interface{} (#34)

Reference: #30
Reference: #31

Previously, implementers could introduce mismatched key-value pairs or expect `f` suffix-like string formatting of the message due to the final `...interface{}` variadic argument. Updating this to `...map[string]interface{}` has the following benefits:

- Calls that errantly were treating these as formatter functions will now receive a compiler error in the majority of cases (except parameters that already satisfied the `map[string]interface{}` type).
- Matched pairing is now enforced via the compiler, preventing occurence of go-hclog's `EXTRA_VALUE_AT_END` key in entries.
- Keys are now enforced to be `string`, where before they could be defined as other types and beholden to go-hclog's behavior of calling `fmt.Sprintf("%s", key)` resulting in likely unexpected keys for non-string types:

```
true: %!s(bool=true)
123: %!s(int=123)
123.456: %!s(float64=123.456)
[]string{"oops"}: [oops]
MyCustomType (without String() method): {}
```

Some disadvantages of this new approach include:

- Additional typing of the `map[string]T{}` for each call. Implementors can opt for `map[string]string` in many cases, or Go 1.18+ `map[string]any`, in preference over the potentially confusing/annoying `interface{}` typing.
- The burden of converting existing calls.

Pragmatically however, the advantages outweigh the disadvantages as this Go module does not yet have full compatibility promises (pre-1.0) and the direct dependencies are expected to grow exponentially in the near future when its existance is broadcasted more. Catching this critical API change earlier rather than later will have less of an effect on the ecosystem.

.changelog/34.txt

@@ -0,0 +1,7 @@
+```release-note:breaking-change
+tflog: The `Trace()`, `Debug()`, `Info()`, `Warn()`, and `Error()` functions and `Subsystem` equivalents now use `...map[string]interface{}` as the final optional parameter, where the `string` is the structured logging key, rather than expecting matched `key interface{}, value interface{}` pairs. If multiple maps contain the same key, the value is shallow merged.
+```
+
+```release-note:breaking-change
+tfsdklog: The `Trace()`, `Debug()`, `Info()`, `Warn()`, and `Error()` functions and `Subsystem` equivalents now use `...map[string]interface{}` as the final optional parameter, where the `string` is the structured logging key, rather than expecting matched `key interface{}, value interface{}` pairs. If multiple maps contain the same key, the value is shallow merged.
+```

internal/hclogutils/args.go

@@ -0,0 +1,36 @@
+package hclogutils
+
+// MapsToArgs will shallow merge field maps into the slice of key1, value1,
+// key2, value2, ... arguments expected by hc-log.Logger methods.
+func MapsToArgs(maps ...map[string]interface{}) []interface{} {
+	switch len(maps) {
+	case 0:
+		return nil
+	case 1:
+		result := make([]interface{}, 0, len(maps[0])*2)
+
+		for k, v := range maps[0] {
+			result = append(result, k)
+			result = append(result, v)
+		}
+
+		return result
+	default:
+		mergedMap := make(map[string]interface{}, 0)
+
+		for _, m := range maps {
+			for k, v := range m {
+				mergedMap[k] = v
+			}
+		}
+
+		result := make([]interface{}, 0, len(mergedMap)*2)
+
+		for k, v := range mergedMap {
+			result = append(result, k)
+			result = append(result, v)
+		}
+
+		return result
+	}
+}

internal/hclogutils/args_test.go

@@ -0,0 +1,173 @@
+package hclogutils_test
+
+import (
+	"sort"
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+	"github.com/hashicorp/terraform-plugin-log/internal/hclogutils"
+)
+
+func TestMapsToArgs(t *testing.T) {
+	t.Parallel()
+
+	testCases := map[string]struct {
+		maps         []map[string]interface{}
+		expectedArgs []interface{}
+	}{
+		"nil": {
+			maps:         nil,
+			expectedArgs: nil,
+		},
+		"map-single": {
+			maps: []map[string]interface{}{
+				{
+					"map1-key1": "map1-value1",
+					"map1-key2": "map1-value2",
+					"map1-key3": "map1-value3",
+				},
+			},
+			expectedArgs: []interface{}{
+				"map1-key1", "map1-value1",
+				"map1-key2", "map1-value2",
+				"map1-key3", "map1-value3",
+			},
+		},
+		"map-multiple-different-keys": {
+			maps: []map[string]interface{}{
+				{
+					"map1-key1": "map1-value1",
+					"map1-key2": "map1-value2",
+					"map1-key3": "map1-value3",
+				},
+				{
+					"map2-key1": "map2-value1",
+					"map2-key2": "map2-value2",
+					"map2-key3": "map2-value3",
+				},
+			},
+			expectedArgs: []interface{}{
+				"map1-key1", "map1-value1",
+				"map1-key2", "map1-value2",
+				"map1-key3", "map1-value3",
+				"map2-key1", "map2-value1",
+				"map2-key2", "map2-value2",
+				"map2-key3", "map2-value3",
+			},
+		},
+		"map-multiple-mixed-keys": {
+			maps: []map[string]interface{}{
+				{
+					"key1": "map1-value1",
+					"key2": "map1-value2",
+					"key3": "map1-value3",
+				},
+				{
+					"key4": "map2-value4",
+					"key1": "map2-value1",
+					"key5": "map2-value5",
+				},
+			},
+			expectedArgs: []interface{}{
+				"key1", "map2-value1",
+				"key2", "map1-value2",
+				"key3", "map1-value3",
+				"key4", "map2-value4",
+				"key5", "map2-value5",
+			},
+		},
+		"map-multiple-overlapping-keys": {
+			maps: []map[string]interface{}{
+				{
+					"key1": "map1-value1",
+					"key2": "map1-value2",
+					"key3": "map1-value3",
+				},
+				{
+					"key1": "map2-value1",
+					"key2": "map2-value2",
+					"key3": "map2-value3",
+				},
+			},
+			expectedArgs: []interface{}{
+				"key1", "map2-value1",
+				"key2", "map2-value2",
+				"key3", "map2-value3",
+			},
+		},
+		"map-multiple-overlapping-keys-shallow": {
+			maps: []map[string]interface{}{
+				{
+					"key1": map[string]interface{}{
+						"submap-key1": "map1-value1",
+						"submap-key2": "map1-value2",
+						"submap-key3": "map1-value3",
+					},
+					"key2": "map1-value2",
+					"key3": "map1-value3",
+				},
+				{
+					"key1": map[string]interface{}{
+						"submap-key4": "map2-value4",
+						"submap-key5": "map2-value5",
+						"submap-key6": "map2-value6",
+					},
+					"key2": "map2-value2",
+					"key3": "map2-value3",
+				},
+			},
+			expectedArgs: []interface{}{
+				"key1", map[string]interface{}{
+					"submap-key4": "map2-value4",
+					"submap-key5": "map2-value5",
+					"submap-key6": "map2-value6",
+				},
+				"key2", "map2-value2",
+				"key3", "map2-value3",
+			},
+		},
+	}
+
+	for name, testCase := range testCases {
+		name, testCase := name, testCase
+
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			got := hclogutils.MapsToArgs(testCase.maps...)
+
+			if len(got)%2 != 0 {
+				t.Fatalf("expected even number of key-value fields, got: %v", got)
+			}
+
+			if got == nil && testCase.expectedArgs == nil {
+				return // sortedGot will return []interface{}{} below, nil is what we want
+			}
+
+			// Map retrieval is indeterminate in Go, sort the result first.
+			// This logic is only necessary in this testing as its automatically
+			// handled in go-hclog.
+			gotKeys := make([]string, 0, len(got)/2)
+			gotValues := make(map[string]interface{}, len(got)/2)
+
+			for i := 0; i < len(got); i += 2 {
+				k, v := got[i].(string), got[i+1]
+				gotKeys = append(gotKeys, k)
+				gotValues[k] = v
+			}
+
+			sort.Strings(gotKeys)
+
+			sortedGot := make([]interface{}, 0, len(got))
+
+			for _, k := range gotKeys {
+				sortedGot = append(sortedGot, k)
+				sortedGot = append(sortedGot, gotValues[k])
+			}
+
+			if diff := cmp.Diff(sortedGot, testCase.expectedArgs); diff != "" {
+				t.Errorf("unexpected difference: %s", diff)
+			}
+		})
+	}
+}

tflog/provider.go

@@ -3,6 +3,7 @@ package tflog
 import (
 	"context"
 
+	"github.com/hashicorp/terraform-plugin-log/internal/hclogutils"
 	"github.com/hashicorp/terraform-plugin-log/internal/logging"
 )
 
@@ -21,10 +22,11 @@ func With(ctx context.Context, key string, value interface{}) context.Context {
 	return logging.SetProviderRootLogger(ctx, logger.With(key, value))
 }
 
-// Trace logs `msg` at the trace level to the logger in `ctx`, with `args` as
-// structured arguments in the log output. `args` is expected to be pairs of
-// key and value.
-func Trace(ctx context.Context, msg string, args ...interface{}) {
+// Trace logs `msg` at the trace level to the logger in `ctx`, with optional
+// `additionalFields` structured key-value fields in the log output. Fields are
+// shallow merged with any defined on the logger, e.g. by the `With()` function,
+// and across multiple maps.
+func Trace(ctx context.Context, msg string, additionalFields ...map[string]interface{}) {
 	logger := logging.GetProviderRootLogger(ctx)
 	if logger == nil {
 		// this essentially should never happen in production
@@ -34,13 +36,14 @@ func Trace(ctx context.Context, msg string, args ...interface{}) {
 		// so just making this a no-op is fine
 		return
 	}
-	logger.Trace(msg, args...)
+	logger.Trace(msg, hclogutils.MapsToArgs(additionalFields...)...)
 }
 
-// Debug logs `msg` at the debug level to the logger in `ctx`, with `args` as
-// structured arguments in the log output. `args` is expected to be pairs of
-// key and value.
-func Debug(ctx context.Context, msg string, args ...interface{}) {
+// Debug logs `msg` at the debug level to the logger in `ctx`, with optional
+// `additionalFields` structured key-value fields in the log output. Fields are
+// shallow merged with any defined on the logger, e.g. by the `With()` function,
+// and across multiple maps.
+func Debug(ctx context.Context, msg string, additionalFields ...map[string]interface{}) {
 	logger := logging.GetProviderRootLogger(ctx)
 	if logger == nil {
 		// this essentially should never happen in production
@@ -50,13 +53,14 @@ func Debug(ctx context.Context, msg string, args ...interface{}) {
 		// so just making this a no-op is fine
 		return
 	}
-	logger.Debug(msg, args...)
+	logger.Debug(msg, hclogutils.MapsToArgs(additionalFields...)...)
 }
 
-// Info logs `msg` at the info level to the logger in `ctx`, with `args` as
-// structured arguments in the log output. `args` is expected to be pairs of
-// key and value.
-func Info(ctx context.Context, msg string, args ...interface{}) {
+// Info logs `msg` at the info level to the logger in `ctx`, with optional
+// `additionalFields` structured key-value fields in the log output. Fields are
+// shallow merged with any defined on the logger, e.g. by the `With()` function,
+// and across multiple maps.
+func Info(ctx context.Context, msg string, additionalFields ...map[string]interface{}) {
 	logger := logging.GetProviderRootLogger(ctx)
 	if logger == nil {
 		// this essentially should never happen in production
@@ -66,13 +70,14 @@ func Info(ctx context.Context, msg string, args ...interface{}) {
 		// so just making this a no-op is fine
 		return
 	}
-	logger.Info(msg, args...)
+	logger.Info(msg, hclogutils.MapsToArgs(additionalFields...)...)
 }
 
-// Warn logs `msg` at the warn level to the logger in `ctx`, with `args` as
-// structured arguments in the log output. `args` is expected to be pairs of
-// key and value.
-func Warn(ctx context.Context, msg string, args ...interface{}) {
+// Warn logs `msg` at the warn level to the logger in `ctx`, with optional
+// `additionalFields` structured key-value fields in the log output. Fields are
+// shallow merged with any defined on the logger, e.g. by the `With()` function,
+// and across multiple maps.
+func Warn(ctx context.Context, msg string, additionalFields ...map[string]interface{}) {
 	logger := logging.GetProviderRootLogger(ctx)
 	if logger == nil {
 		// this essentially should never happen in production
@@ -82,13 +87,14 @@ func Warn(ctx context.Context, msg string, args ...interface{}) {
 		// so just making this a no-op is fine
 		return
 	}
-	logger.Warn(msg, args...)
+	logger.Warn(msg, hclogutils.MapsToArgs(additionalFields...)...)
 }
 
-// Error logs `msg` at the error level to the logger in `ctx`, with `args` as
-// structured arguments in the log output. `args` is expected to be pairs of
-// key and value.
-func Error(ctx context.Context, msg string, args ...interface{}) {
+// Error logs `msg` at the error level to the logger in `ctx`, with optional
+// `additionalFields` structured key-value fields in the log output. Fields are
+// shallow merged with any defined on the logger, e.g. by the `With()` function,
+// and across multiple maps.
+func Error(ctx context.Context, msg string, additionalFields ...map[string]interface{}) {
 	logger := logging.GetProviderRootLogger(ctx)
 	if logger == nil {
 		// this essentially should never happen in production
@@ -98,5 +104,5 @@ func Error(ctx context.Context, msg string, args ...interface{}) {
 		// so just making this a no-op is fine
 		return
 	}
-	logger.Error(msg, args...)
+	logger.Error(msg, hclogutils.MapsToArgs(additionalFields...)...)
 }

tflog/provider_example_test.go

@@ -47,7 +47,10 @@ func ExampleTrace() {
 	exampleCtx := getExampleContext()
 
 	// non-example-setup code begins here
-	Trace(exampleCtx, "hello, world", "foo", 123, "colors", []string{"red", "blue", "green"})
+	Trace(exampleCtx, "hello, world", map[string]interface{}{
+		"foo":    123,
+		"colors": []string{"red", "blue", "green"},
+	})
 
 	// Output:
 	// {"@level":"trace","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}
@@ -64,7 +67,10 @@ func ExampleDebug() {
 	exampleCtx := getExampleContext()
 
 	// non-example-setup code begins here
-	Debug(exampleCtx, "hello, world", "foo", 123, "colors", []string{"red", "blue", "green"})
+	Debug(exampleCtx, "hello, world", map[string]interface{}{
+		"foo":    123,
+		"colors": []string{"red", "blue", "green"},
+	})
 
 	// Output:
 	// {"@level":"debug","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}
@@ -81,7 +87,10 @@ func ExampleInfo() {
 	exampleCtx := getExampleContext()
 
 	// non-example-setup code begins here
-	Info(exampleCtx, "hello, world", "foo", 123, "colors", []string{"red", "blue", "green"})
+	Info(exampleCtx, "hello, world", map[string]interface{}{
+		"foo":    123,
+		"colors": []string{"red", "blue", "green"},
+	})
 
 	// Output:
 	// {"@level":"info","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}
@@ -98,7 +107,10 @@ func ExampleWarn() {
 	exampleCtx := getExampleContext()
 
 	// non-example-setup code begins here
-	Warn(exampleCtx, "hello, world", "foo", 123, "colors", []string{"red", "blue", "green"})
+	Warn(exampleCtx, "hello, world", map[string]interface{}{
+		"foo":    123,
+		"colors": []string{"red", "blue", "green"},
+	})
 
 	// Output:
 	// {"@level":"warn","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}
@@ -115,7 +127,10 @@ func ExampleError() {
 	exampleCtx := getExampleContext()
 
 	// non-example-setup code begins here
-	Error(exampleCtx, "hello, world", "foo", 123, "colors", []string{"red", "blue", "green"})
+	Error(exampleCtx, "hello, world", map[string]interface{}{
+		"foo":    123,
+		"colors": []string{"red", "blue", "green"},
+	})
 
 	// Output:
 	// {"@level":"error","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}