Jetty 9 Hangs, QueuedThreadPool Growing Large

Question

Gần đây chúng tôi đã nâng cấp các máy chủ Jetty của chúng tôi từ phiên bản 6.1.25 lên 9.0.4. Chúng được triển khai trên Java 1.7.0_11 64-bit trên một máy chủ Windows 2008.

Ngoài những thay đổi cấu hình bắt buộc cho Jetty (start.ini - rất hay), chúng tôi đã lưu tất cả các cờ JVM giống như trước đây. 6 ngày sau khi triển khai trong môi trường sản xuất, máy chủ không phản hồi các yêu cầu HTTP. Nội bộ 'nhịp tim' xử lý tiếp tục chạy bình thường trong thời gian này nhưng nó không phục vụ yêu cầu bên ngoài. Dịch vụ đã được khởi động lại và 6 ngày sau nó lại không phản hồi.

Trong quá trình đánh giá ban đầu của tôi, tôi nghĩ rằng tôi đã tham gia một nội dung nào đó với số https://bugs.eclipse.org/bugs/show_bug.cgi?id=357318. Tuy nhiên, vấn đề JVM đó đã được chuyển đổi từ Java 1.8_0XX sang Java 1.7.0_06. Điều này dẫn tôi đến xem xét xử lý Thread.

Nghĩ rằng nó có thể liên quan đến trường hợp 400617/410550 trên trang nhật thực mặc dù nó không hiển thị chính nó giống như ghi lên, và trường hợp đã được giải quyết rõ ràng trong Jetty 9.0.3.

Giám sát ứng dụng qua JMX cho thấy rằng Số lượng chủ đề cho chuỗi 'qtp' tiếp tục tăng theo thời gian và tôi đã không thành công khi tìm kiếm giải pháp. cấu hình Chủ đề đang đặt ra cho:

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

Tất cả các chủ đề qtp thường trong CHỜ nhà nước với stack trace sau:

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) 

Sau khi xem xét kỹ hơn, điều này dường khác nhau từ các chủ đề mới nhất mà có trạng thái sau:

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) 

Dựa trên quy ước đặt tên, một số các chủ đề qtp rất cũ (qtp1805176801-206) trong khi một số rất mới (qtp18051768 01-6973). Tôi thấy nó thú vị rằng các chủ đề cũ không phải là thời gian ra dựa trên thời gian chờ 60 giây nhàn rỗi. Các ứng dụng dịch vụ khách hàng trong giờ làm việc của Mỹ và phần lớn là nhàn rỗi trong những giờ sáng sớm mà tại đó thời gian tôi mong đợi gần như tất cả các hồ bơi để có được làm sạch.

Hy vọng ai đó có thể chỉ cho tôi hướng đi đúng đắn về cách theo dõi sự cố này. Kinh nghiệm của tôi với Jetty khiến tôi tin rằng công cụ của họ rất chắc chắn và hầu hết các vấn đề đều có lập trình trong việc thực hiện của chúng tôi (đã có) hoặc liên quan đến JVM (thực hiện điều đó). Cũng mở để gợi ý nếu bạn nghĩ rằng tôi có thể được theo đuổi một red-herring trên Threads.

THÔNG TIN MỚI: Truy tìm ngoại lệ một chút xa hơn, điều này dường như được gây ra khi cuộc gọi GWT RPC hết thời gian chờ phản hồi. Theo dõi ngăn xếp sau đây cho thấy một ngoại lệ trong tệp nhật ký có liên quan đến một Chủ đề ở trạng thái không hợp lệ. Sử dụng tính năng này để xem lại và tìm các báo cáo khác về các vấn đề tương tác 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

QueuedThreadPool là một nhóm chia sẻ chủ đề. Các chủ đề trong đó sẽ được sử dụng lại cho các quá trình xử lý khác. Có, theo dõi các hồ bơi thread, giả sử chủ đề sẽ được làm sạch, là một cá trích đỏ. Những chủ đề đó sẽ rơi ra khỏi hồ bơi, từ từ, trong một thời gian dài (nghĩ giờ). Đây là một quyết định hiệu suất trong hồ bơi thread (tạo ra là tốn kém, làm điều đó càng ít càng tốt).

Đối với stacktrace bạn dán, nó không đầy đủ, do đó, số lượng đoán về hành vi là rất cao.Nhưng điều đó đang được nói, 2 dòng đó có thể cho biết hoạt động bình thường, nhưng không có phần còn lại của stacktrace có rất ít để tiếp tục.

Ngoài ra, các phiên bản Java bạn đang sử dụng 1.7.0_06 và 1.7.0_11 rất cũ và bạn phải chịu hàng trăm lỗi được sửa.

Answer 2

Đã kết thúc đăng câu hỏi trên trang web Eclipse/Jetty. Có thể sử dụng liên kết sau đây để theo dõi bất kỳ sửa chữa cố định nào đối với giải pháp.

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

Vấn đề này đã làm với các khóa Semaphore trên Chủ đề QTP đã được timed out trong yêu cầu như là một phần của một cuộc gọi RPC GWT. Yêu cầu ban đầu được hẹn giờ, với thời gian chờ là 30 giây. Yêu cầu hết thời gian chờ trong khi phương thức Semaphore.acquire hoàn tất. Là một phần của yêu cầu dọn dẹp, HTTPConnection cố gắng .consumeAll theo yêu cầu, một lần nữa thử Sempahore.acquire. Lần này, yêu cầu không được hẹn giờ và khóa vẫn được giữ nguyên cho đến khi luồng bị gián đoạn.

Sự cố có vẻ rất cụ thể đối với nền tảng vì Jetty không thể tái tạo vấn đề và tôi không thể tìm thấy bất kỳ báo cáo nào khác về vấn đề này. Hơn nữa, điều này chỉ xảy ra ở một trong các môi trường sản xuất của chúng tôi. Tôi đoán là có điều gì đó đang xảy ra giữa Mã RPC GWT, Jetty và Hệ điều hành. Chúng tôi đã lên kế hoạch nâng cấp nhỏ cho JDK, Jetty và GWT SDK.

Cách giải quyết Công việc ban đầu xung quanh là để ngắt thủ công các chủ đề bị khóa vài lần một ngày thông qua bảng điều khiển JMX. Giải pháp dài hạn của chúng tôi là xây dựng một cơ chế dọn dẹp tìm các chủ đề bị khóa này và gọi phương thức ngắt trên chúng.

Answer 3

Tôi có cùng với Jetty 9.2.3.v20140905 và Java (build 1.8.0_20-b26) 64 bit.

Cách giải quyết. Cài đặt monit http://mmonit.com/monit/

# monit.conf 
check process jetty-service with pidfile "/opt/jetty-service/jetty.pid" 
start program = "/usr/sbin/service jetty-service start" with timeout 30 seconds 
stop program = "/usr/sbin/service jetty-service stop" 
if totalmem is greater than 1268 MB for 10 cycles then restart 
if 5 restarts within 5 cycles then timeout