To provide some context, what is supposed to be happening here is that when a connector starts, it registers with the transaction manager by providing a NamedXAResourceFactory that the tm can use to try to get a useable XAResource that it can use for recovery. The tm tries immediately but if it encounters any errors it just waits and tries again later. So as long as no threads are hanging and, in this case, we can eventually connect to AMQ then recovery should eventually complete. You can expect to get these exceptions in the log while remote resources are not available. You can also get them if a remote resource becomes unavailable with a transaction that is prepared but not committed.
I'm starting to wonder if these exception traces appear to be too alarming even if they don't indicate an actual problem :-) thanks david jencks On Dec 19, 2010, at 4:19 AM, Shawn Jiang wrote: > Similar exceptions in geronimo 2.2.1 when connecting to derby during a > recovery process. > > https://issues.apache.org/jira/browse/GERONIMO-5736 > > Is it possible that some context is not there when txmanager is trying to do > the recovery ? > > On Sat, Dec 18, 2010 at 8:59 PM, Ivan <[email protected]> wrote: > Seems that Geronimo 2.1.7 will try to do a recovery while a MDB is deployed, > the error occurs in the process, I hope that any one could help to shed me > some lights, > thanks. > ---> > 2010-12-15 12:59:05,156 INFO [TcpTransport] TcpTransport is created LOCAL > [0.0.0.0/0.0.0.0:-1 ] REMOTE [null:0] > java.lang.Throwable > at > org.apache.activemq.transport.tcp.TcpTransport.<init>(TcpTransport.java:95) > at > org.apache.activemq.transport.tcp.TcpTransportFactory.createTcpTransport(TcpTransportFactory.java:131) > at > org.apache.activemq.transport.tcp.TcpTransportFactory.createTransport(TcpTransportFactory.java:116) > at > org.apache.activemq.transport.TransportFactory.doConnect(TransportFactory.java:116) > at > org.apache.activemq.transport.TransportFactory.doConnect(TransportFactory.java:43) > at > org.apache.activemq.transport.TransportFactory.connect(TransportFactory.java:77) > at > org.apache.activemq.ActiveMQConnectionFactory.createTransport(ActiveMQConnectionFactory.java:230) > at > org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnection(ActiveMQConnectionFactory.java:245) > at > org.apache.activemq.ActiveMQConnectionFactory.createConnection(ActiveMQConnectionFactory.java:168) > at > org.apache.activemq.ra.ActiveMQResourceAdapter.makeConnection(ActiveMQResourceAdapter.java:108) > at > org.apache.activemq.ra.ActiveMQResourceAdapter.makeConnection(ActiveMQResourceAdapter.java:102) > at > org.apache.activemq.ra.ActiveMQManagedConnectionFactory.createManagedConnection(ActiveMQManagedConnectionFactory.java:109) > at > org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.getConnection(MCFConnectionInterceptor.java:49) > at > org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.getConnection(XAResourceInsertionInterceptor.java:41) > at > org.apache.geronimo.connector.outbound.SinglePoolConnectionInterceptor.internalGetConnection(SinglePoolConnectionInterceptor.java:69) > at > org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.getConnection(AbstractSinglePoolConnectionInterceptor.java:80) > at > org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:49) > at > org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:109) > at > org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39) > at > org.apache.geronimo.connector.outbound.OutboundNamedXAResourceFactory.getNamedXAResource(OutboundNamedXAResourceFactory.java:56) > at > org.apache.geronimo.transaction.manager.RecoverTask.run(RecoverTask.java:49) > at > org.apache.geronimo.transaction.manager.TransactionManagerImpl.registerNamedXAResourceFactory(TransactionManagerImpl.java:353) > at > org.apache.geronimo.connector.outbound.AbstractConnectionManager.doRecovery(AbstractConnectionManager.java:65) > at > org.apache.geronimo.connector.outbound.ManagedConnectionFactoryWrapper.doStart(ManagedConnectionFactoryWrapper.java:166) > at > org.apache.geronimo.gbean.runtime.GBeanInstance.createInstance(GBeanInstance.java:998) > at > org.apache.geronimo.gbean.runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java:268) > at > org.apache.geronimo.gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:102) > at > org.apache.geronimo.gbean.runtime.GBeanInstance.start(GBeanInstance.java:541) > at > org.apache.geronimo.gbean.runtime.GBeanDependency.attemptFullStart(GBeanDependency.java:111) > at > org.apache.geronimo.gbean.runtime.GBeanDependency.addTarget(GBeanDependency.java:146) > at > org.apache.geronimo.gbean.runtime.GBeanDependency$1.running(GBeanDependency.java:120) > at > org.apache.geronimo.kernel.basic.BasicLifecycleMonitor.fireRunningEvent(BasicLifecycleMonitor.java:176) > at > org.apache.geronimo.kernel.basic.BasicLifecycleMonitor.access$300(BasicLifecycleMonitor.java:44) > at > org.apache.geronimo.kernel.basic.BasicLifecycleMonitor$RawLifecycleBroadcaster.fireRunningEvent(BasicLifecycleMonitor.java:254) > at > org.apache.geronimo.gbean.runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java:294) > at > org.apache.geronimo.gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:102) > at > org.apache.geronimo.gbean.runtime.GBeanInstanceState.startRecursive(GBeanInstanceState.java:124) > at > org.apache.geronimo.gbean.runtime.GBeanInstance.startRecursive(GBeanInstance.java:555) > at > org.apache.geronimo.kernel.basic.BasicKernel.startRecursiveGBean(BasicKernel.java:379) > at > org.apache.geronimo.kernel.config.ConfigurationUtil.startConfigurationGBeans(ConfigurationUtil.java:456) > at > org.apache.geronimo.kernel.config.KernelConfigurationManager.start(KernelConfigurationManager.java:188) > at > org.apache.geronimo.kernel.config.SimpleConfigurationManager.startConfiguration(SimpleConfigurationManager.java:563) > at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:600) > at > org.apache.geronimo.gbean.runtime.ReflectionMethodInvoker.invoke(ReflectionMethodInvoker.java:34) > at > org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:124) > at > org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:832) > at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57) > at > org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35) > at > org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96) > at > org.apache.geronimo.kernel.config.EditableConfigurationManager$$EnhancerByCGLIB$$ac8e3b68.startConfiguration(<generated>) > at > org.apache.geronimo.system.main.EmbeddedDaemon.doStartup(EmbeddedDaemon.java:206) > at > org.apache.geronimo.system.main.EmbeddedDaemon.execute(EmbeddedDaemon.java:89) > at > org.apache.geronimo.kernel.util.MainConfigurationBootstrapper.main(MainConfigurationBootstrapper.java:45) > at org.apache.geronimo.cli.AbstractCLI.executeMain(AbstractCLI.java:67) > at org.apache.geronimo.cli.daemon.DaemonCLI.main(DaemonCLI.java:30) > > > 2010/12/17 Ivan <[email protected]> > Sorry for the repeated sending, just add geronimo mail list. > > > 2010/12/17 Ivan <[email protected]> > After adding some outputs, the error seems to happen after the socket of the > server side received the wireformatinfo, then on the next call of > readCommand, it fails to read bytes ... > > --> > 2010-12-17 10:42:13,046 INFO [TcpTransport] BEGIN TAG [1292553733046-99-1] > Receive command [LOCAL [/127.0.0.1:61616 ] REMOTE [/127.0.0.1:2843]] > 2010-12-17 10:42:13,046 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo > { version=2, properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true, > CacheSize=1024, StackTraceEnabled=true, MaxInactivityDuration=30000, > SizePrefixDisabled=false, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} > 2010-12-17 10:42:13,046 INFO [TcpTransport$MonitorDataOutput] BEGIN > writeInt() v = [174] > 2010-12-17 10:42:13,046 INFO [TcpTransport$MonitorDataOutput] END writeInt() > 2010-12-17 10:42:13,046 INFO [TcpTransport$MonitorDataOutput] BEGIN > write(byte[] b, int off, int len) b = [ [...@73507350] off = [0] len = [174] > 2010-12-17 10:42:13,046 INFO [TcpTransport$MonitorDataOutput] END > write(byte[] b, int off, int len) > 2010-12-17 10:42:13,046 INFO [TcpTransport] BEGIN TAG [1292553733046-98-1] > Receive command [LOCAL [/127.0.0.1:2843 ] REMOTE [localhost/127.0.0.1:61616]] > 2010-12-17 10:42:13,046 INFO [TcpBufferedInputStream] fill() n = [178] > position = [0] count = [0] thread id = [99] > 2010-12-17 10:42:13,046 INFO [TcpTransport] command [WireFormatInfo { > version=2, properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true, > CacheSize=1024, StackTraceEnabled=true, MaxInactivityDuration=30000, > SizePrefixDisabled=false, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}] is > send correctly [LOCAL [/127.0.0.1:2843 ] REMOTE [localhost/127.0.0.1:61616]] > 2010-12-17 10:42:13,046 INFO [TcpTransport] END TAG [1292553733046-99-1] > Receive command [LOCAL [/127.0.0.1:61616 ] REMOTE [/127.0.0.1:2843]] command > = [WireFormatInfo { version=2, properties={TightEncodingEnabled=true, > TcpNoDelayEnabled=true, CacheSize=1024, StackTraceEnabled=true, > MaxInactivityDuration=30000, CacheEnabled=true, SizePrefixDisabled=false}, > magic=[A,c,t,i,v,e,M,Q]}] > 2010-12-17 10:42:13,046 DEBUG [WireFormatNegotiator] Received WireFormat: > WireFormatInfo { version=2, properties={TightEncodingEnabled=true, > TcpNoDelayEnabled=true, CacheSize=1024, StackTraceEnabled=true, > MaxInactivityDuration=30000, CacheEnabled=true, SizePrefixDisabled=false}, > magic=[A,c,t,i,v,e,M,Q]} > 2010-12-17 10:42:13,046 DEBUG [WireFormatNegotiator] LOCAL > [0.0.0.0/0.0.0.0:61616 ] REMOTE [/127.0.0.1:2843] before negotiation: > OpenWireFormat{version=2, cacheEnabled=false, stackTraceEnabled=false, > tightEncodingEnabled=false, sizePrefixDisabled=false} > 2010-12-17 10:42:13,046 DEBUG [WireFormatNegotiator] LOCAL > [0.0.0.0/0.0.0.0:61616 ] REMOTE [/127.0.0.1:2843] after negotiation: > OpenWireFormat{version=2, cacheEnabled=true, stackTraceEnabled=true, > tightEncodingEnabled=true, sizePrefixDisabled=false} > 2010-12-17 10:42:13,046 INFO [TcpTransport] BEGIN TAG [1292553733046-99-2] > Receive command [LOCAL [0.0.0.0/0.0.0.0:61616 ] REMOTE [/127.0.0.1:2843]] > 2010-12-17 10:42:13,046 INFO [TcpBufferedInputStream] fill() n = [-1] > position = [0] count = [0] thread id = [99] > 2010-12-17 10:42:13,046 INFO [TcpBufferedInputStream] fill() n = [-1] > position = [0] count = [0] thread id = [99] > 2010-12-17 10:42:13,046 INFO [TcpBufferedInputStream] fill() n = [-1] > position = [0] count = [0] thread id = [99] > 2010-12-17 10:42:13,046 INFO [TcpBufferedInputStream] fill() n = [-1] > position = [0] count = [0] thread id = [99] > 2010-12-17 10:42:13,046 INFO [TcpTransport] END TAG > [1292553733046-99-2] Receive command [LOCAL [0.0.0.0/0.0.0.0:61616 ] REMOTE > [/127.0.0.1:2843]] > > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267) > at > org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:268) > at > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:244) > > at java.lang.Thread.run(Thread.java:736) > <-- > > 2010/12/17 Ivan <[email protected]> > > Hi, > I am using Geronimo 2.1.7, which shipped ActiveMQ 4.1.2, it sometimes > reported the error below after deploying a MDB. I know that ActiveMQ 4.1.2 is > a very very old version, but .... > I hope some one could help to give some hints, so that I could port some > changes from the trunk. > Thanks. > ---> > 2010-12-17 09:56:56,875 ERROR [TransportConnector] Could not accept > connection from /127.0.0.1:1823: java.io.IOException: The transport is n > ot running. > java.io.IOException: The transport is not running. > at > org.apache.activemq.transport.TransportSupport.checkStarted(TransportSupport.java:103) > at > org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:125) > at > org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:145) > at > org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:80) > at > org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:93) > at > org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:47) > at > org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1138) > at > org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:805) > at > org.apache.activemq.broker.TransportConnection.start(TransportConnection.java:885) > at > org.apache.activemq.broker.TransportConnector$1.onAccept(TransportConnector.java:148) > at > org.apache.activemq.transport.tcp.TcpTransportServer.run(TcpTransportServer.java:162) > at java.lang.Thread.run(Thread.java:736) > <--- > > Also, I could find the exception message below in the log > ---> > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267) > at > org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:269) > at > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:245) > at java.lang.Thread.run(Thread.java:736) > <--- > -- > Ivan > > > > -- > Ivan > > > > -- > Ivan > > > > -- > Ivan > > > > -- > Shawn
