Re: Hang in TestSsl testRenegotiateWorks for NIO2 (was Re: [VOTE] Release Apache Tomcat 8.0.43)
2017-04-07 14:49 GMT+02:00 Rainer Jung : > Am 07.04.2017 um 11:22 schrieb Rémy Maucherat: > >> 2017-04-06 21:57 GMT+02:00 Rainer Jung : >> >> I am not much close, but r1781988 broke it: >>> >>> "Ensure that executor thread pools used with connectors pre-start the >>> configured minimum number of idle threads." >>> >>> The change itself is OK, but as a consequence the test is now executing >>> with more threads in the executor: >>> >>> Index: java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java >>> === >>> --- java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java >>> (revision >>> 1781987) >>> +++ java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java >>> (revision >>> 1781988) >>> @@ -63,19 +63,23 @@ >>> >>> public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, >>> long >>> keepAliveTime, TimeUnit unit, BlockingQueue workQueue, >>> RejectedExecutionHandler handler) { >>> super(corePoolSize, maximumPoolSize, keepAliveTime, unit, >>> workQueue, handler); >>> +prestartAllCoreThreads(); >>> } >>> >>> public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, >>> long >>> keepAliveTime, TimeUnit unit, BlockingQueue workQueue, >>> ThreadFactory threadFactory, >>> RejectedExecutionHandler handler) { >>> super(corePoolSize, maximumPoolSize, keepAliveTime, unit, >>> workQueue, threadFactory, handler); >>> +prestartAllCoreThreads(); >>> } >>> >>> public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, >>> long >>> keepAliveTime, TimeUnit unit, BlockingQueue workQueue, >>> ThreadFactory threadFactory) { >>> super(corePoolSize, maximumPoolSize, keepAliveTime, unit, >>> workQueue, threadFactory, new RejectHandler()); >>> +prestartAllCoreThreads(); >>> } >>> >>> public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, >>> long >>> keepAliveTime, TimeUnit unit, BlockingQueue workQueue) { >>> super(corePoolSize, maximumPoolSize, keepAliveTime, unit, >>> workQueue, new RejectHandler()); >>> +prestartAllCoreThreads(); >>> } >>> >>> public long getThreadRenewalDelay() { >>> >>> >>> So at least that's why I observed it first in 8.0.42, the version that >>> change was included. >>> >>> But I'm not close to the root cause. >>> >>> Reproducability on my slow Solaris 10 Sparc system is very good, about >>> 80% >>> of all attempts show the hang. >>> >>> This test is skipped with NIO. With NIO2, it works for me, so it's not, >>> >> but when I had a look then, I became convinced it's impossible to >> guarantee >> the process will work with async IO and the SSL engine. Basically, it's >> really a blocking IO thing, preferably all integrated like with java.io. >> However, the feature should be kept since usually the user will not be in >> the worst case scenario, unlike the test. >> >> So if this bothers you, the easiest at this point is to skip the test for >> NIO2 in Tomcat 8.0. >> > > Hi Rémy > > what about: > > Index: build.xml > === > --- build.xml (revision 1790439) > +++ build.xml (working copy) > @@ -1480,6 +1480,8 @@ > unless="${test.openssl.exists}" /> > > if="${test.excludePerformance}" /> > + > + > > > > > > so one can exclude tests by listing them in property "test.exclude". For > me on Solaris TestSsl hangs the test suite, so I would prefer to > skip/exclude it, all others currently do not have a problem with it. So we > can keep the test enabled for now and I will disable it in my environment > using the new test.exclude property. Once more people or Gump etc. report > failures we can officially skip it. > > WDYT? > > +1, this option won't hurt obviously. Right now, the code is: protected static boolean isRenegotiationSupported(Tomcat tomcat) { String protocol = tomcat.getConnector().getProtocolHandlerClassName(); if (protocol.contains("Apr")) { // Disabled by default in 1.1.20 windows binary (2010-07-27) return false; } if (protocol.contains("NioProtocol") || (protocol.contains("Nio2Protocol") && isMacOs())) { // Doesn't work on all platforms - see BZ 56448. return false; } return true; } So if we know it doesn't work on Solaris, it can be filtered out there. Rémy
Re: Hang in TestSsl testRenegotiateWorks for NIO2 (was Re: [VOTE] Release Apache Tomcat 8.0.43)
Am 07.04.2017 um 11:22 schrieb Rémy Maucherat: 2017-04-06 21:57 GMT+02:00 Rainer Jung : I am not much close, but r1781988 broke it: "Ensure that executor thread pools used with connectors pre-start the configured minimum number of idle threads." The change itself is OK, but as a consequence the test is now executing with more threads in the executor: Index: java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java === --- java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision 1781987) +++ java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision 1781988) @@ -63,19 +63,23 @@ public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, RejectedExecutionHandler handler) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, ThreadFactory threadFactory, RejectedExecutionHandler handler) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, ThreadFactory threadFactory) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, new RejectHandler()); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, new RejectHandler()); +prestartAllCoreThreads(); } public long getThreadRenewalDelay() { So at least that's why I observed it first in 8.0.42, the version that change was included. But I'm not close to the root cause. Reproducability on my slow Solaris 10 Sparc system is very good, about 80% of all attempts show the hang. This test is skipped with NIO. With NIO2, it works for me, so it's not, but when I had a look then, I became convinced it's impossible to guarantee the process will work with async IO and the SSL engine. Basically, it's really a blocking IO thing, preferably all integrated like with java.io. However, the feature should be kept since usually the user will not be in the worst case scenario, unlike the test. So if this bothers you, the easiest at this point is to skip the test for NIO2 in Tomcat 8.0. Hi Rémy what about: Index: build.xml === --- build.xml (revision 1790439) +++ build.xml (working copy) @@ -1480,6 +1480,8 @@ unless="${test.openssl.exists}" /> if="${test.excludePerformance}" /> + + so one can exclude tests by listing them in property "test.exclude". For me on Solaris TestSsl hangs the test suite, so I would prefer to skip/exclude it, all others currently do not have a problem with it. So we can keep the test enabled for now and I will disable it in my environment using the new test.exclude property. Once more people or Gump etc. report failures we can officially skip it. WDYT? Regards, Rainer - To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org
Re: Hang in TestSsl testRenegotiateWorks for NIO2 (was Re: [VOTE] Release Apache Tomcat 8.0.43)
2017-04-06 21:57 GMT+02:00 Rainer Jung : > I am not much close, but r1781988 broke it: > > "Ensure that executor thread pools used with connectors pre-start the > configured minimum number of idle threads." > > The change itself is OK, but as a consequence the test is now executing > with more threads in the executor: > > Index: java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java > === > --- java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision > 1781987) > +++ java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision > 1781988) > @@ -63,19 +63,23 @@ > > public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long > keepAliveTime, TimeUnit unit, BlockingQueue workQueue, > RejectedExecutionHandler handler) { > super(corePoolSize, maximumPoolSize, keepAliveTime, unit, > workQueue, handler); > +prestartAllCoreThreads(); > } > > public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long > keepAliveTime, TimeUnit unit, BlockingQueue workQueue, > ThreadFactory threadFactory, > RejectedExecutionHandler handler) { > super(corePoolSize, maximumPoolSize, keepAliveTime, unit, > workQueue, threadFactory, handler); > +prestartAllCoreThreads(); > } > > public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long > keepAliveTime, TimeUnit unit, BlockingQueue workQueue, > ThreadFactory threadFactory) { > super(corePoolSize, maximumPoolSize, keepAliveTime, unit, > workQueue, threadFactory, new RejectHandler()); > +prestartAllCoreThreads(); > } > > public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long > keepAliveTime, TimeUnit unit, BlockingQueue workQueue) { > super(corePoolSize, maximumPoolSize, keepAliveTime, unit, > workQueue, new RejectHandler()); > +prestartAllCoreThreads(); > } > > public long getThreadRenewalDelay() { > > > So at least that's why I observed it first in 8.0.42, the version that > change was included. > > But I'm not close to the root cause. > > Reproducability on my slow Solaris 10 Sparc system is very good, about 80% > of all attempts show the hang. > > This test is skipped with NIO. With NIO2, it works for me, so it's not, but when I had a look then, I became convinced it's impossible to guarantee the process will work with async IO and the SSL engine. Basically, it's really a blocking IO thing, preferably all integrated like with java.io. However, the feature should be kept since usually the user will not be in the worst case scenario, unlike the test. So if this bothers you, the easiest at this point is to skip the test for NIO2 in Tomcat 8.0. Rémy
Re: Hang in TestSsl testRenegotiateWorks for NIO2 (was Re: [VOTE] Release Apache Tomcat 8.0.43)
I am not much close, but r1781988 broke it: "Ensure that executor thread pools used with connectors pre-start the configured minimum number of idle threads." The change itself is OK, but as a consequence the test is now executing with more threads in the executor: Index: java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java === --- java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision 1781987) +++ java/org/apache/tomcat/util/threads/ThreadPoolExecutor.java (revision 1781988) @@ -63,19 +63,23 @@ public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, RejectedExecutionHandler handler) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, ThreadFactory threadFactory, RejectedExecutionHandler handler) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, ThreadFactory threadFactory) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, new RejectHandler()); +prestartAllCoreThreads(); } public ThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, new RejectHandler()); +prestartAllCoreThreads(); } public long getThreadRenewalDelay() { So at least that's why I observed it first in 8.0.42, the version that change was included. But I'm not close to the root cause. Reproducability on my slow Solaris 10 Sparc system is very good, about 80% of all attempts show the hang. Regards, Rainer Am 05.04.2017 um 00:32 schrieb Rainer Jung: Hi Violeta, Am 04.04.2017 um 16:12 schrieb Violeta Georgieva: Hi Rainer, 2017-03-30 23:59 GMT+03:00 Rainer Jung : Am 28.03.2017 um 17:28 schrieb Violeta Georgieva: The proposed Apache Tomcat 8.0.43 release is now available for voting. It can be obtained from: https://dist.apache.org/repos/dist/dev/tomcat/tomcat-8/v8.0.43/ The Maven staging repo is: https://repository.apache.org/content/repositories/orgapachetomcat-1127/ The svn tag is: http://svn.apache.org/repos/asf/tomcat/tc8.0.x/tags/TOMCAT_8_0_43/ The proposed 8.0.43 release is: [ ] Broken - do not release [X] Stable - go ahead and release as 8.0.43 +1 to release but note one hang in TestSsl testRenegotiateWorks for NIO2. I cannot reproduce this hanging test neither on MAC nor Ubuntu. Is it possible that it is related to something with your setup? Also Buildbot and Gump are OK. For me it fails about 50% of the time (NIO2). I added some debug logging: the handshake in the TesterHandshakeListener happens during the first request in the loop in TestSsl.testRenegotiateWorks(), but then when executing the second request in the loop it hangs when trying to read the first character of the first response line. Here's a log using FINEST log level. The SEVERE lines are not errors, but the log output I added to the test class: 00:18:21.141 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTING_PREP] 00:18:21.141 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTING] 00:18:21.142 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio2-127.0.0.1-auto-3-35749"] 00:18:21.156 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTED] 00:18:21.156 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [StandardService[Tomcat]] to [STARTED] 00:18:21.157 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [StandardServer[-1]] to [STARTED] 00:18:21.163 FINE [http-nio2-127.0.0.1-auto-3-Acceptor-0] org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting up[http-nio2-127.0.0.1-auto-3-Acceptor-0] latch=0 00:18:21.194 FINE [http-nio2-127.0.0.1-auto-3-Acceptor-0] org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting up[http-nio2-127.0.0.1-auto-3-Acceptor-0] latch=1 00:18:21.197 SEVERE [main] org.apache.tomcat.util.net.TestSsl.testRenegotiateWorks begin request before socket.startHandshake 00:18:21.198 SEVERE [main] org.apache.tomcat.util.net.TestSsl.doReq
Re: Hang in TestSsl testRenegotiateWorks for NIO2 (was Re: [VOTE] Release Apache Tomcat 8.0.43)
Hi Violeta, Am 04.04.2017 um 16:12 schrieb Violeta Georgieva: Hi Rainer, 2017-03-30 23:59 GMT+03:00 Rainer Jung : Am 28.03.2017 um 17:28 schrieb Violeta Georgieva: The proposed Apache Tomcat 8.0.43 release is now available for voting. It can be obtained from: https://dist.apache.org/repos/dist/dev/tomcat/tomcat-8/v8.0.43/ The Maven staging repo is: https://repository.apache.org/content/repositories/orgapachetomcat-1127/ The svn tag is: http://svn.apache.org/repos/asf/tomcat/tc8.0.x/tags/TOMCAT_8_0_43/ The proposed 8.0.43 release is: [ ] Broken - do not release [X] Stable - go ahead and release as 8.0.43 +1 to release but note one hang in TestSsl testRenegotiateWorks for NIO2. I cannot reproduce this hanging test neither on MAC nor Ubuntu. Is it possible that it is related to something with your setup? Also Buildbot and Gump are OK. For me it fails about 50% of the time (NIO2). I added some debug logging: the handshake in the TesterHandshakeListener happens during the first request in the loop in TestSsl.testRenegotiateWorks(), but then when executing the second request in the loop it hangs when trying to read the first character of the first response line. Here's a log using FINEST log level. The SEVERE lines are not errors, but the log output I added to the test class: 00:18:21.141 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTING_PREP] 00:18:21.141 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTING] 00:18:21.142 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio2-127.0.0.1-auto-3-35749"] 00:18:21.156 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [Connector[org.apache.coyote.http11.Http11Nio2Protocol-auto-3]] to [STARTED] 00:18:21.156 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [StandardService[Tomcat]] to [STARTED] 00:18:21.157 FINE [main] org.apache.catalina.util.LifecycleBase.setStateInternal Setting state for [StandardServer[-1]] to [STARTED] 00:18:21.163 FINE [http-nio2-127.0.0.1-auto-3-Acceptor-0] org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting up[http-nio2-127.0.0.1-auto-3-Acceptor-0] latch=0 00:18:21.194 FINE [http-nio2-127.0.0.1-auto-3-Acceptor-0] org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting up[http-nio2-127.0.0.1-auto-3-Acceptor-0] latch=1 00:18:21.197 SEVERE [main] org.apache.tomcat.util.net.TestSsl.testRenegotiateWorks begin request before socket.startHandshake 00:18:21.198 SEVERE [main] org.apache.tomcat.util.net.TestSsl.doRequest begin request 00:18:21.289 FINE [http-nio2-127.0.0.1-auto-3-exec-4] org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.register Register Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.290 FINE [http-nio2-127.0.0.1-auto-3-exec-4] org.apache.tomcat.util.modeler.Registry.registerComponent Managed= Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.291 FINER [http-nio2-127.0.0.1-auto-3-exec-4] com.sun.jmx.mbeanserver.Repository.contains name = Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.291 FINER [http-nio2-127.0.0.1-auto-3-exec-4] com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean ObjectName = Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.291 FINE [http-nio2-127.0.0.1-auto-3-exec-4] org.apache.tomcat.util.modeler.BaseModelMBean.preRegister preRegister org.apache.coyote.RequestInfo@1c22e0 Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.291 FINER [http-nio2-127.0.0.1-auto-3-exec-4] com.sun.jmx.mbeanserver.Repository.addMBean name = Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.292 FINER [http-nio2-127.0.0.1-auto-3-exec-4] com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.addObject Send create notification of object Tomcat:name=HttpRequest1,type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749" 00:18:21.292 FINER [http-nio2-127.0.0.1-auto-3-exec-4] com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.sendNotification JMX.mbean.registered Tomcat:type=RequestProcessor,worker="http-nio2-127.0.0.1-auto-3-35749",name=HttpRequest1 00:18:21.293 FINE [http-nio2-127.0.0.1-auto-3-exec-4] org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process Socket: [org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@1b4ba80:org.apache.tomcat.util.net.SecureNio2Channel@32156a:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected local=/127.0.0.1:35749 remote=/127.0.0.1:35750]], Status