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

webhook EOF errors #1509

Open
mattmoor opened this issue Jul 16, 2020 · 46 comments
Open

webhook EOF errors #1509

mattmoor opened this issue Jul 16, 2020 · 46 comments
Labels
area/API area/test-and-release kind/bug Categorizes issue or PR as related to a bug. lifecycle/frozen Indicates that an issue or PR should not be auto-closed due to staleness.

Comments

@mattmoor
Copy link
Member

/area API
/area test-and-release
/kind bug

Expected Behavior

When we run our e2e tests with chaos there are no failures due to the webhook shutting down.

Actual Behavior

We intermittently see failures like this: Post https://eventing-webhook.knative-eventing-qh1fjbnng8.svc:443/resource-conversion?timeout=30s: EOF ever since we enabled webhook chaos.

@knative-prow-robot knative-prow-robot added area/API area/test-and-release kind/bug Categorizes issue or PR as related to a bug. labels Jul 16, 2020
@mattmoor
Copy link
Member Author

cc @vaikas

@mattmoor
Copy link
Member Author

I already made two changed to try and mitigate this:

  1. Bumped the terminationGracePeriodSecond in our webhook pods to 300 to give the webhook itself greater control over the drain duration.
  2. Bumped the network.DefaultDrainTimeout: Bump the drain timeout #1501 to give the API Server more time to observe the endpoints change.

@mattmoor
Copy link
Member Author

From the Go http.Server Shutdown documentation:

When Shutdown is called, Serve, ListenAndServe, and ListenAndServeTLS immediately return ErrServerClosed. Make sure the program doesn't exit and waits instead for Shutdown to return.

I wondered if this might be our problem, but we call ListenAndServeTLS here:

pkg/webhook/webhook.go

Lines 207 to 210 in f1b8240

eg.Go(func() error {
if err := server.ListenAndServeTLS("", ""); err != nil && err != http.ErrServerClosed {
logger.Errorw("ListenAndServeTLS for admission webhook returned error", zap.Error(err))
return err
and seem to properly check for ErrServerClosed

@mattmoor
Copy link
Member Author

I started a thread in #sig-api-machinery here: https://kubernetes.slack.com/archives/C0EG7JC6T/p1594910493127400

@mattmoor
Copy link
Member Author

Alright, so one of the things I have been wondering is around Keep-Alives and whether that might be a reason the API server takes so long to realize an endpoint is no longer good. I noticed the following comment on Go's SetKeepAlivesEnabled:

SetKeepAlivesEnabled controls whether HTTP keep-alives are enabled. By default, keep-alives are always enabled. Only very resource-constrained environments or servers in the process of shutting down should disable them.

... emphasis mine.

Now it turns out that Go's http logic is already smart about disabling keep-alive when it is shutting down:

func (s *Server) doKeepAlives() bool {
	return atomic.LoadInt32(&s.disableKeepAlives) == 0 && !s.shuttingDown()
}

However, when we lame duck we aren't yet .shuttingDown() so I believe keep-alives will continue throughout our network.DefaultDrainTimeout until Shutdown() is actually called.

I believe testing this should be as simple as calling server.SetKeepAlivesEnabled(false) here:

However, if this works then we should probably consider doing something similar across our various dataplane components as well. cc @tcnghia

mattmoor added a commit to mattmoor/pkg that referenced this issue Jul 16, 2020
@mattmoor
Copy link
Member Author

We believe that @vaikas is still seeing some webhook failures that should be synced past the above change, so we aren't out of the woods yet.

mattmoor added a commit to mattmoor/pkg that referenced this issue Jul 17, 2020
This implements a new `http.Handler` called `Drainer`, which is intended to wrap some inner `http.Handler` business logic with a new outer handler that can respond to Kubelet probes (successfully until told to "Drain()").

This takes over the webhook's relatively new probe handling and lame duck logic with one key difference.  Previously the webhook waited for a fixed period after SIGTERM before exitting, but the new logic waits for this same grace period AFTER THE LAST REQUEST.  So if the handler keeps getting (non-probe) requests, the timer will continually reset, and once it stops receiving requests for the configured grace period, "Drain()" will return and the webhook will exit.

The goal of this work is to try to better cope with what we believe to be high tail latencies of the API server seeing that a webhook replica is shutting down.

Related: knative#1509
mattmoor added a commit to mattmoor/pkg that referenced this issue Jul 17, 2020
This implements a new `http.Handler` called `Drainer`, which is intended to wrap some inner `http.Handler` business logic with a new outer handler that can respond to Kubelet probes (successfully until told to "Drain()").

This takes over the webhook's relatively new probe handling and lame duck logic with one key difference.  Previously the webhook waited for a fixed period after SIGTERM before exitting, but the new logic waits for this same grace period AFTER THE LAST REQUEST.  So if the handler keeps getting (non-probe) requests, the timer will continually reset, and once it stops receiving requests for the configured grace period, "Drain()" will return and the webhook will exit.

The goal of this work is to try to better cope with what we believe to be high tail latencies of the API server seeing that a webhook replica is shutting down.

Related: knative#1509
@mattmoor
Copy link
Member Author

The new "Drainer" handler in the linked PR uses a dynamic drain timeout where it waits for at least network.DefaultDrainTimeout after the last request before terminating the webhook. With that constant set to 45s, let's see if there are any failures... 🤞

knative-prow-robot pushed a commit that referenced this issue Jul 18, 2020
* Implement a new shared "Drainer" handler.

This implements a new `http.Handler` called `Drainer`, which is intended to wrap some inner `http.Handler` business logic with a new outer handler that can respond to Kubelet probes (successfully until told to "Drain()").

This takes over the webhook's relatively new probe handling and lame duck logic with one key difference.  Previously the webhook waited for a fixed period after SIGTERM before exitting, but the new logic waits for this same grace period AFTER THE LAST REQUEST.  So if the handler keeps getting (non-probe) requests, the timer will continually reset, and once it stops receiving requests for the configured grace period, "Drain()" will return and the webhook will exit.

The goal of this work is to try to better cope with what we believe to be high tail latencies of the API server seeing that a webhook replica is shutting down.

Related: #1509

* Switch to RWLock
mattmoor added a commit to mattmoor/eventing that referenced this issue Jul 18, 2020
This is attempting to try and combat the webhook Post EOF errors we have been seeing intermittently: knative/pkg#1509
knative-prow-robot pushed a commit to knative/eventing that referenced this issue Jul 18, 2020
This is attempting to try and combat the webhook Post EOF errors we have been seeing intermittently: knative/pkg#1509
@mattmoor
Copy link
Member Author

One of the two flakes in eventing yesterday was this:

TestChannelDataPlaneSuccess/InMemoryChannel-messaging.knative.dev/v1/full-event_encoding_binary_version_1.0: creation.go:108: Failed to create subscription "full-event-binary-10-sub": Internal error occurred: failed calling webhook "webhook.eventing.knative.dev": Post https://eventing-webhook.knative-eventing-sfqaktzdqa.svc:443/defaulting?timeout=2s: EOF

I need to track down whether that CI run had the drainer stuff in yet.

@mattmoor
Copy link
Member Author

mattmoor commented Jul 19, 2020

Hmm looks like it was at 239f7fc, which includes the drainer.

Link to the full run: https://prow.knative.dev/view/gcs/knative-prow/logs/ci-knative-eventing-continuous/1284652424807583744

@vaikas
Copy link
Contributor

vaikas commented Jul 21, 2020

Tomorrow I'm going to add a workaround for this by using Retry loops, just like we do for when pod creates (or configmaps fail) with very specific error cases. This will be a workaround for now hopefully so that we'll be able to not get tests that fail if they hit this condition. Reconcilers should be resilient to this, but tests that use create*orFail will not, so this will at least cut down some noise. I'll make sure to log these so at least we see how often this happens.

@markusthoemmes
Copy link
Contributor

@mattmoor
Copy link
Member Author

It definitely is. Open to suggestions on how we might keep chipping away at this / instrument / debug / ...

@mattmoor
Copy link
Member Author

I had an idea chatting with @markusthoemmes a bit on slack.

Right now there's a lot of machinery standing between us and the EOFs that it is making them harder to debug than they should be. The thought is: can we have a more dedicated probing process that we can use to reproduce this (maybe more consistently)?

@dprotaso
Copy link
Member

Interestingly one way to reproduce this consistently is to panic in the webhook when handling a request (ie. the defaulting logic)

golang's http server recovers these panics and logs an error.

We should potentially recover ourselves so we can return an 'internal server' type error

@dprotaso
Copy link
Member

dprotaso commented May 19, 2021

As part of knative/serving#11225 I encountered EOF's/context deadline exceeded. After adding some tracing I've seen our web hooks respond <10ms but then the API server still returns a timeout.

So I don't think this is isolated to just our web hooks.

My next steps is to start testing with a non-managed k8s service to be able to get API server logs

knative-prow-robot pushed a commit to knative/eventing that referenced this issue May 20, 2021
Serving has done this as well, the chaosduck killing the webhook causes
errors being tracked in knative/pkg#1509
pierDipi added a commit to pierDipi/eventing-kafka that referenced this issue Nov 9, 2021
Mitigation for knative/pkg#1509.

Same fix was used in eventing core to mitigate webhook EOF
errors.

Signed-off-by: Pierangelo Di Pilato <[email protected]>
knative-prow-robot pushed a commit to knative-extensions/eventing-kafka that referenced this issue Nov 9, 2021
Mitigation for knative/pkg#1509.

Same fix was used in eventing core to mitigate webhook EOF
errors.

Signed-off-by: Pierangelo Di Pilato <[email protected]>
pierDipi added a commit to pierDipi/eventing-kafka that referenced this issue Nov 10, 2021
Mitigation for knative/pkg#1509.

Same fix was used in eventing core to mitigate webhook EOF
errors.

Signed-off-by: Pierangelo Di Pilato <[email protected]>
pierDipi added a commit to pierDipi/eventing-kafka that referenced this issue Nov 10, 2021
Mitigation for knative/pkg#1509.

Same fix was used in eventing core to mitigate webhook EOF
errors.

Signed-off-by: Pierangelo Di Pilato <[email protected]>
pierDipi added a commit to pierDipi/eventing-kafka that referenced this issue Nov 10, 2021
Mitigation for knative/pkg#1509.

Same fix was used in eventing core to mitigate webhook EOF
errors.

Signed-off-by: Pierangelo Di Pilato <[email protected]>
pierDipi added a commit to pierDipi/eventing-kafka-broker that referenced this issue Aug 8, 2022
This test sometimes fails due to [1].

[1] knative/pkg#1509

Signed-off-by: Pierangelo Di Pilato <[email protected]>
pierDipi added a commit to pierDipi/eventing-kafka-broker that referenced this issue Aug 8, 2022
This test sometimes fails due to [1].

[1] knative/pkg#1509

Signed-off-by: Pierangelo Di Pilato <[email protected]>
knative-prow bot pushed a commit to knative-extensions/eventing-kafka-broker that referenced this issue Aug 9, 2022
This test sometimes fails due to [1].

[1] knative/pkg#1509

Signed-off-by: Pierangelo Di Pilato <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/API area/test-and-release kind/bug Categorizes issue or PR as related to a bug. lifecycle/frozen Indicates that an issue or PR should not be auto-closed due to staleness.
Projects
None yet
Development

No branches or pull requests

8 participants