Hi, 2013/7/26 Simone Bordet <[email protected]>
> Hi, > > On Fri, Jul 26, 2013 at 12:00 PM, Mikhail Mazursky <[email protected]> > wrote: > > 2013/7/26 Simone Bordet <[email protected]> > >> Perhaps you're using more than 1 thread pool, configured in other XML > >> files. > >> > > No, I checked. Is that even possible? > > Sure it is. > Server has one pool, Connectors may have their own, some Servlet may > use HttpClient which has its own, etc. > > We never saw this problem, so I have doubt that there is a problem in > QueuedThreadPool. > > How do you know it is Jetty that creates those threads ? > I did a kill -3 <PID> (jstack failed to get traces) and used grep to figure out what's happening # grep "\"qtp" ./26.log | wc -l 800 Lines are like this: 2013-07-26_04:22:51.83659 "qtp1610394324-740494" prio=10 tid=0x00007fde60763800 nid=0x74e1 waiting for monitor entry [0x00007fdcf7d7d000] 2013-07-26_04:22:51.83743 "qtp1610394324-740492" prio=10 tid=0x00007fde604de800 nid=0x74cc waiting for monitor entry [0x00007fdd5c5c4000] 2013-07-26_04:22:51.83855 "qtp1610394324-740477" prio=10 tid=0x00007fde604de000 nid=0x74c2 waiting for monitor entry [0x00007fdd322a0000] 2013-07-26_04:22:51.83893 "qtp1610394324-740476" prio=10 tid=0x00007fde604dd000 nid=0x74c1 waiting for monitor entry [0x00007fdd0a4a3000] 2013-07-26_04:22:51.83935 "qtp1610394324-740475" prio=10 tid=0x00007fde6096b800 nid=0x74c0 runnable [0x00007fdd43d3d000] Threads with name staring with "qtp" are created only by Jetty, other threads have different names. Some more facts: - JVM thrown OutOfMemoryErrors several times during our load testing - maybe such condition is not handled very well in Jetty? The cause of OOM is definitelly not Jetty but our application. But maybe it happened in Jetty's thread and broke something in Jetty? - A lot of Jetty threads are stuck with this stacktrace: 2013-07-26_04:22:51.82477 "qtp1610394324-740607" prio=10 tid=0x00007fde60776800 nid=0x7752 waiting for monitor entry [0x00007fdd329a7000] 2013-07-26_04:22:51.82478 java.lang.Thread.State: BLOCKED (on object monitor) 2013-07-26_04:22:51.82480 at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:390) 2013-07-26_04:22:51.82481 - waiting to lock <0x00000005262b1e90> (a org.eclipse.jetty.osgi.boot.internal.webapp.OSGiWebappClassLoader) 2013-07-26_04:22:51.82482 at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:383) 2013-07-26_04:22:51.82482 at ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:202) 2013-07-26_04:22:51.82483 at ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:227) 2013-07-26_04:22:51.82484 at ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:136) 2013-07-26_04:22:51.82484 at ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:99) 2013-07-26_04:22:51.82485 at ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:55) 2013-07-26_04:22:51.82486 at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147) 2013-07-26_04:22:51.82488 at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:129) 2013-07-26_04:22:51.82488 at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439) 2013-07-26_04:22:51.82491 at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:395) 2013-07-26_04:22:51.82493 at ch.qos.logback.classic.Logger.log(Logger.java:787) 2013-07-26_04:22:51.82494 at org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:607) 2013-07-26_04:22:51.82495 at org.eclipse.jetty.util.log.JettyAwareLogger.warn(JettyAwareLogger.java:431) 2013-07-26_04:22:51.82496 at org.eclipse.jetty.util.log.Slf4jLog.warn(Slf4jLog.java:69) 2013-07-26_04:22:51.82497 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:517) 2013-07-26_04:22:51.82498 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) 2013-07-26_04:22:51.82498 at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557) 2013-07-26_04:22:51.82499 at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) 2013-07-26_04:22:51.82500 at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1075) 2013-07-26_04:22:51.82501 at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384) 2013-07-26_04:22:51.82501 at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) 2013-07-26_04:22:51.82502 at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009) 2013-07-26_04:22:51.82505 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) 2013-07-26_04:22:51.82506 at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255) 2013-07-26_04:22:51.82507 at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154) 2013-07-26_04:22:51.82508 at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) 2013-07-26_04:22:51.82508 at org.eclipse.jetty.server.Server.handle(Server.java:370) 2013-07-26_04:22:51.82509 at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489) 2013-07-26_04:22:51.82510 at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:949) 2013-07-26_04:22:51.82511 at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1011) 2013-07-26_04:22:51.82511 at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644) 2013-07-26_04:22:51.82512 at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) 2013-07-26_04:22:51.82513 at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) 2013-07-26_04:22:51.82514 at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668) 2013-07-26_04:22:51.82516 at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) 2013-07-26_04:22:51.82517 at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) 2013-07-26_04:22:51.82518 at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) 2013-07-26_04:22:51.82518 at java.lang.Thread.run(Thread.java:724) # grep "PackagingDataCalculator.loadClass" ./26.log | wc -l 332 # grep "org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(" ./26.log | wc -l 656 This looks like classloading problem to me. The thread, that holds the lock, have this stacktrace: 2013-07-26_04:22:51.86917 "qtp1610394324-739498" prio=10 tid=0x00007fde60808800 nid=0x6f8f runnable [0x00007fdd4baba000] 2013-07-26_04:22:51.86918 java.lang.Thread.State: RUNNABLE 2013-07-26_04:22:51.86919 at java.lang.ClassLoader.findLoadedClass0(Native Method) 2013-07-26_04:22:51.86920 at java.lang.ClassLoader.findLoadedClass(ClassLoader.java:1085) 2013-07-26_04:22:51.86920 at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.publicFindLoaded(DefaultClassLoader.java:192) 2013-07-26_04:22:51.86921 at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLoadedClass(ClasspathManager.java:477) 2013-07-26_04:22:51.86922 at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:462) 2013-07-26_04:22:51.86923 at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:216) 2013-07-26_04:22:51.86923 at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:395) 2013-07-26_04:22:51.86924 at org.eclipse.osgi.internal.loader.SingleSourcePackage.loadClass(SingleSourcePackage.java:35) 2013-07-26_04:22:51.86925 at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:452) 2013-07-26_04:22:51.86926 at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:421) 2013-07-26_04:22:51.86928 at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:412) 2013-07-26_04:22:51.86929 at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107) 2013-07-26_04:22:51.86930 at java.lang.ClassLoader.loadClass(ClassLoader.java:357) 2013-07-26_04:22:51.86930 at org.eclipse.jetty.osgi.boot.internal.webapp.OSGiWebappClassLoader.findClass(OSGiWebappClassLoader.java:167) 2013-07-26_04:22:51.86931 at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:421) 2013-07-26_04:22:51.86932 - locked <0x00000005262b1e90> (a org.eclipse.jetty.osgi.boot.internal.webapp.OSGiWebappClassLoader) 2013-07-26_04:22:51.86933 at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:383) 2013-07-26_04:22:51.86933 at ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:202) 2013-07-26_04:22:51.86934 at ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:227) 2013-07-26_04:22:51.86935 at ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:136) 2013-07-26_04:22:51.86936 at ch.qos.logback.classic.spi.PackagingDataCalculator.populateUncommonFrames(PackagingDataCalculator.java:111) 2013-07-26_04:22:51.86938 at ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:103) 2013-07-26_04:22:51.86939 at ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:55) 2013-07-26_04:22:51.86940 at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147) 2013-07-26_04:22:51.86940 at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:129) 2013-07-26_04:22:51.86941 at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439) 2013-07-26_04:22:51.86942 at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:395) 2013-07-26_04:22:51.86943 at ch.qos.logback.classic.Logger.log(Logger.java:787) 2013-07-26_04:22:51.86943 at org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:607) 2013-07-26_04:22:51.86945 at org.eclipse.jetty.util.log.JettyAwareLogger.warn(JettyAwareLogger.java:431) 2013-07-26_04:22:51.86945 at org.eclipse.jetty.util.log.Slf4jLog.warn(Slf4jLog.java:69) 2013-07-26_04:22:51.86946 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:517) 2013-07-26_04:22:51.86947 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
_______________________________________________ jetty-users mailing list [email protected] https://dev.eclipse.org/mailman/listinfo/jetty-users
