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

[camel-validator] Non valid exchange ends in pending queue

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Done
    • Affects Version/s: fuse-7.1
    • Fix Version/s: fuse-7.4-GA
    • Component/s: Camel
    • Labels:
      None

      Description

      1) Deploy camel-context such as

      <camelContext xmlns="http://camel.apache.org/schema/blueprint" id="camel-context">
      
      		<validators>
      			<predicateValidator type="csv:CSVUser">
      				<simple>${body} contains 'valid'</simple>
      			</predicateValidator>
      		</validators>
      
      		<route>
      			<from uri="timer:x?repeatCount=1"/>
      			<setBody><constant>shouldFail</constant></setBody>
      			<to uri="direct:start" />
      		</route>
      		<route>
      			<from uri="direct:start" />
      			<inputType urn="csv:CSVUser" validate="true"/>
      			<log message="${body}"/>
      			<to uri="mock:out"/>
      		</route>
      	</camelContext>
      

      2) undeploy the bundle
      3) see log

      2018-09-12 12:43:15,611 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Route: route1 started and consuming from: timer://x?repeatCount=1
      2018-09-12 12:43:15,612 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Route: route2 started and consuming from: direct://start
      2018-09-12 12:43:15,613 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Total 2 routes, of which 2 are started
      2018-09-12 12:43:15,614 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Apache Camel 2.21.0.fuse-710018-redhat-00001 (CamelContext: camel-context) started in 0.277 seconds
      2018-09-12 12:43:15,622 | INFO  | -redhat-00001/deploy | o.a.f.fileinstall                | 11 - org.apache.felix.fileinstall - 3.6.4 | Started bundle: blueprint:file:/home/jbouska/servers/fuse-karaf-7.1.0.fuse-710018-redhat-00001/deploy/camel-context.xml
      2018-09-12 12:43:16,626 | ERROR | hread #1 - timer://x | o.a.c.p.DefaultErrorHandler      | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Failed delivery for (MessageId: ID-jbouska-ThinkPad-W541-1536748995173-0-2 on ExchangeId: ID-jbouska-ThinkPad-W541-1536748995173-0-1). Exhausted after delivery attempt: 1 caught: org.apache.camel.processor.validation.PredicateValidationException: Validation failed for Predicate[Simple: ${body} contains 'valid']. Exchange[]
      
      Message History
      ---------------------------------------------------------------------------------------------------------------------------------------
      RouteId              ProcessorId          Processor                                                                        Elapsed (ms)
      [route1            ] [route1            ] [timer://x?repeatCount=1                                                       ] [         9]
      [route1            ] [setBody1          ] [setBody[constant{shouldFail}]                                                 ] [         1]
      [route1            ] [to1               ] [direct:start                                                                  ] [         6]
      
      Stacktrace
      ---------------------------------------------------------------------------------------------------------------------------------------
      org.apache.camel.processor.validation.PredicateValidationException: Validation failed for Predicate[Simple: ${body} contains 'valid']. Exchange[]
      	at org.apache.camel.processor.validation.PredicateValidatingProcessor.process(PredicateValidatingProcessor.java:52) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.impl.validator.ProcessorValidator.validate(ProcessorValidator.java:62) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.ContractAdvice.doValidate(ContractAdvice.java:184) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.ContractAdvice.before(ContractAdvice.java:74) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:149) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.direct.DirectBlockingProducer.process(DirectBlockingProducer.java:53) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:148) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:548) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:201) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.Pipeline.process(Pipeline.java:138) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.Pipeline.process(Pipeline.java:101) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:201) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.timer.TimerConsumer.sendTimerExchange(TimerConsumer.java:197) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.timer.TimerConsumer$1.run(TimerConsumer.java:79) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at java.util.TimerThread.mainLoop(Timer.java:555) [?:?]
      	at java.util.TimerThread.run(Timer.java:505) [?:?]
      2018-09-12 12:43:16,632 | WARN  | hread #1 - timer://x | o.a.c.c.t.TimerConsumer          | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Error processing exchange. Exchange[ID-jbouska-ThinkPad-W541-1536748995173-0-1]. Caused by: [org.apache.camel.processor.validation.PredicateValidationException - Validation failed for Predicate[Simple: ${body} contains 'valid']. Exchange[]]
      org.apache.camel.processor.validation.PredicateValidationException: Validation failed for Predicate[Simple: ${body} contains 'valid']. Exchange[]
      	at org.apache.camel.processor.validation.PredicateValidatingProcessor.process(PredicateValidatingProcessor.java:52) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.impl.validator.ProcessorValidator.validate(ProcessorValidator.java:62) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.ContractAdvice.doValidate(ContractAdvice.java:184) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.ContractAdvice.before(ContractAdvice.java:74) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:149) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.direct.DirectBlockingProducer.process(DirectBlockingProducer.java:53) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:148) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:548) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:201) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.Pipeline.process(Pipeline.java:138) ~[60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.Pipeline.process(Pipeline.java:101) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:201) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.timer.TimerConsumer.sendTimerExchange(TimerConsumer.java:197) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at org.apache.camel.component.timer.TimerConsumer$1.run(TimerConsumer.java:79) [60:org.apache.camel.camel-core:2.21.0.fuse-710018-redhat-00001]
      	at java.util.TimerThread.mainLoop(Timer.java:555) [?:?]
      	at java.util.TimerThread.run(Timer.java:505) [?:?]
      2018-09-12 12:43:40,880 | INFO  | pipe-uninstall 223   | o.a.a.b.c.BlueprintExtender      | 49 - org.apache.aries.blueprint.core - 1.9.0 | Destroying BlueprintContainer for bundle camel-context.xml/0.0.0
      2018-09-12 12:43:40,881 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Stopping CamelContext: camel-context
      2018-09-12 12:43:40,881 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Apache Camel 2.21.0.fuse-710018-redhat-00001 (CamelContext: camel-context) is shutting down
      2018-09-12 12:43:40,883 | INFO  |  Event Dispatcher: 1 | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Starting to graceful shutdown 2 routes (timeout 300 seconds)
      2018-09-12 12:43:40,887 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 300 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:41,889 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 299 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:42,890 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 298 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:43,891 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 297 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:44,891 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 296 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:45,892 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 295 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:46,892 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 294 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:47,893 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 293 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:48,894 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 292 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:49,894 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 291 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:50,895 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 290 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:51,895 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 289 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:52,896 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 288 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:53,897 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 287 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:54,897 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 286 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:55,898 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 285 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:56,898 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 284 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:57,899 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 283 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:58,900 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 282 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:43:59,900 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 281 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:00,901 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 280 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:01,901 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 279 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:02,902 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 278 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:03,903 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 277 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:04,903 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 276 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:05,904 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 275 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:06,905 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 274 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:07,905 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 273 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:08,906 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 272 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:09,907 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 271 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:10,907 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 270 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:11,908 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 269 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:12,908 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 268 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:13,909 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 267 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:14,910 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 266 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:15,911 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 265 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:16,911 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 264 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:17,912 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 263 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:18,912 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 262 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:19,913 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 261 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:20,914 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 260 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:21,914 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 259 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:22,915 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 258 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:23,915 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 257 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:24,916 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 256 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:25,917 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 255 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:26,917 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 254 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:27,918 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 253 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:28,918 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 252 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:29,919 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 251 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:30,920 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 250 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:31,920 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 249 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:32,921 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 248 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:33,921 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 247 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:34,922 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 246 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:35,923 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 245 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:36,923 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 244 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:37,924 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 243 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:38,924 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 242 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:39,925 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Waiting as there are still 1 inflight and pending exchanges to complete, timeout in 241 seconds. Inflights per route: [route2 = 1]
      2018-09-12 12:44:40,881 | WARN  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Interrupted while waiting during graceful shutdown, will force shutdown now.
      2018-09-12 12:44:40,881 | WARN  |  Event Dispatcher: 1 | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Timeout occurred during graceful shutdown. Forcing the routes to be shutdown now. Notice: some resources may still be running as graceful shutdown did not complete successfully.
      2018-09-12 12:44:40,881 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Route: route2 shutdown complete, was consuming from: direct://start
      2018-09-12 12:44:40,881 | WARN  | pipe-uninstall 223   | a.a.b.c.BlueprintEventDispatcher | 49 - org.apache.aries.blueprint.core - 1.9.0 | Listener timed out, will be ignored
      java.util.concurrent.TimeoutException: null
      	at java.util.concurrent.AbstractExecutorService.doInvokeAny(AbstractExecutorService.java:184) ~[?:?]
      	at java.util.concurrent.AbstractExecutorService.invokeAny(AbstractExecutorService.java:225) ~[?:?]
      	at org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$4.call(ScheduledExecutorServiceWrapper.java:182) ~[49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$15.call(ScheduledExecutorServiceWrapper.java:443) ~[49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.utils.threading.RWLock.runReadOperation(RWLock.java:33) ~[49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.runUnlessShutdown(ScheduledExecutorServiceWrapper.java:440) ~[49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.invokeAny(ScheduledExecutorServiceWrapper.java:177) ~[49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListener(BlueprintEventDispatcher.java:188) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListeners(BlueprintEventDispatcher.java:178) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintEventDispatcher.blueprintEvent(BlueprintEventDispatcher.java:133) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:888) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:324) [49:org.apache.aries.blueprint.core:1.9.0]
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
      	at org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:345) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:237) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422) [49:org.apache.aries.blueprint.core:1.9.0]
      	at org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1179) [?:?]
      	at org.apache.felix.framework.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:730) [?:?]
      	at org.apache.felix.framework.EventDispatcher.fireBundleEvent(EventDispatcher.java:485) [?:?]
      	at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4579) [?:?]
      	at org.apache.felix.framework.Felix.stopBundle(Felix.java:2626) [?:?]
      	at org.apache.felix.framework.Felix.uninstallBundle(Felix.java:2750) [?:?]
      	at org.apache.felix.framework.BundleImpl.uninstall(BundleImpl.java:1055) [?:?]
      	at org.apache.karaf.bundle.command.Uninstall.executeOnBundle(Uninstall.java:34) [120:org.apache.karaf.bundle.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.karaf.bundle.command.BundlesCommand.doExecute(BundlesCommand.java:67) [120:org.apache.karaf.bundle.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.karaf.bundle.command.BundlesCommand.execute(BundlesCommand.java:56) [120:org.apache.karaf.bundle.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:84) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:571) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:497) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:386) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:417) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) [144:org.apache.karaf.shell.core:4.2.0.fuse-710024-redhat-00002]
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
      	at java.lang.Thread.run(Thread.java:748) [?:?]
      2018-09-12 12:44:40,882 | INFO  | ad #2 - ShutdownTask | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Route: route1 shutdown complete, was consuming from: timer://x?repeatCount=1
      2018-09-12 12:44:40,882 | INFO  |  Event Dispatcher: 1 | o.a.c.i.DefaultShutdownStrategy  | 60 - org.apache.camel.camel-core - 2.21.0.fuse-710018-redhat-00001 | Graceful shutdown of 2 routes completed in 59 seconds
      2018-09-12 12:44:40,901 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Apache Camel 2.21.0.fuse-710018-redhat-00001 (CamelContext: camel-context) uptime 1 minute
      2018-09-12 12:44:40,901 | INFO  |  Event Dispatcher: 1 | o.a.c.b.BlueprintCamelContext    | 58 - org.apache.camel.camel-blueprint - 2.21.0.fuse-710018-redhat-00001 | Apache Camel 2.21.0.fuse-710018-redhat-00001 (CamelContext: camel-context) is shutdown in 1 minute
      

      Is that expected behavior? Shouldn't we rather destroy the message than put the exchange to pending queue?

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  jondruse Jiri Ondrusek
                  Reporter:
                  jbouska Jan Bouska
                  Tester:
                  Jan Bouska
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  5 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: