You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Claus Ibsen <cl...@gmail.com> on 2014/12/24 10:23:05 UTC
Re: ShutdownTask thread does not complete
Hi
We recently fixed something, do you mind testing with 2.14-SNAPSHOT (I
think the fix missed 2.14.1). And see if that helps.
If this is still a problem then please log a JIRA.
On Fri, Sep 12, 2014 at 11:06 AM, Preben.Asmussen <pr...@dr.dk> wrote:
> Hi
>
> On several components that extends ScheduledBatchPollingConsumer I have seen
> that the ShutdownTask thread seems not to complete when suspending/resuming
> a route.
>
> The route suspend/resume works as expected but the spawned shutdown thread
> keeps running in WAITING state.
>
> Shutdown trace for a jpa consumer ->
> [CP Connection(5)-10.112.16.101] DefaultShutdownStrategy INFO
> Starting to graceful shutdown 1 routes (timeout 300 seconds)
> [CP Connection(5)-10.112.16.101] DefaultExecutorServiceManager DEBUG
> Created new ThreadPool for source:
> org.apache.camel.impl.DefaultShutdownStrategy@f8bca77 with name:
> ShutdownTask. ->
> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@700bb0e9[Running,
> pool size = 0, active threads = 0, queued tasks = 0, completed tasks =
> 0][ShutdownTask]
> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG There
> are 1 routes to suspend
> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG Route:
> dbin-Route suspended and shutdown deferred, was consuming from:
> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG Route:
> dbin-Route preparing to shutdown complete.
> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy INFO Route:
> dbin-Route suspend complete, was consuming from:
> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
> [CP Connection(5)-10.112.16.101] DefaultShutdownStrategy INFO
> Graceful shutdown of 1 routes completed in 0 seconds
> [CP Connection(5)-10.112.16.101] SpringCamelContext INFO Route:
> dbin-Route is suspended, was consuming from:
> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG
> Warming up route id: dbin-Route having autoStartup=true
> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG Route:
> dbin-Route >>>
> EventDrivenConsumerRoute[Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
> ->
> Channel[TransactionErrorHandler:PROPAGATION_REQUIRED[Pipeline[[Channel[BeanProcessor[org.dbin.MyConverter(0x1941d09e)]],
> Channel[sendTo(Endpoint[dboutJpa://org.dbin.DemoOut])],
> Channel[BeanProcessor[org.dbin.MyConverter(0x412eec30)]],
> Channel[convertBodyTo[java.lang.String]],
> Channel[sendTo(Endpoint[activemq://queue:demoin])],
> Channel[sendTo(Endpoint[direct://audit])], Channel[choice{when Filter[if:
> XPath: /Demo/id/text() = '6' do: Channel[ThrowException]]}]]]]]]
> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG
> Resuming consumer (order: 1003) on route: dbin-Route
> [CP Connection(5)-10.112.16.101] ServiceHelper DEBUG
> Resuming service
> Consumer[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
> [CP Connection(5)-10.112.16.101] SpringCamelContext INFO Route:
> dbin-Route resumed and consuming from:
> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>
>
> A threaddump shows that the ShutdownTask is in waiting
>
> "Camel (dbin-Context) thread #11 - ShutdownTask" daemon prio=6
> tid=0x0000000014275800 nid=0x1cd8 waiting on condition [0x0000000016e0e000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000d50e0140> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
> at
> java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
>
> Locked ownable synchronizers:
> - None
>
> And the heapdump shows ->
>
> "Camel (dbin-Context) thread #11 - ShutdownTask" daemon prio=5 tid=192
> WAITING
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
> Local Variable:
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject#54
> Local Variable:
> java.util.concurrent.locks.AbstractQueuedSynchronizer$Node#12
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
> Local Variable: java.util.concurrent.LinkedBlockingQueue#11
> Local Variable: java.util.concurrent.atomic.AtomicInteger#821
> Local Variable: java.util.concurrent.locks.ReentrantLock#1517
> at
> java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
> Local Variable:
> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor#1
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> Local Variable: java.util.concurrent.ThreadPoolExecutor$Worker#13
> at java.lang.Thread.run(Thread.java:745)
>
> I'm running this on jdk1.7.0_67 with camel v. 2.13.1 - The same seems to be
> the case on 2.14.0
>
> Any ideas ?
>
> Best,
> Preben
>
>
>
>
> --
> View this message in context: http://camel.465427.n5.nabble.com/ShutdownTask-thread-does-not-complete-tp5756412.html
> Sent from the Camel - Users mailing list archive at Nabble.com.
--
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen
hawtio: http://hawt.io/
fabric8: http://fabric8.io/
Re: ShutdownTask thread does not complete
Posted by Claus Ibsen <cl...@gmail.com>.
Hi
Okay I took a look and its because the graceful shutdown uses a
background thread to do the shutdown work. And that is a single
threaded thread-pool which has a core pool size of 1. And so the
thread is kept around.
I am improving this to allow the thread pool to terminate idle
threads, so after 60 seconds the thread will be terminated.
I logged a ticket
https://issues.apache.org/jira/browse/CAMEL-8177
On Wed, Dec 24, 2014 at 10:23 AM, Claus Ibsen <cl...@gmail.com> wrote:
> Hi
>
> We recently fixed something, do you mind testing with 2.14-SNAPSHOT (I
> think the fix missed 2.14.1). And see if that helps.
>
> If this is still a problem then please log a JIRA.
>
>
> On Fri, Sep 12, 2014 at 11:06 AM, Preben.Asmussen <pr...@dr.dk> wrote:
>> Hi
>>
>> On several components that extends ScheduledBatchPollingConsumer I have seen
>> that the ShutdownTask thread seems not to complete when suspending/resuming
>> a route.
>>
>> The route suspend/resume works as expected but the spawned shutdown thread
>> keeps running in WAITING state.
>>
>> Shutdown trace for a jpa consumer ->
>> [CP Connection(5)-10.112.16.101] DefaultShutdownStrategy INFO
>> Starting to graceful shutdown 1 routes (timeout 300 seconds)
>> [CP Connection(5)-10.112.16.101] DefaultExecutorServiceManager DEBUG
>> Created new ThreadPool for source:
>> org.apache.camel.impl.DefaultShutdownStrategy@f8bca77 with name:
>> ShutdownTask. ->
>> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@700bb0e9[Running,
>> pool size = 0, active threads = 0, queued tasks = 0, completed tasks =
>> 0][ShutdownTask]
>> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG There
>> are 1 routes to suspend
>> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG Route:
>> dbin-Route suspended and shutdown deferred, was consuming from:
>> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy DEBUG Route:
>> dbin-Route preparing to shutdown complete.
>> [ext) thread #11 - ShutdownTask] DefaultShutdownStrategy INFO Route:
>> dbin-Route suspend complete, was consuming from:
>> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>> [CP Connection(5)-10.112.16.101] DefaultShutdownStrategy INFO
>> Graceful shutdown of 1 routes completed in 0 seconds
>> [CP Connection(5)-10.112.16.101] SpringCamelContext INFO Route:
>> dbin-Route is suspended, was consuming from:
>> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG
>> Warming up route id: dbin-Route having autoStartup=true
>> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG Route:
>> dbin-Route >>>
>> EventDrivenConsumerRoute[Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>> ->
>> Channel[TransactionErrorHandler:PROPAGATION_REQUIRED[Pipeline[[Channel[BeanProcessor[org.dbin.MyConverter(0x1941d09e)]],
>> Channel[sendTo(Endpoint[dboutJpa://org.dbin.DemoOut])],
>> Channel[BeanProcessor[org.dbin.MyConverter(0x412eec30)]],
>> Channel[convertBodyTo[java.lang.String]],
>> Channel[sendTo(Endpoint[activemq://queue:demoin])],
>> Channel[sendTo(Endpoint[direct://audit])], Channel[choice{when Filter[if:
>> XPath: /Demo/id/text() = '6' do: Channel[ThrowException]]}]]]]]]
>> [CP Connection(5)-10.112.16.101] SpringCamelContext DEBUG
>> Resuming consumer (order: 1003) on route: dbin-Route
>> [CP Connection(5)-10.112.16.101] ServiceHelper DEBUG
>> Resuming service
>> Consumer[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>> [CP Connection(5)-10.112.16.101] SpringCamelContext INFO Route:
>> dbin-Route resumed and consuming from:
>> Endpoint[dbinJpa://org.dbin.DemoIn?consumeLockEntity=false&consumer.query=select+d+from+org.dbin.DemoIn+d+order+by+sekvens&maximumResults=10]
>>
>>
>> A threaddump shows that the ShutdownTask is in waiting
>>
>> "Camel (dbin-Context) thread #11 - ShutdownTask" daemon prio=6
>> tid=0x0000000014275800 nid=0x1cd8 waiting on condition [0x0000000016e0e000]
>> java.lang.Thread.State: WAITING (parking)
>> at sun.misc.Unsafe.park(Native Method)
>> - parking to wait for <0x00000000d50e0140> (a
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
>> at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
>> at
>> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
>> at
>> java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>> at java.lang.Thread.run(Thread.java:745)
>>
>> Locked ownable synchronizers:
>> - None
>>
>> And the heapdump shows ->
>>
>> "Camel (dbin-Context) thread #11 - ShutdownTask" daemon prio=5 tid=192
>> WAITING
>> at sun.misc.Unsafe.park(Native Method)
>> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
>> at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
>> Local Variable:
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject#54
>> Local Variable:
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$Node#12
>> at
>> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
>> Local Variable: java.util.concurrent.LinkedBlockingQueue#11
>> Local Variable: java.util.concurrent.atomic.AtomicInteger#821
>> Local Variable: java.util.concurrent.locks.ReentrantLock#1517
>> at
>> java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
>> Local Variable:
>> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor#1
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>> Local Variable: java.util.concurrent.ThreadPoolExecutor$Worker#13
>> at java.lang.Thread.run(Thread.java:745)
>>
>> I'm running this on jdk1.7.0_67 with camel v. 2.13.1 - The same seems to be
>> the case on 2.14.0
>>
>> Any ideas ?
>>
>> Best,
>> Preben
>>
>>
>>
>>
>> --
>> View this message in context: http://camel.465427.n5.nabble.com/ShutdownTask-thread-does-not-complete-tp5756412.html
>> Sent from the Camel - Users mailing list archive at Nabble.com.
>
>
>
> --
> Claus Ibsen
> -----------------
> Red Hat, Inc.
> Email: cibsen@redhat.com
> Twitter: davsclaus
> Blog: http://davsclaus.com
> Author of Camel in Action: http://www.manning.com/ibsen
> hawtio: http://hawt.io/
> fabric8: http://fabric8.io/
--
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen
hawtio: http://hawt.io/
fabric8: http://fabric8.io/