Repository: go-kratos/kratos
Pull request #2484 (2022-11-02 22:50:21)

fix(filter): filter out keyvals if keyFunc is provided
#### Description (what this PR does / why we need it):

This PR fixes a bug where a `filterFunc` couldn't filter/override a keyval. This was a regression introduced [here](https://github.com/go-kratos/kratos/pull/1901/files).

The root cause was that to take into account the log prefix, we made a copy of the original keyvals and the filter was applied on such copy. This means that any filterFunc that was meant to override the original keyvals, was changing the copy instead.

This PR changes the code to apply a filter func in both the prefix and the log keyvals. The test cases have been also updated to cover all the scenarios.

#### Which issue(s) this PR fixes (resolves / be part of):
Refs #1897


#### Other special notes for the reviewers:
<!--
* Somethings that need extra attention for the reviewers
* Some additional notes, TODO list, etc.
-->



Patch:
diff --git a/log/filter.go b/log/filter.go
index ab572377..993fa926 100644
--- a/log/filter.go
+++ b/log/filter.go
@@ -64,20 +64,18 @@ func (f *Filter) Log(level Level, keyvals ...interface{}) error {
 	if level < f.level {
 		return nil
 	}
-	// fkv is used to provide a slice to contains both logger.prefix and keyvals for filter
-	var fkv []interface{}
+	// prefixkv contains the slice of arguments defined as prefixes during the log initialization
+	var prefixkv []interface{}
 	l, ok := f.logger.(*logger)
 	if ok && len(l.prefix) > 0 {
-		fkv = make([]interface{}, 0, len(l.prefix)+len(keyvals))
-		fkv = append(fkv, l.prefix...)
-		fkv = append(fkv, keyvals...)
+		prefixkv = make([]interface{}, 0, len(l.prefix))
+		prefixkv = append(prefixkv, l.prefix...)
 	}
-	if !ok {
-		fkv = keyvals
-	}
-	if f.filter != nil && f.filter(level, fkv...) {
+
+	if f.filter != nil && (f.filter(level, prefixkv...) || f.filter(level, keyvals...)) {
 		return nil
 	}
+
 	if len(f.key) > 0 || len(f.value) > 0 {
 		for i := 0; i < len(keyvals); i += 2 {
 			v := i + 1


Test patch:
diff --git a/contrib/log/aliyun/aliyun_test.go b/contrib/log/aliyun/aliyun_test.go
index c4bfde48..e3e224ad 100644
--- a/contrib/log/aliyun/aliyun_test.go
+++ b/contrib/log/aliyun/aliyun_test.go
@@ -116,21 +116,22 @@ func TestToString(t *testing.T) {
 		{"float64", 6.66, "6.66"},
 		{"max float64", math.MaxFloat64, "179769313486231570000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}, //nolint:lll
 		{"float32", float32(6.66), "6.66"},
-		{"max float32", math.MaxFloat32, "340282346638528860000000000000000000000"},
-		{"int", int(math.MaxInt64), "9223372036854775807"},
+		{"max float32", float32(math.MaxFloat32), "340282350000000000000000000000000000000"},
+		{"int", math.MaxInt64, "9223372036854775807"},
 		{"uint", uint(math.MaxUint64), "18446744073709551615"},
-		{"int8", math.MaxInt8, "127"},
-		{"uint8", math.MaxUint8, "255"},
-		{"int16", math.MaxInt16, "32767"},
-		{"uint16", math.MaxUint16, "65535"},
-		{"int32", math.MaxInt32, "2147483647"},
-		{"uint32", math.MaxUint32, "4294967295"},
-		{"int64", math.MaxInt64, "9223372036854775807"},
+		{"int8", int8(math.MaxInt8), "127"},
+		{"uint8", uint8(math.MaxUint8), "255"},
+		{"int16", int16(math.MaxInt16), "32767"},
+		{"uint16", uint16(math.MaxUint16), "65535"},
+		{"int32", int32(math.MaxInt32), "2147483647"},
+		{"uint32", uint32(math.MaxUint32), "4294967295"},
+		{"int64", int64(math.MaxInt64), "9223372036854775807"},
 		{"uint64", uint64(math.MaxUint64), "18446744073709551615"},
 		{"string", "abc", "abc"},
 		{"bool", false, "false"},
 		{"[]byte", []byte("abc"), "abc"},
 		{"struct", struct{ Name string }{}, `{"Name":""}`},
+		{"nil", nil, ""},
 	}
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
diff --git a/contrib/log/tencent/tencent_test.go b/contrib/log/tencent/tencent_test.go
index 76bc13bd..df1fe367 100644
--- a/contrib/log/tencent/tencent_test.go
+++ b/contrib/log/tencent/tencent_test.go
@@ -120,21 +120,22 @@ func TestToString(t *testing.T) {
 		{"float64", 6.66, "6.66"},
 		{"max float64", math.MaxFloat64, "179769313486231570000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}, //nolint:lll
 		{"float32", float32(6.66), "6.66"},
-		{"max float32", math.MaxFloat32, "340282346638528860000000000000000000000"},
-		{"int", int(math.MaxInt64), "9223372036854775807"},
+		{"max float32", float32(math.MaxFloat32), "340282350000000000000000000000000000000"},
+		{"int", math.MaxInt64, "9223372036854775807"},
 		{"uint", uint(math.MaxUint64), "18446744073709551615"},
-		{"int8", math.MaxInt8, "127"},
-		{"uint8", math.MaxUint8, "255"},
-		{"int16", math.MaxInt16, "32767"},
-		{"uint16", math.MaxUint16, "65535"},
-		{"int32", math.MaxInt32, "2147483647"},
-		{"uint32", math.MaxUint32, "4294967295"},
-		{"int64", math.MaxInt64, "9223372036854775807"},
+		{"int8", int8(math.MaxInt8), "127"},
+		{"uint8", uint8(math.MaxUint8), "255"},
+		{"int16", int16(math.MaxInt16), "32767"},
+		{"uint16", uint16(math.MaxUint16), "65535"},
+		{"int32", int32(math.MaxInt32), "2147483647"},
+		{"uint32", uint32(math.MaxUint32), "4294967295"},
+		{"int64", int64(math.MaxInt64), "9223372036854775807"},
 		{"uint64", uint64(math.MaxUint64), "18446744073709551615"},
 		{"string", "abc", "abc"},
 		{"bool", false, "false"},
 		{"[]byte", []byte("abc"), "abc"},
 		{"struct", struct{ Name string }{}, `{"Name":""}`},
+		{"nil", nil, ""},
 	}
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
diff --git a/log/filter_test.go b/log/filter_test.go
index d3c8d548..3e36deac 100644
--- a/log/filter_test.go
+++ b/log/filter_test.go
@@ -102,13 +102,19 @@ func TestFilterFuncWitchLoggerPrefix(t *testing.T) {
 			want:   "",
 		},
 		{
+			// Filtered value
 			logger: NewFilter(With(NewStdLogger(buf), "caller", "caller"), FilterFunc(testFilterFuncWithLoggerPrefix)),
-			want:   "INFO caller=caller msg=msg\n",
+			want:   "INFO caller=caller msg=msg filtered=***\n",
+		},
+		{
+			// NO prefix
+			logger: NewFilter(With(NewStdLogger(buf)), FilterFunc(testFilterFuncWithLoggerPrefix)),
+			want:   "INFO msg=msg filtered=***\n",
 		},
 	}
 
 	for _, tt := range tests {
-		err := tt.logger.Log(LevelInfo, "msg", "msg")
+		err := tt.logger.Log(LevelInfo, "msg", "msg", "filtered", "true")
 		if err != nil {
 			t.Fatal("err should be nil")
 		}
@@ -128,6 +134,9 @@ func testFilterFuncWithLoggerPrefix(level Level, keyvals ...interface{}) bool {
 		if keyvals[i] == "prefix" {
 			return true
 		}
+		if keyvals[i] == "filtered" {
+			keyvals[i+1] = fuzzyStr
+		}
 	}
 	return false
 }