Thomas MAUGIN created CXF-8702:
----------------------------------
Summary: Graceful shutdown : Error 404 with "Can't find the
request for XXXXX's Observer" on - Springboot + CXF Server
Key: CXF-8702
URL: https://issues.apache.org/jira/browse/CXF-8702
Project: CXF
Issue Type: Bug
Components: JAX-RS
Affects Versions: 3.5.2
Reporter: Thomas MAUGIN
Attachments: cxf-shutdown.zip, flood_requests.jmx
h2. General Description :
Issue happens on all our Springboot (tomcat) + CXF app.
Spring boot version : 2.4.13 (same on 2.6.7) / CXF version : 3.5.1 (same on
3.4.4, 3.5.2)
Java 1.8.0_312 and Java 11.0.15
Integration is done with
{{org.apache.cxf.cxf-spring-boot-starter-jaxrs-3.5.1.jar}} and
{{org.apache.cxf.cxf-spring-boot-autoconfigure-3.5.1.jar}}
On each graceful shutdown that is happening under a moderate load, a few
requests are being rejected in 404 by the service.
The corresponding log is {{"Can't find the request for XXXXX's Observer"}}
XXXXX is the full request that has been rejected.
The http response body answer for the call is {{<html><body>No service was
found.</body></html>}}
h2. Integration :
CXF server is started like this :
{code:java}
@Bean
public Server flowManagementServiceRsServer() {
final JAXRSServerFactoryBean endpoint = new JAXRSServerFactoryBean();
endpoint.setBus(bus);
endpoint.setAddress("/");
endpoint.setServiceBean(new Service());
return endpoint.create();
}
{code}
Shutdown is managed by spring boot with "new" graceful shutdown
{{server.shutdown=graceful}} and
{{spring.lifecycle.timeout-per-shutdown-phase=25s}}
h2. Reproduction :
Having a performance test on an endpoint (for example
[http://localhost:8080/services/request]) and stopping gracefully, the app
allow to reproduce the issue at will.
See cxf-shutdown.zip project to reproduce.
Use the following command just before trying to shutdown :
{code:java}
seq 1 2000 | xargs -I $ -n1 -P10 curl [http://127.0.0.1:8080/services/request]
{code}
Or see the JMeter project to do the same.
h2. Logs and trace :
{code:java}
. ____ _ __ _ _
/
/ __{_}'{_} __ _ {_}({_})_ __ __ _ \ \ \ \
( ( )___ | '_ | '{_}| | '{_} \/ _` | \ \ \ \
/ __{_})| |{_})| | | | | || (_| | ) ) ) )
' |___{_}| .{_}{_}|{_}| |{_}|{_}| |{_}_{_}, | / / / /
=========|{_}|==============|{_}_{_}/=/{_}/{_}/{_}/
:: Spring Boot :: (v2.6.7)
2022-05-09 18:00:05.456 INFO 706858 — [ main]
org.example.Application : Starting Application using Java
11.0.15 on LT-XXX with PID 706858
(/home/user/workspace/git/cxf-shutdown/target/classes started by user in
/home/user/workspace/git/cxf-shutdown)
2022-05-09 18:00:05.459 INFO 706858 — [ main]
org.example.Application : No active profile set, falling back
to 1 default profile: "default"
2022-05-09 18:00:06.719 INFO 706858 — [ main]
o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s):
8080 (http)
2022-05-09 18:00:06.728 INFO 706858 — [ main]
o.apache.catalina.core.StandardService : Starting service [Tomcat]
2022-05-09 18:00:06.729 INFO 706858 — [ main]
org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache
Tomcat/9.0.62]
2022-05-09 18:00:06.795 INFO 706858 — [ main]
o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded
WebApplicationContext
2022-05-09 18:00:06.795 INFO 706858 — [ main]
w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext:
initialization completed in 1285 ms
2022-05-09 18:00:07.042 INFO 706858 — [ main]
org.apache.cxf.endpoint.ServerImpl : Setting the server's publish address
to be /
2022-05-09 18:00:07.400 INFO 706858 — [ main]
o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080
(http) with context path ''
2022-05-09 18:00:07.444 INFO 706858 — [ main]
org.example.Application : Started Application in 2.393 seconds
(JVM running for 3.103)
2022-05-09 18:00:18.867 INFO 706858 — [ionShutdownHook]
o.s.b.w.e.tomcat.GracefulShutdown : Commencing graceful shutdown.
Waiting for active requests to complete
2022-05-09 18:00:18.867 WARN 706858 — [io-8080-exec-10]
o.a.c.t.servlet.ServletController : Can't find the request for
[http://127.0.0.1:8080/services/request's] Observer
2022-05-09 18:00:18.873 INFO 706858 — [tomcat-shutdown]
o.s.b.w.e.tomcat.GracefulShutdown : Graceful shutdown complete
Process finished with exit code 130 (interrupted by signal 2: SIGINT)
{code}
--
This message was sent by Atlassian Jira
(v8.20.7#820007)
