Improve testing logger #5346
Improve testing logger #5346
Conversation
|
|
|
Pinging @elastic/elastic-agent-control-plane (Team:Elastic-Agent-Control-Plane) |
|
|
| log, obs := logger.NewTesting("watcher") | ||
| defer func() { | ||
| if t.Failed() { | ||
| obs.PrettyPrintf(t.Log) |
There was a problem hiding this comment.
Maybe we can implement String() to ObserverLogs? Then the usage becomes t.Log(obs)
There was a problem hiding this comment.
What I don't like on this idea is that ObservedLogs contains all logs, so a String() method would have to decide how to deal with the multi-line nature of it and it'd not be possible to print one log at a time.
There was a problem hiding this comment.
You are right that String() would make this a bit more limited in use, but ObserverLogs has filters you can apply to limit the amount of logs that would be returned (see Filter* methods). I understand the limitation regarding multiline logs.
Another consideration is that PrettyPrintf calls the callback function with a string, so it is kinda like an inversion of control, wouldn't it read better to have t.Log(obs.Pretty())? This way it plays better with Logf, FatalF or any other Printer utility you might use. I believe it gives more control to the caller.
There was a problem hiding this comment.
+1 for having String() or Pretty() implemented for ObservedLogs or even for a single LoggedEntry as it would be easier and more flexible
There was a problem hiding this comment.
My reservation about adding ObserverLogs.String() is that it would write all logs into one big string, which can use a lot of memory when there's a lot of logs. I like the approach of dumping the logs to strings one at a time.
On the other hand, my concern about the ObserverLogs.TakeAndPrettyPrint() method is that causes code like https://github.com/elastic/elastic-agent/pull/5346/files#diff-1881a0cf2ec8461140501dbbb913d9d91b93f00572c2e13977a6fca09b5ba92bR185:
obs = &logger.ObservedLogs{ObservedLogs: obs.Filter(func(entry observer.LoggedEntry) bool {
where you need to encapsulate the result of obs.Filter in a new logger.ObservedLogs. This notation is a bit verbose.
Another approach would be to have a function like printTestLogs(t *testing.T, logs []observer.LoggedEntry) like the one already defined here:
func printLogs(t *testing.T, logs []observer.LoggedEntry) {
t.Helper()
for _, entry := range logs {
t.Logf("[%s] %s", entry.Level, entry.Message) // add dumping entry.ContextMap()
}
}This function could then be used like this:
defer func() {
if t.Failed() {
printTestLogs(t, obs.TakeAll())
}
}()One benefit of ObserverLogs.TakeAndPrettyPrint over printLogs is that TakeAndPrettyPrint accepts a print function, giving the caller the choice where the logs are printed. But don't we always want to use t.Log in the tests?
There was a problem hiding this comment.
I still think using t.Log(obs.Pretty()) or even obs.String() would be a more idiomatic approach. If performance becomes a concern, we can always use strings.Builder.
I don’t want to prolong this discussion as I don't have strong arguments to favor one approach over the other; it seems more like a matter of preference. What do you think, @AndersonQ?
There was a problem hiding this comment.
I'd agree with you if it were a straight forward thing, but it isn't because the type isn't on our code.
It'd require to bring back the new type, which makes using the original methods a bit annoying. And again, ObserverLogs holds several lines of logs which I rather not put on a single string. Adding the method on LogEntry would mean more new types. So I kept the original idea, something to pretty print ObserverLogs but with a simpler implementation
680661a to
1220dd6
Compare
|
This pull request is now in conflicts. Could you fix it? 🙏 |
| @@ -133,12 +134,11 @@ LOOP: | |||
| // block on connection, don't retry connection, and fail on temp dial errors | |||
| // always a local connection it should connect quickly so the timeout is only 1 second | |||
| connectCtx, connectCancel := context.WithTimeout(ctx, 1*time.Second) | |||
| //nolint:staticcheck // requires changing client signature | |||
There was a problem hiding this comment.
Why is this nolint clause being removed?
There was a problem hiding this comment.
Just a comment on the pretty-printing already pointed out by @mauri870
The removal of nolint directive now introduces a lint failure, I would rather we fix the problem if possible, or maybe restore the nolint if it's too much work extraneous to this PR and fix it in a follow-up PR
d807fd4 to
0f8abc5
Compare
it was removed by mistake, it's back now |
21e5c3d to
52b96dd
Compare
|
@mauri870, @pchila, @andrzej-stencel how about now? I think it's a better compromise, following the idea @andrzej-stencel suggested. |
| logger.Error("an error message") | ||
| logger.Errorw("an error message with keys", "key1", "value1") | ||
|
|
||
| pintFn := func(a ...any) { fmt.Println(a...) } |
There was a problem hiding this comment.
A pint is always good! 🍻
move logger.NewTesting to loggertesting.New add loggertesting.PrintObservedLogs to pretty print observer.ObservedLogs
52b96dd to
d49f013
Compare
…-agent into improve-logger-testing
pkg/core/logger/loggertest/logger.go
Outdated
| // one at a time, printFn. It calls `observer.ObservedLogs.TakeAll`, | ||
| // therefore, after calling it, the ObservedLogs will be empty. | ||
| func PrintObservedLogs(obs *observer.ObservedLogs, printFn func(a ...any)) { | ||
| rawLogs := obs.TakeAll() |
There was a problem hiding this comment.
[suggestion/non-blocking] TakeAll modifies the state of obs, so ideally I would keep it out of this function. I understand that this makes the call to PrintObservedLogs a bit longer, user needs to pass obs.TakeAll() instead of just obs as the parameter. I'm leaving it up to you Anderson.
|
* add loggertesting package move logger.NewTesting to loggertesting.New add loggertesting.PrintObservedLogs to pretty print logs from a observer.ObservedLogs (cherry picked from commit 0126540) # Conflicts: # internal/pkg/agent/application/upgrade/watcher_test.go # pkg/component/runtime/manager_fake_input_test.go
* add loggertesting package move logger.NewTesting to loggertesting.New add loggertesting.PrintObservedLogs to pretty print logs from a observer.ObservedLogs (cherry picked from commit 0126540)
What does this PR do?
Adds a PrettyPrintf method to ObservedLogs to logger.NewTesting
Why is it important?
The testing logger is helpful, however on every failed test it's necessary to manually format the logs before printing. That leads to several tests just printing the logs as they are which isn't the best for reading them and investigating why the test failed.
The new
PrettyPrintfmethod provides an easy way to pretty print the logsChecklist
[ ] I have made corresponding changes to the documentation[ ] I have made corresponding change to the default configuration files[ ] I have added an entry in./changelog/fragmentsusing the changelog tool[ ] I have added an integration test or an E2E testDisruptive User Impact
None
How to test this PR locally
run the test
TestObservedLogs_PrettyPrintfRelated issues
Questions to ask yourself