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 <xhhsld@gmail.com> 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 <xhhsld@gmail.com>
Sorry for the repeated sending, just add geronimo mail list.


2010/12/17 Ivan <xhhsld@gmail.com>
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 = [ [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 <xhhsld@gmail.com>

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