Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

VC-35738: Assert the logs in TestNoneCache #619

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

maelvls
Copy link
Member

@maelvls maelvls commented Nov 14, 2024

In #612, it is written:

// 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.

It says that "an error is logged", but the logs aren't asserted. I found ktesting's documentation (https://pkg.go.dev/k8s.io/klog/v2/ktesting) that it is possible to assert the logs. I've tried doing that in this PR.

WDYT?

@maelvls maelvls requested a review from wallrj November 14, 2024 10:34
@maelvls maelvls changed the title VC-35738: VC-35738: Assert the logs in TestNoneCache Nov 14, 2024
@maelvls maelvls changed the base branch from master to VC-35738/remove-logs-dot-log-2 November 14, 2024 10:35
Base automatically changed from VC-35738/remove-logs-dot-log-2 to VC-35738/feature November 14, 2024 11:38
Base automatically changed from VC-35738/feature to master November 14, 2024 12:26
Copy link
Member

@wallrj wallrj left a comment

Choose a reason for hiding this comment

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

I've stated my case below. Interested to hear your counter arguments.

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()))
}
Copy link
Member

Choose a reason for hiding this comment

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

In config_test I used ktesting like this:

func recordLogs(t *testing.T) (logr.Logger, ktesting.Buffer) {
log := ktesting.NewLogger(t, ktesting.NewConfig(ktesting.BufferLogs(true)))
testingLogger, ok := log.GetSink().(ktesting.Underlier)
require.True(t, ok)
return log, testingLogger.GetBuffer()
}

// 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), ktesting.BufferLogs(true)))
	testingLogger, ok := log.GetSink().(ktesting.Underlier)
	require.True(t, ok)
	buffer := testingLogger.GetBuffer()
	type notCachable struct{}
	onAdd(log, &notCachable{}, nil)
	onUpdate(log, &notCachable{}, nil, nil)
	onDelete(log, &notCachable{}, nil)
	assert.Equal(t, testutil.Undent(`
		ERROR Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="add"
		ERROR Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="update"
		ERROR Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="delete"
        `), buffer.String())
}

The advantage is that you don't have to worry about timestamps in the logs; you only assert that the logged messages have the expected severity and that the message and additional structured fields are visible.

An additional advantage, and the real reason I created this test, was to be able to see and verify that the correct line numbers were being logged.

$ go test ./pkg/datagatherer/k8s/... -run TestNoneCache -v
=== RUN   TestNoneCache
    cache.go:53: E1115 09:54:01.716188] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="add"
    cache.go:66: E1115 09:54:01.716256] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="update"
    cache.go:80: E1115 09:54:01.716376] Cache update failure err="not a cacheResource type: *k8s.notCachable missing metadata/uid field" operation="delete"
--- PASS: TestNoneCache (0.00s)
PASS
ok      github.com/jetstack/preflight/pkg/datagatherer/k8s      0.032s

I had forgotten to use the WithHelper modifier in the logging helper function and the go test -v output helped me get that right.

func logCacheUpdateFailure(log logr.Logger, obj interface{}, operation string) {
// We use WithCallStackHelper to ensure the correct caller line numbers in the log messages
helper, log := log.WithCallStackHelper()
helper()
err := fmt.Errorf("not a cacheResource type: %T missing metadata/uid field", obj)
log.Error(err, "Cache update failure", "operation", operation)
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants