Only request bodies with content-type multipart/* and application/x-www-form-urlencoded work

[candrews]

Make a request through zuul using a POST or PUT verb with a content-type that is not multipart/* or application/x-www-form-urlencoded`

When Zuul makes the request to the backend, it won't include the request body.

The reason is that the original request body is consumed in org.springframework.cloud.netflix.zuul.filters.TraceProxyRequestHelper.debug(String, String, MultiValueMap<String, String>, MultiValueMap<String, String>, InputStream) leaving no request body to consume when org.springframework.cloud.netflix.zuul.filters.route.SimpleHostRoutingFilter actually sends the request.

Requests of content-type application/x-www-form-urlencoded work because org.springframework.cloud.netflix.zuul.filters.pre.FormBodyWrapperFilter gets the body. Requests of type multipart/* work because org.springframework.cloud.netflix.zuul.filters.ProxyRequestHelper.shouldDebugBody(RequestContext) explicitly excludes them.

To reproduce the issue, just make a request through zuul with a Content-Type of text/plain, for example, and you'll always get a time out error as the backend server will keep waiting for response body that it will never get.

I believe this issue was originally reported at #2610

[spencergibb]

I'm unable to reproduce this with a POST with text/plain.

Can you provide a complete, minimal, verifiable sample that reproduces the problem? It should be available as a GitHub (or similar) project or attached to this issue as a zip file.

[candrews]

My apologies if this isn't that completely minimal, but it does reproduce the problem and it's really easy to run.

Grab this:
https://www.integralblue.com/zuul3418.tar.gz

And run: ./mvnw spring-boot:run -Dspring-boot.run.profiles=localhost

See the problem with:
curl -H 'Content-Type: abc/xyz' --data "stuff" http://localhost:8080/TEST.php

Now see how the problem is fixed by editing src/main/resources/application.properties and uncommenting the zuul.trace-request-body=false line at the bottom.

and trying that same curl command again.

[spencergibb]

$ curl -H 'Content-Type: abc/xyz' --data "stuff" http://localhost:8080/TEST.php                                                                                                    (9121)[14:19:53]
{"timestamp":1552673996272,"status":404,"error":"Not Found","message":"No message available","path":"/TEST.php"}   

I'm going to ask that you spend some time making a minimal app I can use.

[candrews]

The problem is that the request's InputStream is being read multiple times which doesnt' work as Zuul is expecting unless the request is wrapped to specifically implement that behavior. Zuul is expecting to call ServletRequest.getInputStream() and each time get a different InputStream instance over the same data; but, the base ServletRequest provided by the application server doesn't do that - it returns the same InputStream instance each time which means it can only be read once.

If the request's content type is application/x-www-form-urlencoded, the request is wrapped by WorkaroundFormBodyWrapperFilter and its getInputStream() implementation returns a new InputStream of the data each time it's called: https://github.com/spring-cloud/spring-cloud-netflix/blob/v2.1.1.RELEASE/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/pre/FormBodyWrapperFilter.java#L180

If the request's content contains "multipart", see https://github.com/spring-cloud/spring-cloud-netflix/blob/v2.1.1.RELEASE/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/ProxyRequestHelper.java#L273, then Zuul doesn't debug it, avoiding this issue.

So if the content type isn't application/x-www-form-urlencoded or multipart, then the request isn't wrapped and it will be consumed at https://github.com/spring-cloud/spring-cloud-netflix/blob/blob/v2.1.1.RELEASE/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/TraceProxyRequestHelper.java#L129 Once the trace/debugger consume it, when Zuul goes to read the InputStream, there's no data to read off it.

[spencergibb]

I understand your reasoning but was unable to replicate the described behaviour with a minimal app.

I couldn't get your app to behave

I'm going to ask that you spend some time making a minimal app I can use.

[candrews]

Here's a minimal app: https://www.integralblue.com/zuul3418-2.tar.gz
Run ./mvnw spring-boot:run
and see the problem with:
curl -H 'Content-Type: abc/xyz' --data "stuff" http://localhost:8080/TEST.php
You'll see a long delay, and then a stack trace. That's the problem.

I've found that this issue is only reproducible when zuul.use-filter=true and zuul.servlet-path=/. When both are set that way, at https://github.com/spring-cloud/spring-cloud-netflix/blob/v2.1.1.RELEASE/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/TraceProxyRequestHelper.java#L87 requestEntity is an instance of org.apache.catalina.connector.CoyoteInputStream. When they are not set that way, requestEntity is an instance of com.netflix.zuul.http.ServletInputStreamWrapper which explains the behavior as ServletInputStreamWrapper does allow getInputStream() to be called multiple times while CoyoteInputStream does not.

[candrews]

Tracing a bit, I noticed that when this occurs, at https://github.com/spring-cloud/spring-cloud-netflix/blob/v2.1.1.RELEASE/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/pre/Servlet30WrapperFilter.java#L74 request is a org.apache.catalina.connector.RequestFacade which is not an instance of HttpServletRequestWrapper, and RequestUtils.isDispatcherServletRequest() returns false, so the method returns null.

One solution would be to change this method to remove the RequestUtils.isDispatcherServletRequest() so it always buffers the body.

[spencergibb]

If it only happens with zuul.use-filter=true, then why use it?

Removing the call to RequestUtils.isDispatcherServletRequest() is not an option as we have well-documented ways to NOT buffer.

[candrews]

If it only happens with zuul.use-filter=true, then why use it?

I think those reasons are covered in #2887

I like the idea of not buffering, don't get me wrong - but I also want to work :) Perhaps the buffering decision can be made based on the value of the zuul.trace-request-body setting as well?

[spencergibb]

I'm not keen to add make a buffering decision based off of something that historically hasn't had anything to do with buffering.

So far the only user of zuul.use-filter=true I know of is you. I'd rather turn off trace request body if zuul.use-filter=true.

[candrews]

I'd rather turn off trace request body if zuul.use-filter=true.

That seems reasonable. Should trace request body be off by default always?

On a related note, https://github.com/spring-cloud/spring-cloud-netflix/blob/2.0.x/spring-cloud-netflix-zuul/src/main/java/org/springframework/cloud/netflix/zuul/filters/pre/Servlet30WrapperFilter.java has this comment:

// TODO: only if in servlet 3.0 env

and its class level javadocs is:

/**
 * Pre {@link ZuulFilter} that wraps requests in a Servlet 3.0 compliant wrapper.
 * Zuul's default wrapper is only Servlet 2.5 compliant.
 * @author Spencer Gibb
 */

Since spring-cloud-netflix-zuul runs on Spring Boot 2.0, and Spring Boot 2.0 requires Servlet 3.1 (see https://docs.spring.io/spring-boot/docs/2.0.0.RELEASE/reference/html/getting-started-system-requirements.html), it seems that filter should either be removed (since it's no longer necessary), renamed, or its use replaced by using Spring's org.springframework.web.util.ContentCachingRequestWrapper.

[spencergibb]

Should trace request body be off by default always?

Probably, but we won't be making a breaking change anymore.

The problem was the zuul HttpServletRequestWrapper didn't implement servlet 3.0 methods. Not sure if that was ever fixed. That would be the only reason to remove it, not what boot or spring defaults to.

[spencergibb]

Should trace request body be off by default always?

Probably, but we won't be making a breaking change anymore.

After thinking about it, I'd be ok making this change for Hoxton (2.2.x)