Re: [EsiGate-users] TR: Connection thread leak

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

Hello,

Today we tried to deploy previous version of ESIGate (ESI 5.0) and it seems to work well in our context.
What do you think about this idea of using previous version of your component?
Is this version reliable enough for a quite used website on production ?
Do you have warnings about this version ?

Thx,
Emilie

De : fx....@gm... [mailto:fx....@gm...] De la part de Francois-Xavier Bonnet
Envoyé : mercredi 20 juillet 2016 16:40
À : Lorenzati Yannick <YLo...@vo...>
Cc : Poupon Emilie <EP...@VO...>; web...@li...; fra...@ce...; Auffredou Thomas <TAu...@vo...>
Objet : Re: TR: [EsiGate-users] Connection thread leak

Good catch! Thank you very much, I have been able to reproduce the issue.
I think that this problem occurs only when you are performing an include, then you get a 302 redirect and also the redirect response contains a body. Usually servers don't send a body with a redirect, only a "location" header, that is probably why we didn't see this bug before.
This might be due to the way EsiGate handles redirects in method org.esigate.Driver.render(String, IncomingRequest, Renderer...). As the redirect contains a body that is not consumed, HttpClient cannot release the connection. I guess adding a response.close() inside the while loop should fix the issue.

2016-07-20 15:38 GMT+02:00 Lorenzati Yannick <YLo...@vo...<mailto:YLo...@vo...>>:
Hello,

We make a little UnitTest to illustrate the leak.
We add a module connection-leak, you can found it here :
https://github.com/ylorenza/esigate/tree/esigate-5.1-connLeak/connection-leak

Just do

git clone https://github.com/ylorenza/esigate
git checkout esigate-5.1-connLeak
mvn compile
cd connection-leak/
mvn test -Dtest=TestLeak#testConnectionOverPoolSize

This test testConnectionOverPoolSize illustrate the bug. If we launch it with esigate 5.0, it pass.

Hope it will help you

De : fx....@gm...<mailto:fx....@gm...> [mailto:fx....@gm...] De la part de Francois-Xavier Bonnet
Envoyé : mercredi 13 juillet 2016 18:10
À : Auffredou Thomas <TAu...@vo...><mailto:TAu...@vo...>
Cc : Poupon Emilie <EP...@VO...><mailto:EP...@VO...>; Francois-Xavier Bonnet <fra...@ce...><mailto:fra...@ce...>; web...@li...<mailto:web...@li...>

Objet : Re: [EsiGate-users] Connection thread leak

I agree with you, according to the thread dump, all the threads are waiting for a connection from the connection pool. There must be a connection leak somewhere. Now we need to find when and why this happens...

2016-07-13 17:44 GMT+02:00 Auffredou Thomas <TAu...@vo...<mailto:TAu...@vo...>>:
Hello,

I really suspect the apache PoolingHttpClientConnectionManager.
For some reason it doesn’t release connection from to the pool when ESIGate fetches resources resulting with a 302.

Every connection from ESIgate to the backend server is in CLOSE_WAIT state, meaning it has been closed by the server but the pool does not discard it.

A thread dump shows those clients are awaiting the request to complete indefinitely.  (PoolEntryFuture.java:133)
I didn’t find any configuration directive in ESIGate to evict old connections from the pool.

You will find the full thread dump in the attached file.

Thanks for your help and your time
Thomas

De : Poupon Emilie
Envoyé : mardi 12 juillet 2016 19:36
À : Francois-Xavier Bonnet <fra...@ce...<mailto:fra...@ce...>>
Cc : Auffredou Thomas <TAu...@vo...<mailto:TAu...@vo...>>; web...@li...<mailto:web...@li...>
Objet : RE: [EsiGate-users] Connection thread leak

In our logs, we can see the http 302 response :
740 INFO http-nio-10.98.65.31-51125-exec-30 org.esigate.extension.FetchLogging - http://preprod1.tri.vsct.fr - GET /fr/page-editoriale/idvroom-le-covoiturage-au-quotidien?alextest HTTP/1.1 {user-agent: curl/7.43.0,accept: */*,wl-proxy-ssl: true,clientip: 194.3.103.60,X-Forwarded-For: 194.3.103.60, 10.41.5.221, 10.98.64.37,x-forwarded-host: preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>, preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>,x-forwarded-server: preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>, preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>,X-Forwarded-Proto: http,X-Esigate-Int-Surrogate-Id: esigate,Surrogate-Capabilities: esigate="Surrogate/1.0 ESI/1.0 ESI-Inline/1.0 X-ESI-Fragment/1.0 X-ESI-Replace/1.0 X-ESI-XSLT/1.0 ESIGATE/4.0",Content-Length: 0,Host: preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>,Connection: Keep-Alive,Accept-Encoding: gzip,deflate} -> HTTP/1.1 200 OK (2005 ms) {Date: Tue, 12 Jul 2016 17:10:52 GMT,X-Content-Type-Options: nosniff,Expires: Sun, 19 Nov 1978 05:00:00 GMT,X-Content-Type-Options: nosniff,Content-Language: fr,Content-Type: text/html; charset=utf-8,Cache-Control: max-age=180, public,Transfer-Encoding: chunked,Connection: close,Accept-Ranges: bytes}

And then, our already seen UnknownHostException.
This is not a DNS server problem, we check this point.

On our configuration, we force HTTPS on the Apache front end.
Because of what I have read, I want to do a test with an HTTP website. I’ll tell you about this test tomorrow.
2016-07-12 18:37:32,864 ERROR http-nio-10.98.65.31-51125-exec-11 org.esigate.HttpErrorPage - Error retrieving URL
java.net.UnknownHostException: preprod1.tri.vsct.fr<http://preprod1.tri.vsct.fr>: unknown error
        at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
        at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:907)
        at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1302)
        at java.net.InetAddress.getAllByName0(InetAddress.java:1255)
        at java.net.InetAddress.getAllByName(InetAddress.java:1171)
        at java.net.InetAddress.getAllByName(InetAddress.java:1105)
        at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:44)
        at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:101)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318)
        at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363)
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219)
        at org.esigate.http.ProxyingHttpClientBuilder$1.execute(ProxyingHttpClientBuilder.java:105)
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
        at org.esigate.http.HttpClientRequestExecutor.execute(HttpClientRequestExecutor.java:307)
        at org.esigate.Driver.render(Driver.java:188)
        at org.esigate.esi.IncludeElement.processPage(IncludeElement.java:193)
        at org.esigate.esi.IncludeElement.onTagEnd(IncludeElement.java:81)
        at org.esigate.parser.ParserContextImpl.endElement(ParserContextImpl.java:92)
        at org.esigate.parser.Parser.parse(Parser.java:76)
        at org.esigate.esi.EsiRenderer.render(EsiRenderer.java:122)
        at org.esigate.Driver.performRendering(Driver.java:401)
        at org.esigate.Driver.performRendering(Driver.java:360)
        at org.esigate.Driver.proxy(Driver.java:295)
        at org.esigate.DriverFactory.proxy(DriverFactory.java:403)
        at org.esigate.servlet.ProxyFilter.doFilter(ProxyFilter.java:60)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
        at psiprobe.Tomcat70AgentValve.invoke(Tomcat70AgentValve.java:62)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1721)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1679)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

Emilie

De : fx....@gm...<mailto:fx....@gm...> [mailto:fx....@gm...] De la part de Francois-Xavier Bonnet
Envoyé : mardi 12 juillet 2016 17:48
À : Poupon Emilie <EP...@VO...<mailto:EP...@VO...>>
Cc : Francois-Xavier Bonnet <fra...@ce...<mailto:fra...@ce...>>; Auffredou Thomas <TAu...@vo...<mailto:TAu...@vo...>>; web...@li...<mailto:web...@li...>
Objet : Re: [EsiGate-users] Connection thread leak

EsiGate is following automatically redirects when performing an ESI include so this should work unless the response from the server is invalid. There should be more details about the 502 in the logs or in the error page.

2016-07-12 17:30 GMT+02:00 Poupon Emilie <EP...@vo...<mailto:EP...@vo...>>:
We found out something !

It seems that we implemented a too complex error management with bad redirections :
If an error occurs on an ESI inclusion request (ex : "resource not found" on application site), our app returns a 302 to rederect users on a “clean 404 error page” (which is on DRUPAL side).
At this stage, EsiGate don’t manage the 302 and responds with a 502 + the thread is blocked.

We are going to improve our application and the error management to not respond a 302 to an ESI request.

Do you know about EsiGate problems when getting a 302 response in the context of an ESI tag request? Do you have ideas to manage these cases.
Thx,
Emilie Poupon Adam
Responsable Delivery Web Mobile
VSC Technologies

De : fx....@gm...<mailto:fx....@gm...> [mailto:fx....@gm...<mailto:fx....@gm...>] De la part de Francois-Xavier Bonnet
Envoyé : mardi 12 juillet 2016 15:41

À : Poupon Emilie <EP...@VO...<mailto:EP...@VO...>>
Cc : Francois-Xavier Bonnet <fra...@ce...<mailto:fra...@ce...>>; Auffredou Thomas <TAu...@vo...<mailto:TAu...@vo...>>; web...@li...<mailto:web...@li...>
Objet : Re: [EsiGate-users] Connection thread leak

It looks like you might have an issue with your DNS server. Did you keep the full thread dump where you took the abstract in your first mail?