camel-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ├ľnder Sezgin (JIRA) <j...@apache.org>
Subject [jira] [Commented] (CAMEL-11750) Camel route with multicast (parallel) generate huge CPU load
Date Thu, 07 Sep 2017 08:42:00 GMT

    [ https://issues.apache.org/jira/browse/CAMEL-11750?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16156693#comment-16156693
] 

├ľnder Sezgin commented on CAMEL-11750:
--------------------------------------

well, i would say if you have got long running tasks and and you push many tasks to your direct
endpoint which will cause oveflooding your processor chain / route, i think this is a design
issue.
i am not convinced that you can put delay to each task you send to direct enpoint. this may
resolve your issue because you have got long running tasks. 
what if you don't have long running tasks and you want to multicast and parallelize your route?
I think putting delay will break such scenario as i mentioned as "what if".

i think you need to use throttler EIP if you have long running tasks and overflooding your
direct endpoint to reduce the number of messages to your direct enpoint because you have got
long running tasks. 

> Camel route with multicast (parallel) generate huge CPU load
> ------------------------------------------------------------
>
>                 Key: CAMEL-11750
>                 URL: https://issues.apache.org/jira/browse/CAMEL-11750
>             Project: Camel
>          Issue Type: Bug
>          Components: camel-core
>            Reporter: Nazar Vishka
>            Priority: Critical
>
> I've created simple [Spring Camel Route application|https://github.com/leofromgroza/camel-long-term-route]
that can be used for issue reproducing. Here we have very simple route:
> {code}
>     public void configure() throws Exception {
>         from("direct:start").routeId("start")
>                 .multicast().parallelProcessing()
>                 .to("direct:very-long-task", "direct:long-task")
>                 .end();
>         from("direct:long-task").routeId("long-task")
>                 .log("Started long-task")
>                 .process(exchange -> Thread.sleep(5000))
>                 .log("Finished long-task")
>                 .end();
>         from("direct:very-long-task").routeId("very-long-task")
>                 .log("Started very-long-task")
>                 .process(exchange -> Thread.sleep(35000))
>                 .log("Finished very-long-task")
>                 .end();
>     }{code}
> From our main route 'start' we are starting in parallel two sub-routes: 'long-task' and
'very-long-task'. They are just doing something for some period of time and do not generate
any load to the system.
> But I found that when one task finished earlier than other one, route start to make a
huge CPU load. Here you can see a CPU usage during executiong of Camel route that was mentioned
earlier (after finishing of 'long-task' usage of CPU uncreased from 0 to 12.5%):
> !https://content.screencast.com/users/NazarV/folders/Jing/media/830268f0-d184-4c57-adb1-b782ea63fa6d/2017-09-06_1241.png!
> Screenshot was made when I was running route on my Windows PC with 4 physical CPU cores
+ 4 HT. On Unix systems we found that after end of 'long-task' it used 100% of one core till
the end of work.
> One more interesting thing that i've found is that the main load on the system was generated
by the thread MulticastProcessor-AggregateTask that was spending a lot of time in the method
java.util.concurrent.locks.AbstractQueuedSynchronizer.ConditionObject#awaitNanos that was
called from java.util.concurrent.DelayQueue#poll(long, java.util.concurrent.TimeUnit):
> {code}"Camel (camel-1) thread #2 - MulticastProcessor-AggregateTask" #29 daemon prio=5
os_prio=0 tid=0x00000000215e3000 nid=0x7a0 runnable [0x0000000022eaf000]
>    java.lang.Thread.State: RUNNABLE
> 	at java.lang.Thread.isInterrupted(Native Method)
> 	at java.lang.Thread.interrupted(Thread.java:944)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.checkInterruptWhileWaiting(AbstractQueuedSynchronizer.java:2002)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2079)
> 	at java.util.concurrent.DelayQueue.poll(DelayQueue.java:273)
> 	at org.apache.camel.util.concurrent.SubmitOrderedCompletionService.poll(SubmitOrderedCompletionService.java:127)
> 	at org.apache.camel.processor.MulticastProcessor$AggregateOnTheFlyTask.aggregateOnTheFly(MulticastProcessor.java:463)
> 	at org.apache.camel.processor.MulticastProcessor$AggregateOnTheFlyTask.run(MulticastProcessor.java:418)
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at java.lang.Thread.run(Thread.java:745){code}
> In DelayQueue#poll(long, java.util.concurrent.TimeUnit) we have a piece of code:
> {code}E first = q.peek();
> if (first == null) {
>  ...
> } else {
>   long delay = first.getDelay(NANOSECONDS);
>     ...
>   long timeLeft =  available.awaitNanos(delay) {code}
> During debugging I found that E first is object of class [org.apache.camel.util.concurrent.SubmitOrderedCompletionService.SubmitOrderFutureTask|https://github.com/apache/camel/blob/camel-2.19.2/camel-core/src/main/java/org/apache/camel/util/concurrent/SubmitOrderedCompletionService.java]
and it's very interesting [getDelay(TimeUnit) method|https://github.com/apache/camel/blob/camel-2.19.2/camel-core/src/main/java/org/apache/camel/util/concurrent/SubmitOrderedCompletionService.java#L64]
always return 1. I thing that is a source of current issue:
> {code} public long getDelay(TimeUnit unit) {
>             // if the answer is 0 then this task is ready to be taken
>             return id - index.get();
>         }{code}
> So when delay is 1, AggregateTask thread is not sleeping at all and generates a huge
CPU load all the time when it is waiting for the end of the last task.
> I think that [getDelay(TimeUnit) method|https://github.com/apache/camel/blob/camel-2.19.2/camel-core/src/main/java/org/apache/camel/util/concurrent/SubmitOrderedCompletionService.java#L64]
should be somehow re-implemented.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message