round durations to the second in events, errors and messages

[tmmorin]

This is a small evolution so that messages like health check failed after 30.040865791s: timeout are made shorter and more readable, by rounding the duration to the nearest second and avoid useless decimals. The new messages will look like health check failed after 30s: timeout.

This is aimed to make logs, events and status conditions messages a bit more readable.

[tmmorin]

hello @stefanprodan
am I right to think that the CI check error is unrelated to my PR ?

[stefanprodan]

@tmmorin can you rebase with upstream main and force push. The CI error should be fixed.

[tmmorin]

@tmmorin can you rebase with upstream main and force push. The CI error should be fixed.

done

[stefanprodan]

Ok so tests are failing due to Health check passed in 0s. I think we should print the ms if the duration is under 1s

[tmmorin]

Ok so tests are failing due to Health check passed in 0s. I think we should print the ms if the duration is under 1s

ah, fair point indeed

[tmmorin]

I made the suggested change, however this unit test is failing:

=== RUN   TestKustomizationReconciler_WaitConditions/emits_event_for_the_new_revision
=== NAME  TestKustomizationReconciler_WaitConditions
     kustomization_wait_test.go:263: 
         Expected
             <bool>: false
         to be true

I don't get why because, for sure, the logic for generating events is not changed by my PR.

[stefanprodan]

for sure, the logic for generating events is not changed by my PR.

It is changing a lot, events are no longer unique and they get dropped by deduplication.

[tmmorin]

It is changing a lot, events are no longer unique and they get dropped by deduplication.

Ok, I see: implicitly the current code (at least the testing code) is relying on timing as a source of "unique event ids". This is unusual.

Should the way events are tested be changed ? (e.g. byt testing "new event" or "lastTimestamp is after last action")

Or should the side-effect of the new behavior behind this change be avoided ?

Including the metadata.generation in the messages is feasible for "Reconciliation finished in" : e.g "Reconciliation of generation %d finished in ...". But this idea wouldn't work for "Reconciliation failed after ....", nor for "Health check failed after..." or "Health passed in...".

[stefanprodan]

It’s not the testing code the issue here but Kubernetes itself which doesn’t create a new event and drops duplicates, we’re been avoiding by having the full duration in the message so Kubernetes will not see it as a duplicate. Also having the generation with not fix anything as the same generation can reconcile new state from Git.

[stefanprodan]

To fix the tests we probably have to look at the increment number and determine deduplication.

[tmmorin]

Yes, yes, I got it -- the test expects a new event and works only if the events escape deduplication by having pseudo-unique messages.

Also having the generation with not fix anything as the same generation can reconcile new state from Git.

Yes, indeed.