Fix deadlock during shutdown which prevented leader election cleanup #1688
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
Before this fix, the deadlock would prevent the leader pod from giving up its lease, which would make it take several minutes for new pods to be allowed to elect a new leader. During that time, no Pinniped controllers could write to the Kube API, so important resources were not being updated during that window. It would also make pod shutdown take about 1 minute. After this fix, the leader gives up its lease immediately, and pod shutdown takes about 1 second. This improves restart/upgrade time and also fixes the problem where there was no leader for several minutes after a restart/upgrade. The deadlock was between the post-start hook and the pre-shutdown hook. The pre-shutdown hook blocked until a certain background goroutine in the post-start hook finished, but that goroutine could not finish until the pre-shutdown hook finished. Thus, they were both blocked, waiting for each other infinitely. Eventually the process would be externally killed. This deadlock was most likely introduced by some change in Kube's generic api server package related to how the many complex channels used during server shutdown interact with each other, and was not noticed when we upgraded to the version which introduced the change.
cfryanr
force-pushed
the
fix_shutdown_deadlock
branch
from
368b1e8 to
ca6c29e
Compare
cfryanr
commented
Sep 21, 2023
| go func() { | ||
| defer cancel() | ||
|
|
||
| <-postStartContext.StopCh |
There was a problem hiding this comment.
This is where the deadlock was happening. This StopCh channel is not going to be closed until our pre-shutdown hook finishes running. But our pre-shutdown hook calls shutdown.Wait() which is effectively waiting for this goroutine to end (because this goroutine cancels the context which allows the runControllers() call to stop blocking, which in turn ends the WaitGroup that the pre-shutdown hook is waiting for).
Codecov Report
@@ Coverage Diff @@
## main #1688 +/- ##
==========================================
- Coverage 79.21% 79.15% -0.06%
==========================================
Files 163 163
Lines 15758 15769 +11
==========================================
Hits 12482 12482
- Misses 2961 2972 +11
Partials 315 315
|
|
Nice find! |
cfryanr
force-pushed
the
fix_shutdown_deadlock
branch
from
843189f to
389adfa
Compare
cfryanr
commented
Sep 22, 2023
Comment on lines
+50
to
+60
| // Skip tailing pod logs for test runs that are using alternate group suffixes. There seems to be a bug in our | ||
| // kubeclient package which causes an "unable to find resp serialier" (sic) error for pod log API responses when | ||
| // the middleware is active. Since we do not tail pod logs in production code (or anywhere else at this time), | ||
| // we don't need to fix that bug right now just for this test. | ||
| if env.APIGroupSuffix == "pinniped.dev" { |
There was a problem hiding this comment.
This new integration test failed for CI test jobs which use an alternate API group suffix. It looks like there is a bug in our kubeclient package for tailing logs when the middleware is active. For now, I just worked around it by only tailing logs in this test when the API group suffix is equal to the default.
cfryanr
changed the title
cfryanr
force-pushed
the
fix_shutdown_deadlock
branch
from
389adfa to
5e06c6d
Compare
cfryanr
commented
Sep 25, 2023
Comment on lines
+27
to
+31
| // Only run this test in CI on Kind clusters, because something about restarting the pods | ||
| // in this test breaks the "kubectl port-forward" commands that we are using in CI for | ||
| // AKS, EKS, and GKE clusters. The Go code that we wrote for graceful pod shutdown should | ||
| // not be sensitive to which distribution it runs on, so running this test only on Kind | ||
| // should give us sufficient coverage for what we are trying to test here. |
There was a problem hiding this comment.
I also had to work around an unexpected problem in CI where restarting the pods somehow breaks the kubectl port-forward that we use in CI during AKS/EKS/GKE integration testing.
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.
Before this fix, the deadlock would prevent the leader pod from giving up its lease, which would make it take several minutes for new pods to be allowed to elect a new leader. During that time, no Pinniped controllers could write to the Kube API, so important resources were not being updated during that window. It would also make pod shutdown take about 1 minute.
After this fix, the leader gives up its lease immediately, and pod shutdown takes about 1 second. This improves restart/upgrade time and also fixes the problem where there was no leader for several minutes after a restart/upgrade.
The deadlock was between the post-start hook and the pre-shutdown hook. The pre-shutdown hook blocked until a certain background goroutine in the post-start hook finished, but that goroutine could not finish until the pre-shutdown hook finished. Thus, they were both blocked, waiting for each other infinitely. Eventually the process would be externally killed.
This deadlock was most likely introduced by some change in Kube's generic api server package related to how the many complex channels used during server shutdown interact with each other, and was not noticed when we upgraded to the version which introduced the change.
The bug first appears in Pinniped v0.18.0, in which the Kube libraries were updated from 0.23.6 to 0.24.1. The relevant code in Pinniped had no changes around the time of that release. However, the kube library changed to wait for the pre-shutdown hooks to finish before continuing the remainder of the shutdown process (see the file genericapiserver.go in this diff) thus creating this deadlock.
Release note: