-
Task
-
Resolution: Fixed
-
L3 - Default
-
None
-
Not defined
Context:
In case a Websocket connection breaks we often see logs such as:
ERROR o.c.o.websocket.StatusNotifier - can't write status to web socket org.eclipse.jetty.io.EofException: null at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279) at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:584) at org.eclipse.jetty.websocket.common.extensions.AbstractExtension.nextOutgoingFrame(AbstractExtension.java:155) at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.nextOutgoingFrame(PerMessageDeflateExtension.java:123) at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.access$1100(CompressExtension.java:44) at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.compress(CompressExtension.java:591) at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.deflate(CompressExtension.java:488) at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.process(CompressExtension.java:468) at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.outgoingFrame(CompressExtension.java:244) at org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher.process(ExtensionStack.java:400) at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.outgoingFrame(ExtensionStack.java:277) at org.eclipse.jetty.websocket.common.WebSocketSession.outgoingFrame(WebSocketSession.java:359) at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.uncheckedSendFrame(WebSocketRemoteEndpoint.java:306) at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.blockingWrite(WebSocketRemoteEndpoint.java:106) at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendString(WebSocketRemoteEndpoint.java:384) at org.eclipse.jetty.websocket.jsr356.JsrBasicRemote.sendText(JsrBasicRemote.java:107) at org.camunda.optimize.websocket.StatusNotifier.sendStatus(StatusNotifier.java:59) at org.camunda.optimize.websocket.StatusNotifier.<init>(StatusNotifier.java:37) at org.camunda.optimize.websocket.StatusWebSocket.onOpen(StatusWebSocket.java:41) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70) at org.eclipse.jetty.websocket.jsr356.annotations.OnOpenCallable.call(OnOpenCallable.java:52) at org.eclipse.jetty.websocket.jsr356.annotations.JsrEvents.callOpen(JsrEvents.java:170) at org.eclipse.jetty.websocket.jsr356.endpoints.JsrAnnotatedEventDriver.onConnect(JsrAnnotatedEventDriver.java:191) at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.openSession(AbstractEventDriver.java:216) at org.eclipse.jetty.websocket.jsr356.endpoints.AbstractJsrEventDriver.openSession(AbstractJsrEventDriver.java:103) at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:492) at org.eclipse.jetty.websocket.common.WebSocketSession.onOpened(WebSocketSession.java:458) at org.eclipse.jetty.io.AbstractConnection.onOpened(AbstractConnection.java:213) at org.eclipse.jetty.io.AbstractConnection.onOpen(AbstractConnection.java:205) at org.eclipse.jetty.io.AbstractEndPoint.upgrade(AbstractEndPoint.java:442) at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:387) at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:743) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:363) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) at java.lang.Thread.run(Thread.java:748) Caused by: java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) at sun.nio.ch.IOUtil.write(IOUtil.java:148) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:501) at java.nio.channels.SocketChannel.write(SocketChannel.java:502) at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:273) ... 59 common frames omitted
Which are way too verbose and not worth an error log.
We should rather log such a case only as WARN and without a stacktrace. For debugging purposes we may add an additional debug log statement that also includes the stacktrace to still be able to root-cause in case these connection drops happen too frequently.
AT:
- only a single line WARN log statement is issued on IOException when writing to a status websocket
- the exception stacktrace is logged with an additional debug log statement only
- ensure sure broken connections are properly removed