Skip to content

Commit

Permalink
TestNoneCache now checks the output of the logs
Browse files Browse the repository at this point in the history
  • Loading branch information
maelvls committed Nov 14, 2024
1 parent e8c5eed commit f5f86b3
Show file tree
Hide file tree
Showing 4 changed files with 95 additions and 63 deletions.
11 changes: 10 additions & 1 deletion pkg/datagatherer/k8s/cache_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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, &notCachable{}, nil)
onUpdate(log, &notCachable{}, nil, nil)
onDelete(log, &notCachable{}, 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()))
}
65 changes: 3 additions & 62 deletions pkg/logs/logs_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,6 @@ import (
"log/slog"
"os"
"os/exec"
"regexp"
"strings"
"testing"
"time"
Expand All @@ -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.
Expand Down Expand Up @@ -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")
})
}
}
Expand Down
41 changes: 41 additions & 0 deletions pkg/testutil/logs.go
Original file line number Diff line number Diff line change
@@ -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+"`)
)
41 changes: 41 additions & 0 deletions pkg/testutil/logs_test.go
Original file line number Diff line number Diff line change
@@ -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))
})
}
}

0 comments on commit f5f86b3

Please sign in to comment.