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

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

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: FIS 2.0
    • Fix Version/s: Future
    • Component/s: FIS-Spring Boot
    • Labels:

      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>
      

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                maschmid Marek Schmidt
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated: