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.

Sign up for GitHub

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

Jump to bottom

Error messages emitted on shared informers shutdown #2528

Closed
sivanov-nuodb opened this issue Oct 5, 2020 · 4 comments
Closed

Error messages emitted on shared informers shutdown #2528

sivanov-nuodb opened this issue Oct 5, 2020 · 4 comments
Labels
status/never-stale

Comments

@sivanov-nuodb
Copy link

Fabric8 Kubernetes client 4.11.0.

When invoking SharedInformerFactory::stopAllRegisteredInformers()} to gracefully shutdown all registered informers a lot of thread interrupted and socket closed exceptions are printed in the log as ERROR messages. It doesn't make sense to log them during shutting down. These may incorrectly indicate to the user that there is a problem with the application code using the client. As the logging level is ERROR, the only way for the application to suppress them is to suppress the class loggers, however, this has the risk of losing a "real" error message during normal operations.

2020-09-02T19:10:32.663+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.ProcessorListener pool-4-thread-1 Processor thread interrupted: null
2020-09-02T19:10:32.664+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.ProcessorListener pool-7-thread-1 Processor thread interrupted: null
2020-09-02T19:10:32.666+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.ProcessorListener pool-16-thread-1 Processor thread interrupted: null
2020-09-02T19:10:32.667+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.ProcessorListener pool-13-thread-1 Processor thread interrupted: null
2020-09-02T19:10:32.667+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.ProcessorListener pool-10-thread-1 Processor thread interrupted: null
2020-09-02T19:10:32.828+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.Controller informer-controller-DaemonSet DefaultController#processLoop got interrupted null
java.lang.InterruptedException: null
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
   at io.fabric8.kubernetes.client.informers.cache.DeltaFIFO.pop(DeltaFIFO.java:322)
   at io.fabric8.kubernetes.client.informers.cache.Controller.processLoop(Controller.java:157)
   at io.fabric8.kubernetes.client.informers.cache.Controller.run(Controller.java:115)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.828+0000 WARN  io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager OkHttp https://10.96.0.1/... Exec Failure
java.net.SocketException: Socket closed
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
   at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
   at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   at okio.Okio$2.read(Okio.java:140)
   at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
   at okio.RealBufferedSource.request(RealBufferedSource.java:68)
   at okio.RealBufferedSource.require(RealBufferedSource.java:61)
   at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
   at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
   at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
   at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
   at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
   at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203)
   at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.829+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.Controller informer-controller-Deployment DefaultController#processLoop got interrupted null
java.lang.InterruptedException: null
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
   at io.fabric8.kubernetes.client.informers.cache.DeltaFIFO.pop(DeltaFIFO.java:322)
   at io.fabric8.kubernetes.client.informers.cache.Controller.processLoop(Controller.java:157)
   at io.fabric8.kubernetes.client.informers.cache.Controller.run(Controller.java:115)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.829+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.Controller informer-controller-Pod DefaultController#processLoop got interrupted null
java.lang.InterruptedException: null
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
   at io.fabric8.kubernetes.client.informers.cache.DeltaFIFO.pop(DeltaFIFO.java:322)
   at io.fabric8.kubernetes.client.informers.cache.Controller.processLoop(Controller.java:157)
   at io.fabric8.kubernetes.client.informers.cache.Controller.run(Controller.java:115)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.834+0000 WARN  io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager OkHttp https://10.96.0.1/... Exec Failure
java.net.SocketException: Socket closed
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
   at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
   at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   at okio.Okio$2.read(Okio.java:140)
   at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
   at okio.RealBufferedSource.request(RealBufferedSource.java:68)
   at okio.RealBufferedSource.require(RealBufferedSource.java:61)
   at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
   at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
   at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
   at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
   at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
   at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203)
   at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.834+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.Controller informer-controller-PersistentVolumeClaim DefaultController#processLoop got interrupted null
java.lang.InterruptedException: null
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
   at io.fabric8.kubernetes.client.informers.cache.DeltaFIFO.pop(DeltaFIFO.java:322)
   at io.fabric8.kubernetes.client.informers.cache.Controller.processLoop(Controller.java:157)
   at io.fabric8.kubernetes.client.informers.cache.Controller.run(Controller.java:115)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.839+0000 ERROR  io.fabric8.kubernetes.client.informers.cache.Controller informer-controller-StatefulSet DefaultController#processLoop got interrupted null
java.lang.InterruptedException: null
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
   at io.fabric8.kubernetes.client.informers.cache.DeltaFIFO.pop(DeltaFIFO.java:322)
   at io.fabric8.kubernetes.client.informers.cache.Controller.processLoop(Controller.java:157)
   at io.fabric8.kubernetes.client.informers.cache.Controller.run(Controller.java:115)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.854+0000 INFO  org.eclipse.jetty.server.AbstractConnector Thread-5 Stopped application@236861da{SSL,[ssl, http/1.1]}{0.0.0.0:8888}
2020-09-02T19:10:32.855+0000 WARN  io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager OkHttp https://10.96.0.1/... Exec Failure
java.net.SocketException: Socket closed
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
   at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
   at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   at okio.Okio$2.read(Okio.java:140)
   at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
   at okio.RealBufferedSource.request(RealBufferedSource.java:68)
   at okio.RealBufferedSource.require(RealBufferedSource.java:61)
   at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
   at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
   at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
   at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
   at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
   at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203)
   at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.868+0000 WARN  io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager OkHttp https://10.96.0.1/... Exec Failure
java.net.SocketException: Socket closed
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
   at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
   at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   at okio.Okio$2.read(Okio.java:140)
   at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
   at okio.RealBufferedSource.request(RealBufferedSource.java:68)
   at okio.RealBufferedSource.require(RealBufferedSource.java:61)
   at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
   at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
   at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
   at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
   at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
   at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203)
   at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   at java.lang.Thread.run(Thread.java:748)
2020-09-02T19:10:32.876+0000 WARN  io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager OkHttp https://10.96.0.1/... Exec Failure
java.net.SocketException: Socket closed
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
   at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
   at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   at okio.Okio$2.read(Okio.java:140)
   at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
   at okio.RealBufferedSource.request(RealBufferedSource.java:68)
   at okio.RealBufferedSource.require(RealBufferedSource.java:61)
   at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
   at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
   at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
   at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
   at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
   at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203)
   at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   at java.lang.Thread.run(Thread.java:748)
@stale
Copy link

stale bot commented Jan 11, 2021

This issue has been automatically marked as stale because it has not had any activity since 90 days. It will be closed if no further activity occurs within 7 days. Thank you for your contributions!

@stale stale bot added the status/stale label Jan 11, 2021
@sivanov-nuodb
Copy link
Author

This issue is still relevant.

@stale stale bot removed the status/stale label Jan 11, 2021
@goldmann
Copy link
Contributor

Seeing this in v5.0.0 as well.

My use case is a Quarkus app. When it is stopping, I call stopAllRegisteredInformers() to shut down gracefully all my informers, but it results in a stacktrace similar to what we can see above.

void onStop(@Observes ShutdownEvent ev) {
    sharedInformerFactory.stopAllRegisteredInformers();
}

@shawkins
Copy link
Contributor

Mostly resolved based upon all of the informer related changes in 5.3 - 5.5 in particular #3001

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
status/never-stale
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@goldmann @shawkins @rohanKanojia @sivanov-nuodb