Uploaded image for project: 'Red Hat Fuse'
  1. Red Hat Fuse
  2. ENTESB-8418

cxfrs://http camel graceful shutdown with Spring Boot regression

    XMLWordPrintable

Details

    • Bug
    • Resolution: Obsolete
    • Major
    • None
    • FIS 2.0
    • FIS

    Description

      Migrating a test application with camel cxfrs from camel-cdi (working with FIS 1.0) to Spring Boot and FIS 2.0.

      The new spring-boot version behaves weirdly wrt. graceful shutdown:

      having a camel route that contains a "delay", issuing a term does cause the camel graceful shutdown. However, the client receives a 404 when the exchange completes, instead of the expected reply

      from("cxfrs://http://0.0.0.0:8080/rest?resourceClasses=io.fabric8.quickstarts.camelcdi.Service&bindingStyle=SimpleConsumer")
                .log("Request: type='${header.operationName}', body='${body}'")
                .removeHeader("Content-Length") // https://issues.apache.org/jira/browse/CAMEL-7246
                .setHeader("uuid", method(uuidBean, "uuid"))
                .choice()
                    .when().simple("${in.header.operationName} == 'delay'")
                        .delay(simple("${body.delay}"))
                        .transform().simple("${header.uuid} ${body.text}")
                .endChoice()
                    .when().simple("${in.header.operationName} == 'count'")
                        .bean(counterBean, "count")
                        .log("count before delay ${header.cid} ${header.count}")
                        .delay(simple("${header.delay}"))
                        .log("count after delay ${header.cid} ${header.count}")
                        .transform().simple("${header.uuid} ${header.count}")
                .endChoice()
                .otherwise()
                    .transform()
                    .simple("${header.uuid} NOP");

      logs:

        .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.4.1.RELEASE)

13:31:32.131 [main] INFO  o.a.camel.spring.boot.FatJarRouter - Starting FatJarRouter v2.18.1.fuse-000003 on rico with PID 4573 (/home/maschmid/.m2/repository/org/apache/camel/camel-spring-boot/2.18.1.fuse-000003/camel-spring-boot-2.18.1.fuse-000003.jar started by maschmid in /home/maschmid/tmp/fis-camel-cxf-graceful-shutdown/fis2)
13:31:32.134 [main] INFO  o.a.camel.spring.boot.FatJarRouter - No active profile set, falling back to default profiles: default
13:31:32.192 [main] INFO  o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@bd2c204: startup date [Mon Oct 24 13:31:32 CEST 2016]; root of context hierarchy
13:31:32.812 [main] INFO  o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.apache.camel.spring.boot.CamelAutoConfiguration' of type [class org.apache.camel.spring.boot.CamelAutoConfiguration$$EnhancerBySpringCGLIB$$40e408d5] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
13:31:32.871 [main] INFO  i.f.q.camelcdi.DelayDeployment - No DEPLOYMENT_DELAY env set, not delaying deployment.
13:31:33.334 [main] INFO  o.a.c.i.c.DefaultTypeConverter - Loaded 205 type converters
13:31:33.746 [main] INFO  o.s.j.e.a.AnnotationMBeanExporter - Registering beans for JMX exposure on startup
13:31:33.791 [main] INFO  o.a.c.spring.boot.RoutesCollector - Loading additional Camel XML routes from: classpath:camel/*.xml
13:31:33.792 [main] INFO  o.a.c.spring.boot.RoutesCollector - Loading additional Camel XML rests from: classpath:camel-rest/*.xml
13:31:33.792 [main] INFO  o.a.c.spring.boot.RoutesCollector - Starting CamelMainRunController to ensure the main thread keeps running
13:31:33.800 [CamelMainRunController] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) is starting
13:31:33.802 [CamelMainRunController] INFO  o.a.c.m.ManagedManagementStrategy - JMX is enabled
13:31:33.803 [main] INFO  o.a.camel.spring.boot.FatJarRouter - Started FatJarRouter in 1.921 seconds (JVM running for 5.369)
13:31:33.921 [CamelMainRunController] INFO  o.a.c.i.DefaultRuntimeEndpointRegistry - Runtime endpoint registry is in extended mode gathering usage statistics of all incoming and outgoing endpoints (cache limit: 1000)
13:31:34.058 [CamelMainRunController] INFO  o.a.camel.spring.SpringCamelContext - StreamCaching is not in use. If using streams then its recommended to enable stream caching. See more details at http://camel.apache.org/stream-caching.html
13:31:34.278 [CamelMainRunController] INFO  org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be http://0.0.0.0:8080/rest
13:31:34.382 [CamelMainRunController] INFO  org.eclipse.jetty.util.log - Logging initialized @5948ms
13:31:34.429 [CamelMainRunController] INFO  org.eclipse.jetty.server.Server - jetty-9.3.11.v20160721
13:31:34.443 [CamelMainRunController] WARN  o.e.j.server.handler.AbstractHandler - No Server set for org.apache.cxf.transport.http_jetty.JettyHTTPServerEngine$1@491dfd5a
13:31:34.464 [CamelMainRunController] INFO  o.e.jetty.server.AbstractConnector - Started ServerConnector@72389bfc{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
13:31:34.464 [CamelMainRunController] INFO  org.eclipse.jetty.server.Server - Started @6030ms
13:31:34.471 [CamelMainRunController] WARN  o.e.j.server.handler.ContextHandler - Empty contextPath
13:31:34.510 [CamelMainRunController] INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.h.ContextHandler@670a2807{/,null,AVAILABLE}
13:31:34.511 [CamelMainRunController] INFO  o.a.camel.spring.SpringCamelContext - Route: route1 started and consuming from: cxfrs://http://0.0.0.0:8080/rest?bindingStyle=SimpleConsumer&resourceClasses=io.fabric8.quickstarts.camelcdi.Service
13:31:34.511 [main] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) is starting
13:31:34.511 [main] INFO  o.a.camel.spring.SpringCamelContext - Total 1 routes, of which 1 are started.
13:31:34.512 [main] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) started in 0.708 seconds
13:31:34.513 [CamelMainRunController] INFO  o.a.camel.spring.SpringCamelContext - Total 1 routes, of which 1 are started.
13:31:34.513 [CamelMainRunController] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) started in 0.708 seconds
13:31:45.048 [qtp866330021-24] INFO  route1 - Request: type='count', body='5,1000,42'
13:31:45.056 [qtp866330021-24] INFO  route1 - count before delay 42 6
13:31:46.056 [qtp866330021-24] INFO  route1 - count after delay 42 6
13:31:48.518 [qtp866330021-19] INFO  route1 - Request: type='count', body='5,20000,42'
13:31:48.519 [qtp866330021-19] INFO  route1 - count before delay 42 6
^C13:31:52.730 [Thread-2] INFO  o.s.c.a.AnnotationConfigApplicationContext - Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@bd2c204: startup date [Mon Oct 24 13:31:32 CEST 2016]; root of context hierarchy
13:31:52.730 [Thread-3] INFO  o.a.c.m.MainSupport$HangupInterceptor - Received hang up - stopping the main instance.
13:31:52.731 [Thread-1] INFO  o.a.c.m.MainSupport$HangupInterceptor - Received hang up - stopping the main instance.
13:31:52.731 [Thread-3] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) is shutting down
13:31:52.732 [Thread-3] INFO  o.a.c.impl.DefaultShutdownStrategy - Starting to graceful shutdown 1 routes (timeout 300 seconds)
13:31:52.733 [Thread-2] INFO  o.s.j.e.a.AnnotationMBeanExporter - Unregistering JMX-exposed beans on shutdown
13:31:52.741 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.e.j.server.handler.ContextHandler - Stopped o.e.j.s.h.ContextHandler@670a2807{/,null,UNAVAILABLE}
13:31:52.741 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Route: route1 shutdown complete, was consuming from: cxfrs://http://0.0.0.0:8080/rest?bindingStyle=SimpleConsumer&resourceClasses=io.fabric8.quickstarts.camelcdi.Service
13:31:52.743 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 300 seconds. Inflights per route: [route1 = 1]
13:31:53.744 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 299 seconds. Inflights per route: [route1 = 1]
13:31:54.745 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 298 seconds. Inflights per route: [route1 = 1]
13:31:55.746 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 297 seconds. Inflights per route: [route1 = 1]
13:31:56.746 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 296 seconds. Inflights per route: [route1 = 1]
13:31:57.747 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 295 seconds. Inflights per route: [route1 = 1]
13:31:58.748 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 294 seconds. Inflights per route: [route1 = 1]
13:31:59.749 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 293 seconds. Inflights per route: [route1 = 1]
13:32:00.750 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 292 seconds. Inflights per route: [route1 = 1]
13:32:01.751 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 291 seconds. Inflights per route: [route1 = 1]
13:32:02.752 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 290 seconds. Inflights per route: [route1 = 1]
13:32:03.753 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 289 seconds. Inflights per route: [route1 = 1]
13:32:04.754 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 288 seconds. Inflights per route: [route1 = 1]
13:32:05.755 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 287 seconds. Inflights per route: [route1 = 1]
13:32:06.756 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 286 seconds. Inflights per route: [route1 = 1]
13:32:07.757 [Camel (CamelCxf) thread #0 - ShutdownTask] INFO  o.a.c.impl.DefaultShutdownStrategy - Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 285 seconds. Inflights per route: [route1 = 1]
13:32:08.757 [Thread-3] INFO  o.a.c.impl.DefaultShutdownStrategy - Graceful shutdown of 1 routes completed in 16 seconds
13:32:08.785 [Thread-3] INFO  o.a.camel.main.MainLifecycleStrategy - CamelContext: CamelCxf has been shutdown, triggering shutdown of the JVM.
13:32:08.785 [Thread-3] INFO  o.a.camel.main.MainLifecycleStrategy - CamelContext: CamelCxf has been shutdown, triggering shutdown of the JVM.
13:32:08.786 [Thread-3] WARN  o.a.c.impl.DefaultInflightRepository - Shutting down while there are still 1 inflight exchanges.
13:32:08.798 [Thread-3] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) uptime 34.995 seconds
13:32:08.799 [Thread-3] INFO  o.a.camel.spring.SpringCamelContext - Apache Camel 2.18.1.fuse-000003 (CamelContext: CamelCxf) is shutdown in 16.067 seconds

      curl output (after starting the curl and then ctrl-C'd the spring-boot:run'd app)

      $ curl 127.0.0.1:8080/rest/srv/count?count=5\&cid=42\&delay=20000
<html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=utf-8"/>
<title>Error 404 Not Found</title>
</head>
<body><h2>HTTP ERROR 404</h2>
<p>Problem accessing /rest/srv/count. Reason:
<pre>    Not Found</pre></p><hr><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.3.11.v20160721</a><hr/>

</body>
</html>

      Attachments

        Activity

          People

            Unassigned Unassigned
            maschmid@redhat.com Marek Schmidt
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: