Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

tflog+tfsdklog: Change final variadic function parameter in logging functions to ...map[string]interface{} #34

Merged
merged 5 commits into from
Mar 8, 2022
Merged

tflog+tfsdklog: Change final variadic function parameter in logging functions to ...map[string]interface{} #34

Show file tree
Hide file tree
Changes from 4 commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
4562edc
tflog+tfsdklog: Change final variadic function parameter in logging f…
bflad Mar 4, 2022
933cd77
Update CHANGELOG for #34
bflad Mar 4, 2022
aa4a5f5
tflog+tfsdklog: Rename additionalPairs to additionalFields
bflad Mar 8, 2022
2e5c436
tflog+tfsdklog: Additional pair to field renaming
bflad Mar 8, 2022
ae49fe5
Merge branch 'main' into bflad-map-parameters
bflad Mar 8, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 7 additions & 0 deletions .changelog/34.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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.
```
36 changes: 36 additions & 0 deletions internal/hclogutils/args.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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)
Comment on lines +19 to +27
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Correct if I'm wrong: what you are really after here (to feed to the second call to make() is for the sum of the number of keys in each map. So the creation of the intermediary mergedMap feels unnecessary memory allocation that will be thrown away when we get out of here.

It is a nitpick, where probably allocating and deallocating a map ain't a bit deal, but I feel Id be remiss if I didn't suggest a cheaper approach:

  • count the sum of keys
  • loop over all maps to add all their keys to the result

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The intermediate map performs key deduplication, otherwise, yeah we would just loop through all the maps to append to a single slice. Refer also to the unit tests such as map-multiple-mixed-keys and map-multiple-overlapping-keys.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I see what you are doing.


for k, v := range mergedMap {
result = append(result, k)
result = append(result, v)
}

return result
}
}
173 changes: 173 additions & 0 deletions internal/hclogutils/args_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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)
}
})
}
}
56 changes: 31 additions & 25 deletions tflog/provider.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package tflog
import (
"context"

"github.com/hashicorp/terraform-plugin-log/internal/hclogutils"
"github.com/hashicorp/terraform-plugin-log/internal/logging"
)

Expand All @@ -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
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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...)...)
}
25 changes: 20 additions & 5 deletions tflog/provider_example_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"},
})
Comment on lines +50 to +53
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Funny enough, I created a similar construct in my last gig: it was Java Exception but the idea was the same. Exceptions happening deep in a call stack would carry extra context in the form of Map.of(PAIRS...) and then New Relic APM would render them as additional context in the error reporting tab.

So, I'm a big fan of this refactoring you are doing.


// Output:
// {"@level":"trace","@message":"hello, world","@module":"provider","colors":["red","blue","green"],"foo":123}
Expand All @@ -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}
Expand All @@ -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}
Expand All @@ -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}
Expand All @@ -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}
Expand Down
Loading