Hi,
1) Scheduler thread cost much CPU, I enabled monitor module, there're stack
traces of busy threads:
16:07:42.560:WARN:oejm.ThreadMonitor:Thread-13:
org.eclipse.jetty.monitor.thread.ThreadMonitorException: Thread
'Scheduler-225690927'[RUNNABLE,id:34,cpu:92.65%] STACK TRACE
at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:225)
at sun.nio.ch.IOUtil.read(IOUtil.java:198)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375)
at
org.eclipse.jetty.io.ChannelEndPoint.fill(ChannelEndPoint.java:136)
at
org.eclipse.jetty.server.HttpInputOverHTTP.nextContent(HttpInputOverHTTP.java:104)
at
org.eclipse.jetty.server.HttpInputOverHTTP.nextContent(HttpInputOverHTTP.java:30)
at
org.eclipse.jetty.server.HttpInput.getNextContent(HttpInput.java:110)
at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:245)
at
org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:327)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:401)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:238)
at
org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1159)
at
org.eclipse.jetty.server.HttpChannelState.complete(HttpChannelState.java:440)
at
org.eclipse.jetty.server.AsyncContextState.complete(AsyncContextState.java:92)
at
my.web.async.BasicAsyncListener.onTimeout(BasicAsyncListener.java:34)
at
org.eclipse.jetty.server.HttpChannelState.expired(HttpChannelState.java:396)
at
org.eclipse.jetty.server.HttpChannelState$AsyncTimeout.run(HttpChannelState.java:699)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
16:18:18.738:WARN:oejm.ThreadMonitor:Thread-13:
org.eclipse.jetty.monitor.thread.ThreadMonitorException: Thread
'Scheduler-225690927'[RUNNABLE,id:34,cpu:92.94%] STACK TRACE
at sun.nio.ch.NativeThread.current(Native Method)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:321)
at
org.eclipse.jetty.io.ChannelEndPoint.fill(ChannelEndPoint.java:136)
at
org.eclipse.jetty.server.HttpInputOverHTTP.nextContent(HttpInputOverHTTP.java:104)
at
org.eclipse.jetty.server.HttpInputOverHTTP.nextContent(HttpInputOverHTTP.java:30)
at
org.eclipse.jetty.server.HttpInput.getNextContent(HttpInput.java:110)
at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:245)
at
org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:327)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:401)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:238)
at
org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1159)
at
org.eclipse.jetty.server.HttpChannelState.complete(HttpChannelState.java:440)
at
org.eclipse.jetty.server.AsyncContextState.complete(AsyncContextState.java:92)
at
my.web.async.BasicAsyncListener.onTimeout(BasicAsyncListener.java:34)
at
org.eclipse.jetty.server.HttpChannelState.expired(HttpChannelState.java:396)
at
org.eclipse.jetty.server.HttpChannelState$AsyncTimeout.run(HttpChannelState.java:699)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
2) There's no blockForContent() in stack trace this time. I've found
blockForContent() before I set a customized ReadListener.
3) I did a test later to verify whether jetty hold correct state or not. I
changed org.eclipse.jetty.server.HttpConnection.completed method, line
325-327:
else if (_parser.inContentState() && _generator.isPersistent()) {
LOG.warn(String.format("req=%s, _parser=%s, _parser.eof=%s",
_channel.getRequest(), _parser, _parser.isAtEOF()), new
Exception("testparserstate")); // Complete reading the request
_channel.getRequest().getHttpInput().consumeAll(); }
and also my.web.async.BasicAsyncListener.onTimeout
public void onTimeout(AsyncEvent event) throws IOException {
logger.debug("onTimeout> req={}, params={}", asyncCtx.getRequest(),
(reqInfoHolder != null ? reqInfoHolder.getParameterMap() : null));
reqInfoHolder will be initialized in myReadListener.onAllDataRead().
I got some output soon (not in connections leak state):
11:26:21.730:WARN:oejs.HttpConnection:Scheduler-1639539799: req=[POST
/api/user/msg/send]@624993057 org.eclipse.jetty.server.Request@2540a321,
_parser=HttpParser{s=CONTENT,0 of 48}, _parser.eof=false
11:26:21,729 DEBUG [Scheduler-1639539799] my.web.async.BasicAsyncListener:
onTimeout> req=[POST /api/user/msg/send]@624993057
org.eclipse.jetty.server.Request@2540a321, params=null
Looks jetty hold correct state.
4) This issue won't occur soon, once I get debug log for HttpInput and
HttpInputOverHTTP, I'll reply again.
2014/1/15 Simone Bordet <[email protected]>
> Hi,
>
> On Tue, Jan 14, 2014 at 2:13 PM, Zen Zhong <[email protected]> wrote:
> > Hi,
> >
> > I found there's connections leak in jetty. Environment: CentOS 6 x86_64,
> JDK
> > 7u25 x86_64, jetty-9.1.0.
>
> You have 3 stack dumps that look almost the same.
> Since reads are non blocking, the timer thread was caught at that
> point in all 3 times.
> Did you experience 100% CPU usage for 1 core ?
>
> Otherwise it can be explained with a really slow client.
> Method consumedAll() reads from the client, and it always reads
> something. Had it read 0 bytes, you would have seen a stack dump
> waiting in blockForContent().
>
> If you can reproduce this problem, can you enable debug logging for
> HttpInput and HttpInputOverHTTP ?
> That should tell us what's going on.
>
> Thanks !
>
> --
> Simone Bordet
> ----
> http://cometd.org
> http://webtide.com
> http://intalio.com
> Developer advice, training, services and support
> from the Jetty & CometD experts.
> Intalio, the modern way to build business applications.
> _______________________________________________
> jetty-users mailing list
> [email protected]
> https://dev.eclipse.org/mailman/listinfo/jetty-users
>
_______________________________________________
jetty-users mailing list
[email protected]
https://dev.eclipse.org/mailman/listinfo/jetty-users
