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

fix: flaky test #2961

Merged
merged 2 commits into from
Dec 16, 2022
Merged

fix: flaky test #2961

merged 2 commits into from
Dec 16, 2022

Conversation

CaptainStandby
Copy link
Contributor

@CaptainStandby CaptainStandby commented Dec 16, 2022

This fixes a problematic unit test, that monitors log messages and expected a specific message at the end of the list. This has been corrected by searching for the expected message in the list.

Related issue(s)

Checklist

  • I have read the contributing guidelines.
  • I have referenced an issue containing the design document if my change
    introduces a new feature.
  • I am following the
    contributing code guidelines.
  • I have read the security policy.
  • I confirm that this pull request does not address a security
    vulnerability. If this pull request addresses a security vulnerability, I
    confirm that I got the approval (please contact
    security@ory.sh) from the maintainers to push
    the changes.
  • I have added tests that prove my fix is effective or that my feature
    works.
  • I have added or changed the documentation.

Further Comments

@codecov
Copy link

codecov bot commented Dec 16, 2022

Codecov Report

Merging #2961 (d43e869) into master (1ed6839) will increase coverage by 0.35%.
The diff coverage is n/a.

❗ Current head d43e869 differs from pull request most recent head 1397fcc. Consider uploading reports for the commit 1397fcc to get more accurate results

@@            Coverage Diff             @@
##           master    #2961      +/-   ##
==========================================
+ Coverage   75.89%   76.25%   +0.35%     
==========================================
  Files         311      309       -2     
  Lines       19185    19032     -153     
==========================================
- Hits        14560    14512      -48     
+ Misses       3486     3396      -90     
+ Partials     1139     1124      -15     
Impacted Files Coverage Δ
selfservice/strategy/oidc/provider_config.go 34.04% <0.00%> (-4.85%) ⬇️
selfservice/strategy/oidc/provider_linkedin.go
selfservice/strategy/oidc/provider_lark.go
courier/courier_dispatcher.go 60.29% <0.00%> (+14.70%) ⬆️

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

fix test?

Revert "hack: try to fix test"

This reverts commit 213b8fa.

add some explanations
@CaptainStandby CaptainStandby marked this pull request as ready for review December 16, 2022 14:32
@CaptainStandby CaptainStandby changed the title hack: try to fix test fix: flaky test Dec 16, 2022
alnr
alnr previously approved these changes Dec 16, 2022
@CaptainStandby CaptainStandby merged commit 4e5dcd0 into master Dec 16, 2022
@CaptainStandby CaptainStandby deleted the hf-fix-build branch December 16, 2022 19:25

// There are a bunch of log messages beeing logged. We are looking for a specific one.
timeout := time.After(time.Millisecond * 500)
outer:
Copy link
Member

Choose a reason for hiding this comment

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

If possible try to avoid labels for better readability :)


select {
case <-ctx.Done():
panic("the test could not complete as the context timed out before the file watcher updated")
Copy link
Member

Choose a reason for hiding this comment

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

No panics ever please

for _, v := range hook.AllEntries() {
s, err := v.String()
if err != nil {
t.Errorf("Unexpected Error: %s", err.Error())
Copy link
Member

Choose a reason for hiding this comment

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

Please use require.NoError or assert.NoError

@aeneasr
Copy link
Member

aeneasr commented Dec 16, 2022

@CaptainStandby can you please address the comments in a follow-up PR? Thank you!

@CaptainStandby
Copy link
Contributor Author

CaptainStandby commented Dec 16, 2022

@aeneasr Sure thing #2964

Copy link
Member

@zepatrik zepatrik left a comment

Choose a reason for hiding this comment

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

I also investigated this already. The underlying issue is that marshalAndWrite causes two notifications (one for .Truncate and one for .Write).
The file content is then read after the first event. Depending on the speed of the system/disk this can then flake, returning invalid content (i.e. empty file), or the expected content. Ideally we would do an atomic file write in the test instead, but this is also OK.

@CaptainStandby
Copy link
Contributor Author

Yeah, we noticed this too and the first take on fixing this, was doing atomic file write. But we decided to go with this approach, because we wanted to retain the "flakyness" of the write to test that the system could correctly deal with that situation.
Maybe a specific test, that simulates a problematic write could be added, now that I think about it.

@alnr
Copy link
Contributor

alnr commented Dec 19, 2022

Yes, the non-atomic write is almost certainly the problem.

Like @CaptainStandby said, we purposefully kept that test behavior because non-atomic writes could easily happen in real-world use, too. Instead of changing the test to use an atomic move, we more broadly inspect what's logged.

A similar flakyness could happen if the logger internally re-ordered log lines.

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.

4 participants