Re: [jetty-users] Too many threads

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]

Re: [jetty-users] Too many threads

From: Mikhail Mazursky <ash2kk@xxxxxxxxx>
Date: Fri, 26 Jul 2013 18:41:41 +0600
Delivered-to: jetty-users@xxxxxxxxxxx
List-archive: <https://dev.eclipse.org/mailman/private/jetty-users>
List-help: <mailto:jetty-users-request@eclipse.org?subject=help>
List-subscribe: <https://dev.eclipse.org/mailman/listinfo/jetty-users>, <mailto:jetty-users-request@eclipse.org?subject=subscribe>
List-unsubscribe: <https://dev.eclipse.org/mailman/options/jetty-users>, <mailto:jetty-users-request@eclipse.org?subject=unsubscribe>

Hi,

2013/7/26 Simone Bordet <sbordet@xxxxxxxxxxx>

Hi,

On Fri, Jul 26, 2013 at 12:00 PM, Mikhail Mazursky <ash2kk@xxxxxxxxx> wrote:

> 2013/7/26 Simone Bordet <sbordet@xxxxxxxxxxx>
>> 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)

References:
- [jetty-users] Too many threads
  - From: Mikhail Mazursky
- Re: [jetty-users] Too many threads
  - From: Simone Bordet
- Re: [jetty-users] Too many threads
  - From: Mikhail Mazursky
- Re: [jetty-users] Too many threads
  - From: Simone Bordet

Prev by Date: Re: [jetty-users] Too many threads
Next by Date: [jetty-users] Jetty 9.0.4 issue (also in 9.0.5-SNAPSHOT) with Spring MVC Async (test provided)
Previous by thread: Re: [jetty-users] Too many threads
Next by thread: [jetty-users] Jetty 9.0.4 issue (also in 9.0.5-SNAPSHOT) with Spring MVC Async (test provided)
Index(es):
- Date
- Thread

Breadcrumbs