I will start by saying this is an extremely weird issue involving file uploads > 65KB and TestRestTemplate. And since TestRestTemplate and RestTemplate both reply on the Apache HTTP client it's possible this isn't even a Spring issue.
I have been debugging this for 4 days it's not clear to me why this is happening and I could use some help.
Reproduction
Git repo containing reproduction: https://github.com/workmanw/spring-test-bug-demo
Steps
- Run
mvn clean testone or more times on Mac OS (I have not been able to reproduce in docker or on linux) - You will see the following error:
2021-07-02 21:26:49.921 INFO 25652 --- [o-auto-1-exec-1] o.apache.coyote.http11.Http11Processor : Error parsing HTTP request header
Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.
java.lang.IllegalArgumentException: Invalid character found in method name [AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA0x0d0x0a--6hXCZ7NXvctrRhMdQfCslrHNTVm930eH--0x0d0x0aPOST]. HTTP method names must be tokens
at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:417) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:261) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.39.jar:9.0.39]
at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]
Explanation
What appears to be happening is that when files over 65K are uploaded this way the contents of the body in the buffer gets shifted around when it's sent over the wire.
The request body should look like this:
POST /v1/demo/upload HTTP/1.1
Content-Type: multipart/form-data;charset=UTF-8;boundary=jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq
Content-Length: 66203
Host: localhost:61694
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.11)
Accept-Encoding: gzip,deflate
--jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq
Content-Disposition: form-data; name="file"; filename="SingleFile.txt"
Content-Type: text/plain
Content-Length: 66000
AAAAAAA...<66,000x A>...AAAAAAA
--jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq--
However with this reproduction, the last portion of the body gets shifted to the beginning of the request. Looks like this:
AAAAAAAAAA
--jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq--
POST /v1/demo/upload HTTP/1.1
Content-Type: multipart/form-data;charset=UTF-8;boundary=jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq
Content-Length: 66203
Host: localhost:61694
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.11)
Accept-Encoding: gzip,deflate
--jgV0Bpae6rNX-ZcB2FrJmBOVr8kS3yzAvq
Content-Disposition: form-data; name="file"; filename="SingleFile.txt"
Content-Type: text/plain
Content-Length: 66000
AAAAAAAAAAA...<66,000x A>...
The above results in a malformed HTTP request that Tomcat is unable to parse. This results in the Invalid character found in method name error observed above.
Observation
If a breakpoint is added to Http11InputBuffer::parseRequestLine, which is on the Tomcat receiving end, this can be observed by watching contents of the byteBuffer as its read from the socket.
If a breakpoint is added to SocketOutputStream::socketWrite, which is on the test sending end, the contents can be observed as serialized correctly.
Writing header:
Writing body:
Comment From: bclozel
If the content is correct at the SocketOutputStream::socketWrite level, then it's probably not a Spring Boot issue.
Also, not being able to reproduce this issue on other hosts is another clue. I'm wondering if this might be an issue with a local proxy or antivirus. This wouldn't be a first unfortunately. Can you temporarily disable such tools and still reproduce the issue?
Comment From: workmanw
@bclozel It is reproducible by everyone on my team. I tried on our family computer this morning w/ the same JVM and could not reproduce it of course 😡 . Let me see if my corporate overloads will allow me to disable the some of the bloatware and retest. Can we leave this open until next week. I will follow up either way.
One other interesting data point seems to be if I remove the @AutoConfigureWireMock(port = 0) annotation it resolves the issue.
Comment From: bclozel
I think you're onto something. I've consistently reproduced this issue on my macOS laptop (of course bloatware involved here as well).
But I cannot reproduce the problem after removing the spring-cloud-starter-contract-stub-runner dependency. There might be a problem with the instrumentation provided by spring-cloud-contract or a library conflict? I'm not familiar enough with that project to find the cause of this issue.
Could you create an issue on the dedicated issue tracker here: https://github.com/spring-cloud/spring-cloud-contract/issues
I'm closing this issue for now as I can't reproduce it without Spring Cloud being involved. Your sample application is well written so I'm sure this is good reproducer for Spring Cloud Contract.
Note that I've locally simplified the test method and I can still reproduce the problem:
private void testUploadFile(int fileSize) {
MultiValueMap<String, Object> body = new LinkedMultiValueMap<>();
TextFileResource textFileResource = new TextFileResource("SingleFile.txt", fileSize);
body.add("file", textFileResource);
ResponseEntity<Map> s = testRestTemplate.postForEntity(URI.create("/v1/demo/upload"), body, Map.class);
Map<String, String> responseBody = s.getBody();
assertEquals(Integer.toString(fileSize), responseBody.get("uploadedFileSize"));
}
Comment From: workmanw
@bclozel Thanks for the simplified reproduction. I also noticed the spring-cloud-contract issue when trying to create the issue. I attributed it to a timing or race condition because without it it uses a much simpler code path.
We use cloudstrike as our antivirus software. Any chance you're using the same? I have some early indications that that might be the culprit.
Comment From: bclozel
@workmanw I'm not using the same antivirus software.
Comment From: workmanw
@bclozel We got to the root of the issue working with our corporate IT. It turns out that Apple made in 11.13.1 that broke the way a CrowdStrike module interacted with the Apple API. Specially CrowdStrike's Falcon EDR module. I apologize for not having any sources to cite, the only references I was given to the issue were behind private ticket systems :( . We disabled the CrowdStrike EDR module and could no longer reproduce the issue.
Thanks a ton for pointing me toward antivirus.