Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [jetty-dev] long response time lead to high CPU in jetty when using httpd server in front and a short timeout setting

Jan & Joakim,
Thanks a lot for your response. I really tried to upgrade the jetty, but no luck.
The project has dependency on the cxf, but cxf has dependency on the class:
org.eclipse.jetty.server.ssl.SslSelectChannelConnector. So currently I can not use the latest jetty 9.X to reproduce the issue.
And I have a simple test case , simply run it then you reproduce the issue.

Reproduce steps:
1.
unzip the attachment jetty-issue-demo.zip
mvn clean package
mvn camel:run

then you will see the port 9292 is listening.


2.
Install Apache HTTPD (tested with version 2.2.15)
Install Apache mod_ssl module
Copy the following configuration(attached) to a new file in conf.d.

3. restart the httpd server, after visiting the service through the below command several times:
curl -k --user admin:adminhttps://localhost:443/demo/aaa

then I can see the high cpu in the jetty.


After debuging the code, when the issue occurs, here it goes to a infinite loop, while the len==0 since the flush is not successful.
AbstractHttpConnection.sendContent(Object content)
                 while (len>=0)
                    {
                        super._generator.completeUncheckedAddContent();
                        _out.flush();

                        max = super._generator.prepareUncheckedAddContent();
                        buffer = super._generator.getUncheckedBuffer();
                        len=buffer.readFrom(in,max);
                    }

In the AbstractGenerator.flush(long maxIdleTime) seems here there should be an exception thrown out.
It has an condition _endp.isOpen()&& !_endp.isOutputShutdown() actually here in customer's scenario, the endpoint is closed due to the timeout in the http side.

            while (now<end && (content!=null && content.length()>0 ||buffer!=null && buffer.length()>0) && _endp.isOpen()&& !_endp.isOutputShutdown())
            {
                blockForOutput(end-now);
                now=System.currentTimeMillis();
            }

And I also raised the bug https://bugs.eclipse.org/bugs/show_bug.cgi?id=456741 for your reference.
Thanks a lot for your looking into it.

On 01/16/2015 06:53 PM, Jan Bartel wrote:
Hi Vicky,

Actually, Jetty-8 is end-of-life, so it will be difficult for any of
the jetty committers to spend much time on this issue unless you could
provide a small reproduction test harness. Even then, any work on it
would have to be a lower priority than jetty-9 work.  If you can
produce a small test case, then please also include details of your
execution platform (os and version) and jvm version and we'll do our
best to try and get some time to take a look at it, but no promises.

If its possible for you, then an upgrade to jetty-9 would be
recommended as there have been a lot of modifications to the io layer,
including handling of ssl. If you absolutely cannot upgrade, or you
need help with upgrading, then please contact Webtide
(info@xxxxxxxxxxx) who can provide you some commercial support to meet
your requirements.

cheers
Jan

On 16 January 2015 at 03:34, Vicky Wu <xiwu@xxxxxxxxxx> wrote:
Joakim,

Thanks a lot for the response!  I am testing on the latest jetty
8.1.16.V20140903.
I invoked the service for 3 times.
curl -k --user admin:admin https://localhost:443/demo/aaa
And collected the thread dumps 6 times.
I can see that these three threads 19057,19052, 19055 are consuming high
cpu.
And the method HttpGenerator.flushBuffer() went to an infinite loop.

eg:
"qtp1224044906-21" prio=10 tid=0x00007f22a88d5000 nid=0x4a71 runnable
[0x00007f22c9d68000]
    java.lang.Thread.State: RUNNABLE
     at
org.eclipse.jetty.http.HttpGenerator.flushBuffer(HttpGenerator.java:811)
     at
org.eclipse.jetty.http.AbstractGenerator.flush(AbstractGenerator.java:443)
     at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:100)
     at
org.eclipse.jetty.server.AbstractHttpConnection$Output.flush(AbstractHttpConnection.java:1123)
     at
org.eclipse.jetty.server.AbstractHttpConnection$Output.sendContent(AbstractHttpConnection.java:1237)
     at
org.apache.cxf.transport.http_jetty.JettyHTTPDestination$JettyOutputStream.copyFrom(JettyHTTPDestination.java:316)
     at org.apache.cxf.helpers.IOUtils.copy(IOUtils.java:105)
     at
org.apache.cxf.transport.http.AbstractHTTPDestination$WrappedOutputStream.copyFrom(AbstractHTTPDestination.java:752)
     at org.apache.cxf.helpers.IOUtils.copy(IOUtils.java:105)
     at org.apache.cxf.helpers.IOUtils.copyAndCloseInput(IOUtils.java:113)
     at
org.apache.cxf.jaxrs.provider.BinaryDataProvider.copyInputToOutput(BinaryDataProvider.java:186)
     at
org.apache.cxf.jaxrs.provider.BinaryDataProvider.writeTo(BinaryDataProvider.java:151)
     at
org.apache.cxf.jaxrs.utils.JAXRSUtils.writeMessageBody(JAXRSUtils.java:1360)
     at
org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.serializeMessage(JAXRSOutInterceptor.java:244)
     at
org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.processResponse(JAXRSOutInterceptor.java:117)
     at
org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.handleMessage(JAXRSOutInterceptor.java:80)
     at
org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307)
     - locked <0x00000000c6dc6c20> (a
org.apache.cxf.phase.PhaseInterceptorChain)
     at
org.apache.cxf.interceptor.OutgoingChainInterceptor.handleMessage(OutgoingChainInterceptor.java:83)
     at
org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307)
     - locked <0x00000000c6667ae8> (a
org.apache.cxf.phase.PhaseInterceptorChain)
     at
org.apache.cxf.phase.PhaseInterceptorChain.resume(PhaseInterceptorChain.java:277)
     - locked <0x00000000c6667ae8> (a
org.apache.cxf.phase.PhaseInterceptorChain)
     at
org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:78)
     - locked <0x00000000c6667ae8> (a
org.apache.cxf.phase.PhaseInterceptorChain)
     at
org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243)
     at
org.apache.cxf.transport.http_jetty.JettyHTTPDestination.doService(JettyHTTPDestination.java:261)
     at
org.apache.cxf.transport.http_jetty.JettyHTTPHandler.handle(JettyHTTPHandler.java:70)
     at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1088)
     at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1024)
     at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
     at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:193)
     at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
     at org.eclipse.jetty.server.Server.handleAsync(Server.java:410)
     at
org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:519)
     at
org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:971)
     at
org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1033)
     at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644)
     at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
     at
org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
     at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:196)
     at
org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:696)
     at
org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
     at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
     at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
     at java.lang.Thread.run(Thread.java:744)

    Locked ownable synchronizers:
     - None




On 01/15/2015 09:31 PM, Joakim Erdfelt wrote:

What version of Jetty?
And have you taken a few timed thread dumps during the high CPU situation to
capture what specifically is looping?

--
Joakim Erdfelt <joakim@xxxxxxxxxxx>
webtide.com - intalio.com/jetty
Expert advice, services and support from from the Jetty & CometD experts
eclipse.org/jetty - cometd.org

On Thu, Jan 15, 2015 at 3:05 AM, Vicky Wu <xiwu@xxxxxxxxxx> wrote:
All,

I have a long response time CXF restful web service and I am using camel
to expose this CXF endpoint. The response time is 2 mins.
At the same time I have the httpd as the front proxy while it has the
setting timeout=60
<VirtualHost *:443>
...
       <Proxy balancer://cxfrs>
            BalancerMemberhttps://localhost:9292/demo/aaa  retry=10
timeout=60
       </Proxy>
       ProxyPass /demo/aaa balancer://cxfrs
...
</VirtualHost>

When I visit the service through the below command several times(3~5
times):

curl -k --user admin:adminhttps://localhost:443/demo/aaa

after several mins, I can see the high cpu in the jetty through "top"
command and the jetty code is running in an infinite loop.

Would you please help on this issue?


--
Best Regards,
Xiaohui(Vicky) Wu

_______________________________________________
jetty-dev mailing list
jetty-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe
from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev



_______________________________________________
jetty-dev mailing list
jetty-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from
this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev


--
Best Regards,
Xiaohui(Vicky) Wu


_______________________________________________
jetty-dev mailing list
jetty-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from
this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev



--
Best Regards,
Xiaohui(Vicky) Wu

LoadModule ssl_module modules/mod_ssl.so
Listen 443
AddType application/x-x509-ca-cert .crt
AddType application/x-pkcs7-crl    .crl
SSLPassPhraseDialog  builtin
#SSLSessionCache         shmcb:/var/cache/mod_ssl/scache(512000)
SSLSessionCacheTimeout  310
SSLMutex default
SSLRandomSeed startup file:/dev/urandom  256
SSLRandomSeed connect builtin
SSLCryptoDevice builtin

#----------------------------------
# 443
#----------------------------------
NameVirtualHost *:443
<VirtualHost *:443>
        ServerName pvm-xiwu-fuse61
        ServerAlias pvm-xiwu-fuse61
        SSLEngine on
        SSLProtocol all +SSLv3 +TLSv1 
        SSLCipherSuite ALL:!ADH:RC4+RSA:+HIGH:+MEDIUM:!LOW:!SSLv2:!EXPORT
        SSLCertificateFile      /etc/pki/tls/certs/localhost.crt
        SSLCertificateKeyFile   /etc/pki/tls/private/localhost.key        

        ErrorLog logs/443_error_log
        # Host Time "Request String" Bytes Status ServerActioningRequest ThisServerName TimeTakenMicroseconds(/1000000)
        CustomLog logs/443_balancer_log  "%h %t \"%r\" %b %s %{BALANCER_WORKER_NAME}e %v %D"
        LogLevel warn
        SetEnvIf User-Agent ".*MSIE.*" \
                 nokeepalive ssl-unclean-shutdown \
                 downgrade-1.0 force-response-1.0
      SSLProxyEngine On

      # CXF REST endpoint
      <Proxy balancer://cxfrs>
           BalancerMember https://localhost:9292/demo/aaa retry=10 timeout=60
      </Proxy>
      ProxyPass /demo/aaa balancer://cxfrs

</VirtualHost>

Attachment: jetty-issue-demo.zip
Description: Zip archive


Back to the top