- Notifications
You must be signed in to change notification settings - Fork927
test: add logging to TestWorkspaceActivityBump/Dial#15089
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 ourterms of service andprivacy statement. We’ll occasionally send you account related emails.
Already on GitHub?Sign in to your account
Merged
Merged
Uh oh!
There was an error while loading.Please reload this page.
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.Learn more about bidirectional Unicode characters
If a test is running slow, the workspace deadline check can beslow. Since we use 'now' as a reference point, any time driftwill affect the results.
If the hypothesis of a 10s time drift is true, this loop might beacting slow.
Emyrk commentedOct 15, 2024
waitedFor := time.Now() | ||
// lastChecked is for logging within the Eventually loop. | ||
// Debouncing log lines to every second to prevent spam. | ||
lastChecked := time.Time{} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Made totime.Time
so the first loop is always logged.
spikecurtis approved these changesOct 16, 2024
774c9dd
intomain 29 checks passed
Uh oh!
There was an error while loading.Please reload this page.
Sign up for freeto subscribe to this conversation on GitHub. Already have an account?Sign in.
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Uh oh!
There was an error while loading.Please reload this page.
My initial notes:coder/internal#102 (comment)
I am a bit split on how best to solve this. It is a classic problem of what is
now
.At it's core, what is happening is:
now
deadeline-now=1hr
For an unknown reason,
Detect Bump
seems to have taken 10s in the flake failure. Sonow
has drifted 10s later then step 1.Our time tolerance is 10s, so the test fails.
Without more logs, it's difficult to know for certain. What makes this more confusing, is the
Detect bump
should detect when the bump happens, meaningnow
should be relative to when this loop unblocks.So the implementation of taking
now
after the loop is correct.What did I do then?
I added logging information to output timing information of this for loop. If we get another failure, this timing information should be helpful.
I also made the time drift allowed (was 10s) to match the maximum waiting time of the for loop. It's not perfect, but now the loop should take max ~15s, and the time comparison will allow 15s leeway.
Just a note that I do not believe there is any bugs in the production code. Looking at the failure logs, the activity bump works as expected.