What linux distribution are you running?  Curious if selinux is active on
your system.

--
Joakim Erdfelt <[email protected]>
webtide.com <http://www.webtide.com/> - intalio.com/jetty
Expert advice, services and support from from the Jetty & CometD experts
eclipse.org/jetty - cometd.org


On Thu, Jan 16, 2014 at 7:45 PM, Zen Zhong <[email protected]> wrote:

> Hi, Simone
>
> I enabled debug logging for HttpInput and HttpInputOverHttp. I found java
> process was killed by kernel today, I'm not sure whether the issue was
> reproduced or not this time, but Scheduler thread really cost much time to
> read data from one connection, some logs as following:
>
> In /var/log/messages, there're many "Out of socket memory" and "possible
> SYN flooding on port 80. Sending cookies.", and one "Jan 16 19:35:01
> <hostname> kernel: Out of memory: Kill process 30279 (java) score 367 or
> sacrifice child".
>
> tail -n 10000000 /data/jetty/logs/2014_01_16.stderrout.log > temp
> less -N temp
>       1 2014-01-16
> 19:29:56.442:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@fa92e29 filled 0
>       2 2014-01-16
> 19:29:56.442:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@fa92e29 filled 0
>       3 2014-01-16
> 19:29:56.442:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@fa92e29 filled 0
> ...<repeat>
> 3868890 2014-01-16
> 19:31:25.810:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@713f72e1 filled 0
> 3868891 2014-01-16
> 19:31:25.810:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@713f72e1 filled -1
> 3868892 2014-01-16 19:31:25.810:DBUG:oejs.HttpInput:Scheduler-1456460106:
> HttpInputOverHTTP@713f72e1 early EOF
> 3868893 2014-01-16 19:31:25.810:DBUG:oejs.HttpInput:Scheduler-1456460106:
> HttpInputOverHTTP@713f72e1 eof EARLY_EOF
> ...<ignore some timeout exception>
> 3868952 2014-01-16
> 19:31:27.076:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> 3868953 2014-01-16
> 19:31:27.076:WARN:oejs.HttpConnection:Scheduler-1456460106: req=[POST
> /api/oauth2/token]@955987031 
> org.eclipse.jetty.server.Request@38fb34538689537, 
> _parser=HttpParser{s=CONTENT,0 of 61}, _parser.eof=false
> 3868954 java.lang.Exception: testparserstate
> 3868955         at
> org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:326)
> 3868956         at
> org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:401)
> 3868957         at
> org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:238)
> 3868958         at
> org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1159)
> 3868959         at
> org.eclipse.jetty.server.HttpChannelState.complete(HttpChannelState.java:440)
> 3868960         at
> org.eclipse.jetty.server.AsyncContextState.complete(AsyncContextState.java:92)
> 3868961         at
> my.web.async.BasicAsyncListener.onTimeout(BasicAsyncListener.java:36)
> 3868962         at
> org.eclipse.jetty.server.HttpChannelState.expired(HttpChannelState.java:396)
> 3868963         at
> org.eclipse.jetty.server.HttpChannelState$AsyncTimeout.run(HttpChannelState.java:699)
> 3868964         at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> 3868965         at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> 3868966         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> 3868967         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> 3868968         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> 3868969         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> 3868970         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 3868971         at java.lang.Thread.run(Thread.java:724)
> 3868972 2014-01-16
> 19:31:27.076:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> 3868973 2014-01-16
> 19:31:27.076:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> 3868974 2014-01-16
> 19:31:27.076:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> ...<repeat>
> 4151735 2014-01-16
> 19:31:33.536:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> 4151736 2014-01-16
> 19:31:33.536:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled 0
> 4151737 2014-01-16
> 19:31:33.536:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad filled -1
> 4151738 2014-01-16 19:31:33.536:DBUG:oejs.HttpInput:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad early EOF
> 4151739 2014-01-16 19:31:33.536:DBUG:oejs.HttpInput:Scheduler-1456460106:
> HttpInputOverHTTP@5a1809ad eof EARLY_EOF
> 4151740 2014-01-16
> 19:31:33.640:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> 4151741 2014-01-16
> 19:31:33.640:WARN:oejs.HttpConnection:Scheduler-1456460106: req=[POST
> /api/oauth2/token]@1603375770 
> org.eclipse.jetty.server.Request@5f919241517419a, 
> _parser=HttpParser{s=CONTENT,0 of 126}, _parser.eof=false
> 4151742 java.lang.Exception: testparserstate
> 4151743         at
> org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:326)
> 4151744         at
> org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:401)
> 4151745         at
> org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:238)
> 4151746         at
> org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1159)
> 4151747         at
> org.eclipse.jetty.server.HttpChannelState.complete(HttpChannelState.java:440)
> 4151748         at
> org.eclipse.jetty.server.AsyncContextState.complete(AsyncContextState.java:92)
> 4151749         at
> my.web.async.BasicAsyncListener.onTimeout(BasicAsyncListener.java:36)
> 4151750         at
> org.eclipse.jetty.server.HttpChannelState.expired(HttpChannelState.java:396)
> 4151751         at
> org.eclipse.jetty.server.HttpChannelState$AsyncTimeout.run(HttpChannelState.java:699)
> 4151752         at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> 4151753         at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> 4151754         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> 4151755         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> 4151756         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> 4151757         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> 4151758         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 4151759         at java.lang.Thread.run(Thread.java:724)
> 4151760 2014-01-16
> 19:31:33.641:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> 4151761 2014-01-16
> 19:31:33.641:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> 4151762 2014-01-16
> 19:31:33.641:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> ...<repeat>
> 9999998 2014-01-16
> 19:35:01.223:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> 9999999 2014-01-16
> 19:35:01.223:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
> 10000000 2014-01-16
> 19:35:01.223:DBUG:oejs.HttpInputOverHTTP:Scheduler-1456460106:
> HttpInputOverHTTP@e2db5db filled 0
>
> Thanks
>
>
> 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
>
>
_______________________________________________
jetty-users mailing list
[email protected]
https://dev.eclipse.org/mailman/listinfo/jetty-users

Reply via email to