On Fri, Mar 8, 2024 at 9:28 PM Rainer Jung <rainer.j...@kippdata.de> wrote: > > Again, this is not a new failure and it happens extremely infrequent. > Observed with JSSE on various Linux distributions and with various JVM > versions and vendors. Only observed for TC 8.5 and 9, but for 10.1 and > 11 the unit tests are run with much fewer JVM combinations so I can not > exclude the problem might happen there as well. > > This info is not intended to prevent a release. > > The typical situation is: > > Testcase: testBug49567 took 21.162 sec > FAILED > expected:<...alse2true3true4true5[false]> but > was:<...alse2true3true4true5[]> > junit.framework.AssertionFailedError: > expected:<...alse2true3true4true5[false]> but > was:<...alse2true3true4true5[]> > at > org.apache.catalina.core.TestAsyncContextImpl.testBug49567(TestAsyncContextImpl.java:163) > at > java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) > > The execution log contains: > > 22-Feb-2024 11:19:03.617 INFO [main] > org.apache.catalina.startup.LoggingBaseTest.setUp Starting test case > [testBug49567] > 22-Feb-2024 11:19:03.626 INFO [main] > org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler > ["http-nio-127.0.0.1-auto-11"] > 22-Feb-2024 11:19:03.627 INFO [main] > org.apache.catalina.core.StandardService.startInternal Starting service > [Tomcat] > 22-Feb-2024 11:19:03.627 INFO [main] > org.apache.catalina.core.StandardEngine.startInternal Starting Servlet > engine: [Apache Tomcat/9.0.86] > 22-Feb-2024 11:19:03.640 INFO [main] > org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler > ["http-nio-127.0.0.1-auto-11-46529"] > Exception in thread "Thread-9" java.lang.NullPointerException: Cannot > invoke "org.apache.catalina.connector.Request.getCoyoteRequest()" > because "this.request" is null > at > org.apache.catalina.core.AsyncContextImpl.isStarted(AsyncContextImpl.java:295) > at > org.apache.catalina.connector.Request.isAsyncStarted(Request.java:1715) > at > org.apache.catalina.connector.RequestFacade.isAsyncStarted(RequestFacade.java:749) > at > org.apache.catalina.core.TestAsyncContextImpl$Bug49567Servlet$1$1.run(TestAsyncContextImpl.java:383) > at java.base/java.lang.Thread.run(Thread.java:1583) > 22-Feb-2024 11:19:24.685 INFO [main] > org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler > ["http-nio-127.0.0.1-auto-11-46529"] > 22-Feb-2024 11:19:24.693 INFO [main] > org.apache.catalina.core.StandardService.stopInternal Stopping service > [Tomcat] > 22-Feb-2024 11:19:24.729 INFO [main] > org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler > ["http-nio-127.0.0.1-auto-11-46529"] > 22-Feb-2024 11:19:24.739 INFO [main] > org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler > ["http-nio-127.0.0.1-auto-11-46529"] > > > or as a variation: > > 08-Mar-2024 14:44:59.132 INFO [main] > org.apache.catalina.startup.LoggingBaseTest.setUp Starting test case > [testBug49528] > 08-Mar-2024 14:44:59.141 INFO [main] > org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler > ["http-nio2-127.0.0.1-auto-10"] > 08-Mar-2024 14:44:59.151 INFO [main] > org.apache.catalina.core.StandardService.startInternal Starting service > [Tomcat] > 08-Mar-2024 14:44:59.151 INFO [main] > org.apache.catalina.core.StandardEngine.startInternal Starting Servlet > engine: [Apache Tomcat/9.0.86sp1] > 08-Mar-2024 14:44:59.170 INFO [main] > org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler > ["http-nio2-127.0.0.1-auto-10-37101"] > java.lang.NullPointerException: Cannot invoke > "org.apache.catalina.connector.Request.getCoyoteRequest()" because > "this.request" is null > at > org.apache.catalina.core.AsyncContextImpl.isStarted(AsyncContextImpl.java:295) > at > org.apache.catalina.connector.Request.isAsyncStarted(Request.java:1715) > at > org.apache.catalina.connector.RequestFacade.isAsyncStarted(RequestFacade.java:749) > at > org.apache.catalina.core.TestAsyncContextImpl$Bug49528Servlet$1.run(TestAsyncContextImpl.java:303) > at > org.apache.catalina.core.AsyncContextImpl$RunnableWrapper.run(AsyncContextImpl.java:543) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) > at java.base/java.lang.Thread.run(Thread.java:1583) > 08-Mar-2024 14:45:00.196 INFO [main] > org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler > ["http-nio2-127.0.0.1-auto-10-37101"] > 08-Mar-2024 14:45:00.198 INFO [main] > org.apache.catalina.core.StandardService.stopInternal Stopping service > [Tomcat] > 08-Mar-2024 14:45:00.217 INFO [main] > org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler > ["http-nio2-127.0.0.1-auto-10-37101"] > 08-Mar-2024 14:45:00.219 INFO [main] > org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler > ["http-nio2-127.0.0.1-auto-10-37101"] > > > In addition to these failures I also see NullPointerExceptions in other > places and other test cases in TestAsyncContextImpl. Those typically go > unnoticed, because they do not result in a test failure. It seems they > happen during test shutdown, so they might be unrelated and not > important. An example: > > 17-Jan-2024 15:14:13.604 INFO [main] > org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler > ["http-nio-127.0.0.1-auto-44-53668"] > 17-Jan-2024 15:14:13.611 INFO [main] > org.apache.catalina.core.StandardService.stopInternal Stopping service > [Tomcat] > 17-Jan-2024 15:14:13.616 INFO [main] > org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler > ["http-nio-127.0.0.1-auto-44-53668"] > 17-Jan-2024 15:14:13.621 SEVERE [http-nio-127.0.0.1-auto-44-exec-1] > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun Error > running socket processor > java.lang.NullPointerException > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.getSelectionKey(NioEndpoint.java:1835) > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1797) > at > org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.lang.Thread.run(Thread.java:750) > Exception in thread "http-nio-127.0.0.1-auto-44-exec-1" > java.lang.NullPointerException > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.getSelectionKey(NioEndpoint.java:1835) > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1813) > at > org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) > at > org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.lang.Thread.run(Thread.java:750) > 17-Jan-2024 15:14:13.631 INFO [main] > org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler > ["http-nio-127.0.0.1-auto-44-53668"]
Ok, so I don't know about the rest for now, but however for NIO, it has a lot of important refactorings and fixes in newer Java versions. The code causing the NPE here is the workaround to avoid a ridiculous deadlock (is this particular case, simply closing a channel could have the NIO internal code deadlock itself - Tomcat is not holding any lock or anything, obviously). Maybe it could be a bit more defensive to avoid the NPE ... Basically Oracle "abandoned" NIO for a while after Java 1.7, they did NIO2 instead. NIO2 seemed stable and clean (IMO it is). Then after a while people were still using NIO and it had all sorts of problems, so they went back and actually refactored significantly. Java 11 has these fixes. Then later they added features that are not in NIO2 like the Unix domain sockets. So now NIO2 is the "abandoned" one. My conclusion is that NIO has more issues on Java 1.8 (so probably consider NIO2 instead ?), but NIO is fine on Java 11+, and then might be "better" on Java 17+ (because new features, always a good thing). Rémy > > > Thanks and regards, > > Rainer > > --------------------------------------------------------------------- > To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org > For additional commands, e-mail: dev-h...@tomcat.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org
