diff --git a/pkg/datagatherer/k8s/cache_test.go b/pkg/datagatherer/k8s/cache_test.go index a8616b89..f70fb6f5 100644 --- a/pkg/datagatherer/k8s/cache_test.go +++ b/pkg/datagatherer/k8s/cache_test.go @@ -8,10 +8,12 @@ import ( "github.com/d4l3k/messagediff" "github.com/go-logr/logr" "github.com/pmylund/go-cache" + "github.com/stretchr/testify/assert" "k8s.io/apimachinery/pkg/runtime" "k8s.io/klog/v2/ktesting" "github.com/jetstack/preflight/api" + "github.com/jetstack/preflight/pkg/testutil" ) func makeGatheredResource(obj runtime.Object, deletedAt api.Time) *api.GatheredResource { @@ -143,10 +145,17 @@ func TestOnAddCache(t *testing.T) { // TestNoneCache demonstrates that the cache helpers do not crash if passed a // non-cachable object, but log an error with a reference to the object type. func TestNoneCache(t *testing.T) { - log := ktesting.NewLogger(t, ktesting.NewConfig(ktesting.Verbosity(10))) + var buffer ktesting.BufferTL + log := ktesting.NewLogger(&buffer, ktesting.NewConfig(ktesting.Verbosity(10))) type notCachable struct{} onAdd(log, ¬Cachable{}, nil) onUpdate(log, ¬Cachable{}, nil, nil) onDelete(log, ¬Cachable{}, nil) + + assert.Equal(t, testutil.Undent(` + E0000 00:00:00.000000] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="add" + E0000 00:00:00.000000] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="update" + E0000 00:00:00.000000] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="delete" + `), testutil.ReplaceWithStaticTimestamps(buffer.String())) } diff --git a/pkg/logs/logs_test.go b/pkg/logs/logs_test.go index f48a1b4c..ef239f61 100644 --- a/pkg/logs/logs_test.go +++ b/pkg/logs/logs_test.go @@ -10,7 +10,6 @@ import ( "log/slog" "os" "os/exec" - "regexp" "strings" "testing" "time" @@ -22,6 +21,7 @@ import ( "k8s.io/klog/v2" "github.com/jetstack/preflight/pkg/logs" + "github.com/jetstack/preflight/pkg/testutil" ) // TestLogs demonstrates how the logging flags affect the logging output. @@ -307,67 +307,8 @@ E0000 00:00:00.000000 00000 logs_test.go:000] "Contextual error" err="fake-err test.expectStdout = strings.TrimPrefix(test.expectStdout, "\n") test.expectStderr = strings.TrimPrefix(test.expectStderr, "\n") - require.Equal(t, test.expectStdout, replaceWithStaticTimestamps(stdoutStr), "stdout doesn't match") - require.Equal(t, test.expectStderr, replaceWithStaticTimestamps(stderrStr), "stderr doesn't match") - }) - } -} - -var ( - timestampRegexpStdLog = regexp.MustCompile(`\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}`) - timestampRegexpKlog = regexp.MustCompile(`\d{4} \d{2}:\d{2}:\d{2}\.\d{6} +\d+`) - timestampRegexpJSON = regexp.MustCompile(`"ts":\d+\.?\d*`) - fileAndLineRegexpJSON = regexp.MustCompile(`"caller":"([^"]+).go:\d+"`) - fileAndLineRegexpKlog = regexp.MustCompile(` ([^:]+).go:\d+`) -) - -// Replaces the klog and JSON timestamps with a static timestamp to make it -// easier to assert the logs. It also replaces the line number with 000 as it -// often changes. -// -// I1018 15:12:57.953433 22183 logs.go:000] log -// {"ts":1729258473588.828,"caller":"log/log.go:000","msg":"log Print","v":0} -// 2024/10/18 15:40:50 log Print -// -// to the fixed: -// -// I0000 00:00:00.000000 00000 logs.go:000] log -// {"ts":0000000000000.000,"caller":"log/log.go:000","msg":"log Print","v":0} -// 0000/00/00 00:00:00 log Print -func replaceWithStaticTimestamps(input string) string { - input = timestampRegexpKlog.ReplaceAllString(input, "0000 00:00:00.000000 00000") - input = timestampRegexpJSON.ReplaceAllString(input, `"ts":0000000000000.000`) - input = timestampRegexpStdLog.ReplaceAllString(input, "0000/00/00 00:00:00") - input = fileAndLineRegexpJSON.ReplaceAllString(input, `"caller":"$1.go:000"`) - input = fileAndLineRegexpKlog.ReplaceAllString(input, " $1.go:000") - return input -} - -func Test_replaceWithStaticTimestamps(t *testing.T) { - tests := []struct { - name string - input string - expected string - }{ - { - name: "klog", - input: `I1018 15:20:42.861239 2386 logs_test.go:13] "Contextual Info Level 3" logger="foo" key="value"`, - expected: `I0000 00:00:00.000000 00000 logs_test.go:000] "Contextual Info Level 3" logger="foo" key="value"`, - }, - { - name: "json-with-nanoseconds", - input: `{"ts":1729270111728.125,"caller":"logs/logs_test.go:000","msg":"slog Warn","v":0}`, - expected: `{"ts":0000000000000.000,"caller":"logs/logs_test.go:000","msg":"slog Warn","v":0}`, - }, - { - name: "json-might-not-have-nanoseconds", - input: `{"ts":1729270111728,"caller":"logs/logs_test.go:000","msg":"slog Info","v":0}`, - expected: `{"ts":0000000000000.000,"caller":"logs/logs_test.go:000","msg":"slog Info","v":0}`, - }, - } - for _, test := range tests { - t.Run(test.name, func(t *testing.T) { - assert.Equal(t, test.expected, replaceWithStaticTimestamps(test.input)) + require.Equal(t, test.expectStdout, testutil.ReplaceWithStaticTimestamps(stdoutStr), "stdout doesn't match") + require.Equal(t, test.expectStderr, testutil.ReplaceWithStaticTimestamps(stderrStr), "stderr doesn't match") }) } } diff --git a/pkg/testutil/logs.go b/pkg/testutil/logs.go new file mode 100644 index 00000000..b43af446 --- /dev/null +++ b/pkg/testutil/logs.go @@ -0,0 +1,41 @@ +package testutil + +import ( + "regexp" +) + +// Replaces the klog and JSON timestamps with a static timestamp to make it +// easier to assert the logs. It also replaces the line number with 000 as it +// often changes. +// +// From: I1018 15:12:57.953433 22183 logs.go:000] log +// To: I0000 00:00:00.000000 00000 logs.go:000] log +// +// From: I1018 15:12:57.953433] log +// To: I0000 00:00:00.000000] log +// +// From: {"ts":1729258473588.828,"caller":"log/log.go:000","msg":"log Print","v":0} +// To: {"ts":0000000000000.000,"caller":"log/log.go:000","msg":"log Print","v":0} +// +// From: 2024/10/18 15:40:50 log Print +// To: 0000/00/00 00:00:00 log Print +func ReplaceWithStaticTimestamps(input string) string { + input = timestampRegexpKlog.ReplaceAllString(input, "0000 00:00:00.000000 00000") + input = timestampRegexpKlogAlt.ReplaceAllString(input, "0000 00:00:00.000000") + input = timestampRegexpJSON.ReplaceAllString(input, `"ts":0000000000000.000`) + input = timestampRegexpStdLog.ReplaceAllString(input, "0000/00/00 00:00:00") + input = fileAndLineRegexpJSON.ReplaceAllString(input, `"caller":"$1.go:000"`) + input = fileAndLineRegexpKlog.ReplaceAllString(input, " $1.go:000") + return input +} + +var ( + timestampRegexpStdLog = regexp.MustCompile(`\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}`) + + timestampRegexpKlog = regexp.MustCompile(`\d{4} \d{2}:\d{2}:\d{2}\.\d{6} +\d+`) + timestampRegexpKlogAlt = regexp.MustCompile(`\d{4} \d{2}:\d{2}:\d{2}\.\d{6}`) + fileAndLineRegexpKlog = regexp.MustCompile(` ([^:]+).go:\d+`) + + timestampRegexpJSON = regexp.MustCompile(`"ts":\d+\.?\d*`) + fileAndLineRegexpJSON = regexp.MustCompile(`"caller":"([^"]+).go:\d+"`) +) diff --git a/pkg/testutil/logs_test.go b/pkg/testutil/logs_test.go new file mode 100644 index 00000000..430a525d --- /dev/null +++ b/pkg/testutil/logs_test.go @@ -0,0 +1,41 @@ +package testutil + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestReplaceWithStaticTimestamps(t *testing.T) { + tests := []struct { + name string + input string + expected string + }{ + { + name: "klog", + input: `I1018 15:20:42.861239 2386 logs_test.go:13] "Contextual Info Level 3" logger="foo" key="value"`, + expected: `I0000 00:00:00.000000 00000 logs_test.go:000] "Contextual Info Level 3" logger="foo" key="value"`, + }, + { + name: "klog without process ID and without file name", + input: `E1114 11:15:39.455086] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="add"`, + expected: `E0000 00:00:00.000000] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="add"`, + }, + { + name: "json-with-nanoseconds", + input: `{"ts":1729270111728.125,"caller":"logs/logs_test.go:000","msg":"slog Warn","v":0}`, + expected: `{"ts":0000000000000.000,"caller":"logs/logs_test.go:000","msg":"slog Warn","v":0}`, + }, + { + name: "json-might-not-have-nanoseconds", + input: `{"ts":1729270111728,"caller":"logs/logs_test.go:000","msg":"slog Info","v":0}`, + expected: `{"ts":0000000000000.000,"caller":"logs/logs_test.go:000","msg":"slog Info","v":0}`, + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + assert.Equal(t, test.expected, ReplaceWithStaticTimestamps(test.input)) + }) + } +}