camel-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Claus Ibsen <claus.ib...@gmail.com>
Subject Re: Gracefull shutdown timeouts due to NotifyBuilder blocks on context
Date Thu, 26 Apr 2012 06:16:21 GMT
On Wed, Apr 25, 2012 at 1:29 PM,  <m.schmidt@icw.de> wrote:
> Hi Claus,
>
> I've attached a Eclipse/Maven testcase which exposes the blocking thread
> state every time. At least for me ;-)
>
> Could you give it a go?
>

Thanks for the test case. I will take a look when I get some time.

> cheers,
>
> Matthias
>
> Matthias Schmidt | Senior Software Engineer | Development & Delivery
> InterComponentWare AG | Altrottstraße 31 | 69190 Walldorf (Baden) |
> Germany
> Tel.: +49 (0) 6227 385 333 81 | Fax: +49 (0) 6227 385 471
> m.schmidt@icw.de | www.icw.de
>
> **************************************************************************************************
> conhIT 2012 ? ICW ist Bronzesponsor
>
> Besuchen Sie uns auf der conhIT im Besprechungsraum Passau 14
> Vereinbaren Sie schon jetzt Ihren Gesprächstermin unter:
> www.icw-global.com/conhit
>
> Unser conhIT-Programm finden Sie unter: www.icw-global.com/conhit-programm
> **************************************************************************************************
>
>
>
>
> Claus Ibsen <claus.ibsen@gmail.com> wrote on 21.04.2012 10:07:52:
>
>> [image removed]
>>
>> Re: Gracefull shutdown timeouts due to NotifyBuilder blocks on context
>>
>> Claus Ibsen
>>
>> to:
>>
>> users
>>
>> 21.04.2012 10:09
>>
>> Please respond to users
>>
>> Hi
>>
>> I logged a ticket to get this fixed
>> https://issues.apache.org/jira/browse/CAMEL-5200
>>
>> Can you reproduce the issue every time? If so it would be nice if you
>> could create an unit test so we can add that to the code base
>> to test against regressions.
>>
>>
>>
>> On Fri, Apr 20, 2012 at 7:49 PM, Claus Ibsen <claus.ibsen@gmail.com>
> wrote:
>> > Hi
>> >
>> > What version of Camel are you using?
>> >
>> > What are you using the NotifyBuilder for? Its intend is for
>> testing purposes.
>> >
>> > But it seems maybe NotifyBuilder should possible ignore events when
>> > the CamelContext is shutting down.
>> >
>> >
>> > On Fri, Apr 20, 2012 at 2:22 PM,  <m.schmidt@icw.de> wrote:
>> >> Hi *,
>> >>
>> >> We have have a rather annoying issue of a camel shutdown hanging when
> an
>> >> exception happens in a processor. See an abbreviated, numbered stack
>> >> below. Seems like a race condition, since it doesn't happen all the
> time.
>> >> We could provoke this simply by having a processor like this:
>> >>
>> >> public class SingleKeyMappingProcessor implements Processor {
>> >>
>> >>    public void process(final Exchange exchange) {
>> >>
>> >>        throw new NullPointerException("BANG");
>> >>                }
>> >> }
>> >>
>> >> We have tried to work around this issue with various combinations of
>> >> ShutdownStrategies and
>> >> .shutdownRunningTask(ShutdownRunningTask.CompleteAllTasks) operations
> on
>> >> the route.
>> >>
>> >> Env.: Camel 2.8.1, JDK 1.7.0_03 client 32Bit, KlingonXP SP3
>> >>
>> >> Problem: If by chance the main thread shutting down the context
> happens to
>> >> aquire the context lock first (see line #73, id 0x28201580), the
>> >> NotifyBuilder blocks on this very lock (line #26, id 0x28201580). The
>> >> (unconfigured) shutdown thread waits it's 300 secs for the route to
> drain
>> >> it's inflight messages (line #4, DefaultShutdownStrategy.java:427).
>> >>
>> >> Any ideas how to fix this or how to work around?
>> >>
>> >> Cheers & thx,
>> >>
>> >> Matthias
>> >>
>> >> 00000001 "Camel (camelContext) thread #5 - ShutdownTask" daemon
> prio=6
>> >> tid=0x0368cc00 nid=0x1494 waiting on condition [0x0423f000]
>> >> 00000002    java.lang.Thread.State: TIMED_WAITING (sleeping)
>> >> 00000003        at java.lang.Thread.sleep(Native Method)
>> >> 00000004        at
>> >> org.apache.camel.impl.DefaultShutdownStrategy$ShutdownTask.run
>> (DefaultShutdownStrategy.java:427)
>> >> 00000005        at
>> >>
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>> >> 00000006        at
>> >> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>> >> 00000007        at
>> >> java.util.concurrent.FutureTask.run(FutureTask.java:138)
>> >> 00000008        at
>> >> java.util.concurrent.ThreadPoolExecutor$Worker.runTask
>> (ThreadPoolExecutor.java:886)
>> >> 00000009        at
>> >> java.util.concurrent.ThreadPoolExecutor$Worker.run
>> (ThreadPoolExecutor.java:908)
>> >> 00000010        at java.lang.Thread.run(Thread.java:619)
>> >> 00000011
>> >> 00000012 "Camel Thread 4 - ShutdownTask" daemon prio=6 tid=0x036cbc00
>> >> nid=0x1558 waiting on condition [0x041ef000]
>> >> 00000013    java.lang.Thread.State: WAITING (parking)
>> >> 00000014        at sun.misc.Unsafe.park(Native Method)
>> >> 00000015        - parking to wait for  <0x289370f8> (a
>> >>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>> >> 00000016        at
>> >> java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
>> >> 00000017        at
>> >> java.util.concurrent.locks.AbstractQueuedSynchronizer
>> $ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
>> >> 00000018        at
>> >>
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
>> >> 00000019        at
>> >> java.util.concurrent.ThreadPoolExecutor.getTask
>> (ThreadPoolExecutor.java:947)
>> >> 00000020        at
>> >> java.util.concurrent.ThreadPoolExecutor$Worker.run
>> (ThreadPoolExecutor.java:907)
>> >> 00000021        at java.lang.Thread.run(Thread.java:619)
>> >> 00000022
>> >> 00000023 "Camel (camelContext) thread #0 -
>> >> file://target/test-classes/testdata/testInput/lab21" daemon prio=6
>> >> tid=0x036a5400 nid=0x1534 waiting for monitor entry [0x040af000]
>> >> 00000024    java.lang.Thread.State: BLOCKED (on object monitor)
>> >> 00000025        at
>> >> org.apache.camel.impl.DefaultCamelContext.getRoutes
>> (DefaultCamelContext.java:561)
>> >> 00000026        - waiting to lock <0x28201580> (a
>> >> org.apache.camel.spring.SpringCamelContext)
>> >> 00000027        at
>> >> org.apache.camel.util.EndpointHelper.getRouteIdFromEndpoint
>> (EndpointHelper.java:358)
>> >> 00000028        at
>> >>
> org.apache.camel.builder.NotifyBuilder$2.onExchange(NotifyBuilder.java:137)
>> >> 00000029        at
>> >> org.apache.camel.builder.NotifyBuilder
>> $EventPredicateSupport.onExchangeFailed(NotifyBuilder.java:1336)
>> >> 00000030        at
>> >> org.apache.camel.builder.NotifyBuilder
>> $CompoundEventPredicate.onExchangeFailed(NotifyBuilder.java:1420)
>> >> 00000031        at
>> >> org.apache.camel.builder.NotifyBuilder
>> $ExchangeNotifier.onExchangeFailed(NotifyBuilder.java:1222)
>> >> 00000032        at
>> >> org.apache.camel.builder.NotifyBuilder$ExchangeNotifier.notify
>> (NotifyBuilder.java:1197)
>> >> 00000033        at
>> >> org.apache.camel.util.EventHelper.doNotifyEvent(EventHelper.java:576)
>> >> 00000034        at
>> >> org.apache.camel.util.EventHelper.notifyExchangeFailed
>> (EventHelper.java:355)
>> >> 00000035        at
>> >>
> org.apache.camel.impl.DefaultUnitOfWork.done(DefaultUnitOfWork.java:219)
>> >> 00000036        at
>> >> org.apache.camel.processor.UnitOfWorkProcessor.doneUow
>> (UnitOfWorkProcessor.java:156)
>> >> 00000037        at
>> >> org.apache.camel.processor.UnitOfWorkProcessor.access$000
>> (UnitOfWorkProcessor.java:36)
>> >> 00000038        at
>> >> org.apache.camel.processor.UnitOfWorkProcessor$1.done
>> (UnitOfWorkProcessor.java:109)
>> >> 00000039        at
>> >> org.apache.camel.processor.Pipeline.process(Pipeline.java:105)
>> >> 00000040        at
>> >> org.apache.camel.processor.UnitOfWorkProcessor.process
>> (UnitOfWorkProcessor.java:102)
>> >> 00000041        at
>> >> org.apache.camel.util.AsyncProcessorHelper.process
>> (AsyncProcessorHelper.java:78)
>> >> 00000042        at
>> >> org.apache.camel.processor.DelegateAsyncProcessor.processNext
>> (DelegateAsyncProcessor.java:98)
>> >> 00000043        at
>> >> org.apache.camel.processor.DelegateAsyncProcessor.process
>> (DelegateAsyncProcessor.java:89)
>> >> 00000044        at
>> >> org.apache.camel.management.InstrumentationProcessor.process
>> (InstrumentationProcessor.java:69)
>> >> 00000045        at
>> >>
>> org.apache.camel.component.file.GenericFileConsumer.processExchange
>> (GenericFileConsumer.java:315)
>> >> 00000046        at
>> >> org.apache.camel.component.file.GenericFileConsumer.processBatch
>> (GenericFileConsumer.java:151)
>> >> 00000047        at
>> >> org.apache.camel.component.file.GenericFileConsumer.poll
>> (GenericFileConsumer.java:117)
>> >> 00000048        at
>> >> org.apache.camel.impl.ScheduledPollConsumer.doRun
>> (ScheduledPollConsumer.java:133)
>> >> 00000049        at
>> >> org.apache.camel.impl.ScheduledPollConsumer.run
>> (ScheduledPollConsumer.java:88)
>> >> 00000050        at
>> >>
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>> >> 00000051        at
>> >>
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
>> >> 00000052        at
>> >> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
>> >> 00000053        at
>> >> java.util.concurrent.ScheduledThreadPoolExecutor
>> $ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
>> >> 00000054        at
>> >> java.util.concurrent.ScheduledThreadPoolExecutor
>> $ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
>> >> 00000055        at
>> >> java.util.concurrent.ScheduledThreadPoolExecutor
>> $ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
>> >> 00000056        at
>> >> java.util.concurrent.ThreadPoolExecutor$Worker.runTask
>> (ThreadPoolExecutor.java:886)
>> >> 00000057        at
>> >> java.util.concurrent.ThreadPoolExecutor$Worker.run
>> (ThreadPoolExecutor.java:908)
>> >> 00000058        at java.lang.Thread.run(Thread.java:619)
>> >> 00000059
>> >> 00000060 "main" prio=6 tid=0x003b7000 nid=0x9a4 waiting on condition
>> >> [0x009de000]
>> >> 00000061    java.lang.Thread.State: TIMED_WAITING (parking)
>> >> 00000062        at sun.misc.Unsafe.park(Native Method)
>> >> 00000063        - parking to wait for  <0x23195d68> (a
>> >> java.util.concurrent.FutureTask$Sync)
>> >> 00000064        at
>> >>
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
>> >> 00000065        at
>> >>
>>
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos
>> (AbstractQueuedSynchronizer.java:1011)
>> >> 00000066        at
>> >>
>>
> java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos
>> (AbstractQueuedSynchronizer.java:1303)
>> >> 00000067        at
>> >> java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:227)
>> >> 00000068        at
> java.util.concurrent.FutureTask.get(FutureTask.java:91)
>> >> 00000069        at
>> >> org.apache.camel.impl.DefaultShutdownStrategy.doShutdown
>> (DefaultShutdownStrategy.java:129)
>> >> 00000070        at
>> >> org.apache.camel.impl.DefaultShutdownStrategy.shutdown
>> (DefaultShutdownStrategy.java:92)
>> >> 00000071        at
>> >> org.apache.camel.impl.DefaultShutdownStrategy.shutdown
>> (DefaultShutdownStrategy.java:84)
>> >> 00000072        at
>> >> org.apache.camel.impl.DefaultCamelContext.doStop
>> (DefaultCamelContext.java:1460)
>> >> 00000073        - locked <0x28201580> (a
>> >> org.apache.camel.spring.SpringCamelContext)
>> >> 00000074        at
>> >> org.apache.camel.impl.ServiceSupport.stop(ServiceSupport.java:100)
>> >> 00000075        at
>> >> org.apache.camel.impl.ServiceSupport.stop(ServiceSupport.java:124)
>> >> 00000076        at
>> >> com.icw.cm.integration.CmApplicationTest.stopContext
>> (CmApplicationTest.java:140)
>> >> 00000077        at
> sun.reflect.NativeMethodAccessorImpl.invoke0(Native
>> >> Method)
>> >> 00000078        at
>> >> sun.reflect.NativeMethodAccessorImpl.invoke
>> (NativeMethodAccessorImpl.java:39)
>> >> 00000079        at
>> >> sun.reflect.DelegatingMethodAccessorImpl.invoke
>> (DelegatingMethodAccessorImpl.java:25)
>> >> 00000080        at java.lang.reflect.Method.invoke(Method.java:597)
>> >> 00000081        at
>> >> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall
>> (FrameworkMethod.java:44)
>> >> 00000082        at
>> >> org.junit.internal.runners.model.ReflectiveCallable.run
>> (ReflectiveCallable.java:15)
>> >> 00000083        at
>> >> org.junit.runners.model.FrameworkMethod.invokeExplosively
>> (FrameworkMethod.java:41)
>> >> 00000084        at
>> >>
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
>> >> 00000085        at
>> >> org.junit.runners.ParentRunner.run(ParentRunner.java:236)
>> >> 00000086        at org.junit.runners.Suite.runChild(Suite.java:128)
>> >> 00000087        at org.junit.runners.Suite.runChild(Suite.java:24)
>> >> 00000088        at
>> >> org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
>> >> 00000089        at
>> >> org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
>> >> 00000090        at
>> >> org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
>> >> 00000091        at
>> >> org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
>> >> 00000092        at
>> >> org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
>> >> 00000093        at
>> >> org.junit.internal.runners.statements.RunBefores.evaluate
>> (RunBefores.java:28)
>> >> 00000094        at
>> >>
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
>> >> 00000095        at
>> >> org.junit.runners.ParentRunner.run(ParentRunner.java:236)
>> >> 00000096        at
>> >> org.apache.maven.surefire.junit4.JUnit4TestSet.execute
>> (JUnit4TestSet.java:59)
>> >> 00000097        at
>> >>
>>
> org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet
>> (AbstractDirectoryTestSuite.java:115)
>> >> 00000098        at
>> >>
>> org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute
>> (AbstractDirectoryTestSuite.java:102)
>> >> 00000099        at
>> >> org.apache.maven.surefire.Surefire.run(Surefire.java:180)
>> >> 00000100        at
> sun.reflect.NativeMethodAccessorImpl.invoke0(Native
>> >> Method)
>> >> 00000101        at
>> >> sun.reflect.NativeMethodAccessorImpl.invoke
>> (NativeMethodAccessorImpl.java:39)
>> >> 00000102        at
>> >> sun.reflect.DelegatingMethodAccessorImpl.invoke
>> (DelegatingMethodAccessorImpl.java:25)
>> >> 00000103        at java.lang.reflect.Method.invoke(Method.java:597)
>> >> 00000104        at
>> >>
>> org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess
>> (SurefireBooter.java:350)
>> >> 00000105        at
>> >> org.apache.maven.surefire.booter.SurefireBooter.main
>> (SurefireBooter.java:1021)
>> >>
>> >> Matthias Schmidt | Senior Software Engineer | Development & Delivery
>> >> InterComponentWare AG | Altrottstraße 31 | 69190 Walldorf (Baden) |
>> >> Germany
>> >> Tel.: +49 (0) 6227 385 333 81 | Fax: +49 (0) 6227 385 471
>> >> m.schmidt@icw.de | www.icw.de
>> >>
>> >>
>>
> **************************************************************************************************
>> >> conhIT 2012 ? ICW ist Bronzesponsor
>> >>
>> >> Besuchen Sie uns auf der conhIT im Besprechungsraum Passau 14
>> >> Vereinbaren Sie schon jetzt Ihren Gesprächstermin unter:
>> >> www.icw-global.com/conhit
>> >>
>> >> Unser conhIT-Programm finden Sie unter:
> www.icw-global.com/conhit-programm
>> >>
>>
> **************************************************************************************************
>> >>
>> >>
>> >>
>> >>
>> >>
>> >>
>> >> InterComponentWare AG:
>> >> Vorstand: Peter Kirschbauer (Vors.), Jörg Stadler
>> >> Aufsichtsratsvors.: Prof. Dr. Christof Hettich
>> >> Firmensitz: 69190 Walldorf, Altrottstraße 31
>> >> AG Mannheim HRB 351761 / USt.-IdNr.: DE 198388516
>> >
>> >
>> >
>> > --
>> > Claus Ibsen
>> > -----------------
>> > CamelOne 2012 Conference, May 15-16, 2012: http://camelone.com
>> > FuseSource
>> > Email: cibsen@fusesource.com
>> > Web: http://fusesource.com
>> > Twitter: davsclaus, fusenews
>> > Blog: http://davsclaus.blogspot.com/
>> > Author of Camel in Action: http://www.manning.com/ibsen/
>>
>>
>>
>> --
>> Claus Ibsen
>> -----------------
>> CamelOne 2012 Conference, May 15-16, 2012: http://camelone.com
>> FuseSource
>> Email: cibsen@fusesource.com
>> Web: http://fusesource.com
>> Twitter: davsclaus, fusenews
>> Blog: http://davsclaus.blogspot.com/
>> Author of Camel in Action: http://www.manning.com/ibsen/
>
>
>
>
> InterComponentWare AG:
> Vorstand: Peter Kirschbauer (Vors.), Jörg Stadler
> Aufsichtsratsvors.: Prof. Dr. Christof Hettich
> Firmensitz: 69190 Walldorf, Altrottstraße 31
> AG Mannheim HRB 351761 / USt.-IdNr.: DE 198388516



-- 
Claus Ibsen
-----------------
CamelOne 2012 Conference, May 15-16, 2012: http://camelone.com
FuseSource
Email: cibsen@fusesource.com
Web: http://fusesource.com
Twitter: davsclaus, fusenews
Blog: http://davsclaus.blogspot.com/
Author of Camel in Action: http://www.manning.com/ibsen/

Mime
View raw message