Replies: 4 comments 10 replies
-
6.5 introduced #4675 - just like the go client handling, we forcibly kill the watches after they've been running for between 5 and 10 minutes. Apparently it's still possible for the api server to stop sending events, but not actually close, an active watch. We had one instance of this fixed upstream, but since it seems to happen more often than the wild, we needed to be more defensive.
This particular exception handling is new. We are trying to distinguish between connection related exceptions and exceptions that are due to other problems, such as protocol violations. The behavior you are seeing here does not match with what I saw locally with the jdk client - for example killing the api server pod would result in onClose being called instead - so there could be some variation by JRE. So unfortunately we'll need to correct the handling in JdkWebSocketImpl for this, and probably will need to be more tolerant to the possibility that the informer is simply crash looping - #5047 (comment)
Yes, you may call the method isRunning, or call stopped().whenComplete(...) to install a call back that will include the terminating exception.
I need to correct that - the exceptionHandler does have all terminating exceptions forwarded to it. By default if it's a non-http gone WatchException and the informer had already been started, it will terminate. |
Beta Was this translation helpful? Give feedback.
-
|
I know there were some fixes in 6.5. That is why I hoped they would address this when it was reported with 6.4. But now it still seems to be an issue in 6.6. In the log which I have from Strimzi, the informer seems to be stuck for at least 50 minutes - so the timeout and reopening does not seem to fix it. I will try to add some additional logic to use the |
Beta Was this translation helpful? Give feedback.
-
It will be important to differentiate the exact case. With 6.5+ a single watch cannot be up for more than 10 minutes. After that time if you are not getting events, then it could be one of:
|
Beta Was this translation helpful? Give feedback.
-
Well, if I understand it correctly, this happens only internally inside the informer. So the watch is closed and recreated again and the informer continues to run, right? |
Beta Was this translation helpful? Give feedback.
-
|
Yes we are including a timeout in the watch request sent to the api server and have added a client-side fail-safe to terminate the watch as well. The expected scenario is that the watch will be re-established. |
Beta Was this translation helpful? Give feedback.
-
|
@scholzj can you confirm what is happening when you override the exception handler and see the message "watch failed for v1/namespaces/strimzi/pods, will retry" - does the informer resume? |
Beta Was this translation helpful? Give feedback.
-
|
I cannot really confirm that I'm afraid ... but I think at least for some of them it does. This is the full log I have from the user: https://gist.githubusercontent.com/Aaron-ML/88d0c9fb46d41862a9dbf4b9d9476e77/raw/cda38d24c5e741e84d62905a6927f84707eca2f3/operator.log ... if you look for the error, it shows up multiple times in random intervals. So my read on this is that the informer recovered from it at least in all apart from the last case because otherwise there would be no next watch failure if the previous failure was not recreated. But I do not know if the last one for example for some reason failed. |
Beta Was this translation helpful? Give feedback.
-
|
I see 198 retries and 434 loggings of the reset exception - there would generally be two loggings for the informer, once by the overridden exceptionHandler, then once by the reflector warning. The unmatched loggings of the reset exception seem to be coming from plain watches: The watches that have close handling may be able to restart, but those called out in strimzi/strimzi-kafka-operator#8060 will not. I'd say at first glance then it does appear that the informers are recovering as expected given that the exceptionHandler is telling the informer to always retry.
#5153 will clean up seeing the Connection reset exceptions raised to this level in the first place - they should be handled by the Watch layer. We'll only proactively terminate on specific protocol errors. The changes should also make it clearer in the logs what is going on - for example if the Watch is simply restarting without doing anything. It's not expected that you should have to use an exceptionHandler, but that is definitely a viable workaround in the meantime. |
Beta Was this translation helpful? Give feedback.
-
|
Right, sorry, I forgot to mention that ... the watchers we use directly outside of informers have our own reconnect mechanism (or the 2 from the issue you mentioned don't, but the others do). So you would not see the Fabric8 message for them. Only the watch errors logged by
Yeah, I know ... I hoped it would give more insights. Which in a way does, but not enough. |
Beta Was this translation helpful? Give feedback.
-
|
@shawkins I got some logs from another user with 6.6.1. It is attached in https://github.com/orgs/strimzi/discussions/8343#discussioncomment-5975573 (the file But never for pods - always only for our custom resources. So not sure how much it helps. |
Beta Was this translation helpful? Give feedback.
-
|
@scholzj this looks like an entirely expected sequence:
Indicates that this is not an informer based watch - there is no timeout specified.
The server has shutdown the watch websocket. Without a timeout specified the watch can live anywhere between 1-2 hours by default on openshift.
After double checking that the previous watch was closed, a new one has successfully started. |
Beta Was this translation helpful? Give feedback.
-
That explains why the Pods are not listed there as that is an informer and not a watch. That said, it does not seem like anything else was logged there that would explain why the informer got stuck. |
Beta Was this translation helpful? Give feedback.
-
|
@scholzj the only log that seems to contain informer related pod watches is the problem-at link in the subsequent comment.
The last such log is:
From there things go silent for the pods watch in terms of restarts. This is not expected as both the client and the server should enforce a timeout. The latest pr proposes a fail safe restart of the watch if our attempt to kill it fails: https://github.com/fabric8io/kubernetes-client/pull/5153/files#diff-7ca5806d751b9d76ce33e1adbef2dabd2ef3c10d499aeb66215451bd8bbff802R167 The most likely problem sequence would have to do with - if for whatever reason we don't receive a close back from the server within a minute of sending one, then abort is invoked. However I just double checked the side-effects of abort and it never invokes onClose or onError, so the downstream logic would have no idea the websocket is dead. I'll see what makes sense to refine this - at least add some logging and some additional safety logic - or possibly remove it as Jetty nor Vertx have this logic. |
Beta Was this translation helpful? Give feedback.
-
|
Makes sense. Thanks. |
Beta Was this translation helpful? Give feedback.
-
In Strimzi, we use informers and indexers to watch various Kubernetes resources - such as Pods, Secrets, or custom resources. Based on the reports from the users, it seems to happen to some of them that the informers get stuck. When it gets stuck, the informer does not get any new events and the indexer is not updated anymore. While the re-sync events are still raised by the informer, they are not really useful when the informer gives you old information. We seem to be experiencing that with 6.4 and 6.6.1.
The way we use the informer is that we use the
runnableInformer(...)method => e.g. withclient.pods().runnableInformer(300_000L)whereclientis the Kubernetes client instance. We start the informer and wait for it to sync. I also tried to add the exception handler with the.exceptionHandler()method to log any possible errors. At least in one environment it seems to log something like this:(The first message is from the
.exceptionHandler(...)method, the second is from Fabric8 itself). But not sure how this is related as this should be recoverable.What might be also notable, we use the JDK Java client.
I'm not really sure what is causing this - whether is environment-related, something in our code, etc. And I never managed to see it in any of my environments. Is there something you can recommend to debug this?
Thanks a lot for any possible suggestions.
Beta Was this translation helpful? Give feedback.
All reactions