Jetty 9 挂起，QueuedThreadPool 越来越大

Question

我们最近将 Jetty 服务器从版本 6.1.25 升级到 9.0.4。它们部署在 Windows 2008 服务器上的 Java 1.7.0_11 64 位上。

除了 Jetty 所需的配置更改(start.ini - 非常好)，我们保持所有 JVM 标志与以前相同。在生产环境中部署 6 天后，服务器对 HTTP 请求没有响应。在此期间，内部“心跳”处理继续正常运行，但不为外部请求提供服务。该服务重新启动，6 天后它再次变得无响应。

在我的初步审查期间，我以为我对 https://bugs.eclipse.org/bugs/show_bug.cgi?id=357318 有所了解。 .但是，该 JVM 问题已从 Java 1.8_0XX 向后移植到 Java 1.7.0_06。这让我回顾了线程处理。

认为它可能与 eclipse 站点上的案例 400617/410550 相关，尽管它并不像文章那样呈现出来，并且该案例显然已在 Jetty 9.0.3 中得到解决。

通过 JMX 监视应用程序显示“qtp”线程的线程数随着时间的推移继续增长，我一直没有成功寻找解决方案。线程配置当前设置为:

threads.min=10
threads.max=200
threads.timeout=60000

所有 qtp 线程通常都处于 WAITING 状态，并具有以下堆栈跟踪:

Name: qtp1805176801-285
State: WAITING on java.util.concurrent.Semaphore$NonfairSync@4bf4a3b0
Total blocked: 0  Total waited: 110

Stack trace: 
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(Unknown Source)
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(Unknown Source)
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(Unknown Source)
java.util.concurrent.Semaphore.acquire(Unknown Source)
org.eclipse.jetty.util.BlockingCallback.block(BlockingCallback.java:96)
org.eclipse.jetty.server.HttpConnection$Input.blockForContent(HttpConnection.java:457)
org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:282)
   - locked org.eclipse.jetty.util.ArrayQueue@3273ba91
org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:360)
org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:340)
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:224)
org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
java.lang.Thread.run(Unknown Source)

仔细观察后，这似乎与具有以下状态的最新线程不同:

Name: qtp1805176801-734
State: TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@77b83b6e
Total blocked: 5  Total waited: 478

Stack trace: 
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:390)
org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:509)
org.eclipse.jetty.util.thread.QueuedThreadPool.access$700(QueuedThreadPool.java:48)
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:563)
java.lang.Thread.run(Unknown Source)

根据命名约定，一些 qtp 线程很旧(qtp1805176801-206)，而一些很新(qtp1805176801-6973)。我发现有趣的是，旧线程没有根据 60 秒空闲超时超时。应用程序在美国工作时间为客户提供服务，而在凌晨时分大部分时间都处于空闲状态，我希望几乎所有的池都会被清理干净。

希望有人能够在如何追踪这个问题方面为我指出正确的方向。我在 Jetty 的经验让我相信他们的东西非常可靠，大多数问题要么是我们的实现中的程序化问题(去过那里)，要么是与 JVM 相关的(这样做过)。如果您认为我可能会在线程上追逐红鲱鱼，也欢迎提出建议。

新信息:
进一步跟踪异常，这似乎是由于 GWT RPC 调用在等待响应时超时而导致的。以下堆栈跟踪显示了与处于无效状态的线程相关的日志文件中的异常。使用它来查看和查找有关 Jetty/GWT 交互问题的其他报告。

2013-09-03 08:41:49.249:WARN:/webapp:qtp488328684-414: Exception while dispatching incoming RPC call
java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30015/30000 ms
    at org.eclipse.jetty.util.BlockingCallback.block(BlockingCallback.java:103)
    at org.eclipse.jetty.server.HttpConnection$Input.blockForContent(HttpConnection.java:457)
    at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:130)
    at java.io.InputStream.read(Unknown Source)
    at com.google.gwt.user.server.rpc.RPCServletUtils.readContent(RPCServletUtils.java:175)
    at com.google.gwt.user.server.rpc.RPCServletUtils.readContentAsGwtRpc(RPCServletUtils.java:205)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.readContent(AbstractRemoteServiceServlet.java:182)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:239)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:755)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:698)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1506)
    at c.t.b.servlet.PipelineFilter.doFilter(PipelineFilter.java:56)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494)
    at c.v.servlet.SetRequestEncoding.doFilter(SetRequestEncoding.java:27)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494)
    at c.t.b.servlet.OutOfMemoryFilter.doFilter(OutOfMemoryFilter.java:39)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1486)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:503)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:138)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:564)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:213)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1094)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:432)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:175)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1028)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:136)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:258)
    at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
    at org.eclipse.jetty.server.Server.handle(Server.java:445)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:267)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:224)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
    at java.lang.Thread.run(Unknown Source)
Caused by: 
java.util.concurrent.TimeoutException: Idle timeout expired: 30015/30000 ms
    at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:153)
    at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50)
    at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
    at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
    at java.util.concurrent.FutureTask.run(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)

Answer 1

最终在 Eclipse/Jetty 网站上发布了这个问题。以下链接可用于跟踪解决方案的任何永久性修复。

https://bugs.eclipse.org/bugs/show_bug.cgi?id=416477

该问题与 QTP 线程上的信号量锁定有关，该线程在请求​​期间作为 GWT RPC 调用的一部分已超时。原始请求是计时的，超时时间为 30 秒。请求在等待 Semaphore.acquire 方法完成时超时。作为请求清理的一部分，HTTPConnection 尝试对请求使用 .consumeAll，这再次尝试使用 Sempahore.acquire。这一次，请求没有计时并且锁保持在原位，直到线程被中断。

由于 Jetty 无法重现该问题，而且我无法找到有关该问题的任何其他报告，因此该问题似乎与该平台非常相关。此外，这只发生在我们的生产环境之一。我的猜测是 GWT RPC 代码、Jetty 和操作系统之间发生了一些事情。我们计划对 JDK、Jetty 和 GWT SDK 进行小幅升级。

解决方法
最初的解决方法是每天通过 JMX 控制台手动中断锁定的线程几次。我们的长期解决方案是建立一个清理机制，寻找这些锁定的线程并调用它们的中断方法。