camel-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From m.schm...@icw.de
Subject Re: Gracefull shutdown timeouts due to NotifyBuilder blocks on context
Date Tue, 24 Apr 2012 14:12:33 GMT
Hi Claus,

thanks for this super-fast response & fix! I'm providing a junit4 testcase 
ASAP.

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  
Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message