Affects: 2.2.4.RELEASE
There is strange behavior in Spring controller. Once per some amount of requests (even identical request), Spring Controller (GET) gets all input request parameters as null, ParameterMap of HttpServletRequest is empty, but queryString (HttpServletRequest.getQueryString) is not null (has expected value). Metric shows that error occurs in about 0.1 - 0.7% of case in high load, and can't reproducible locally. In tcpdump request string looks correct, so likely middle-ware is not involved.
Any idea what could be the cause/make some influence that lead to such behavior?
Example
Request: https:some-host/version/endpoint?prm1=Value1&prm2=2&prm3=Value3 Response: mostly 200, but in ~0.5% 204
Controller code:
import io.micrometer.core.instrument.MeterRegistry;
import io.swagger.v3.oas.annotations.Operation;
import io.swagger.v3.oas.annotations.media.Schema;
import io.swagger.v3.oas.annotations.tags.Tag;
import lombok.AllArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.apache.logging.log4j.util.Strings;
import org.springframework.http.ResponseEntity;
import org.springframework.validation.annotation.Validated;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
import javax.servlet.http.HttpServletRequest;
import javax.validation.constraints.Max;
import javax.validation.constraints.Min;
import java.util.Objects;
@RestController
@RequestMapping("version")
@AllArgsConstructor
@Schema(name = "Swagger schema")
@Tag(name = "Swagger tag")
@Validated
@Slf4j
public class SomeService {
private final MeterRegistry meterRegistry;
//other dependencies
@Operation(description = "Swagger description")
@GetMapping(value = "endpoint")
public ResponseEntity<Object> find(
@RequestParam(required = false, name = "prm1") String parameter1,
@RequestParam(required = false, name = "prm2", defaultValue = "1") @Min(1) @Max(2) @Schema(description = "Some description for prm2") Integer parameter2,
@RequestParam(required = false, name = "prm3") @Schema(description = "Some description for prm3") String parameter3,
HttpServletRequest request) {
String queryString = request.getQueryString();
//Issue: queryString=prm1=Value1&prm2=2&prm3=Value3
//but parameter1=null parameter2=null parameter3=null
if (Strings.isNotBlank(queryString) && queryString.contains("prm1") && Objects.isNull(parameter1)) {
meterRegistry.counter("issue_total").increment();
}
//...
if(Objects.isNull(parameter1)){
return ResponseEntity.noContent().build();
}else {
return ResponseEntity.ok("OK");
}
}
}
Comment From: olgakorichkovskaya
Found the root cause. Asynchronous method with reading request parameters was called in ResponseBodyAdvice for endpoint.
@Slf4j
@ControllerAdvice(assignableTypes = SomeService.class)
public class BodyAdvice extends ResponseEntityExceptionHandler implements ResponseBodyAdvice<Object> {
private AsyncComponent asyncComponent;
@Override
public Object beforeBodyWrite(LegacySpacesWrapper o,
MethodParameter methodParameter,
MediaType mediaType,
Class<? extends HttpMessageConverter<?>> aClass,
ServerHttpRequest serverHttpRequest,
ServerHttpResponse serverHttpResponse) {
if (serverHttpRequest instanceof ServletServerHttpRequest &&
serverHttpResponse instanceof ServletServerHttpResponse) {
HttpServletResponse servletResponse = ((ServletServerHttpResponse) serverHttpResponse).getServletResponse();
int status = servletResponse.getStatus();
HttpServletRequest servletRequest = ((ServletServerHttpRequest) serverHttpRequest).getServletRequest();
asyncComponent.logRequestParameters(servletRequest, status);
}
return o;
}
}
@Component
@Slf4j
public class AsyncComponent {
@Async
public void logRequestParameters(HttpServletRequest request, int status) {
String val1 = request.getParameter("prm1");
String val2 = request.getParameter("prm2");
String val3 = request.getParameter("prm3");
log.info("{},{},{}", val1, val2, val3);
}
}
So the question is following: is it any correct way to call asynchronous method in ResponseBodyAdvice with reading requests parameters?
Comment From: bclozel
Sorry it took us so long to reply here.
I think you've found the main issue here: Tomcat only guarantees access to the request and response data during the lifecycle of the exchange. As soon as the response is completed, Tomcat may recycle the request object entirely (as it is pooling resources for performance reasons). Here, your AsyncComponent
is trying to access those resources in a separate thread, which might be processed after the response is closed.
I'm probably missing lots of context here but I think that getting the request parameters as a map HttpServletRequest#getParameterMap
before calling the async method would be good enough in this case.
If you have further questions, please ask them on StackOverflow. Thanks!