Skip to content

Revisit Tyrus logging, prefer System.Logger instead of JUL or STDOUT. #953

@dmatej

Description

@dmatej

This sparked my interest when I have noticed this in logs of the GlassFish Server 7.1.0 running TCK 10.0.7. GlassFish redirects STDOUT to own GJULE handlers, but using STDERR/STDOUT still harms performance, readability and ability to filter and redirect logging.

Also, I am not sure, if this should be processed as an error, but that is controversial with any library working with I/O, how they should handle request to stop, because then clients can block restarts OR their request can be interrupted.

Maybe we should do something like

If we were asked to stop, log these errors just as debug level, count them, and when we really stopped, log just warning about the count of interrupted sessions/requests, whatever it is.

03:21:51.393  [2026-02-07T02:20:42.318568Z] [GF 7.1.0] [SEVERE] [] [jakarta.enterprise.logging.stderr] [tid: _ThreadID=93 _ThreadName=http-listener-1(2)] [levelValue: 1000] [[
03:21:51.393    java.lang.IllegalStateException: The connection has been closed.
03:21:51.393  	at org.glassfish.tyrus.core.TyrusSession.checkConnectionState(TyrusSession.java:544)
03:21:51.393  	at org.glassfish.tyrus.core.TyrusSession.getBasicRemote(TyrusSession.java:207)
03:21:51.393  	at WebappClassLoader//com.sun.ts.tests.websocket.spec.servercontainer.addendpoint.WSTestServer.onClose(WSTestServer.java:148)
03:21:51.393  	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
03:21:51.393  	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
03:21:51.393  	at org.glassfish.tyrus.core.AnnotatedEndpoint.callMethod(AnnotatedEndpoint.java:556)
03:21:51.393  	at org.glassfish.tyrus.core.AnnotatedEndpoint.onClose(AnnotatedEndpoint.java:571)
03:21:51.393  	at org.glassfish.tyrus.core.AnnotatedEndpoint.onClose(AnnotatedEndpoint.java:580)
03:21:51.393  	at org.glassfish.tyrus.core.TyrusEndpointWrapper.onClose(TyrusEndpointWrapper.java:1246)
03:21:51.393  	at org.glassfish.tyrus.core.TyrusWebSocket.onClose(TyrusWebSocket.java:110)
03:21:51.393  	at org.glassfish.tyrus.core.frame.CloseFrame.respond(CloseFrame.java:112)
03:21:51.393  	at org.glassfish.tyrus.core.ProtocolHandler.process(ProtocolHandler.java:826)
03:21:51.393  	at org.glassfish.tyrus.core.TyrusWebSocketEngine$TyrusReadHandler.handle(TyrusWebSocketEngine.java:552)
03:21:51.393  	at org.glassfish.tyrus.servlet.TyrusHttpUpgradeHandler.onDataAvailable(TyrusHttpUpgradeHandler.java:150)
03:21:51.393  	at org.apache.catalina.connector.InputBuffer$ReadHandlerImpl.processDataAvailable(InputBuffer.java:422)
03:21:51.393  	at org.apache.catalina.connector.InputBuffer$ReadHandlerImpl.onDataAvailable(InputBuffer.java:387)
03:21:51.393  	at org.glassfish.grizzly.http.io.InputBuffer.invokeHandler(InputBuffer.java:1019)
03:21:51.393  	at org.glassfish.grizzly.http.io.InputBuffer.invokeHandlerOnProperThread(InputBuffer.java:1012)
03:21:51.393  	at org.glassfish.grizzly.http.io.InputBuffer.append(InputBuffer.java:907)
03:21:51.393  	at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:224)
03:21:51.393  	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:88)
03:21:51.393  	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:246)
03:21:51.393  	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:178)
03:21:51.393  	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:118)
03:21:51.393  	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:96)
03:21:51.393  	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:51)
03:21:51.393  	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:510)
03:21:51.393  	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:82)
03:21:51.393  	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:83)
03:21:51.393  	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:101)
03:21:51.393  	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:535)
03:21:51.393  	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:515)
03:21:51.393  	at java.base/java.lang.Thread.run(Thread.java:1583)

Metadata

Metadata

Assignees

Labels

enhancementNew feature or request

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions