Make sure Stop hooks are executed when Start times out on a long-running Start hook #1061
Conversation
This file contains 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
Codecov Report
@@ Coverage Diff @@
## master #1061 +/- ##
=======================================
Coverage 98.52% 98.52%
=======================================
Files 39 39
Lines 2989 2989
=======================================
Hits 2945 2945
Misses 37 37
Partials 7 7
📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more |
sywhang
approved these changes
Mar 27, 2023
sywhang
added a commit
to sywhang/fx
that referenced
this pull request
Mar 28, 2023
In uber-go#1061, a fix was made to ensure all Stop hooks whose corresponding Start hooks ran successfully were run. This does not fix a case where it's possible for the Start hooks to race with the Stop hooks. In particular, it's possible for a Start hook to be in the middle of execution when Fx App bails out of the execution loop due to Start lifecycle context expiration. If the Stop hook happens to be running when the Start hook finishes running, the same hook will be run twice because the l.hooks and l.numStarted can change in the middle of the Stop hook execution loop. The fix is quite simple - we need to snapshot this state before going into the Stop hook execution loop so that the changed state due to the Start hook that updated the state does not affect the Stop hook execution loop. Verified that the attached test fails without the fix made in this PR with the following error: ``` --- FAIL: TestAppStart (0.00s) --- FAIL: TestAppStart/race_test (0.30s) app_test.go:1252: Error Trace: /Users/sungyoon/go/src/github.com/uber-go/fx/app_test.go:1252 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:338 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:300 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:700 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:781 /Users/sungyoon/go/src/github.com/uber-go/fx/asm_arm64.s:1172 Error: expected each hook to run exactly once only Test: TestAppStart/race_test FAIL ```
sywhang
added a commit
to sywhang/fx
that referenced
this pull request
Mar 28, 2023
In uber-go#1061, a fix was made to ensure all Stop hooks whose corresponding Start hooks ran successfully were run. This does not fix a case where it's possible for the Start hooks to race with the Stop hooks. In particular, it's possible for a Start hook to be in the middle of execution when Fx App bails out of the execution loop due to Start lifecycle context expiration. If the Stop hook happens to be running when the Start hook finishes running, the same hook will be run twice because the l.hooks and l.numStarted can change in the middle of the Stop hook execution loop. The fix is quite simple - we need to snapshot this state before going into the Stop hook execution loop so that the changed state due to the Start hook that updated the state does not affect the Stop hook execution loop. Verified that the attached test fails without the fix made in this PR with the following error: ``` --- FAIL: TestAppStart (0.00s) --- FAIL: TestAppStart/race_test (0.30s) app_test.go:1252: Error Trace: /Users/sungyoon/go/src/github.com/uber-go/fx/app_test.go:1252 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:338 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:300 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:700 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:781 /Users/sungyoon/go/src/github.com/uber-go/fx/asm_arm64.s:1172 Error: expected each hook to run exactly once only Test: TestAppStart/race_test FAIL ```
sywhang
added a commit
that referenced
this pull request
Mar 28, 2023
In #1061, a fix was made to ensure all Stop hooks whose corresponding Start hooks ran successfully were run. This does not fix a case where it's possible for the Start hooks to race with the Stop hooks. In particular, it's possible for a Start hook to be in the middle of execution when Fx App bails out of the execution loop due to Start lifecycle context expiration. If the Stop hook happens to be running when the Start hook finishes running, the same hook will be run twice because the l.hooks and l.numStarted can change in the middle of the Stop hook execution loop. The fix is quite simple - we need to snapshot this state before going into the Stop hook execution loop so that the changed state due to the Start hook that updated the state does not affect the Stop hook execution loop. Verified that the attached test fails without the fix made in this PR with the following error: ``` --- FAIL: TestAppStart (0.00s) --- FAIL: TestAppStart/race_test (0.30s) app_test.go:1252: Error Trace: /Users/sungyoon/go/src/github.com/uber-go/fx/app_test.go:1252 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:338 /Users/sungyoon/go/src/github.com/uber-go/fx/lifecycle.go:300 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:700 /Users/sungyoon/go/src/github.com/uber-go/fx/app.go:781 /Users/sungyoon/go/src/github.com/uber-go/fx/asm_arm64.s:1172 Error: expected each hook to run exactly once only Test: TestAppStart/race_test FAIL ```
JacobOaks
added a commit
that referenced
this pull request
Mar 30, 2023
#1062 introduced a test for fixing a race condition introduced by #1061. #1063 tuned this race condition because it was failing on Windows machines. This PR changes the test to use channels instead of relying on timing to provide more deterministic reproduction of the race, with the caveat being that it's not triggered by context timeout or cancel anymore. I have verified that this consistently fails pre-#1062 and consistently passes post-#1062.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
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.
Currently, none of Stop hooks are run if app.Start fails with a timeout, and app's lifecycle
is stuck on waiting for a long-running Start hook to finish executing. While we cannot run Stop
hook for the long-running Start hook that caused the timeout, we can still run rest of the Stop
hooks for the Start hooks that finished running.
In this PR, this is done by just easing up the requirement for running Stop hooks to include
lifecycle's
startingstate. Ideally the app's lifecycle state should transition intoincompleteStartwhen a long-running Start hook causes the context to timeout and doesnot respect the context expiration. However, this requires a bigger refactor so that all
lifecycle hook invocations are made asynchronous.
Fixes #1035