You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cxf.apache.org by "Thomas MAUGIN (Jira)" <ji...@apache.org> on 2022/05/10 12:19:00 UTC
[jira] [Created] (CXF-8702) Graceful shutdown : Error 404 with "Can't find the request for XXXXX's Observer" on - Springboot + CXF Server
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)