Multipart File upload: Sometimes receiving empty files! [SPR-15955]

[spring-projects-issues]

Alexander Wilhelmer opened SPR-15955 and commented

On my example repo in branch "zero-bytes-files" i was able to reproduce a bug something to do with multipart file upload and the resulting transferTo method. I'm transferring files into temp files and i'm checking against zero byte files, so no data seems to be revceived on the netty server or its a bug in the synchronoss parser,

This test seems to be unfair, because it is starting 20 concurrent threads against the endpoint, but i was able to reproduce this bug on another setting, only with one thread and 100 iterations you are able to reproduce it. But you must host the first endpoint on a remote server. Some files will reproduce it more frequently, some files never. The concurrent threads force the test to reproduce it on localhost. You have to run the test min. five times, search for the first exception.

Tested with M3 (RC3) and SNAPSHOT(RC4) version from spring bootstrap, mainly on windows.

Exception:

2017-09-12 20:01:58.410 ERROR 10032 --- [ctor-http-nio-1] c.e.demo.controller.FileController       : Error!

java.lang.RuntimeException: Zero byte file!

I'm working on a temporary remote test to show the not-threaded reproduction.

---

Affects: 5.0 RC3, 5.0 RC4

Reference URL: https://github.com/awilhelmer/spring5-multipart-demo/tree/zero-bytes-files

Issue Links:

• Delegating File downloads sends incomplete chunks [SPR-15949] #22194 Delegating File downloads sends incomplete chunks

[spring-projects-issues]

Alexander Wilhelmer commented

Added a single threaded remote test. The server instance is hosted on ubuntu with SNAPSHOT version, so this bug don't hit windows only.

The server instance is online for max 7 days.

[spring-projects-issues]

Alexander Wilhelmer commented

Okay i was able to reproduce with another setting, so i can say the problem is the WebClient Sender. Somehting to do with the Multipart POST.

I did this change on the Spring5 App:

  @PostMapping(value = "/file-upload")
   public Mono<ResponseEntity<String>> uploadFile(ServerHttpRequest request) {
      LOG.info("uploadFile called ...");
      Mono<String> stringMono = webClient.post()
            .uri(uriBuilder -> uriBuilder.path("/file-upload2").build())
            .body(request.getBody(), DataBuffer.class)
            .headers(httpHeaders -> {
               httpHeaders.put(HttpHeaders.CONTENT_TYPE, request.getHeaders().get(HttpHeaders.CONTENT_TYPE)) ;
            })
            .retrieve()
            .bodyToMono(String.class);

      return stringMono.map(s -> new ResponseEntity<>(s, HttpStatus.OK));
}

The receiver wasn't a Spring5 App and checks the request against zero byte files.
I can reproduce the error when the initial sender was Spring5 Webclient (Junit Test). I can't reproduce it when the sender was a Apache HTTP Client.

[spring-projects-issues]

Brian Clozel commented

Hi Alexander Wilhelmer

I've spent quite some time with your repro project given its complexity, I can't figure out what's the feature under test nor what is actually failing.

I can point you to a few places that could explain the current behavior though:

1. Mixing Thread management and reactive pipelines is bound to concurrency issues; the reactive pipeline itself is processing events on multiple threads. All bets are off at that point. I'd suggest you to use something like Flux.range and processing things on the Schedulers.elastic() to achieve concurrency if that's what you'd like.
2. I don't understand why you're calling a controller from another using the webclient; this is just adding indirection without exercising more parts of the framework
3. you're calling blocking code from within your reactive pipeline (creating a temp file for example), without scheduling those parts on a relevant scheduler
4. the FilePart.transferTo(file); call returns a Mono<Void>, which means you have to subscribe to it and wait for it to be completed before considering that bytes have been transferred. In my opinion, this is most likely the source of the problem here, since you might read the file before it's been written.

Could you rework your sample with this feedback?

[spring-projects-issues]

Alexander Wilhelmer commented

Hi Brian Clozel,

i reworked my example to make the test more simple. That was possible, cause i identified the problem is the WebClient sender, not the Server instance itself (see my last comment).

Some comments on your points.

1. I used concurrent Threads to force the problem on localhost. On the remote test i don't use multiple threads. So this isn't the problem here.
2. I tried to reproduce this bug on a simpler setting. I noticed this bug when i was using this setting: Client -> Server A -> Server B. I tried to simulate Server B with a second endpoint. I didn't know that the problem was the initial sender.
3. I don't know to how to schedule that. The transferTo Method is blokking anyway.
4. TransferTo is blocking... https://github.com/spring-projects/spring-framework/blob/master/spring-web/src/main/java/org/springframework/http/codec/multipart/SynchronossPartHttpMessageReader.java The method is returning an empty Mono at the end, after all blocking operations are finished.

Please update my repo and you have a very simple construct to reproduce.

[spring-projects-issues]

Brian Clozel commented

I took your sample app and rewrote the test to avoid playing with threads:

@Test
	public void uploadFile() throws Exception {
		MultiValueMap<String, Object> parts = createParts();
		Flux<String> responses = Flux.range(0, 100)
				.subscribeOn(Schedulers.elastic())
				.flatMap(count -> webClient.post()
						.uri("/test/file-upload")
						.body(BodyInserters.fromMultipartData(parts))
						.exchange()
						.returnResult(String.class)
						.getResponseBody());

		StepVerifier.create(responses)
				.expectComplete()
				.verify(Duration.ofSeconds(30));
	}

I can't reproduce the issue.
Note that by default there will be concurrency (up to 256 requested elements concurrently), so there are many requests in-flight at any moment.

[spring-projects-issues]

Alexander Wilhelmer commented

I added the concurrency threads to reproduce it on localhost. Just removing concurrency against localhost to fix the issue doesn't help, when testing against remote server (network!) still fails without concurrency.

[spring-projects-issues]

Alexander Wilhelmer commented

Test RemoteTest.java:

  int iterations = 500;
      for (int i = 0; i < iterations; i++) {
         LOG.info("Calling test post...");
         webClient.post()
               .uri(uriBuilder -> uriBuilder.path("/test/file-upload").build())
               .accept(MediaType.MULTIPART_FORM_DATA)
               .body(BodyInserters.fromMultipartData(parts))
               .exchange()
               .expectBody(String.class)
               .consumeWith(body -> {
                  if (body.getResponseBody() != null) {
                     throw new AssertionError(String.format("Error, File size incorrect! Server Message: %s", body.getResponseBody()));
                  }
               });

      }

Result:

2017-09-20 18:03:12.903  INFO 2796 --- [           main] c.e.demo.controller.FileControllerTest   : Calling test post...

java.lang.AssertionError: Error, File size incorrect! Server Message: Zero byte File!

> POST http://176.28.9.73:8080/test/file-upload
> WebTestClient-Request-Id: [203]
> Accept: [multipart/form-data]
> Content-Type: [multipart/form-data;boundary=h7mj0mC5Nd92ftFW3f9pAQ5IyEJUbuQC-m;charset=UTF-8]

[spring-projects-issues]

Brian Clozel commented

This is getting really confusing - weren't you pointing to the WebClient as being the culprit? What makes you think that?

[spring-projects-issues]

Alexander Wilhelmer commented

Because when i run this remote test with a simple HTTP Apache Client instead of the WebClient Junit Test i can't reproduce the zero byte file error.
I can create a third test with a apache http client if you want.

[spring-projects-issues]

Brian Clozel commented

I've just confirmed that there might be an issue in MultipartHttpMessageWriter and/or ResourceHttpMessageWriter. In some cases, the file part looks like this:

POST /test/file-upload HTTP/1.1
user-agent: ReactorNetty/0.7.0.BUILD-SNAPSHOT
transfer-encoding: chunked
accept: */*
Content-Type: multipart/form-data;boundary=5FGZiatj7eqaU7HL0vx7UKGjwpGXNL1b0dNhzkSv;charset=UTF-8

2c
--5FGZiatj7eqaU7HL0vx7UKGjwpGXNL1b0dNhzkSv

4f
Content-Type: application/json
Content-Disposition: form-data; name="json"


34
{"fileName":"test-file.jpg","mimeType":"image/jpeg"}
2


2c
--5FGZiatj7eqaU7HL0vx7UKGjwpGXNL1b0dNhzkSv

7a
Content-Type: image/jpeg
Content-Disposition: form-data; name="file"; filename="test-file.jpg"
Content-Length: 70318


2


2e
--5FGZiatj7eqaU7HL0vx7UKGjwpGXNL1b0dNhzkSv--

Headers ans boundary are properly written, but not the actual file content.

[spring-projects-issues]

Brian Clozel commented

There's been quite a few changes around the client and the multipart parser lately.
I can't reproduce this behavior anymore; I've set up a service instance running right now and the following test is consistently green on the latest snapshots:

@Test
	public void multipartTest() throws Exception {
		MultiValueMap<String, Object> parts = createParts();
		ReactorClientHttpConnector connector = new ReactorClientHttpConnector();
		WebClient client = WebClient.builder().clientConnector(connector).baseUrl("http://spring5-multipart.cfapps.io").build();
		Flux<String> responses = Flux.range(0, 100)
				.flatMap(count -> client.post()
						.uri("/test/file-upload")
						.body(BodyInserters.fromMultipartData(parts))
						.retrieve()
						.bodyToMono(String.class));

		StepVerifier.create(responses)
				.expectNextCount(100)
				.expectComplete()
				.verify(Duration.ofSeconds(30));

	}

Alexander Wilhelmer, could you let me know if you can still reproduce that issue against that service instance?