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 Fri, 20 Apr 2012 17:49:18 GMT
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/

Mime
View raw message