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 Kueue startup by waiting for webhooks server using probes #1676

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 0 additions & 12 deletions cmd/experimental/podtaintstolerations/test/e2e/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -29,8 +29,6 @@ import (
"sigs.k8s.io/controller-runtime/pkg/client"
"sigs.k8s.io/controller-runtime/pkg/client/config"
kueue "sigs.k8s.io/kueue/apis/kueue/v1beta1"
kueuetest "sigs.k8s.io/kueue/pkg/util/testing"
"sigs.k8s.io/kueue/test/util"
)

var (
Expand Down Expand Up @@ -67,17 +65,7 @@ func CreateClientUsingCluster() client.Client {
return client
}

func KueueReadyForTesting(client client.Client) {
// To verify that webhooks are ready, let's create a simple resourceflavor
resourceKueue := kueuetest.MakeResourceFlavor("default").Obj()
gomega.Eventually(func() error {
return client.Create(context.Background(), resourceKueue)
}, Timeout, Interval).Should(gomega.Succeed())
util.ExpectResourceFlavorToBeDeleted(ctx, k8sClient, resourceKueue, true)
}

var _ = ginkgo.BeforeSuite(func() {
k8sClient = CreateClientUsingCluster()
ctx = context.Background()
KueueReadyForTesting(k8sClient)
})
13 changes: 12 additions & 1 deletion cmd/kueue/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ package main
import (
"context"
"flag"
"net/http"
"os"

// Import all Kubernetes client auth plugins (e.g. Azure, GCP, OIDC, etc.)
Expand Down Expand Up @@ -278,7 +279,17 @@ func setupProbeEndpoints(mgr ctrl.Manager) {
setupLog.Error(err, "unable to set up health check")
os.Exit(1)
}
if err := mgr.AddReadyzCheck("readyz", healthz.Ping); err != nil {

// Wait for the webhook server to be listening before advertising the
// Kueue replica as ready. This allows users to wait with sending the first
// requests, requiring webhooks, until the Kueue deployment is available, so
// that the early requests are not rejected during the Kueue's startup.
// We wrap the call to GetWebhookServer in a closure to delay calling
// the function, otherwise a not fully-initialized webhook server (without
// ready certs) fails the start of the manager.
if err := mgr.AddReadyzCheck("readyz", func(req *http.Request) error {
return mgr.GetWebhookServer().StartedChecker()(req)
}); err != nil {
Comment on lines +290 to +292
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
if err := mgr.AddReadyzCheck("readyz", func(req *http.Request) error {
return mgr.GetWebhookServer().StartedChecker()(req)
}); err != nil {
if err := mgr.AddReadyzCheck("readyz",mgr.GetWebhookServer().StartedChecker()); err != nil {

Copy link
Contributor

Choose a reason for hiding this comment

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

or could the GetWebhookServer() return different servers on different calls?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I cannot do this, then the replicas never get ready. The function needs to get the webhook server once ready. I think the webhook server is set asynchronously in controller-runtime.

Copy link
Contributor

Choose a reason for hiding this comment

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

.... very strange, maybe the cert manager is is doing it ...
maybe add a comment about this if confirmed.

all other references in sigs are using it directly.
https://github.com/search?q=org%3Akubernetes-sigs%20StartedChecker&type=code

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I think it is indeed about the certs not being ready. One of the projects actually solves this problem too: https://github.com/kubernetes-sigs/hierarchical-namespaces/blob/d367fc08a261135b63d22aeb01c688317d9b7e02/cmd/manager/main.go#L296-L307.

Here they wait explicitly for the certs to be ready, I guess we could do the same so that we don't get the transient errors logged. WDYT?

Copy link
Contributor Author

@mimowo mimowo Feb 1, 2024

Choose a reason for hiding this comment

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

GetWebhookServer().StartedChecker is what we need to determine the readiness.

I'm only not sure why we need a closure for calling it , since from what I can see the field holding the webhook is private and only stable whit an option when crating the manager, however it's not a huge problem.

TBH, I'm not sure why either. What I verified experimentally is that if I just call GetWebhookServer before WaitForCertsReady then the webhook is not initialized, and it stays that way.

I get the following logs then even if keeping the readyz probe like currently, but just invoking GetWebookServer() before registering the probe:

2024-01-31T19:49:50.466048439Z	INFO	setup	kueue/main.go:291	readyz	{"ws": {"Options":{"Host":"","Port":9443,"CertDir":"/tmp/k8s-webhook-server/serving-certs","CertName":"tls.crt","KeyName":"tls.key","ClientCAName":"","TLSOpts":null,"WebhookMux":{}}}, "err": "webhook server has not been started yet"}

I suspect this has something to do with the one-time memorization of the not initialized webhook as runnable here: https://github.com/kubernetes-sigs/controller-runtime/blob/73519a939e27c8465c6c49694356cbd66daf1677/pkg/manager/internal.go#L258.

However, I'm not sure of the details. I would need to further investigate probably with debugger. Let me know if you have some ideas how to get to the bottom of it.

Let me put in the comment what I know so far.

and

, I guess we could do the same so that we don't get the transient errors logged.

What kind of errors?

I meant transient errors before the webhook server is listening, but I didn't how the look like in practice before writing. I was thinking maybe we have many errors about certs not ready. For what I can see we get these errors:

2024-01-31T13:09:29.832263236Z stderr F 2024-01-31T13:09:29.832081013Z	DEBUG	controller-runtime.healthz	healthz/healthz.go:60	healthz check failed	{"checker": "readyz", "error": "webhook server has not been started yet"}

before the checker checks the started field before attempting the connection. So, there is only a small window where we can get transient errors, between setting started: true, and actually listening: https://github.com/kubernetes-sigs/controller-runtime/blob/8475c55f3e00e5611de0880eccd785efa85e8e38/pkg/webhook/server.go#L261-L263. However, I have never seen this errors so far.

Copy link
Contributor

Choose a reason for hiding this comment

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

I have never seen this errors so far.

I'ts normal behavior when the pod is not yet ready, (previously we ware "ready" from the start).

Maybe something like:

Suggested change
if err := mgr.AddReadyzCheck("readyz", func(req *http.Request) error {
return mgr.GetWebhookServer().StartedChecker()(req)
}); err != nil {
if err := mgr.AddReadyzCheck("readyz", func(req *http.Request) error {
select{
case <-certsReady:
return mgr.GetWebhookServer().StartedChecker()(req)
case <-req.Context().Done():
return errors.New("request canceled")
}
}); err != nil {

Could decrease the umber of messages.

But i find it a bit odd to block the http handler.

Copy link
Contributor Author

@mimowo mimowo Feb 1, 2024

Choose a reason for hiding this comment

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

I was thinking about waiting explicitly for certsReady (it is done in the hierarchical-namespaces project as pointed out above).

However, I think it doesn't improve messages., because we already wait for certs ready as mgr.GetWebhookServer().StartedChecker() first checks if started=true (started=true implicitly means that certs are ready). If certs aren't ready we get the nice message: {"checker": "readyz", "error": "webhook server has not been started yet"}. I think this is enough, and no reason to complicate the code.

Copy link
Contributor Author

@mimowo mimowo Feb 1, 2024

Choose a reason for hiding this comment

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

Ok, I think I have some new insights into :

I'm only not sure why we need a closure for calling it , since from what I can see the field holding the webhook is private and only stable whit an option when crating the manager, however it's not a huge problem.

if we call GetWebhookServer early, then the not fully initialized webhook server runnable is registered here: https://github.com/kubernetes-sigs/controller-runtime/blob/73519a939e27c8465c6c49694356cbd66daf1677/pkg/manager/internal.go#L257.

When manager starts it starts all runnables, including the webhook server, but it fails, in this case I see in logs early on:

2024-02-01T12:44:13.308211223Z	INFO	controller-runtime.webhook	webhook/server.go:191	Starting webhook server
2024-02-01T12:44:13.40926745Z	INFO	controller/controller.go:178	Starting EventSource	{"controller": "cert-rotator", "source": "kind source: *v1.Secret"}
2024-02-01T12:44:13.40932954Z	INFO	controller/controller.go:178	Starting EventSource	{"controller": "cert-rotator", "source": "kind source: *unstructured.Unstructured"}
2024-02-01T12:44:13.40933832Z	INFO	manager/internal.go:516	Stopping and waiting for non leader election runnables

Note the presence of "Stopping and waiting for non leader election runnables" just after the start.

OTOH (as in this PR) If we delay calling GetWebhookServer then the runnables are added after the certs are ready, and only then the webhook server is started, then it starts successfully. We the log Starting webhook server is much later (after certs ready).

Copy link
Contributor Author

Choose a reason for hiding this comment

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

slightly polished the comment

setupLog.Error(err, "unable to set up ready check")
os.Exit(1)
}
Expand Down
1 change: 1 addition & 0 deletions hack/e2e-common.sh
Original file line number Diff line number Diff line change
Expand Up @@ -55,5 +55,6 @@ function cluster_kueue_deploy {
else
kubectl apply --server-side -k test/e2e/config
fi
kubectl wait --for=condition=available --timeout=3m deployment/kueue-controller-manager -n kueue-system
Copy link
Contributor

Choose a reason for hiding this comment

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

Can we do this somewhere else ?

It could help if in case of multikue , we deploy in manager, and instead of waiting to be ready now, we also deploy in the workers , and check the availability later on for all of them.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I see, this is a simple way of waiting for Kueue ready. I imagine users would like to use in their setup scripts. Typically it takes a couple of seconds.

One alternative is to revert the removal of KueueReadyForTesting, but I don't like it, because it recreates objects, this takes time and could cover some issues (as it is actually currently in case of single cluster). Actually, in this PR I wanted to remove it to test that it is not necessary.

Other alternatives I see modify KueueReadyForTesting to check the deployment status as this line, or run the entire setup of different clusters for MK in parallel at the script level.

Copy link
Contributor

Choose a reason for hiding this comment

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

+1 on changing KueueReadyForTesting with an availability check for the deployment.

Copy link
Contributor

Choose a reason for hiding this comment

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

Let's leave this for a follow up.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sure, but I'm not sure what is the preferred option as a follow up. Is it returning to the KueueReadyForTesting, but waiting for deployment available, as in the command line?

}

7 changes: 0 additions & 7 deletions test/e2e/multikueue/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -62,11 +62,4 @@ var _ = ginkgo.BeforeSuite(func() {
k8sWorker2Client = util.CreateClientUsingCluster("kind-" + worker2ClusterName)

ctx = context.Background()

//wait for the managers to start
// failing a this point might indicate a manifestation of
// https://kind.sigs.k8s.io/docs/user/known-issues/#pod-errors-due-to-too-many-open-files
util.KueueReadyForTesting(ctx, k8sManagerClient)
util.KueueReadyForTesting(ctx, k8sWorker1Client)
util.KueueReadyForTesting(ctx, k8sWorker2Client)
})
1 change: 0 additions & 1 deletion test/e2e/singlecluster/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -54,5 +54,4 @@ var _ = ginkgo.BeforeSuite(func() {
visibilityClient = util.CreateVisibilityClient("")
impersonatedVisibilityClient = util.CreateVisibilityClient("system:serviceaccount:kueue-system:default")
ctx = context.Background()
util.KueueReadyForTesting(ctx, k8sClient)
})
11 changes: 0 additions & 11 deletions test/util/e2e.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package util

import (
"context"
"fmt"
"os"

Expand All @@ -16,7 +15,6 @@ import (
visibility "sigs.k8s.io/kueue/apis/visibility/v1alpha1"
kueueclientset "sigs.k8s.io/kueue/client-go/clientset/versioned"
visibilityv1alpha1 "sigs.k8s.io/kueue/client-go/clientset/versioned/typed/visibility/v1alpha1"
utiltesting "sigs.k8s.io/kueue/pkg/util/testing"
)

func CreateClientUsingCluster(kContext string) client.Client {
Expand Down Expand Up @@ -64,12 +62,3 @@ func CreateVisibilityClient(user string) visibilityv1alpha1.VisibilityV1alpha1In
visibilityClient := kueueClient.VisibilityV1alpha1()
return visibilityClient
}

func KueueReadyForTesting(ctx context.Context, client client.Client) {
// To verify that webhooks are ready, let's create a simple resourceflavor
resourceKueue := utiltesting.MakeResourceFlavor("default").Obj()
gomega.Eventually(func() error {
return client.Create(context.Background(), resourceKueue)
}, StartUpTimeout, Interval).Should(gomega.Succeed())
ExpectResourceFlavorToBeDeleted(ctx, client, resourceKueue, true)
}