Hallo camel users,
I have a process where I have to use a retry (when another system is locked)
after an amount of time. When the process is waiting (in the delay), other
request (coming in from a queue) should continue to be processed. I tried a
route with <delay asyncDelayed="true"> but this does not work as I expected.
My test camel context is:
<camelContext id="TrisESB-rrts-dvl-delay"
xmlns="http://camel.apache.org/schema/spring"; useMDCLogging="true"
trace="false">
<route id="run-once">
<from uri="timer://run-once?repeatCount=1"/>
<setHeader
headerName="CamelCreatedTimestamp"><simple>${property.CamelCreatedTimestamp}</simple></setHeader>
<log message="start of route
(${date:header.CamelCreatedTimestamp:yyyy-MM-dd-HH:mm:ss.SSS})" />
<setHeader
headerName="windowsUsername"><simple>${sysenv.USERNAME}</simple></setHeader>
<setHeader
headerName="CurrentDT"><simple>${date:now:yyyy-MM-dd
HH:mm:ss.SSS}</simple></setHeader>
<setHeader
headerName="timerCounter"><simple>${property.CamelTimerCounter}</simple></setHeader>
<setHeader
headerName="JMSType"><constant>text</constant></setHeader>
<setHeader
headerName="JMSCorrelationID"><simple>${property.CamelTimerCounter}</simple></setHeader>
<setBody><simple>This is a text test message 1 from
${header.windowsUsername} at ${header.CurrentDT}, fired for the
${property.CamelTimerCounter} time.</simple></setBody>
<to
uri="activemq://queue:edu.{{workenvm}}.timer.entry?timeToLive=300000"/>
<setBody><simple>This is a text test message 2 from
${header.windowsUsername} at ${header.CurrentDT}, fired for the
${property.CamelTimerCounter} time.</simple></setBody>
<to
uri="activemq://queue:edu.{{workenvm}}.timer.entry?timeToLive=300000"/>
<setBody><simple>This is a text test message 3 from
${header.windowsUsername} at ${header.CurrentDT}, fired for the
${property.CamelTimerCounter} time.</simple></setBody>
<to
uri="activemq://queue:edu.{{workenvm}}.timer.entry?timeToLive=300000"/>
<setBody><simple>This is a text test message 4 from
${header.windowsUsername} at ${header.CurrentDT}, fired for the
${property.CamelTimerCounter} time.</simple></setBody>
<to
uri="activemq://queue:edu.{{workenvm}}.timer.entry?timeToLive=300000"/>
<setBody><simple>This is a text test message 5 from
${header.windowsUsername} at ${header.CurrentDT}, fired for the
${property.CamelTimerCounter} time.</simple></setBody>
<to
uri="activemq://queue:edu.{{workenvm}}.timer.entry?timeToLive=300000"/>
<log message="posted message 5 to queue"/>
<log message="end of route
(${date:header.CamelCreatedTimestamp:yyyy-MM-dd-HH:mm:ss.SSS})" />
</route>
<route id="capture-queue-messages">
<from uri="activemq:queue:edu.{{workenvm}}.timer.entry"/>
<setHeader
headerName="CamelCreatedTimestamp"><simple>${property.CamelCreatedTimestamp}</simple></setHeader>
<log message="start of route
(${date:header.CamelCreatedTimestamp:yyyy-MM-dd-HH:mm:ss.SSS})"/>
<log message="receiving queue message '${body}'"/>
<setHeader
headerName="DelayInterval"><constant>{{delayer.interval}}</constant></setHeader>
<log message="delaying for ${header.DelayInterval}"/>
<delay asyncDelayed="true">
<javaScript>org.apache.camel.converter.TimePatternConverter.toMilliSeconds(request.getHeader("DelayInterval"))</javaScript>
<log message="inside delay"/>
</delay>
<log message="end of delay"/>
<log message="end of route
(${date:header.CamelCreatedTimestamp:yyyy-MM-dd-HH:mm:ss.SSS})"/>
</route>
</camelContext>
I would expect that the 2nd (and following) queue messages are processed while
the 1st is still delaying but my log shows that this is not the case. What am I
doing wrong?
The delayer.interval parameter is 7s.
I am using camel 2.17.4 with activemq.
2016-12-22 15:16:59.395 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[run-once] start of route (2016-12-22-15:16:59.388)
2016-12-22 15:16:59.441 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] start of route (2016-12-22-15:16:59.440)
2016-12-22 15:16:59.442 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] receiving queue message 'This is a text test message 1
from rrts at 2016-12-22 15:16:59.396, fired for the 1 time.'
2016-12-22 15:16:59.443 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] delaying for 7s
2016-12-22 15:16:59.482 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[run-once] posted message 5 to queue
2016-12-22 15:16:59.483 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[run-once] end of route (2016-12-22-15:16:59.388)
2016-12-22 15:16:59.611 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Scheduling delayed task to run in 7000
millis for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-3
2016-12-22 15:17:06.612 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task woke up and continues routing
for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-3
2016-12-22 15:17:06.614 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] inside delay
2016-12-22 15:17:06.615 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task done for exchangeId:
ID-LPT-030915-001-50533-1482416217495-0-3
2016-12-22 15:17:06.616 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of delay
2016-12-22 15:17:06.616 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of route (2016-12-22-15:16:59.440)
2016-12-22 15:17:06.665 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] start of route (2016-12-22-15:17:06.664)
2016-12-22 15:17:06.665 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] receiving queue message 'This is a text test message 2
from rrts at 2016-12-22 15:16:59.396, fired for the 1 time.'
2016-12-22 15:17:06.666 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] delaying for 7s
2016-12-22 15:17:06.688 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Scheduling delayed task to run in 7000
millis for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-4
2016-12-22 15:17:13.689 [] [TRACE] [org.apache.camel.processor.Delayer] Delayed
task woke up and continues routing for exchangeId:
ID-LPT-030915-001-50533-1482416217495-0-4
2016-12-22 15:17:13.689 [] [INFO ] [capture-queue-messages] inside delay
2016-12-22 15:17:13.690 [] [TRACE] [org.apache.camel.processor.Delayer] Delayed
task done for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-4
2016-12-22 15:17:13.690 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of delay
2016-12-22 15:17:13.691 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of route (2016-12-22-15:17:06.664)
2016-12-22 15:17:13.726 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] start of route (2016-12-22-15:17:13.725)
2016-12-22 15:17:13.726 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] receiving queue message 'This is a text test message 3
from rrts at 2016-12-22 15:16:59.396, fired for the 1 time.'
2016-12-22 15:17:13.726 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] delaying for 7s
2016-12-22 15:17:13.744 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Scheduling delayed task to run in 7000
millis for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-5
2016-12-22 15:17:20.745 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task woke up and continues routing
for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-5
2016-12-22 15:17:20.745 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] inside delay
2016-12-22 15:17:20.746 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task done for exchangeId:
ID-LPT-030915-001-50533-1482416217495-0-5
2016-12-22 15:17:20.746 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of delay
2016-12-22 15:17:20.746 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of route (2016-12-22-15:17:13.725)
2016-12-22 15:17:20.785 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] start of route (2016-12-22-15:17:20.785)
2016-12-22 15:17:20.786 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] receiving queue message 'This is a text test message 4
from rrts at 2016-12-22 15:16:59.396, fired for the 1 time.'
2016-12-22 15:17:20.786 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] delaying for 7s
2016-12-22 15:17:20.812 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Scheduling delayed task to run in 7000
millis for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-6
2016-12-22 15:17:27.813 [] [TRACE] [org.apache.camel.processor.Delayer] Delayed
task woke up and continues routing for exchangeId:
ID-LPT-030915-001-50533-1482416217495-0-6
2016-12-22 15:17:27.813 [] [INFO ] [capture-queue-messages] inside delay
2016-12-22 15:17:27.813 [] [TRACE] [org.apache.camel.processor.Delayer] Delayed
task done for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-6
2016-12-22 15:17:27.813 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of delay
2016-12-22 15:17:27.813 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of route (2016-12-22-15:17:20.785)
2016-12-22 15:17:27.824 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] start of route (2016-12-22-15:17:27.824)
2016-12-22 15:17:27.825 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] receiving queue message 'This is a text test message 5
from rrts at 2016-12-22 15:16:59.396, fired for the 1 time.'
2016-12-22 15:17:27.825 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] delaying for 7s
2016-12-22 15:17:27.833 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Scheduling delayed task to run in 7000
millis for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-7
2016-12-22 15:17:34.835 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task woke up and continues routing
for exchangeId: ID-LPT-030915-001-50533-1482416217495-0-7
2016-12-22 15:17:34.835 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] inside delay
2016-12-22 15:17:34.835 [ID-LPT-030915-001-50533-1482416217495-0-1] [TRACE]
[org.apache.camel.processor.Delayer] Delayed task done for exchangeId:
ID-LPT-030915-001-50533-1482416217495-0-7
2016-12-22 15:17:34.835 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of delay
2016-12-22 15:17:34.835 [ID-LPT-030915-001-50533-1482416217495-0-1] [INFO ]
[capture-queue-messages] end of route (2016-12-22-15:17:27.824)
--
Kind regards,
Ronny Aerts<mailto:ronny.ae...@intris.be> - Intris nv - Wapenstilstandlaan 47,
2600 Berchem, Belgium
R&D Integration Architect
Prince II<http://en.wikipedia.org/wiki/PRINCE2> certified -
ITIL<http://en.wikipedia.org/wiki/Information_Technology_Infrastructure_Library>
certified
Tel: +32-3-326.50.75
Bezoek onze vernieuwde website<http://www.intris.be/>
Intris nv
Wapenstilstandlaan 47
B-2600 Berchem Tel. +32 3 326 50 75
Fax +32 3 326 42 23
www.intris.be<http://www.intris.be/>
[http://www.intris.be/mail/AEO_Sticker_108pxRGB.jpg] <http://www.intris.be>
DISCLAIMER
This is an e-mail from Intris. The information contained in this communication
is intended solely for use by the individual or entity to whom it is addressed.
Use of this communication by others is prohibited. If the e-mail message was
sent to you by mistake, please notify
supp...@intris.be<mailto:supp...@intris.be>, destroy it without reading, using,
copying or disclosing its contents to any other person.
We accept no liability for damage related to data and/or documents which are
communicated by electronic mail.
