search

micronaut-projects / micronaut-core

Micronaut Application Framework
http://micronaut.io
Apache License 2.0
6.05k stars 1.06k forks source link

Publisher<CompletedFileUpload> to receive multiple file uploads returns more than expected #9892

Open weesftw opened 1 year ago

weesftw commented 1 year ago

Expected Behavior

When uploading multiple files using Publisher<CompletedFileUpload>, respond with the expected number of files and their valid bytes.

Actual Behaviour

In the application created as an example that uploads multiple files using Content-Type: multipart/form-data, I have two parameters called 'allDocuments' and 'allPhotos' that respond to the type Publisher<CompletedFileUpload> and another called 'photo ' which only receives a CompletedFileUpload for a single file. But also, I have additional fields such as: name (string) and age (string).

First Scenario

Requesting the curl below:

curl --location 'http://localhost:8080/upload' \
--form 'allDocuments=@"assets/Sample.pdf"' \
--form 'allDocuments=@"assets/merge-files.zip"' \
--form 'allPhotos=@"assets/github.png"' \
--form 'allPhotos=@"assets/java-logo.png"' \
--form 'allPhotos=@"assets/micronaut-logo.png"' \
--form 'photo=@"assets/micronaut-logo.png"' \
--form 'age="23"'

And iterating the data received over a Flux.from(), I receive the same file more than once:

 __  __ _                                  _   
|  \/  (_) ___ _ __ ___  _ __   __ _ _   _| |_ 
| |\/| | |/ __| '__/ _ \| '_ \ / _` | | | | __|
| |  | | | (__| | | (_) | | | | (_| | |_| | |_ 
|_|  |_|_|\___|_|  \___/|_| |_|\__,_|\__,_|\__|
12:37:01.134 [main] INFO  io.micronaut.runtime.Micronaut - Startup completed in 377ms. Server Running: http://localhost:8080
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip

and checking the integrity of the files, the first file received contains the expected bytes, the others return null/empty.

set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$3
INFO: [allDocuments | doOnSuccess] Received 12 files
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): 37
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] Sample.pdf received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): 80
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): -1
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received is empty
set. 18, 2023 12:37:01 PM com.example.UploadController lambda$upload$2
INFO: [allDocuments | doOnSuccess] merge-files.zip received byte(s): -1

Second Scenario

Another behavior that is important to mention is when I complement the form with the 'name' parameter, the processing of Flux.from(allDocuments), which is the first block() of the structure, ends by reaching the stipulated timeout for no reason... just by adding the 'name' field in the request composition:

curl --location 'http://localhost:8080/upload' \
--form 'allDocuments=@"assets/Sample.pdf"' \
--form 'allDocuments=@"assets/merge-files.zip"' \
--form 'allPhotos=@"assets/github.png"' \
--form 'allPhotos=@"assets/java-logo.png"' \
--form 'allPhotos=@"assets/micronaut-logo.png"' \
--form 'photo=@"assets/micronaut-logo.png"' \
--form 'age="23"' \
--form 'name="weesftw"'

having the result below:

  __ __ _ _
| \/ (_) ___ _ __ ___ _ __ __ _ _ _| |_
| |\/| | |/ __| '__/ _ \| '_ \ / _` | | | | __|
| | | | | (__| | | (_) | | | | (_| | |_| | |_
|_| |_|_|\___|_| \___/|_| |_|\__,_|\__,_|\__|
12:50:10.463 [main] INFO io.micronaut.runtime.Micronaut - Startup completed in 351ms. Server Running: http://localhost:8080
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: Sample.pdf
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:13 PM com.example.UploadController lambda$upload$0
INFO: [allDocuments | doOnNext] Received file: merge-files.zip
Sep. 18, 2023 12:50:28 PM com.example.UploadController lambda$upload$4
INFO: [allDocuments | doFinally] Finished processing request
12:50:28.054 [default-nioEventLoopGroup-1-2] ERROR i.m.http.server.RouteExecutor - Unexpected error occurred: Timeout on blocking read for 15000000000 NANOSECONDS
java.lang.IllegalStateException: Timeout on blocking read for 15000000000 NANOSECONDS
at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:127)
at reactor.core.publisher.Mono.block(Mono.java:1738)
at com.example.UploadController.upload(Application.java:69)

I can't find any source that I can understand this problem... can it be considered a bug?

Steps To Reproduce

  1. clone project
  2. ./gradlew build
  3. java -jar build/libs/demo-0.1-all.jar
  4. execute request1.sh to reproduce first scenario
  5. execute request2.sh to reproduce second scenario

the example files are in the project's assets folder... the scripts attached them.

Environment Information

OS: Ubuntu 22.04.3 LTS JDK Version: openjdk 17.0.7 2023-04-18

Example Application

multiple-upload-file-master.zip

Version

4.1.1

goeh commented 6 months ago

Same here on Micronaut 4.3.4 I have one part named "metadata" and multiple parts named "file". Even though I only send one part as "file" (for example image.jpg) I receive two parts with the same file, first part it correct, the second part is empty (InputStream is already consumed).

@Part("metadata") FileMetadata metadata,
@Part("file") Publisher<CompletedFileUpload> file
loicmathieu commented 5 months ago

When mixing parts of different type (files and plain value) I think you should bind the body with @Body MultipartBody body then check on each part if it's a CompletedFileUpload or not. This works but on my side files are limited to 1GB, I plan to open an issue for that.