From 6c641bdc799199f4fbf46deaae07e4f3bbbc076f Mon Sep 17 00:00:00 2001 From: Ivan De Marino Date: Thu, 14 Jul 2022 13:06:16 +0100 Subject: [PATCH] Add log filtering functionality (#71) * New utility function in `internal/hclogutils`: `ArgsToKeys` It takes `ImplicitArgs()` from `hclog.Logger`, and returns the keys of the k/v pairs slice * Implementing the business logic of filtering in `internal/logging` package * Defining utilities to create `loggerKey`s for storing log filtering configuration in Context * Exposing log filtering on all offerings of this library - tflog root logger - tflog subsystem logger - tfsdklog root logger - tfsdklog subsystem logger * Adding CHANGELOG entries for log filtering and preparing for v0.5.0 release --- .changelog/71.txt | 15 + CHANGELOG.md | 9 + internal/hclogutils/args.go | 49 ++- internal/hclogutils/args_test.go | 139 ++++++++ internal/logging/filtering.go | 105 ++++++ internal/logging/filtering_test.go | 306 +++++++++++++++++ internal/logging/log.go | 48 ++- internal/logging/options.go | 127 +++++++ internal/logging/provider.go | 36 +- internal/logging/sdk.go | 36 +- tflog/provider.go | 194 ++++++++++- tflog/provider_test.go | 531 ++++++++++++++++++++++++++++ tflog/subsystem.go | 193 ++++++++++- tflog/subsystem_test.go | 535 +++++++++++++++++++++++++++++ tfsdklog/sdk.go | 193 ++++++++++- tfsdklog/sdk_test.go | 531 ++++++++++++++++++++++++++++ tfsdklog/subsystem.go | 193 ++++++++++- tfsdklog/subsystem_test.go | 535 +++++++++++++++++++++++++++++ 18 files changed, 3738 insertions(+), 37 deletions(-) create mode 100644 .changelog/71.txt create mode 100644 internal/logging/filtering.go create mode 100644 internal/logging/filtering_test.go diff --git a/.changelog/71.txt b/.changelog/71.txt new file mode 100644 index 0000000..f89571f --- /dev/null +++ b/.changelog/71.txt @@ -0,0 +1,15 @@ +```release-note:feature +tflog: Added `WithOmitLogWithFieldKeys()`, `WithOmitLogWithMessageRegex()`, `WithOmitLogMatchingString()`, `WithMaskFieldValueWithFieldKeys()`, `WithMaskMessageRegex()` and `WithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for the provider root logger +``` + +```release-note:feature +tflog: Added `SubsystemWithOmitLogWithFieldKeys()`, `SubsystemWithOmitLogWithMessageRegex()`, `SubsystemWithOmitLogMatchingString()`, `SubsystemWithMaskFieldValueWithFieldKeys()`, `SubsystemWithMaskMessageRegex()` and `SubsystemWithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for provider subsystem loggers +``` + +```release-note:feature +tfsdklog: Added `WithOmitLogWithFieldKeys()`, `WithOmitLogWithMessageRegex()`, `WithOmitLogMatchingString()`, `WithMaskFieldValueWithFieldKeys()`, `WithMaskMessageRegex()` and `WithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for the SDK root logger +``` + +```release-note:feature +tfsdklog: Added `SubsystemWithOmitLogWithFieldKeys()`, `SubsystemWithOmitLogWithMessageRegex()`, `SubsystemWithOmitLogMatchingString()`, `SubsystemWithMaskFieldValueWithFieldKeys()`, `SubsystemWithMaskMessageRegex()`and `SubsystemWithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for SDK subsystem loggers +``` diff --git a/CHANGELOG.md b/CHANGELOG.md index a21e032..b25ef71 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,12 @@ +# 0.5.0 (July 14, 2022) + +FEATURES: + +* tflog: Added `SubsystemWithOmitLogWithFieldKeys()`, `SubsystemWithOmitLogWithMessageRegex()`, `SubsystemWithOmitLogMatchingString()`, `SubsystemWithMaskFieldValueWithFieldKeys()`, `SubsystemWithMaskMessageRegex()` and `SubsystemWithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for provider subsystem loggers ([#71](https://github.com/hashicorp/terraform-plugin-log/issues/71)) +* tflog: Added `WithOmitLogWithFieldKeys()`, `WithOmitLogWithMessageRegex()`, `WithOmitLogMatchingString()`, `WithMaskFieldValueWithFieldKeys()`, `WithMaskMessageRegex()` and `WithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for the provider root logger ([#71](https://github.com/hashicorp/terraform-plugin-log/issues/71)) +* tfsdklog: Added `SubsystemWithOmitLogWithFieldKeys()`, `SubsystemWithOmitLogWithMessageRegex()`, `SubsystemWithOmitLogMatchingString()`, `SubsystemWithMaskFieldValueWithFieldKeys()`, `SubsystemWithMaskMessageRegex()`and `SubsystemWithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for SDK subsystem loggers ([#71](https://github.com/hashicorp/terraform-plugin-log/issues/71)) +* tfsdklog: Added `WithOmitLogWithFieldKeys()`, `WithOmitLogWithMessageRegex()`, `WithOmitLogMatchingString()`, `WithMaskFieldValueWithFieldKeys()`, `WithMaskMessageRegex()` and `WithMaskLogMatchingString()` functions, which provide log omission and log masking filtering, based on message and argument keys, for the SDK root logger ([#71](https://github.com/hashicorp/terraform-plugin-log/issues/71)) + # 0.4.1 (June 6, 2022) NOTES: diff --git a/internal/hclogutils/args.go b/internal/hclogutils/args.go index 220120f..9e13e71 100644 --- a/internal/hclogutils/args.go +++ b/internal/hclogutils/args.go @@ -1,7 +1,11 @@ package hclogutils -// MapsToArgs will shallow merge field maps into the slice of key1, value1, -// key2, value2, ... arguments expected by hc-log.Logger methods. +import ( + "fmt" +) + +// MapsToArgs will shallow merge field maps into a slice of key/value pairs +// arguments (i.e. `[k1, v1, k2, v2, ...]`) expected by hc-log.Logger methods. func MapsToArgs(maps ...map[string]interface{}) []interface{} { switch len(maps) { case 0: @@ -10,27 +14,50 @@ func MapsToArgs(maps ...map[string]interface{}) []interface{} { result := make([]interface{}, 0, len(maps[0])*2) for k, v := range maps[0] { - result = append(result, k) - result = append(result, v) + result = append(result, k, v) } return result default: - mergedMap := make(map[string]interface{}, 0) + // Pre-allocate a map to merge all the maps into, + // that has at least the capacity equivalent to the number + // of maps to merge + mergedMap := make(map[string]interface{}, len(maps)) + // Merge all the maps into one; + // in case of clash, only the last key is preserved for _, m := range maps { for k, v := range m { mergedMap[k] = v } } - result := make([]interface{}, 0, len(mergedMap)*2) + // As we have merged all maps into one, we can use this + // same function recursively for the `switch case 1`. + return MapsToArgs(mergedMap) + } +} - for k, v := range mergedMap { - result = append(result, k) - result = append(result, v) - } +// ArgsToKeys will extract all keys from a slice of key/value pairs +// arguments (i.e. `[k1, v1, k2, v2, ...]`) expected by hc-log.Logger methods. +// +// Note that, in case of an odd number of arguments, the last key captured +// will refer to a value that does not actually exist. +func ArgsToKeys(args []interface{}) []string { + // Pre-allocate enough capacity to fit all the keys, + // i.e. all the elements in the input array in even position + keys := make([]string, 0, len(args)/2) - return result + for i := 0; i < len(args); i += 2 { + // All keys should be strings, but in case they are not + // we format them to string + switch k := args[i].(type) { + case string: + keys = append(keys, k) + default: + keys = append(keys, fmt.Sprintf("%s", k)) + } } + + return keys } diff --git a/internal/hclogutils/args_test.go b/internal/hclogutils/args_test.go index 53cb66b..22dd976 100644 --- a/internal/hclogutils/args_test.go +++ b/internal/hclogutils/args_test.go @@ -171,3 +171,142 @@ func TestMapsToArgs(t *testing.T) { }) } } + +func TestArgsToKeys(t *testing.T) { + t.Parallel() + + testCases := map[string]struct { + args []interface{} + expectedKeys []string + }{ + "nil": { + args: []interface{}{}, + expectedKeys: []string{}, + }, + "simple": { + args: []interface{}{ + "map1-key1", "map1-value1", + "map1-key2", "map1-value2", + "map1-key3", "map1-value3", + }, + expectedKeys: []string{ + "map1-key1", + "map1-key2", + "map1-key3", + }, + }, + "non-even-number-of-args": { + args: []interface{}{ + "map1-key1", "map1-value1", + "map1-key2", "map1-value2", + "map1-key3", + }, + expectedKeys: []string{ + "map1-key1", + "map1-key2", + "map1-key3", + }, + }, + "multiple-different-keys": { + args: []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", + }, + expectedKeys: []string{ + "map1-key1", + "map1-key2", + "map1-key3", + "map2-key1", + "map2-key2", + "map2-key3", + }, + }, + "multiple-mixed-keys": { + args: []interface{}{ + "key1", "map1-value1", + "key2", "map1-value2", + "key3", "map1-value3", + "key4", "map2-value4", + "key1", "map2-value1", + "key5", "map2-value5", + }, + expectedKeys: []string{ + "key1", + "key2", + "key3", + "key4", + "key1", + "key5", + }, + }, + "multiple-overlapping-keys": { + args: []interface{}{ + "key1", "map1-value1", + "key2", "map1-value2", + "key3", "map1-value3", + "key1", "map2-value1", + "key2", "map2-value2", + "key3", "map2-value3", + }, + expectedKeys: []string{ + "key1", + "key2", + "key3", + "key1", + "key2", + "key3", + }, + }, + "multiple-overlapping-keys-shallow": { + args: []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", + }, + expectedKeys: []string{ + "key1", + "key2", + "key3", + "key1", + "key2", + "key3", + }, + }, + } + + for name, testCase := range testCases { + name, testCase := name, testCase + + t.Run(name, func(t *testing.T) { + t.Parallel() + + got := hclogutils.ArgsToKeys(testCase.args) + + if got == nil && testCase.expectedKeys == nil { + return // sortedGot will return []interface{}{} below, nil is what we want + } + + sort.Strings(got) + sort.Strings(testCase.expectedKeys) + + if diff := cmp.Diff(got, testCase.expectedKeys); diff != "" { + t.Errorf("unexpected difference: %s", diff) + } + }) + } +} diff --git a/internal/logging/filtering.go b/internal/logging/filtering.go new file mode 100644 index 0000000..0834911 --- /dev/null +++ b/internal/logging/filtering.go @@ -0,0 +1,105 @@ +package logging + +import ( + "fmt" + "strings" + + "github.com/hashicorp/terraform-plugin-log/internal/hclogutils" +) + +const logMaskingReplacementString = "***" + +// ShouldOmit takes a log's *string message and slices of arguments, +// and determines, based on the LoggerOpts configuration, if the +// log should be omitted (i.e. prevent it to be printed on the final writer). +func (lo LoggerOpts) ShouldOmit(msg *string, argSlices ...[]interface{}) bool { + // Omit log if any of the configured keys is found + // either in the logger implied arguments, + // or in the additional arguments + if len(lo.OmitLogWithFieldKeys) > 0 { + for _, args := range argSlices { + argKeys := hclogutils.ArgsToKeys(args) + if argKeysContain(argKeys, lo.OmitLogWithFieldKeys) { + return true + } + } + } + + // Omit log if any of the configured regexp matches the log message + if len(lo.OmitLogWithMessageRegex) > 0 { + for _, r := range lo.OmitLogWithMessageRegex { + if r.MatchString(*msg) { + return true + } + } + } + + // Omit log if any of the configured strings is contained in the log message + if len(lo.OmitLogWithMessageStrings) > 0 { + for _, s := range lo.OmitLogWithMessageStrings { + if strings.Contains(*msg, s) { + return true + } + } + } + + return false +} + +// ApplyMask takes a log's *string message and slices of arguments, +// and applies masking of keys' values and/or message, +// based on the LoggerOpts configuration. +// +// Note that the given input is changed-in-place by this method. +func (lo LoggerOpts) ApplyMask(msg *string, argSlices ...[]interface{}) { + if len(lo.MaskFieldValueWithFieldKeys) > 0 { + for _, k := range lo.MaskFieldValueWithFieldKeys { + for _, args := range argSlices { + // Here we loop `i` with steps of 2, starting from position 1 (i.e. `1, 3, 5, 7...`). + // We then look up the key for each argument, by looking at `i-1`. + // This ensures that in case of malformed arg slices that don't have + // an even number of elements, we simply skip the last k/v pair. + for i := 1; i < len(args); i += 2 { + switch argK := args[i-1].(type) { + case string: + if k == argK { + args[i] = logMaskingReplacementString + } + default: + if k == fmt.Sprintf("%s", argK) { + args[i] = logMaskingReplacementString + } + } + } + } + } + } + + // Replace any part of the log message matching any of the configured regexp, + // with a masking replacement string + if len(lo.MaskMessageRegex) > 0 { + for _, r := range lo.MaskMessageRegex { + *msg = r.ReplaceAllString(*msg, logMaskingReplacementString) + } + } + + // Replace any part of the log message equal to any of the configured strings, + // with a masking replacement string + if len(lo.MaskMessageStrings) > 0 { + for _, s := range lo.MaskMessageStrings { + *msg = strings.ReplaceAll(*msg, s, logMaskingReplacementString) + } + } +} + +func argKeysContain(haystack []string, needles []string) bool { + for _, h := range haystack { + for _, n := range needles { + if n == h { + return true + } + } + } + + return false +} diff --git a/internal/logging/filtering_test.go b/internal/logging/filtering_test.go new file mode 100644 index 0000000..4f77858 --- /dev/null +++ b/internal/logging/filtering_test.go @@ -0,0 +1,306 @@ +package logging + +import ( + "regexp" + "testing" + + "github.com/google/go-cmp/cmp" +) + +const testLogMsg = "System FOO has caused error BAR because of incorrectly configured BAZ" + +func TestShouldOmit(t *testing.T) { + t.Parallel() + + testCases := map[string]struct { + lOpts LoggerOpts + msg string + argSlices [][]interface{} + expectedToOmit bool + }{ + "empty-opts": { + lOpts: LoggerOpts{}, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: false, + }, + "omit-log-by-key": { + lOpts: LoggerOpts{ + OmitLogWithFieldKeys: []string{"k2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: true, + }, + "no-omit-log-by-key-if-case-mismatches": { + lOpts: LoggerOpts{ + OmitLogWithFieldKeys: []string{"K2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: false, + }, + "do-not-omit-log-by-key": { + lOpts: LoggerOpts{ + OmitLogWithFieldKeys: []string{"k3"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: false, + }, + "omit-log-matching-regexp-case-insensitive": { + lOpts: LoggerOpts{ + OmitLogWithMessageRegex: []*regexp.Regexp{regexp.MustCompile("(?i)(foo|bar)")}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: true, + }, + "do-not-omit-log-matching-regexp-case-sensitive": { + lOpts: LoggerOpts{ + OmitLogWithMessageRegex: []*regexp.Regexp{regexp.MustCompile("(foo|bar)")}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedToOmit: false, + }, + } + + for name, testCase := range testCases { + name, testCase := name, testCase + + t.Run(name, func(t *testing.T) { + t.Parallel() + + got := testCase.lOpts.ShouldOmit(&testCase.msg, testCase.argSlices...) + + if got != testCase.expectedToOmit { + t.Errorf("expected ShouldOmit to return %t, got %t", testCase.expectedToOmit, got) + } + }) + } +} + +func TestApplyMask(t *testing.T) { + t.Parallel() + + testCases := map[string]struct { + lOpts LoggerOpts + msg string + argSlices [][]interface{} + expectedMsg string + expectedArgSlices [][]interface{} + }{ + "empty-opts": { + lOpts: LoggerOpts{}, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System FOO has caused error BAR because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + }, + "mask-log-by-key": { + lOpts: LoggerOpts{ + MaskFieldValueWithFieldKeys: []string{"k2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System FOO has caused error BAR because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "***", + }, + }, + }, + "no-mask-log-by-key-if-case-mismatches": { + lOpts: LoggerOpts{ + MaskFieldValueWithFieldKeys: []string{"K2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System FOO has caused error BAR because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + }, + "mask-log-by-non-even-args-cannot-mask-missing-value": { + lOpts: LoggerOpts{ + MaskFieldValueWithFieldKeys: []string{"k2", "k4"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + { + "k3", "v3", + "k4", + }, + }, + expectedMsg: "System FOO has caused error BAR because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "***", + }, + { + "k3", "v3", + "k4", + }, + }, + }, + "mask-log-by-non-even-args": { + lOpts: LoggerOpts{ + MaskFieldValueWithFieldKeys: []string{"k2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + "k3", "v3", + "k4", + }, + }, + expectedMsg: "System FOO has caused error BAR because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "***", + "k3", "v3", + "k4", + }, + }, + }, + "mask-log-matching-regexp-case-insensitive": { + lOpts: LoggerOpts{ + MaskMessageRegex: []*regexp.Regexp{regexp.MustCompile("(?i)(foo|bar)")}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System *** has caused error *** because of incorrectly configured BAZ", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + }, + "mask-log-matching-regexp-case-sensitive": { + lOpts: LoggerOpts{ + MaskMessageRegex: []*regexp.Regexp{regexp.MustCompile("incorrectly configured BAZ")}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System FOO has caused error BAR because of ***", + expectedArgSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + }, + "mask-log-by-key-and-matching-regexp": { + lOpts: LoggerOpts{ + MaskMessageRegex: []*regexp.Regexp{regexp.MustCompile("incorrectly configured BAZ")}, + MaskFieldValueWithFieldKeys: []string{"k1", "k2"}, + }, + msg: testLogMsg, + argSlices: [][]interface{}{ + { + "k1", "v1", + "k2", "v2", + }, + }, + expectedMsg: "System FOO has caused error BAR because of ***", + expectedArgSlices: [][]interface{}{ + { + "k1", "***", + "k2", "***", + }, + }, + }, + } + + for name, testCase := range testCases { + name, testCase := name, testCase + + t.Run(name, func(t *testing.T) { + t.Parallel() + + testCase.lOpts.ApplyMask(&testCase.msg, testCase.argSlices...) + + if diff := cmp.Diff(testCase.msg, testCase.expectedMsg); diff != "" { + t.Errorf("unexpected difference detected in log message: %s", diff) + } + + if diff := cmp.Diff(testCase.argSlices, testCase.expectedArgSlices); diff != "" { + t.Errorf("unexpected difference detected in log arguments: %s", diff) + } + }) + } +} diff --git a/internal/logging/log.go b/internal/logging/log.go index 983bc87..4aa80bb 100644 --- a/internal/logging/log.go +++ b/internal/logging/log.go @@ -6,10 +6,10 @@ import ( ) const ( - // Default provider root logger name. + // DefaultProviderRootLoggerName is the default provider root logger name. DefaultProviderRootLoggerName string = "provider" - // Default SDK root logger name. + // DefaultSDKRootLoggerName is the default SDK root logger name. DefaultSDKRootLoggerName string = "sdk" ) @@ -47,8 +47,52 @@ const ( // 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" + + // TFLoggerOpts is the loggerKey that will hold the LoggerOpts associated + // with the provider root logger (at `provider.tf-logger-opts`), and the + // provider sub-system logger (at `provider.SUBSYSTEM.tf-logger-opts`), + // in the context.Context. + // Note that only some LoggerOpts require to be stored this way, + // while others use the underlying *hclog.LoggerOptions of hclog.Logger. + TFLoggerOpts loggerKey = "tf-logger-opts" ) +// providerSubsystemLoggerKey is the loggerKey that will hold the subsystem logger +// for writing logs from within a provider subsystem. +func providerSubsystemLoggerKey(subsystem string) loggerKey { + return ProviderRootLoggerKey + loggerKey("."+subsystem) +} + +// providerRootTFLoggerOptsKey is the loggerKey that will hold +// the LoggerOpts of the provider. +func providerRootTFLoggerOptsKey() loggerKey { + return ProviderRootLoggerKey + "." + TFLoggerOpts +} + +// providerRootTFLoggerOptsKey is the loggerKey that will hold +// the LoggerOpts of a provider subsystem. +func providerSubsystemTFLoggerOptsKey(subsystem string) loggerKey { + return providerSubsystemLoggerKey(subsystem) + "." + TFLoggerOpts +} + +// providerSubsystemLoggerKey is the loggerKey that will hold the subsystem logger +// for writing logs from within an SDK subsystem. +func sdkSubsystemLoggerKey(subsystem string) loggerKey { + return SDKRootLoggerKey + loggerKey("."+subsystem) +} + +// sdkRootTFLoggerOptsKey is the loggerKey that will hold +// the LoggerOpts of the SDK. +func sdkRootTFLoggerOptsKey() loggerKey { + return SDKRootLoggerKey + "." + TFLoggerOpts +} + +// sdkSubsystemTFLoggerOptsKey is the loggerKey that will hold +// the LoggerOpts of an SDK subsystem. +func sdkSubsystemTFLoggerOptsKey(subsystem string) loggerKey { + return sdkSubsystemLoggerKey(subsystem) + "." + TFLoggerOpts +} + var ( // Stderr caches the original os.Stderr when the process is started. // diff --git a/internal/logging/options.go b/internal/logging/options.go index 02891a3..a1467dd 100644 --- a/internal/logging/options.go +++ b/internal/logging/options.go @@ -3,6 +3,7 @@ package logging import ( "io" "os" + "regexp" "github.com/hashicorp/go-hclog" ) @@ -44,6 +45,84 @@ type LoggerOpts struct { // copy existing fields from the root logger. This is only performed // at the time of new subsystem creation. IncludeRootFields bool + + // OmitLogWithFieldKeys indicates that the logger should omit to write + // any log when any of the given keys is found within the arguments. + // + // Example: + // + // OmitLogWithFieldKeys = `['foo', 'baz']` + // + // log1 = `{ msg = "...", args = { 'foo', '...', 'bar', '...' }` -> omitted + // log2 = `{ msg = "...", args = { 'bar', '...' }` -> printed + // log3 = `{ msg = "...", args = { 'baz`', '...', 'boo', '...' }` -> omitted + // + OmitLogWithFieldKeys []string + + // OmitLogWithMessageRegex indicates that the logger should omit to write + // any log that matches any of the given *regexp.Regexp. + // + // Example: + // + // OmitLogWithMessageRegex = `[regexp.MustCompile("(foo|bar)")]` + // + // log1 = `{ msg = "banana apple foo", args = {...}` -> omitted + // log2 = `{ msg = "pineapple mango", args = {...}` -> printed + // log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted + // + OmitLogWithMessageRegex []*regexp.Regexp + + // OmitLogWithMessageStrings indicates that the logger should omit to write + // any log that matches any of the given string. + // + // Example: + // + // OmitLogWithMessageStrings = `['foo', 'bar']` + // + // log1 = `{ msg = "banana apple foo", args = {...}` -> omitted + // log2 = `{ msg = "pineapple mango", args = {...}` -> printed + // log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted + // + OmitLogWithMessageStrings []string + + // MaskFieldValueWithFieldKeys indicates that the logger should mask with asterisks (`*`) + // any argument value where the key matches one of the given keys. + // + // Example: + // + // MaskFieldValueWithFieldKeys = `['foo', 'baz']` + // + // log1 = `{ msg = "...", args = { 'foo', '***', 'bar', '...' }` -> masked value + // log2 = `{ msg = "...", args = { 'bar', '...' }` -> as-is value + // log3 = `{ msg = "...", args = { 'baz`', '***', 'boo', '...' }` -> masked value + // + MaskFieldValueWithFieldKeys []string + + // MaskMessageRegex indicates that the logger should replace, within + // a log message, the portion matching one of the given *regexp.Regexp. + // + // Example: + // + // MaskMessageRegex = `[regexp.MustCompile("(foo|bar)")]` + // + // log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion + // log2 = `{ msg = "pineapple mango", args = {...}` -> as-is + // log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion + // + MaskMessageRegex []*regexp.Regexp + + // MaskMessageStrings indicates that the logger should replace, within + // a log message, the portion matching one of the given strings. + // + // Example: + // + // MaskMessageStrings = `['foo', 'bar']` + // + // log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion + // log2 = `{ msg = "pineapple mango", args = {...}` -> as-is + // log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion + // + MaskMessageStrings []string } // ApplyLoggerOpts generates a LoggerOpts out of a list of Option @@ -114,3 +193,51 @@ func WithoutTimestamp() Option { return l } } + +// WithOmitLogWithFieldKeys appends keys to the LoggerOpts.OmitLogWithFieldKeys field. +func WithOmitLogWithFieldKeys(keys ...string) Option { + return func(l LoggerOpts) LoggerOpts { + l.OmitLogWithFieldKeys = append(l.OmitLogWithFieldKeys, keys...) + return l + } +} + +// WithOmitLogWithMessageRegex appends *regexp.Regexp to the LoggerOpts.OmitLogWithMessageRegex field. +func WithOmitLogWithMessageRegex(expressions ...*regexp.Regexp) Option { + return func(l LoggerOpts) LoggerOpts { + l.OmitLogWithMessageRegex = append(l.OmitLogWithMessageRegex, expressions...) + return l + } +} + +// WithOmitLogWithMessageStrings appends string to the LoggerOpts.OmitLogWithMessageStrings field. +func WithOmitLogWithMessageStrings(matchingStrings ...string) Option { + return func(l LoggerOpts) LoggerOpts { + l.OmitLogWithMessageStrings = append(l.OmitLogWithMessageStrings, matchingStrings...) + return l + } +} + +// WithMaskFieldValueWithFieldKeys appends keys to the LoggerOpts.MaskFieldValueWithFieldKeys field. +func WithMaskFieldValueWithFieldKeys(keys ...string) Option { + return func(l LoggerOpts) LoggerOpts { + l.MaskFieldValueWithFieldKeys = append(l.MaskFieldValueWithFieldKeys, keys...) + return l + } +} + +// WithMaskMessageRegex appends *regexp.Regexp to the LoggerOpts.MaskMessageRegex field. +func WithMaskMessageRegex(expressions ...*regexp.Regexp) Option { + return func(l LoggerOpts) LoggerOpts { + l.MaskMessageRegex = append(l.MaskMessageRegex, expressions...) + return l + } +} + +// WithMaskMessageStrings appends string to the LoggerOpts.MaskMessageStrings field. +func WithMaskMessageStrings(matchingStrings ...string) Option { + return func(l LoggerOpts) LoggerOpts { + l.MaskMessageStrings = append(l.MaskMessageStrings, matchingStrings...) + return l + } +} diff --git a/internal/logging/provider.go b/internal/logging/provider.go index b40a12f..0e6e8f5 100644 --- a/internal/logging/provider.go +++ b/internal/logging/provider.go @@ -60,7 +60,7 @@ const NewProviderSubsystemLoggerWarning = "This log was generated by a subsystem // subsystem in provider space. If no such subsystem logger has been created, // it will return nil. func GetProviderSubsystemLogger(ctx context.Context, subsystem string) hclog.Logger { - logger := ctx.Value(ProviderRootLoggerKey + loggerKey("."+subsystem)) + logger := ctx.Value(providerSubsystemLoggerKey(subsystem)) if logger == nil { return nil } @@ -70,5 +70,37 @@ func GetProviderSubsystemLogger(ctx context.Context, subsystem string) hclog.Log // SetProviderSubsystemLogger sets `logger` as the logger for the named // subsystem in provider space. func SetProviderSubsystemLogger(ctx context.Context, subsystem string, logger hclog.Logger) context.Context { - return context.WithValue(ctx, ProviderRootLoggerKey+loggerKey("."+subsystem), logger) + return context.WithValue(ctx, providerSubsystemLoggerKey(subsystem), logger) +} + +// GetProviderRootTFLoggerOpts retrieves the LoggerOpts of the provider root logger. +// The value is stored in the context.Context: if none is found, a new one will be created. +func GetProviderRootTFLoggerOpts(ctx context.Context) LoggerOpts { + lOpts, ok := ctx.Value(providerRootTFLoggerOptsKey()).(LoggerOpts) + if !ok { + lOpts = LoggerOpts{} + } + + return lOpts +} + +// SetProviderRootTFLoggerOpts sets the LoggerOpts of the provider root logger, in the context. +func SetProviderRootTFLoggerOpts(ctx context.Context, lOpts LoggerOpts) context.Context { + return context.WithValue(ctx, providerRootTFLoggerOptsKey(), lOpts) +} + +// GetProviderSubsystemTFLoggerOpts retrieves the LoggerOpts of the logger for the named provider subsystem. +// The value is stored in the context.Context: if none is found, a new one will be created. +func GetProviderSubsystemTFLoggerOpts(ctx context.Context, subsystem string) LoggerOpts { + lOpts, ok := ctx.Value(providerSubsystemTFLoggerOptsKey(subsystem)).(LoggerOpts) + if !ok { + lOpts = LoggerOpts{} + } + + return lOpts +} + +// SetProviderSubsystemTFLoggerOpts sets the LoggerOpts of the logger for the named provider subsystem, in the context. +func SetProviderSubsystemTFLoggerOpts(ctx context.Context, subsystem string, lOpts LoggerOpts) context.Context { + return context.WithValue(ctx, providerSubsystemTFLoggerOptsKey(subsystem), lOpts) } diff --git a/internal/logging/sdk.go b/internal/logging/sdk.go index 3c6772b..034e928 100644 --- a/internal/logging/sdk.go +++ b/internal/logging/sdk.go @@ -51,6 +51,22 @@ func SetSDKRootLoggerOptions(ctx context.Context, loggerOptions *hclog.LoggerOpt return context.WithValue(ctx, SDKRootLoggerOptionsKey, loggerOptions) } +// GetSDKRootTFLoggerOpts retrieves the LoggerOpts of the SDK root logger. +// The value is stored in the context.Context: if none is found, a new one will be created. +func GetSDKRootTFLoggerOpts(ctx context.Context) LoggerOpts { + lOpts, ok := ctx.Value(sdkRootTFLoggerOptsKey()).(LoggerOpts) + if !ok { + lOpts = LoggerOpts{} + } + + return lOpts +} + +// SetSDKRootTFLoggerOpts sets the LoggerOpts of the SDK root logger, in the context. +func SetSDKRootTFLoggerOpts(ctx context.Context, lOpts LoggerOpts) context.Context { + return context.WithValue(ctx, sdkRootTFLoggerOptsKey(), lOpts) +} + // NewSDKSubsystemLoggerWarning is the text included in log output when a // subsystem is auto-generated by terraform-plugin-log because it was used // before the SDK instantiated it. @@ -60,7 +76,7 @@ const NewSDKSubsystemLoggerWarning = "This log was generated by an SDK subsystem // in SDK space. If no such subsystem logger has been created, it will return // nil. func GetSDKSubsystemLogger(ctx context.Context, subsystem string) hclog.Logger { - logger := ctx.Value(SDKRootLoggerKey + loggerKey("."+subsystem)) + logger := ctx.Value(sdkSubsystemLoggerKey(subsystem)) if logger == nil { return nil } @@ -70,5 +86,21 @@ func GetSDKSubsystemLogger(ctx context.Context, subsystem string) hclog.Logger { // SetSDKSubsystemLogger sets `logger` as the logger for the named subsystem in // SDK space. func SetSDKSubsystemLogger(ctx context.Context, subsystem string, logger hclog.Logger) context.Context { - return context.WithValue(ctx, SDKRootLoggerKey+loggerKey("."+subsystem), logger) + return context.WithValue(ctx, sdkSubsystemLoggerKey(subsystem), logger) +} + +// GetSDKSubsystemTFLoggerOpts retrieves the LoggerOpts of the logger for the named SDK subsystem. +// The value is stored in the context.Context: if none is found, a new one will be created. +func GetSDKSubsystemTFLoggerOpts(ctx context.Context, subsystem string) LoggerOpts { + lOpts, ok := ctx.Value(sdkSubsystemTFLoggerOptsKey(subsystem)).(LoggerOpts) + if !ok { + lOpts = LoggerOpts{} + } + + return lOpts +} + +// SetSDKSubsystemTFLoggerOpts sets the LoggerOpts of the logger for the named SDK subsystem, in the context. +func SetSDKSubsystemTFLoggerOpts(ctx context.Context, subsystem string, lOpts LoggerOpts) context.Context { + return context.WithValue(ctx, sdkSubsystemTFLoggerOptsKey(subsystem), lOpts) } diff --git a/tflog/provider.go b/tflog/provider.go index e450e3b..8da74d8 100644 --- a/tflog/provider.go +++ b/tflog/provider.go @@ -2,7 +2,9 @@ package tflog import ( "context" + "regexp" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/terraform-plugin-log/internal/hclogutils" "github.com/hashicorp/terraform-plugin-log/internal/logging" ) @@ -36,7 +38,13 @@ func Trace(ctx context.Context, msg string, additionalFields ...map[string]inter // so just making this a no-op is fine return } - logger.Trace(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Trace(msg, additionalArgs...) } // Debug logs `msg` at the debug level to the logger in `ctx`, with optional @@ -53,7 +61,13 @@ func Debug(ctx context.Context, msg string, additionalFields ...map[string]inter // so just making this a no-op is fine return } - logger.Debug(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Debug(msg, additionalArgs...) } // Info logs `msg` at the info level to the logger in `ctx`, with optional @@ -70,7 +84,13 @@ func Info(ctx context.Context, msg string, additionalFields ...map[string]interf // so just making this a no-op is fine return } - logger.Info(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Info(msg, additionalArgs...) } // Warn logs `msg` at the warn level to the logger in `ctx`, with optional @@ -87,7 +107,13 @@ func Warn(ctx context.Context, msg string, additionalFields ...map[string]interf // so just making this a no-op is fine return } - logger.Warn(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Warn(msg, additionalArgs...) } // Error logs `msg` at the error level to the logger in `ctx`, with optional @@ -104,5 +130,163 @@ func Error(ctx context.Context, msg string, additionalFields ...map[string]inter // so just making this a no-op is fine return } - logger.Error(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Error(msg, additionalArgs...) +} + +func omitOrMask(ctx context.Context, logger hclog.Logger, msg *string, additionalFields []map[string]interface{}) ([]interface{}, bool) { + tfLoggerOpts := logging.GetProviderRootTFLoggerOpts(ctx) + additionalArgs := hclogutils.MapsToArgs(additionalFields...) + impliedArgs := logger.ImpliedArgs() + + // Apply the provider root LoggerOpts to determine if this log should be omitted + if tfLoggerOpts.ShouldOmit(msg, impliedArgs, additionalArgs) { + return nil, true + } + + // Apply the provider root LoggerOpts to apply masking to this log + tfLoggerOpts.ApplyMask(msg, impliedArgs, additionalArgs) + return additionalArgs, false +} + +// WithOmitLogWithFieldKeys returns a new context.Context that has a modified logger +// that will omit to write any log when any of the given keys is found +// within the arguments. +// +// Each call to this function is additive: +// the keys to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '...', 'bar', '...' }` -> omitted +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> printed +// log3 = `{ msg = "...", args = { 'baz`', '...', 'boo', '...' }` -> omitted +// +func WithOmitLogWithFieldKeys(ctx context.Context, keys ...string) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) +} + +// WithOmitLogWithMessageRegex returns a new context.Context that has a modified logger +// that will omit to write any log that has a message matching any of the +// given *regexp.Regexp. +// +// Each call to this function is additive: +// the regexp to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func WithOmitLogWithMessageRegex(ctx context.Context, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithMessageRegex(expressions...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) +} + +// WithOmitLogMatchingString returns a new context.Context that has a modified logger +// that will omit to write any log that matches any of the given string. +// +// Each call to this function is additive: +// the string to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func WithOmitLogMatchingString(ctx context.Context, matchingStrings ...string) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskFieldValueWithFieldKeys returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) any argument value where the +// key matches one of the given keys. +// +// Each call to this function is additive: +// the keys to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '***', 'bar', '...' }` -> masked value +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> as-is value +// log3 = `{ msg = "...", args = { 'baz`', '***', 'boo', '...' }` -> masked value +// +func WithMaskFieldValueWithFieldKeys(ctx context.Context, keys ...string) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskFieldValueWithFieldKeys(keys...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskMessageRegex returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) all message substrings matching one +// of the given strings. +// +// Each call to this function is additive: +// the regexp to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func WithMaskMessageRegex(ctx context.Context, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskMessageRegex(expressions...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskLogMatchingString returns a new context.Context that has a modified logger +// that masks (replace) with asterisks (`***`) all message substrings equal to one +// of the given strings. +// +// Each call to this function is additive: +// the string to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func WithMaskLogMatchingString(ctx context.Context, matchingStrings ...string) context.Context { + lOpts := logging.GetProviderRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts) + + return logging.SetProviderRootTFLoggerOpts(ctx, lOpts) } diff --git a/tflog/provider_test.go b/tflog/provider_test.go index 1583045..a18c6c9 100644 --- a/tflog/provider_test.go +++ b/tflog/provider_test.go @@ -3,6 +3,7 @@ package tflog_test import ( "bytes" "context" + "regexp" "testing" "github.com/google/go-cmp/cmp" @@ -561,3 +562,533 @@ func TestError(t *testing.T) { }) } } + +const testLogMsg = "System FOO has caused error BAR because of incorrectly configured BAZ" + +func TestWithOmitLogWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k1"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.WithOmitLogWithFieldKeys(ctx, testCase.omitLogKeys...) + + tflog.Warn(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithOmitLogWithMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.WithOmitLogWithMessageRegex(ctx, testCase.omitLogMatchingRegexp...) + + tflog.Debug(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithOmitLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BAZ"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.WithOmitLogMatchingString(ctx, testCase.omitLogMatchingString...) + + tflog.Debug(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskFieldValueWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k1", "k2", "k3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "***", + "k2": "***", + }, + }, + }, + } + + 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) + ctx = tflog.WithMaskFieldValueWithFieldKeys(ctx, testCase.maskLogKeys...) + + tflog.Error(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured ***", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tflog.WithMaskMessageRegex(ctx, testCase.maskLogMatchingRegexp...) + + tflog.Trace(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"incorrectly configured BAZ"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of ***", + "@module": "provider", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tflog.WithMaskLogMatchingString(ctx, testCase.maskLogMatchingString...) + + tflog.Info(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} diff --git a/tflog/subsystem.go b/tflog/subsystem.go index 5cf08f2..cce37f5 100644 --- a/tflog/subsystem.go +++ b/tflog/subsystem.go @@ -2,6 +2,7 @@ package tflog import ( "context" + "regexp" "github.com/hashicorp/go-hclog" "github.com/hashicorp/terraform-plugin-log/internal/hclogutils" @@ -105,7 +106,13 @@ func SubsystemTrace(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetProviderSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewProviderSubsystemLoggerWarning) } - logger.Trace(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Trace(msg, additionalArgs...) } // SubsystemDebug logs `msg` at the debug level to the subsystem logger @@ -124,7 +131,13 @@ func SubsystemDebug(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetProviderSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewProviderSubsystemLoggerWarning) } - logger.Debug(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Debug(msg, additionalArgs...) } // SubsystemInfo logs `msg` at the info level to the subsystem logger @@ -143,7 +156,13 @@ func SubsystemInfo(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetProviderSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewProviderSubsystemLoggerWarning) } - logger.Info(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Info(msg, additionalArgs...) } // SubsystemWarn logs `msg` at the warn level to the subsystem logger @@ -162,7 +181,13 @@ func SubsystemWarn(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetProviderSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewProviderSubsystemLoggerWarning) } - logger.Warn(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Warn(msg, additionalArgs...) } // SubsystemError logs `msg` at the error level to the subsystem logger @@ -181,5 +206,163 @@ func SubsystemError(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetProviderSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewProviderSubsystemLoggerWarning) } - logger.Error(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Error(msg, additionalArgs...) +} + +func subsystemOmitOrMask(ctx context.Context, logger hclog.Logger, subsystem string, msg *string, additionalFields []map[string]interface{}) ([]interface{}, bool) { + tfLoggerOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + additionalArgs := hclogutils.MapsToArgs(additionalFields...) + impliedArgs := logger.ImpliedArgs() + + // Apply the provider root LoggerOpts to determine if this log should be omitted + if tfLoggerOpts.ShouldOmit(msg, impliedArgs, additionalArgs) { + return nil, true + } + + // Apply the provider root LoggerOpts to apply masking to this log + tfLoggerOpts.ApplyMask(msg, impliedArgs, additionalArgs) + return additionalArgs, false +} + +// SubsystemWithOmitLogWithFieldKeys returns a new context.Context that has a modified logger +// that will omit to write any log when any of the given keys is found +// within the arguments. +// +// Each call to this function is additive: +// the keys to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '...', 'bar', '...' }` -> omitted +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> printed +// log3 = `{ msg = "...", args = { 'baz`', '...', 'boo', '...' }` -> omitted +// +func SubsystemWithOmitLogWithFieldKeys(ctx context.Context, subsystem string, keys ...string) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithOmitLogWithMessageRegex returns a new context.Context that has a modified logger +// that will omit to write any log that has a message matching any of the +// given *regexp.Regexp. +// +// Each call to this function is additive: +// the regexp to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func SubsystemWithOmitLogWithMessageRegex(ctx context.Context, subsystem string, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithMessageRegex(expressions...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithOmitLogMatchingString returns a new context.Context that has a modified logger +// that will omit to write any log that matches any of the given string. +// +// Each call to this function is additive: +// the string to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func SubsystemWithOmitLogMatchingString(ctx context.Context, subsystem string, matchingStrings ...string) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskFieldValueWithFieldKeys returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) any argument value where the +// key matches one of the given keys. +// +// Each call to this function is additive: +// the keys to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '***', 'bar', '...' }` -> masked value +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> as-is value +// log3 = `{ msg = "...", args = { 'baz`', '***', 'boo', '...' }` -> masked value +// +func SubsystemWithMaskFieldValueWithFieldKeys(ctx context.Context, subsystem string, keys ...string) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskFieldValueWithFieldKeys(keys...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskMessageRegex returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) all message substrings matching one +// of the given strings. +// +// Each call to this function is additive: +// the regexp to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func SubsystemWithMaskMessageRegex(ctx context.Context, subsystem string, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskMessageRegex(expressions...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskLogMatchingString returns a new context.Context that has a modified logger +// that masks (replace) with asterisks (`***`) all message substrings equal to one +// of the given strings. +// +// Each call to this function is additive: +// the string to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func SubsystemWithMaskLogMatchingString(ctx context.Context, subsystem string, matchingStrings ...string) context.Context { + lOpts := logging.GetProviderSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts) + + return logging.SetProviderSubsystemTFLoggerOpts(ctx, subsystem, lOpts) } diff --git a/tflog/subsystem_test.go b/tflog/subsystem_test.go index 1ec712c..acf35e9 100644 --- a/tflog/subsystem_test.go +++ b/tflog/subsystem_test.go @@ -3,6 +3,7 @@ package tflog_test import ( "bytes" "context" + "regexp" "testing" "github.com/google/go-cmp/cmp" @@ -572,3 +573,537 @@ func TestSubsystemError(t *testing.T) { }) } } + +func TestSubsystemWithOmitLogWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k1"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithOmitLogWithFieldKeys(ctx, testSubsystem, testCase.omitLogKeys...) + + tflog.SubsystemWarn(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithOmitLogWithMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithOmitLogWithMessageRegex(ctx, testSubsystem, testCase.omitLogMatchingRegexp...) + + tflog.SubsystemDebug(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithOmitLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BAZ"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithOmitLogMatchingString(ctx, testSubsystem, testCase.omitLogMatchingString...) + + tflog.SubsystemDebug(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskFieldValueWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k1", "k2", "k3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "***", + "k2": "***", + }, + }, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithMaskFieldValueWithFieldKeys(ctx, testSubsystem, testCase.maskLogKeys...) + + tflog.SubsystemError(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured ***", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithMaskMessageRegex(ctx, testSubsystem, testCase.maskLogMatchingRegexp...) + + tflog.SubsystemTrace(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"incorrectly configured BAZ"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of ***", + "@module": "provider.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tflog.NewSubsystem(ctx, testSubsystem) + ctx = tflog.SubsystemWithMaskLogMatchingString(ctx, testSubsystem, testCase.maskLogMatchingString...) + + tflog.SubsystemInfo(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} diff --git a/tfsdklog/sdk.go b/tfsdklog/sdk.go index a27b7f3..0ce8272 100644 --- a/tfsdklog/sdk.go +++ b/tfsdklog/sdk.go @@ -2,6 +2,7 @@ package tfsdklog import ( "context" + "regexp" "github.com/hashicorp/go-hclog" "github.com/hashicorp/terraform-plugin-log/internal/hclogutils" @@ -121,7 +122,13 @@ func Trace(ctx context.Context, msg string, additionalFields ...map[string]inter // most so just making this a no-op is fine return } - logger.Trace(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Trace(msg, additionalArgs...) } // Debug logs `msg` at the debug level to the logger in `ctx`, with optional @@ -137,7 +144,13 @@ func Debug(ctx context.Context, msg string, additionalFields ...map[string]inter // most so just making this a no-op is fine return } - logger.Debug(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Debug(msg, additionalArgs...) } // Info logs `msg` at the info level to the logger in `ctx`, with optional @@ -153,7 +166,13 @@ func Info(ctx context.Context, msg string, additionalFields ...map[string]interf // most so just making this a no-op is fine return } - logger.Info(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Info(msg, additionalArgs...) } // Warn logs `msg` at the warn level to the logger in `ctx`, with optional @@ -169,7 +188,13 @@ func Warn(ctx context.Context, msg string, additionalFields ...map[string]interf // most so just making this a no-op is fine return } - logger.Warn(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Warn(msg, additionalArgs...) } // Error logs `msg` at the error level to the logger in `ctx`, with optional @@ -185,5 +210,163 @@ func Error(ctx context.Context, msg string, additionalFields ...map[string]inter // most so just making this a no-op is fine return } - logger.Error(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := omitOrMask(ctx, logger, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Error(msg, additionalArgs...) +} + +func omitOrMask(ctx context.Context, logger hclog.Logger, msg *string, additionalFields []map[string]interface{}) ([]interface{}, bool) { + tfLoggerOpts := logging.GetSDKRootTFLoggerOpts(ctx) + additionalArgs := hclogutils.MapsToArgs(additionalFields...) + impliedArgs := logger.ImpliedArgs() + + // Apply the provider root LoggerOpts to determine if this log should be omitted + if tfLoggerOpts.ShouldOmit(msg, impliedArgs, additionalArgs) { + return nil, true + } + + // Apply the provider root LoggerOpts to apply masking to this log + tfLoggerOpts.ApplyMask(msg, impliedArgs, additionalArgs) + return additionalArgs, false +} + +// WithOmitLogWithFieldKeys returns a new context.Context that has a modified logger +// that will omit to write any log when any of the given keys is found +// within the arguments. +// +// Each call to this function is additive: +// the keys to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '...', 'bar', '...' }` -> omitted +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> printed +// log3 = `{ msg = "...", args = { 'baz`', '...', 'boo', '...' }` -> omitted +// +func WithOmitLogWithFieldKeys(ctx context.Context, keys ...string) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) +} + +// WithOmitLogWithMessageRegex returns a new context.Context that has a modified logger +// that will omit to write any log that has a message matching any of the +// given *regexp.Regexp. +// +// Each call to this function is additive: +// the regexp to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func WithOmitLogWithMessageRegex(ctx context.Context, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithMessageRegex(expressions...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) +} + +// WithOmitLogMatchingString returns a new context.Context that has a modified logger +// that will omit to write any log that matches any of the given string. +// +// Each call to this function is additive: +// the string to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func WithOmitLogMatchingString(ctx context.Context, matchingStrings ...string) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskFieldValueWithFieldKeys returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) any argument value where the +// key matches one of the given keys. +// +// Each call to this function is additive: +// the keys to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '***', 'bar', '...' }` -> masked value +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> as-is value +// log3 = `{ msg = "...", args = { 'baz`', '***', 'boo', '...' }` -> masked value +// +func WithMaskFieldValueWithFieldKeys(ctx context.Context, keys ...string) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskFieldValueWithFieldKeys(keys...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskMessageRegex returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) all message substrings matching one +// of the given strings. +// +// Each call to this function is additive: +// the regexp to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func WithMaskMessageRegex(ctx context.Context, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskMessageRegex(expressions...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) +} + +// WithMaskLogMatchingString returns a new context.Context that has a modified logger +// that masks (replace) with asterisks (`***`) all message substrings equal to one +// of the given strings. +// +// Each call to this function is additive: +// the string to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func WithMaskLogMatchingString(ctx context.Context, matchingStrings ...string) context.Context { + lOpts := logging.GetSDKRootTFLoggerOpts(ctx) + + lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts) + + return logging.SetSDKRootTFLoggerOpts(ctx, lOpts) } diff --git a/tfsdklog/sdk_test.go b/tfsdklog/sdk_test.go index 2d1d6fd..25974d0 100644 --- a/tfsdklog/sdk_test.go +++ b/tfsdklog/sdk_test.go @@ -3,6 +3,7 @@ package tfsdklog_test import ( "bytes" "context" + "regexp" "testing" "github.com/google/go-cmp/cmp" @@ -561,3 +562,533 @@ func TestError(t *testing.T) { }) } } + +const testLogMsg = "System FOO has caused error BAR because of incorrectly configured BAZ" + +func TestWithOmitLogWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k1"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.WithOmitLogWithFieldKeys(ctx, testCase.omitLogKeys...) + + tfsdklog.Warn(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithOmitLogWithMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.WithOmitLogWithMessageRegex(ctx, testCase.omitLogMatchingRegexp...) + + tfsdklog.Debug(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithOmitLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BAZ"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.WithOmitLogMatchingString(ctx, testCase.omitLogMatchingString...) + + tfsdklog.Debug(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskFieldValueWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k1", "k2", "k3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "***", + "k2": "***", + }, + }, + }, + } + + 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) + ctx = tfsdklog.WithMaskFieldValueWithFieldKeys(ctx, testCase.maskLogKeys...) + + tfsdklog.Error(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured ***", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tfsdklog.WithMaskMessageRegex(ctx, testCase.maskLogMatchingRegexp...) + + tfsdklog.Trace(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestWithMaskLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"incorrectly configured BAZ"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of ***", + "@module": "sdk", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tfsdklog.WithMaskLogMatchingString(ctx, testCase.maskLogMatchingString...) + + tfsdklog.Info(ctx, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} diff --git a/tfsdklog/subsystem.go b/tfsdklog/subsystem.go index 3445288..37cef52 100644 --- a/tfsdklog/subsystem.go +++ b/tfsdklog/subsystem.go @@ -2,6 +2,7 @@ package tfsdklog import ( "context" + "regexp" "github.com/hashicorp/go-hclog" "github.com/hashicorp/terraform-plugin-log/internal/hclogutils" @@ -105,7 +106,13 @@ func SubsystemTrace(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetSDKSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewSDKSubsystemLoggerWarning) } - logger.Trace(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Trace(msg, additionalArgs...) } // SubsystemDebug logs `msg` at the debug level to the subsystem logger @@ -124,7 +131,13 @@ func SubsystemDebug(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetSDKSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewSDKSubsystemLoggerWarning) } - logger.Debug(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Debug(msg, additionalArgs...) } // SubsystemInfo logs `msg` at the info level to the subsystem logger @@ -143,7 +156,13 @@ func SubsystemInfo(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetSDKSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewSDKSubsystemLoggerWarning) } - logger.Info(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Info(msg, additionalArgs...) } // SubsystemWarn logs `msg` at the warn level to the subsystem logger @@ -162,7 +181,13 @@ func SubsystemWarn(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetSDKSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewSDKSubsystemLoggerWarning) } - logger.Warn(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Warn(msg, additionalArgs...) } // SubsystemError logs `msg` at the error level to the subsystem logger @@ -181,5 +206,163 @@ func SubsystemError(ctx context.Context, subsystem, msg string, additionalFields // create a new logger if one doesn't exist logger = logging.GetSDKSubsystemLogger(NewSubsystem(ctx, subsystem), subsystem).With("new_logger_warning", logging.NewSDKSubsystemLoggerWarning) } - logger.Error(msg, hclogutils.MapsToArgs(additionalFields...)...) + + additionalArgs, shouldOmit := subsystemOmitOrMask(ctx, logger, subsystem, &msg, additionalFields) + if shouldOmit { + return + } + + logger.Error(msg, additionalArgs...) +} + +func subsystemOmitOrMask(ctx context.Context, logger hclog.Logger, subsystem string, msg *string, additionalFields []map[string]interface{}) ([]interface{}, bool) { + tfLoggerOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + additionalArgs := hclogutils.MapsToArgs(additionalFields...) + impliedArgs := logger.ImpliedArgs() + + // Apply the provider root LoggerOpts to determine if this log should be omitted + if tfLoggerOpts.ShouldOmit(msg, impliedArgs, additionalArgs) { + return nil, true + } + + // Apply the provider root LoggerOpts to apply masking to this log + tfLoggerOpts.ApplyMask(msg, impliedArgs, additionalArgs) + return additionalArgs, false +} + +// SubsystemWithOmitLogWithFieldKeys returns a new context.Context that has a modified logger +// that will omit to write any log when any of the given keys is found +// within the arguments. +// +// Each call to this function is additive: +// the keys to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '...', 'bar', '...' }` -> omitted +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> printed +// log3 = `{ msg = "...", args = { 'baz`', '...', 'boo', '...' }` -> omitted +// +func SubsystemWithOmitLogWithFieldKeys(ctx context.Context, subsystem string, keys ...string) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithFieldKeys(keys...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithOmitLogWithMessageRegex returns a new context.Context that has a modified logger +// that will omit to write any log that has a message matching any of the +// given *regexp.Regexp. +// +// Each call to this function is additive: +// the regexp to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func SubsystemWithOmitLogWithMessageRegex(ctx context.Context, subsystem string, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithMessageRegex(expressions...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithOmitLogMatchingString returns a new context.Context that has a modified logger +// that will omit to write any log that matches any of the given string. +// +// Each call to this function is additive: +// the string to omit by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple foo", args = {...}` -> omitted +// log2 = `{ msg = "pineapple mango", args = {...}` -> printed +// log3 = `{ msg = "pineapple mango bar", args = {...}` -> omitted +// +func SubsystemWithOmitLogMatchingString(ctx context.Context, subsystem string, matchingStrings ...string) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithOmitLogWithMessageStrings(matchingStrings...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskFieldValueWithFieldKeys returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) any argument value where the +// key matches one of the given keys. +// +// Each call to this function is additive: +// the keys to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'baz']` +// +// log1 = `{ msg = "...", args = { 'foo', '***', 'bar', '...' }` -> masked value +// log2 = `{ msg = "...", args = { 'bar', '...' }` -> as-is value +// log3 = `{ msg = "...", args = { 'baz`', '***', 'boo', '...' }` -> masked value +// +func SubsystemWithMaskFieldValueWithFieldKeys(ctx context.Context, subsystem string, keys ...string) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskFieldValueWithFieldKeys(keys...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskMessageRegex returns a new context.Context that has a modified logger +// that masks (replaces) with asterisks (`***`) all message substrings matching one +// of the given strings. +// +// Each call to this function is additive: +// the regexp to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `[regexp.MustCompile("(foo|bar)")]` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func SubsystemWithMaskMessageRegex(ctx context.Context, subsystem string, expressions ...*regexp.Regexp) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskMessageRegex(expressions...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) +} + +// SubsystemWithMaskLogMatchingString returns a new context.Context that has a modified logger +// that masks (replace) with asterisks (`***`) all message substrings equal to one +// of the given strings. +// +// Each call to this function is additive: +// the string to mask by are added to the existing configuration. +// +// Example: +// +// configuration = `['foo', 'bar']` +// +// log1 = `{ msg = "banana apple ***", args = {...}` -> masked portion +// log2 = `{ msg = "pineapple mango", args = {...}` -> as-is +// log3 = `{ msg = "pineapple mango ***", args = {...}` -> masked portion +// +func SubsystemWithMaskLogMatchingString(ctx context.Context, subsystem string, matchingStrings ...string) context.Context { + lOpts := logging.GetSDKSubsystemTFLoggerOpts(ctx, subsystem) + + lOpts = logging.WithMaskMessageStrings(matchingStrings...)(lOpts) + + return logging.SetSDKSubsystemTFLoggerOpts(ctx, subsystem, lOpts) } diff --git a/tfsdklog/subsystem_test.go b/tfsdklog/subsystem_test.go index 86cf3e9..ba8f839 100644 --- a/tfsdklog/subsystem_test.go +++ b/tfsdklog/subsystem_test.go @@ -3,6 +3,7 @@ package tfsdklog_test import ( "bytes" "context" + "regexp" "testing" "github.com/google/go-cmp/cmp" @@ -572,3 +573,537 @@ func TestSubsystemError(t *testing.T) { }) } } + +func TestSubsystemWithOmitLogWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "warn", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogKeys: []string{"k1"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithOmitLogWithFieldKeys(ctx, testSubsystem, testCase.omitLogKeys...) + + tfsdklog.SubsystemWarn(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithOmitLogWithMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithOmitLogWithMessageRegex(ctx, testSubsystem, testCase.omitLogMatchingRegexp...) + + tfsdklog.SubsystemDebug(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithOmitLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + omitLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-omission": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "debug", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "omit-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + omitLogMatchingString: []string{"BAZ"}, + expectedOutput: nil, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithOmitLogMatchingString(ctx, testSubsystem, testCase.omitLogMatchingString...) + + tfsdklog.SubsystemDebug(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskFieldValueWithFieldKeys(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogKeys []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-key-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k3", "K3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-by-key": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogKeys: []string{"k1", "k2", "k3"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "error", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "***", + "k2": "***", + }, + }, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithMaskFieldValueWithFieldKeys(ctx, testSubsystem, testCase.maskLogKeys...) + + tfsdklog.SubsystemError(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskMessageRegex(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingRegexp []*regexp.Regexp + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("(?i)BaAnAnA")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-regexp": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingRegexp: []*regexp.Regexp{regexp.MustCompile("BAZ$")}, + expectedOutput: []map[string]interface{}{ + { + "@level": "trace", + "@message": "System FOO has caused error BAR because of incorrectly configured ***", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithMaskMessageRegex(ctx, testSubsystem, testCase.maskLogMatchingRegexp...) + + tfsdklog.SubsystemTrace(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +} + +func TestSubsystemWithMaskLogMatchingString(t *testing.T) { + testCases := map[string]struct { + msg string + additionalFields []map[string]interface{} + maskLogMatchingString []string + expectedOutput []map[string]interface{} + }{ + "no-masking": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "no-matches": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"BaAnAnA"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of incorrectly configured BAZ", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + "mask-log-matching-string": { + msg: testLogMsg, + additionalFields: []map[string]interface{}{ + { + "k1": "v1", + "k2": "v2", + }, + }, + maskLogMatchingString: []string{"incorrectly configured BAZ"}, + expectedOutput: []map[string]interface{}{ + { + "@level": "info", + "@message": "System FOO has caused error BAR because of ***", + "@module": "sdk.test_subsystem", + "k1": "v1", + "k2": "v2", + }, + }, + }, + } + + 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) + ctx = tfsdklog.NewSubsystem(ctx, testSubsystem) + ctx = tfsdklog.SubsystemWithMaskLogMatchingString(ctx, testSubsystem, testCase.maskLogMatchingString...) + + tfsdklog.SubsystemInfo(ctx, testSubsystem, testCase.msg, testCase.additionalFields...) + + 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) + } + }) + } +}