spring-projects / spring-framework

Spring Framework
https://spring.io/projects/spring-framework
Apache License 2.0
56.14k stars 37.95k forks source link

issue with restTemplate.postForEntity(String,Object,Class<T>) with MultiValueMap<String,Object> when updating to Spring Boot 3.2.2 #32350

Closed uli-f closed 6 months ago

uli-f commented 6 months ago

I experience an issue with restTemplate.postForEntity(String,Object,Class<T>) with Object of type MultiValueMap<String,Object>.

Here is a code snippet to demonstrate what I am doing:

public Result postWithMultipart() {
  final String serviceUrl = "http://prediction-service:5010/predict";
  final MultiValueMap<String,Object> parts = new LinkedMultiValueMap<>();
  parts.add("features", Map.of(0, 0, 1, 5, 2, 7));
  parts.add("id", 1L);
  parts.add("smiles", "C1CCCCC1");
  parts.add("expand", 23);
  final ResponseEntity<Result> postForEntity = this.restTemplate.postForEntity(serviceUrl, parts, Result.class);

  if (!postForEntity.getStatusCode().equals(HttpStatus.OK)) {
      System.out.println("Received response status code " + postForEntity.getStatusCode());
  }

  return result;
}

with

public class Result {
   private int id;
   private String result;
}

On the receiving end of this POST request sits a Python flask service.

When using Spring Boot 3.1.9 the request can be understood by the receiver. However, when switching to Spring Boot 3.2.2 the receiver does not understand the request anymore, that is, it is unable to receive the data of the multipart/form-data.

Looking at the logging output of the receiver, the only difference I can spot is the header Transfer-Encoding: chunked that is only present in the request when using Spring Boot 3.2.2. However, it is not present in the logging output of the sender as logged by the CustomClientHttpRequestInterceptor.

As I haven't changed anything else, however, it seems to me that the update from Spring Boot 3.1.9 to Spring Boot 3.2.2 causes the client to not being able to understand the request anymore.

Details of the request can be found below.

POST request send with Spring Boot 3.1.9

Logging the request with a CustomClientHttpRequestInterceptor:

2024-02-22T01:19:35.268+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : ===========================request begin================================================
2024-02-22T01:19:35.269+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : URI         : http://prediction-service:5010/predict
2024-02-22T01:19:35.273+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : Method      : POST
2024-02-22T01:19:35.274+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : Headers     : [Accept:"application/json, application/*+json", Content-Type:"multipart/form-data;boundary=-vAerOABTWl0eqbok2bvrm6VIUDd_tkMo", Content-Length:"893"]
2024-02-22T01:19:35.276+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : Request body: ---vAerOABTWl0eqbok2bvrm6VIUDd_tkMo
Content-Disposition: form-data; name="features"
Content-Type: application/json

{"0":0,"15045":1,"109866":1,"215541":2,"261666":2,"271417":4,"305511":2,"313893":4,"341509":1,"355342":4,"403029":2,"410528":1,"472083":1,"502697":1,"512177":1,"571914":2,"623710":1,"649499":1,"677097":1,"693214":1,"701973":1,"746629":2,"753106":1,"796935":1,"837806":4,"966758":1,"984141":1,"991186":1,"1023999":0}
---vAerOABTWl0eqbok2bvrm6VIUDd_tkMo
Content-Disposition: form-data; name="id"
Content-Type: application/json

1
---vAerOABTWl0eqbok2bvrm6VIUDd_tkMo
Content-Disposition: form-data; name="smiles"
Content-Type: text/plain;charset=UTF-8
Content-Length: 30

CC(=O)N1CCN(CC1)C1=CC=C(F)C=C1
---vAerOABTWl0eqbok2bvrm6VIUDd_tkMo
Content-Disposition: form-data; name="expand"
Content-Type: application/json

23
---vAerOABTWl0eqbok2bvrm6VIUDd_tkMo--

2024-02-22T01:19:35.277+11:00 DEBUG 956 --- [0.0-8050-exec-4] m.r.c.CustomClientHttpRequestInterceptor : ==========================request end================================================

Logging the the request on the receiving end:

request.form ImmutableMultiDict([('features', '{"0":0,"48414":1,"64664":3,"75633":2,"90955":1,"118130":1,"125924":1,"127048":2,"147231":1,"153915":1,"201214":1,"238412":1,"260800":1,"267526":1,"271417":12,"272882":2,"286316":1,"291752":2,"313893":4,"350945":1,"356105":1,"405075":1,"405450":1,"432600":1,"451337":1,"461116":1,"465875":1,"496667":1,"588210":1,"601467":4,"640486":6,"693668":2,"697864":1,"721700":1,"734467":1,"746629":6,"760163":1,"780466":1,"814175":4,"834470":1,"844825":1,"864602":2,"907740":1,"917588":1,"918104":1,"951808":1,"964094":2,"976116":1,"984141":5,"1023999":0}'), ('id', '9'), ('smiles', 'COc1cc(OCCCN(C)C)c2c(c1)C(C)(C)C(c1ccccc1)C2c1ccccc1'), ('expand', '23')])
request.data b''
request.values CombinedMultiDict([ImmutableMultiDict([]), ImmutableMultiDict([('features', '{"0":0,"48414":1,"64664":3,"75633":2,"90955":1,"118130":1,"125924":1,"127048":2,"147231":1,"153915":1,"201214":1,"238412":1,"260800":1,"267526":1,"271417":12,"272882":2,"286316":1,"291752":2,"313893":4,"350945":1,"356105":1,"405075":1,"405450":1,"432600":1,"451337":1,"461116":1,"465875":1,"496667":1,"588210":1,"601467":4,"640486":6,"693668":2,"697864":1,"721700":1,"734467":1,"746629":6,"760163":1,"780466":1,"814175":4,"834470":1,"844825":1,"864602":2,"907740":1,"917588":1,"918104":1,"951808":1,"964094":2,"976116":1,"984141":5,"1023999":0}'), ('id', '9'), ('smiles', 'COc1cc(OCCCN(C)C)c2c(c1)C(C)(C)C(c1ccccc1)C2c1ccccc1'), ('expand', '23')])])
request.headers Content-Type: multipart/form-data;boundary=mdYxT4uYG3O7Uhdtgb5mEKCedxSRHVgt
Content-Length: 1139
Accept: application/json, application/*+json
User-Agent: Java/21.0.1
Host: prediction-service:5010
Connection: keep-alive
request.url http://prediction-service:5010/predict

POST request send with Spring Boot 3.2.2

Logging the request with a CustomClientHttpRequestInterceptor:

2024-02-22T01:24:26.954+11:00  INFO 15704 --- [0.0-8050-exec-1] m.r.controller.HealthCheckController     :   Checking Single Step Retrosynthesis
2024-02-22T01:24:27.037+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : ===========================request begin================================================
2024-02-22T01:24:27.037+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : URI         : http://prediction-service:5010/predict
2024-02-22T01:24:27.039+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : Method      : POST
2024-02-22T01:24:27.039+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : Headers     : [Accept:"application/json, application/*+json", Content-Type:"multipart/form-data;boundary=rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_", Content-Length:"918"]
2024-02-22T01:24:27.040+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : Request body: --rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_
Content-Disposition: form-data; name="features"
Content-Type: application/json

{"0":0,"15045":1,"109866":1,"215541":2,"261666":2,"271417":4,"305511":2,"313893":4,"341509":1,"355342":4,"403029":2,"410528":1,"472083":1,"502697":1,"512177":1,"571914":2,"623710":1,"649499":1,"677097":1,"693214":1,"701973":1,"746629":2,"753106":1,"796935":1,"837806":4,"966758":1,"984141":1,"991186":1,"1023999":0}
--rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_
Content-Disposition: form-data; name="id"
Content-Type: application/json

1
--rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_
Content-Disposition: form-data; name="smiles"
Content-Type: text/plain;charset=UTF-8
Content-Length: 30

CC(=O)N1CCN(CC1)C1=CC=C(F)C=C1
--rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_
Content-Disposition: form-data; name="expand"
Content-Type: application/json

23
--rJr5F32DwCP0BThCe2b12fUT45HCSxhlUuYd-_--
2024-02-22T01:24:27.040+11:00 DEBUG 15704 --- [0.0-8050-exec-1] m.r.c.CustomClientHttpRequestInterceptor : ==========================request end================================================

Logging the the request on the receiving end:

request.form ImmutableMultiDict([])
request.data b''
request.values CombinedMultiDict([ImmutableMultiDict([]), ImmutableMultiDict([])])
request.headers Content-Type: multipart/form-data;boundary=gHNjUi2GzDreUXcBfL0H6gU1fHdP42CnTXnCWBP
Accept: application/json, application/*+json
User-Agent: Java/21.0.1
Host: prediction-service:5010
Connection: keep-alive
Transfer-Encoding: chunked
request.url http://prediction-service:5010/predict
wilkinsona commented 6 months ago

Without knowing how you've created the RestTemplate, it's hard to offer any suggestions. I suspect the difference may be because the underlying ClientHttpRequestFactory is different or is behaving differently but that's only an educated guess at this point.

If you would like us to spend some more time investigating, please spend some time providing a complete yet minimal sample that reproduces the problem. You can share it with us by pushing it to a separate repository on GitHub or by zipping it up and attaching it to this issue.

uli-f commented 6 months ago

Thanks for the feedback. I will compile a sample that is able to reproduce the problem.

uli-f commented 6 months ago

I put together a complete yet minimal sample that reproduces the problem:

issue39760.zip

The class com.example.PredictionController provides an endpoint /result; hitting this endpoint /result kicks off the multipart/form-data POST.

Here is what I experience on my end:

I'd appreciate any help on this.

wilkinsona commented 6 months ago

Thanks. While the sample doesn't reproduce the problem as we don't have access to your other microservice, it did give me enough information to identify the cause of the problem.

The key difference here is that with Spring Boot 3.2.x the request is sent using chunked transfer encoding and with Spring Boot 3.1.x it is not. This is due to this change in Spring Framework 6.1 upon which Spring Boot 3.2 depends. It affects SimpleClientHttpRequestFactory which you're using. I'm not sure what options are available to you to avoid Spring Framework 6.1 sending a chunked request. We'll transfer this issue to the Framework team for their attention.

uli-f commented 6 months ago

Thank you for your looking into this, much appreciated.

The key difference here is that with Spring Boot 3.2.x, the request is sent using chunked transfer encoding and with Spring Boot 3.1.x it is not.

That's what I spotted as the only difference on the receiver's end when looking at the headers.

Looking forward to hearing from the Framework team.

poutsma commented 6 months ago

From the upgrade guide:

To reduce memory usage in RestClient and RestTemplate, most ClientHttpRequestFactory implementations no longer buffer request bodies before sending them to the server. As a result, for certain content types such as JSON, the contents size is no longer known, and a Content-Length header is no longer set. If you would like to buffer request bodies like before, simply wrap the ClientHttpRequestFactory you are using in a BufferingClientHttpRequestFactory.

Please let us know if following the above instructions solves you issue.

uli-f commented 6 months ago

I wrapped the ClientHttpRequestFactory in a BufferingClientHttpRequestFactory in my Bean restTemplate:

@Bean
@Autowired
public RestTemplate restTemplate(RestTemplateBuilder builder) {
    ClientHttpRequestFactory requestFactory = builder.buildRequestFactory();
    builder = builder.requestFactory(() -> new BufferingClientHttpRequestFactory(requestFactory));
    return builder.build();
}

With this change the Python flask service at the receiving end happily understands the request from Spring Boot 3.2.3. ✔️

Thank you @wilkinsona and @poutsma. This was one of the best support experiences I ever had in my life: quick, straight to the point and solved after one round of back and forth 😃