[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [xmlblaster-devel] Lock issue with corba protocoll

To: xmlblaster-devel at server.xmlblaster.org
Subject: Re: [xmlblaster-devel] Lock issue with corba protocoll
From: Peter Antman <pra at mint.se>
Date: 12 Sep 2003 12:50:13 +0200
In-reply-to: <3F6193FE.1080005 at marcelruff.info>
References: <1063357003.4864.7.camel at pra> <3F6193FE.1080005 at marcelruff.info>
Reply-to: xmlblaster-devel at server.xmlBlaster.org
Sender: owner-xmlblaster-devel at server.xmlBlaster.org
On Fri, 2003-09-12 at 11:38, Marcel Ruff wrote:
> Peter Antman wrote:
> > Hi,
> > I have stumbled on a lock/freeze issue with the corba driver, that I
> > have a hard time understanding.
> > 
> > This seems to happen when I set up several connections at once.
> > 
> > Here:s one scenario where I set up a pool of connections with
> > potentially several subscribers per connections. Once in a while the
> > first subscription will freeze. Here's a the thread stack dumps I can
> > find that affects this:
> > 
> > On the client side, adding a subscriber:
> > "Thread Pool Worker-0" prio=1 tid=0x0x92f7b78 nid=0x2f8e in
> > Object.wait() [52a02000..52a03840]
> > 	at java.lang.Object.wait(Native Method)
> > 	- waiting on <0x47ca8f50> (a org.jacorb.orb.ReplyReceiver)
> > 	at java.lang.Object.wait(Object.java:426)
> > 	at
> > org.jacorb.orb.connection.ReplyPlaceholder.getInputStream(ReplyPlaceholder.java:134)
> > 	- locked <0x47ca8f50> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.ReplyReceiver.getReply(ReplyReceiver.java:230)
> > 	- locked <0x47ca8f50> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:851)
> > 	at org.jacorb.orb.Delegate.invoke(Delegate.java:762)
> > 	at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
> > 	at
> > org.xmlBlaster.protocol.corba.authenticateIdl._AuthServerStub.connect(_AuthServerStub.java:78)
> > 	at
> > org.xmlBlaster.client.protocol.corba.CorbaConnection.connect(CorbaConnection.java:501)
> > 	at
> > org.xmlBlaster.client.dispatch.ClientDeliveryConnection.connect(ClientDeliveryConnection.java:390)
> > 	at
> > org.xmlBlaster.client.dispatch.ClientDeliveryConnection.doSend(ClientDeliveryConnection.java:144)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnection.send(DeliveryConnection.java:195)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnectionsHandler.send(DeliveryConnectionsHandler.java:357)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryWorker.run(DeliveryWorker.java:76)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryManager.putPre(DeliveryManager.java:446)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryManager.putPre(DeliveryManager.java:425)
> > 	at
> > org.xmlBlaster.util.queue.ram.RamQueuePlugin.put(RamQueuePlugin.java:642)
> > 	at
> > org.xmlBlaster.client.XmlBlasterAccess.queueMessage(XmlBlasterAccess.java:552)
> > 	at
> > org.xmlBlaster.client.XmlBlasterAccess.connect(XmlBlasterAccess.java:241)
> > 	- locked <0x47b73048> (a org.xmlBlaster.client.XmlBlasterAccess)
> > 	at org.backsource.in.blaster.Connection.setUp(Connection.java:93)
> > 	at org.backsource.in.blaster.Connection.<init>(Connection.java:84)
> > 	at
> > org.backsource.in.blaster.ConnectionPool.getConnection(ConnectionPool.java:149)
> > 	at
> > org.backsource.in.blaster.ConnectionPool.addSubscriber(ConnectionPool.java:89)
> > 	- locked <0x468877b0> (a org.backsource.in.blaster.ConnectionPool)
> > 	at
> > org.backsource.in.blaster.BlasterSubscriberManagerJMX.addSubscriber(BlasterSubscriberManagerJMX.java:324)
> > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > 	at
> > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> > 	at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> > 	at java.lang.reflect.Method.invoke(Method.java:324)
> > 	at
> > org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
> > 	at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:517)
> > 	at org.backsource.jmx.MBeanProxy.invoke(MBeanProxy.java:230)
> > 	at $Proxy48.addSubscriber(Unknown Source)
> > 	at
> > org.backsource.in.blaster.server.SubscriberManagerListener.onMessage(SubscriberManagerListener.java:99)
> > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > 	at
> > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> > 	at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> > 	at java.lang.reflect.Method.invoke(Method.java:324)
> > 	at
> > org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:391)
> > 	at
> > org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
> > 	at
> > org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:88)
> > 	at
> > org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:107)
> > 	at
> > org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:237)
> > 	at
> > org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:98)
> > 	at
> > org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:100)
> > 	at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:208)
> > 	at
> > org.jboss.ejb.MessageDrivenContainer.invoke(MessageDrivenContainer.java:302)
> > 	at
> > org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:962)
> > 	at
> > org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1038)
> > 	at
> > org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:243)
> > 	at
> > org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:603)
> > 	at
> > org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:417)
> > 	- locked <0x468913e8> (a java.util.LinkedList)
> > 	at org.jboss.mq.SpySession.run(SpySession.java:296)
> > 	- locked <0x4688dd48> (a java.util.LinkedList)
> > 	at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
> > 	at
> > EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:727)
> > 	at java.lang.Thread.run(Thread.java:536)
> > 
> > "Connection Consumer for dest TOPIC.subscriberQueue" prio=1
> > tid=0x0x50352a20 nid=0x2f8c in Object.wait() [52982000..52982840]
> > 	at java.lang.Object.wait(Native Method)
> > 	- waiting on <0x468a4200> (a java.util.LinkedList)
> > 	at java.lang.Object.wait(Object.java:426)
> > 	at
> > org.jboss.mq.SpyConnectionConsumer.run(SpyConnectionConsumer.java:202)
> > 	- locked <0x468a4200> (a java.util.LinkedList)
> > 	at java.lang.Thread.run(Thread.java:536)
> > 
> > On the server side, loging the session in:
> > 
> > "RequestProcessor-5" daemon prio=1 tid=0x0x921f930 nid=0x2fa1 in
> > Object.wait() [53315000..53315840]
> > 	at java.lang.Object.wait(Native Method)
> > 	- waiting on <0x47ca8970> (a org.jacorb.orb.ReplyReceiver)
> > 	at java.lang.Object.wait(Object.java:426)
> > 	at
> > org.jacorb.orb.connection.ReplyPlaceholder.getInputStream(ReplyPlaceholder.java:134)
> > 	- locked <0x47ca8970> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.ReplyReceiver.getReply(ReplyReceiver.java:230)
> > 	- locked <0x47ca8970> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:851)
> > 	at org.jacorb.orb.Delegate.invoke(Delegate.java:762)
> > 	at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
> > 	at
> > org.xmlBlaster.protocol.corba.clientIdl._BlasterCallbackStub.ping(_BlasterCallbackStub.java:31)
> > 	at
> > org.xmlBlaster.protocol.corba.CallbackCorbaDriver.ping(CallbackCorbaDriver.java:186)
> > 	at
> > org.xmlBlaster.engine.dispatch.CbDeliveryConnection.connectLowlevel(CbDeliveryConnection.java:92)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnection.initialize(DeliveryConnection.java:107)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnectionsHandler.initialize(DeliveryConnectionsHandler.java:143)
> > 	- locked <0x47ca8b28> (a java.util.ArrayList)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryManager.<init>(DeliveryManager.java:115)
> > 	at
> > org.xmlBlaster.authentication.SessionInfo.<init>(SessionInfo.java:144)
> > 	at
> > org.xmlBlaster.authentication.Authenticate.connect(Authenticate.java:319)
> > 	- locked <0x47ca8ce8> (a org.xmlBlaster.authentication.SubjectInfo)
> > 	at
> > org.xmlBlaster.protocol.corba.AuthServerImpl.connect(AuthServerImpl.java:225)
> > 	at
> > org.xmlBlaster.protocol.corba.AuthServerImpl.connect(AuthServerImpl.java:185)
> > 	at
> > org.xmlBlaster.protocol.corba.authenticateIdl.AuthServerPOATie.connect(AuthServerPOATie.java:48)
> > 	at
> > org.xmlBlaster.protocol.corba.authenticateIdl.AuthServerPOA._invoke(AuthServerPOA.java:55)
> > 	at
> > org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:247)
> > 	at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:496)
> > 	at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:635)
> > 
> > 
> > This also happens sometimes for the publisher, using the k2 adapter.
> > However I have not been able to find the server side equivalence:
> > "Thread Pool Worker-6" prio=1 tid=0x0x82eab48 nid=0x1ca7 in
> > Object.wait() [5d6b7000..5d6b8840]
> > 	at java.lang.Object.wait(Native Method)
> > 	- waiting on <0x474da268> (a org.jacorb.orb.ReplyReceiver)
> > 	at java.lang.Object.wait(Object.java:426)
> > 	at
> > org.jacorb.orb.connection.ReplyPlaceholder.getInputStream(ReplyPlaceholder.java:134)
> > 	- locked <0x474da268> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.ReplyReceiver.getReply(ReplyReceiver.java:230)
> > 	- locked <0x474da268> (a org.jacorb.orb.ReplyReceiver)
> > 	at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:851)
> > 	at org.jacorb.orb.Delegate.invoke(Delegate.java:762)
> > 	at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
> > 	at
> > org.xmlBlaster.protocol.corba.authenticateIdl._AuthServerStub.ping(_AuthServerStub.java:31)
> > 	at
> > org.xmlBlaster.client.protocol.corba.CorbaConnection.ping(CorbaConnection.java:757)
> > 	at
> > org.xmlBlaster.client.dispatch.ClientDeliveryConnection.connectLowlevel(ClientDeliveryConnection.java:95)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnection.initialize(DeliveryConnection.java:107)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryConnectionsHandler.initialize(DeliveryConnectionsHandler.java:143)
> > 	- locked <0x474da428> (a java.util.ArrayList)
> > 	at
> > org.xmlBlaster.util.dispatch.DeliveryManager.<init>(DeliveryManager.java:115)
> > 	at
> > org.xmlBlaster.client.XmlBlasterAccess.connect(XmlBlasterAccess.java:227)
> > 	- locked <0x47442db0> (a org.xmlBlaster.client.XmlBlasterAccess)
> > 	at
> > org.xmlBlaster.j2ee.k2.BlasterManagedConnection.doLogin(BlasterManagedConnection.java:388)
> > 	at
> > org.xmlBlaster.j2ee.k2.BlasterManagedConnection.<init>(BlasterManagedConnection.java:138)
> > 	at
> > org.xmlBlaster.j2ee.k2.BlasterManagedConnectionFactory.createManagedConnection(BlasterManagedConnectionFactory.java:101)
> > 	at
> > org.jboss.resource.connectionmanager.InternalManagedConnectionPool.createConnection(InternalManagedConnectionPool.java:359)
> > 	at
> > org.jboss.resource.connectionmanager.InternalManagedConnectionPool.getConnection(InternalManagedConnectionPool.java:150)
> > 	at
> > org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool.getConnection(JBossManagedConnectionPool.java:548)
> > 	at
> > org.jboss.resource.connectionmanager.BaseConnectionManager2.getManagedConnection(BaseConnectionManager2.java:467)
> > 	at
> > org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:532)
> > 	at
> > org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:822)
> > 	at
> > org.xmlBlaster.j2ee.k2.BlasterConnectionFactoryImpl.getConnection(BlasterConnectionFactoryImpl.java:70)
> > 	at
> > se.tim.in.kernel.channel.server.JmsAdapter.onMessage(JmsAdapter.java:190)
> > 	at sun.reflect.GeneratedMethodAccessor91.invoke(Unknown Source)
> > 	at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> > 	at java.lang.reflect.Method.invoke(Method.java:324)
> > 	at
> > org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:391)
> > 	at
> > org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
> > 	at
> > org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:88)
> > 	at
> > org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:107)
> > 	at
> > org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:237)
> > 	at
> > org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:98)
> > 	at
> > org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:100)
> > 	at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:208)
> > 	at
> > org.jboss.ejb.MessageDrivenContainer.invoke(MessageDrivenContainer.java:302)
> > 	at
> > org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:962)
> > 	at
> > org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1038)
> > 	at
> > org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:243)
> > 	at
> > org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:603)
> > 	at
> > org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:417)
> > 	- locked <0x46ebdc58> (a java.util.LinkedList)
> > 	at org.jboss.mq.SpySession.run(SpySession.java:296)
> > 	- locked <0x46ebaea8> (a java.util.LinkedList)
> > 	at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
> > 	at
> > EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:727)
> > 	at java.lang.Thread.run(Thread.java:536)
> > 
> > Any ideas about this??
> 
> Yes i know about it, i have tried to track it down or have
> a reproducable test but i didn't succeed.
> I have reported it to JacORB but they didn't know how
> to track it down, so it remained an open issue.
> See
>    http://www.jacorb.org/bugzilla/
>    Bug #:  380
> 
> AFAIK it is a mutlithreading bug in JacORB around a notify/wait
> in ReplyReceiver.java, if your case is reproducable we could debug it and find
> the offending code

Oh. Thanks. It's not reproducable in terms of that I can make it happen
every time, but I can "reproduce" it by starting the server many times
until i happens. Generally between 5 and 10 restarts is needed to get
the error to show up.

//Peter
> 
> Marcel
> 
> 
> 
> > 
> > //Peter
> 
> 
> -- 
> http://www.xmlBlaster.org
-- 
------------------------------------------------------------
Peter Antman	Chief Technology Officer, Development
Technology in Media, Box 34105 100 26 Stockholm
WWW: http://www.tim.se	WWW: http://www.backsource.org
Email: pra at tim.se	 
Phone: +46-(0)8-506 381 11 Mobile: +46-(0)704 20 58 11
------------------------------------------------------------
Follow-Ups:
- Re: [xmlblaster-devel] Lock issue with corba protocoll
  - From: Peter Antman <pra at mint.se>
References:
- [xmlblaster-devel] Lock issue with corba protocoll
  - From: Peter Antman <pra at mint.se>
- Re: [xmlblaster-devel] Lock issue with corba protocoll
  - From: Marcel Ruff <mr at marcelruff.info>
Prev by Date: Re: [xmlblaster-devel] Lock issue with corba protocoll
Next by Date: Re: [xmlblaster-devel] Lock issue with corba protocoll
Previous by thread: Re: [xmlblaster-devel] Lock issue with corba protocoll
Next by thread: Re: [xmlblaster-devel] Lock issue with corba protocoll
Index(es):
- Date
- Thread