Spring-cloud-netflix: may be found a bug for httpclient connection leak

[zhangxsh]

refer #2814

I use a subclass of DefaultErrorAttributes to deal with exceptions

 @Component("unifyErrorAttributes")
public class UnifyErrorAttributes extends DefaultErrorAttributes {

But I found that when exception generated,the http client connection can not be released.

here is normal routed request log,there are leased and released both exist,it's normal:

But when route failed,only the http connection leased action exists but no released action,bcz the coming exception disturbed the release action in future:

the PostErrorHandlerFilter.java is a post filter,it throw an exception when route failed.

    @Override
        public Object filter() {
        HttpServletResponse response = RequestContext.getCurrentContext().getResponse();
        int cde = response.getStatus();
        String uri=getOriginalRequest().getRequestURI();
        HttpStatus status=HttpStatus.valueOf(cde);
        String req_detail= (String) 
        ThreadLocalCache.get(GatewayFilterConstants.CacheKey.HTTP_REQ_DETAIL);
        String body= (String) 
        ThreadLocalCache.get(GatewayFilterConstants.CacheKey.HTTP_REQ_BODY_DETAIL);


        if(status.isError()){//||status.is3xxRedirection()){
            runtimeURLCollection.errorUrls(uri,";"+cde+"[route response error]");
            throw new GateWayException(BasicErrorEnum.ERROR_1001,"status:"+cde);
        }
        return null;
    }

so, at last,all of the connections are not released,my app is down.'netstat' shows all TCP in CLOSE_WAIT
my question:
1、is this a problem?
2、how to deal with that?

[zhangxsh]

ip:16.36 and 16.56

[ryanjbaxter]

Is PostErrorHandlerFilter something you wrote?

[zhangxsh]

BTW，PostErrorHandlerFilter is a very very simple post filter，after request routed，it check the response code，if not 2xx then throw an exception，if an exception throws during the time，the http connection will not be released

[ryanjbaxter]

Why throw an exception?

[zhangxsh]

i think throw exception or not is not important，if exception throws unartifically or accidentally in any filter ,they all can cause same problem.

we have changed the exception handle strategy in PostErrorFilter and sloved the problem.But i think this is easy to reproduce ,may be other developers have the same problem but they do not know why.
here is our code,

public class PostErrorHandlerFilter extends BaseZuulFilter {

    Logger logger = LoggerFactory.getLogger(getClass());

    @Autowired
    RuntimeURLCollection runtimeURLCollection;

    @Override
    public String filterType() {
        return POST_TYPE;
    }

    @Override
    public int filterOrder() {
        return 0;
    }

    @Override
    public boolean shouldFilter() {
        return true;
    }

    @Override
    public Object filter() {
        RequestContext ctx = RequestContext.getCurrentContext();
        HttpServletResponse response = ctx.getResponse();

        int cde = response.getStatus();
        String uri=getOriginalRequest().getRequestURI();
        HttpStatus status=HttpStatus.valueOf(cde);
        String req_detail= (String) ThreadLocalCache.get(GatewayFilterConstants.CacheKey.HTTP_REQ_DETAIL);
        String body= (String) ThreadLocalCache.get(GatewayFilterConstants.CacheKey.HTTP_REQ_BODY_DETAIL);


        if(status.isError()){//||status.is3xxRedirection()){
            ctx.setResponseStatusCode(HttpServletResponse.SC_OK);
            DataModel model = new DataModel(CommonConstants.FAILURE, "10086", BasicErrorEnum.ERROR_1001.getErrorMsg(), StringUtils.EMPTY);
            **ctx.setResponseBody(JsonUtils.beanToJson(model));
            List<Pair<String, String>> headers = ctx.getZuulResponseHeaders();
            for (Pair<String, String> header : headers) {
                if ("Content-Type".equalsIgnoreCase(header.first())) {
                    header.setSecond(ContentType.APPLICATION_JSON.toString());
                }
            }
        }**
        return null;
    }

we canceled the exception throws code instead of rewriting the http status code and message , and pass these messages to the SendResponseFilter by RequestContext ,bcz the filter can release the http connections:

[ryanjbaxter]

I understand your point about an exception being thrown and perhaps not closing the connection, but your use case didnt make much sense. Zuul is meant to proxy the response, and just because an error response was returned from the downstream client shouldnt result in an exception being thrown.

Sounds like you found another solution to your problem then, correct me if I am wrong.

[zhangxsh]

yes，that is，an exception being thrown and it surely not closing http connection.
if i do not throw
an exception manually but any runntime exception thrown unpredictable，they have the same consequences，if other developer be not careful ，it”s terrible

[brenuart]

My feeling is the issue is larger than what originally described.
In short: _there is no guarantee the upstream response is always closed._

For instance, although SendResponseFilter#writeResponse() does it's best to guarantee that the response stream from origin is properly closed in all cases (cfr. release pooled connection). However, it does not cover exceptions thrown outside of thath method, like during addResponseHeader() for instance. A first solution could be to wrap the entire run() method with a try/finally and move the close logic there.

But still, this would only guarantee that the response is closed IF it goes through the SendResponseFilter. What would happen if an exception is raised somewhere between, say, the RibbonRoutingFilter and SendResponseFilter filters? Zuul should normally direct the request to the "error" filters - but none of them seems to care about closing the response like what the SendResponseFilter does.

A more robust approach would be:

• filters should explicitly register their resources needing to be disposed when the request is fully completed
• the RequestContext is unset() by the ZuulServletFilter at request completion. We could use a custom version that would dispose registered resources when unset() is invoked.

What you think ?

[ryanjbaxter]

filters should explicitly register their resources needing to be disposed when the request is fully completed

So in this case there would be some code in Spring Cloud Netflix that would then dispose all those resources?

[brenuart]

I'm here thinking about "our" RibbonRoutingFilter and SimpleHostRoutingFilter.
They set the zuulResponse (a ClientHttpResponse or HttpResponse) and the _responseDataStream_ in the context. Both need to be explicitly closed/disposed when done. This is currently done by the SendResponseFilter (only).

One option is to use a custom RequestContext. Both filters would register their resources for destruction in a way similar to requestContext.register(<callback>).
The context would then invoke the callbacks when its unset() method is called.

Another option would be to hook into the _finally_ block of ZuulController's handleRequest() method.
Or maybe we could leverage Spring's RequestHandledEvent.

[brenuart]

Thinking out loud here...
... why not simply register the destruction callbacks under a new custom key in the RequestContext and let the ZuulController invoke them in its finally block ?

Changes would be located in:

• ProxyRequestHelper#setResponse() to register a callback for the _responseDataStream_ and the _zuulResponse_
• ZuulController to invoke the callbacks in the finally block

[zhangxsh]

@brenuart good，you are right，you get the point

[hooverhe]

@brenuart @ryanjbaxter I am also curious that why the following timer didn't take effect while throwing exceptions? The timer should close the expired connections per 5 seconds.
private void initialize() {
this.httpClient = newClient();
SOCKET_TIMEOUT.addCallback(this.clientloader);
CONNECTION_TIMEOUT.addCallback(this.clientloader);
this.connectionManagerTimer.schedule(new TimerTask() {
@Override
public void run() {
if (SimpleHostRoutingFilter.this.connectionManager == null) {
return;
}
SimpleHostRoutingFilter.this.connectionManager.closeExpiredConnections();
}
}, 30000, 5000);
}

[brenuart]

@hooverhe no idea... But if you want to make sure connections and other resources are always disposed after the request is processed and can't wait for this issue to be fixed, you can add the following to your Zuul application:

1/ Create a custom RequestContext implementation as follows:

public class GH2831RequestContext extends RequestContext {
    @Override
    public void unset() {
        disposeResources();
        super.unset();
    }

    /**
     * Dispose {@code zuulResponse} and {@code responseDataStream} when the RequestContext is 
     * unset (ie at request completion).
     */
    private void disposeResources() {
        disposeResource(this.get("zuulResponse"));
        disposeResource(this.getResponseDataStream());
    }


    private void disposeResource(Object resource) {
        if (resource instanceof Closeable) {
            disposeResource((Closeable)resource);
        }
    }

    private void disposeResource(Closeable closeable) {
        if (closeable!=null) {
            try {
                closeable.close();
            }
            catch(Exception e) {
                ReflectionUtils.rethrowRuntimeException(e);
            }
    }
}

2/ Add the following in your @Configuration class:

static {
    RequestContext.setContextClass(GH2831RequestContext.class);
}

That should help... ;-)

[zhangxsh]

@hooverhe @brenuart bcz the expire close timer only close the connections which are expired but leak,leak means the connection can not to close or reuse.

bcz：
1、if exception throws，then the SendResponseFilter can not be invoked,and the connection are not to close:

finally {
            /**
            * Closing the wrapping InputStream itself has no effect on closing the underlying tcp connection since it's a wrapped stream. I guess for http
            * keep-alive. When closing the wrapping stream it tries to reach the end of the current request, which is impossible for infinite http streams. So
            * instead of closing the InputStream we close the HTTP response.
            *
            * @author Johannes Edmeier
            */
            try {
                Object zuulResponse = RequestContext.getCurrentContext()
                        .get("zuulResponse");
                if (zuulResponse instanceof Closeable) {
                    ((Closeable) zuulResponse).close();
                }
                outStream.flush();
                // The container will close the stream for us
            }
            catch (IOException ex) {
            log.warn("Error while sending response to client: " + ex.getMessage());
            }
        }

To see the stack trace,the close activity is doing by the method of "releaseConnection" in ConnectionHolder.java ，close means:

a、really close;
b、not really close ,only mark the connection reusable 

-------------------------------------split-----------------------------------------

private void releaseConnection(final boolean reusable) {
        if (this.released.compareAndSet(false, true)) {
            synchronized (this.managedConn) {
                if (reusable) {
                    this.manager.releaseConnection(this.managedConn,
                            this.state, this.validDuration, this.tunit);
                } else {
                    try {
                        this.managedConn.close();
                        log.debug("Connection discarded");
                    } catch (final IOException ex) {
                        if (this.log.isDebugEnabled()) {
                            this.log.debug(ex.getMessage(), ex);
                        }
                    } finally {
                        this.manager.releaseConnection(
                                this.managedConn, null, 0, TimeUnit.MILLISECONDS);
                    }
                }
            }
        }
    }

if ConnectionHolder not close the connection,the the connection can not reuse and can not cleared by the timer(bcz the timer will find the connection is active although it is idle in fact).

at last,the connection is terminated by the nginx(bcz of keepAlive_timeout config) unilaterally.

when nginx send a FIN package to zuul,then the tcp protocol return ACK and changes the status of this tcp to CLOSE_WAIT locally and notify the http client to close the socket,but the application do not response(no thread to use the socket,the connection is idle in fact),then the connection remains in the status of CLOSE_WAIT。
as the pic shows:

then the connection remains in CLOSE_WAIT . As we mentioned over that,more and more connections are in close_wait.the number of close_wait equals to the value of "max-per-route-connections"

[hooverhe]

@brenuart The codes you provided works fine. Fixed my issue. Thanks.
@zhangxsh Thanks for your explanation and guide. It helps me a lot.

[ancin]

got many helps.thanks all.

[jadetang]

@brenuart
I use the GH2831RequestContent you provided as a temporary solution, but I get this exception in production. Any idea on this?

2018-05-04 07:17:32.250 ERROR [zuul-edge-service,,,] 7 --- [XNIO-2 task-208] io.undertow.request                      : UT005023: Exception handling request to /someUrl

org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.reflect.UndeclaredThrowableException
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:982)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
    at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.careem.sdk.distributed.tracing.sleuth.HttpResponseInjectingTraceFilter.doFilter(HttpResponseInjectingTraceFilter.java:34)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.careem.commons.sdk.ms.configuration.filter.CustomMultiReadFilter.doFilter(CustomMultiReadFilter.java:23)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.careem.zuuledge.filters.spring.LogSamplingFilter.doFilterInternal(LogSamplingFilter.java:34)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.cloud.sleuth.instrument.web.TraceFilter.doFilter(TraceFilter.java:169)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
    at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
    at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
    at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
    at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
    at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:332)
    at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.reflect.UndeclaredThrowableException: null
    at org.springframework.util.ReflectionUtils.rethrowRuntimeException(ReflectionUtils.java:317)
    at com.careem.zuuledge.utils.CustomRequestContext.disposeResource(CustomRequestContext.java:46)
    at com.careem.zuuledge.utils.CustomRequestContext.disposeResources(CustomRequestContext.java:31)
    at com.careem.zuuledge.utils.CustomRequestContext.unset(CustomRequestContext.java:21)
    at com.netflix.zuul.http.ZuulServlet.service(ZuulServlet.java:97)
    at org.springframework.web.servlet.mvc.ServletWrappingController.handleRequestInternal(ServletWrappingController.java:157)
    at org.springframework.cloud.netflix.zuul.web.ZuulController.handleRequest(ZuulController.java:44)
    at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
    ... 74 common frames omitted
Caused by: org.apache.http.MalformedChunkCodingException: CRLF expected at end of chunk
    at org.apache.http.impl.io.ChunkedInputStream.getChunkSize(ChunkedInputStream.java:253)
    at org.apache.http.impl.io.ChunkedInputStream.nextChunk(ChunkedInputStream.java:225)
    at org.apache.http.impl.io.ChunkedInputStream.read(ChunkedInputStream.java:184)
    at org.apache.http.impl.io.ChunkedInputStream.read(ChunkedInputStream.java:213)
    at org.apache.http.impl.io.ChunkedInputStream.close(ChunkedInputStream.java:315)
    at org.apache.http.impl.execchain.ResponseEntityProxy.streamClosed(ResponseEntityProxy.java:143)
    at org.apache.http.conn.EofSensorInputStream.checkClose(EofSensorInputStream.java:228)
    at org.apache.http.conn.EofSensorInputStream.close(EofSensorInputStream.java:172)
    at com.careem.zuuledge.utils.CustomRequestContext.disposeResource(CustomRequestContext.java:44)
    ... 83 common frames omitted

[brenuart]

Your are getting an exception while closing the ResponseEntity - don't know why.
I think the sample RequestContext proposed above should not rethrow such exception but simply log it - just like what the Ribbon and SimpleHost routing filter do.

[jadetang]

yes, I just want to know why there is an exception when closing the response entity.

[brenuart]

No idea… trace it and post what you found ;-)

Or remove the custom RequestContext and see what happens with plain vanilla SpringCloud…

[jadetang]

@brenuart I check the code of SendResponseFilter, it only closes the zuulResponse while in the GH2831RequestContext it actually closes both zuulResponse and responseDataStream. Why do we need to close the ResponseDataStream explicitly since the ResponseDataStream is actually a part of the zuulResponse?

[MeiyappanKannappa]

Hi Could anyone let me know how to solve the error.

[ryanjbaxter]

@MeiyappanKannappa please dont comment on multiple issues

[zhangxsh]

any questions,please mail to:xianshuangzhang#gmail.com

[bramalingam81]

@ryanjbaxter, @zhangxsh , @brenuart Is the fix made available in latest release of Spring Cloud Netflix ? If so, could someone please let know version of release ?

[ryanjbaxter]

@bramalingam81 the author closed the issue, there was never any changes made