Timeout waiting for process kube-apiserver to stop

[ysksuzuki]

What happened:

envtest.Environment.Stop() raises the error timeout waiting for process kube-apiserver to stop with kube-apiserver 1.21.2 that set up using setup-envtest use -p env.

  Unexpected error:
      <errors.aggregate | len:1, cap:1>: [
          <*errors.errorString | 0xc000328c00>{
              s: "timeout waiting for process kube-apiserver to stop",
          },
      ]
      timeout waiting for process kube-apiserver to stop
  occurred

How to reproduce it (as minimally and precisely as possible):

Run this envtest with kube-apiserver 1.21.2.

Environment:

• controller-runtime: 0.9.2
• kube-apiserver: 1.21.2

[stijndehaes]

using 1.20.2 for example works fine

[varshaprasad96]

+1, hit the same issue and using 1.20 binaries works fine.

[erikgb]

+1, I also tested with the 1.22 binaries, and still same issue.

It would be nice if someone with the skills could take a look ASAP. 😉

/priority important-soon

[joelanford]

I'm not able to reproduce this issue with the envtest 1.22.0 binaries and controller-runtime v0.9.6.

To try to reproduce, I bumped to the latest k8s, envtest, and c-r versions here

[hickeyma]

Tested using the cronjob-tutorial, results as follows:

• Kubernetes v1.20.2: No issue
• Kubernetes v1.21.4: Issue as stated
• Kubernetes v1.22.0: Issue as stated

So, looks like issue in Kubernetes v1.21, v1.22.

[hickeyma]

This is what I have found so far. From Kubernetes 1.21+, when it tries to cleanup the test environment, there is a clash if a custom controller is created during testing. It would seem that the controller is still running and kube-apiserver will not respond to shutdown during tear down.

I can get it to work by, changing controller goroutine:

go func() {
		err = k8sManager.Start(ctrl.SetupSignalHandler())
		Expect(err).ToNot(HaveOccurred())
}()

to:

go func() {
		defer GinkgoRecover()
		err = k8sManager.Start(ctrl.SetupSignalHandler())
		Expect(err).ToNot(HaveOccurred(), "failed to run manager")
		gexec.KillAndWait(4 * time.Second)

		// Teardown the test environment once controller is fnished.
		// Otherwise from Kubernetes 1.21+, teardon timeouts waiting on
		// kube-apiserver to return
		err := testEnv.Stop()
		Expect(err).ToNot(HaveOccurred())
}()

and disabling the teardown in AfterSuite.

[tenstad]

Is it a mistake that the ctx with cancel in suite_test.go#L65 is replaced by context.Background() in suite_test.go#L97?

[erikgb]

Thx @tenstad! I think this issue can ble closed, as not a problem (here), ref. cybozu-go/coil#189.

I will prepare a PR to fix the skaffolding (and doc) in kubebuilder, ref. the workaround implemented in kubernetes-sigs/kubebuilder#2302. CC: @hickeyma

[tenstad]

Wondering if canceling the manager context is a workaround for ps.Cmd.Process.Signal(syscall.SIGTERM) not beeing able to stop the kube-apiserver process 🤔

[tenstad]

I think the problem source is a pending watch request, initiated by the controller after
the kube-apiserver has received SIGTERM. The request does not appear to have a timeout,
and is not answered by the apiserver. Graceful shutdown introduced in 1.21 appears to
wait for the pending request to terminate before shutting the apiserver completely.

To avoid the error, one must thus avoid sending watch requests after SIGTERMing the apiserver,
or avoid the watch request pending for more than StopTimeout (default 20s).
Each of the following methods avoid the "timeout waiting for process kube-apiserver to stop" error:

1. cancel() the context used in k8sManager.Start(ctx) before stopping the test environment / apiserver
2. Set Timeout in rest.Config
3. Start the kube-apiserver with --request-timeout (probably due to it controlling ShutdownTimeout)
4. Disable graceful shutdown (--feature-gates=GracefulNodeShutdown=false? - I have not yet been able to verify that this works)

1 will avoid sending requests to the terminating apiserver,
while 2 and 3 will ensure that the apiserver is terminated inside the allowed StopTimeout interval (still causing unnecessary delays).
4 will result in the same behavior as in 1.20, terminating the apiserver regardless of pending requests.

IMO, 1 is the cleanest solution. It is already implemented in kubernetes-sigs/kubebuilder#2379. A context that is canceled in envtest.Environment.Stop() could however be integrated into envtest, making it a bit easier for users.

FYI: I am not experienced with this codebase and the core of k8s, please do not take these as hard facts without verifying yourself.

[Aisuko]

Hi, guys. Hit the same issue here with 1.22.1-darwin-amd64

I have been try to add the cancel() into the AfterSuite(), but it looks like can not solve this issue.

In my situation it looks like the watch mechanism is pending by the server.

var _ = AfterSuite(func() {
	// https://github.com/kubernetes-sigs/controller-runtime/issues/1571
	cancel()
	By("tearing down the test environment,but I do nothing here.")
	err := testEnv.Stop()
	Expect(err).NotTo(HaveOccurred())
})

W0105 18:10:20.398854   63353 reflector.go:441] pkg/mod/k8s.io/client-go@v0.22.1/tools/cache/reflector.go:167: watch of *v1.ReservedIP ended with: an error on the server ("unable to decode an event from the watch stream: http2: client connection lost") has prevented the request from succeeding
STEP: tearing down the test environment,but I do nothing here.

[Aisuko]

I know this is not a solution, if anyone hit same issue like me. This may work for you, I try the solution above, migrate the testEnv.Stop from AfterSuite to BeforeSuite may cause the kube-apiserver process killed failed.

var _ = AfterSuite(func() {
	// https://github.com/kubernetes-sigs/controller-runtime/issues/1571
	cancel()
	By("tearing down the test environment,but I do nothing here.")
	err := testEnv.Stop()
        // Set 4 with random
	if err != nil {
		time.Sleep(4 * time.Second)
	}
	err = testEnv.Stop()
	Expect(err).NotTo(HaveOccurred())
})

[psaia]

I know this is not a solution, if anyone hit same issue like me. This may work for you, I try the solution above, migrate the testEnv.Stop from AfterSuite to BeforeSuite may cause the kube-apiserver process killed failed.

var _ = AfterSuite(func() {
	// https://github.com/kubernetes-sigs/controller-runtime/issues/1571
	cancel()
	By("tearing down the test environment,but I do nothing here.")
	err := testEnv.Stop()
        // Set 4 with random
	if err != nil {
		time.Sleep(4 * time.Second)
	}
	err = testEnv.Stop()
	Expect(err).NotTo(HaveOccurred())
})

For the impatient:

	err := (func() (err error) {
		// Need to sleep if the first stop fails due to a bug:
		// https://github.com/kubernetes-sigs/controller-runtime/issues/1571
		sleepTime := 1 * time.Millisecond
		for i := 0; i < 12; i++ { // Exponentially sleep up to ~4s
			if err = testEnv.Stop(); err == nil {
				return
			}
			sleepTime *= 2
			time.Sleep(sleepTime)
		}
		return
	})()
        Expect(err).NotTo(HaveOccurred())

[UgurTheG]

Maybe if someone still encounters this problem - setting ControlPlaneStopTimeout manually helped me:

	testEnv = &envtest.Environment{
		CRDDirectoryPaths: []string{
			filepath.Join("..", "..", "config", "crd", "bases"),
		},
		ErrorIfCRDPathMissing:   true,
		ControlPlaneStopTimeout: 1 * time.Minute, // Or any duration that suits your tests
	}

[KunWuLuan]

	err := (func() (err error) {
		// Need to sleep if the first stop fails due to a bug:
		// https://github.com/kubernetes-sigs/controller-runtime/issues/1571
		sleepTime := 1 * time.Millisecond
		for i := 0; i < 12; i++ { // Exponentially sleep up to ~4s
			if err = testEnv.Stop(); err == nil {
				return
			}
			sleepTime *= 2
			time.Sleep(sleepTime)
		}
		return
	})()
        Expect(err).NotTo(HaveOccurred())

This works for me.