Bridge connection failures. (noticed on Windows XP, but not on Mac OSX)
richard.spurr Mar 12, 2012 10:07 AMWe have a number of cluster nodes running JBOSS_ AS 7.1.0.Final, and we are getting bridge connection failures in the logs. This happens after anything frm a couple of minutes to 25 mins, then repeats ad infinitum. I have noticed this on Windows XP, but not on Mac OSX .
Has anyone else encountered anything similar ?
I have reproduced the issue with a small standalone.xml configuration in each of 2 Jboss installations. Here is the console output from one instance:
C:\dev-svn\as1\bin>standalone.bat --server-config=as1.xml
Calling "C:\dev-svn\as1\bin\standalone.conf.bat"
===============================================================================
JBoss Bootstrap Environment
JBOSS_HOME: C:\dev-svn\as1
JAVA: C:\Program Files\Java\jdk1.7.0_02\bin\java
JAVA_OPTS: -XX:+TieredCompilation -Dprogram.name=standalone.bat -Xms64M -Xmx512M -XX:MaxPermSize=256M -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.se
rver.gcInterval=3600000 -Djava.net.preferIPv4Stack=true -Dorg.jboss.resolver.warning=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djboss.server.default.c
onfig=standalone.xml
===============================================================================
11:06:30,499 INFO [org.jboss.modules] JBoss Modules version 1.1.1.GA
11:06:30,842 INFO [org.jboss.msc] JBoss MSC version 1.0.2.GA
11:06:30,889 INFO [org.jboss.as] JBAS015899: JBoss AS 7.1.0.Final "Thunder" starting
11:06:31,811 INFO [org.jboss.as.naming] JBAS011800: Activating Naming Subsystem
11:06:31,827 INFO [org.jboss.as.security] JBAS013101: Activating Security Subsystem
11:06:31,858 INFO [org.jboss.as.security] JBAS013100: Current PicketBox version=4.0.6.final
11:06:31,858 INFO [org.jboss.as.clustering.jgroups] JBAS010260: Activating JGroups subsystem.
11:06:31,874 INFO [org.jboss.as.naming] JBAS011802: Starting Naming Service
11:06:31,952 INFO [org.xnio] XNIO Version 3.0.3.GA
11:06:31,952 INFO [org.xnio.nio] XNIO NIO Implementation Version 3.0.3.GA
11:06:31,967 INFO [org.jboss.remoting] JBoss Remoting version 3.2.2.GA
11:06:32,045 INFO [org.apache.coyote.http11.Http11Protocol] Starting Coyote HTTP/1.1 on http--127.0.0.1-8081
11:06:32,092 WARN [org.jboss.as.messaging] JBAS011600: AIO wasn't located on this platform, it will fall back to using pure Java NIO. If your platform is Linux
, install LibAIO to enable the AIO journal
11:06:32,186 INFO [org.hornetq.core.server.impl.HornetQServerImpl] live server is starting with configuration HornetQ Configuration (clustered=true,backup=fals
e,sharedStore=true,journalDirectory=C:\dev-svn\as1\standalone\data\messagingjournal,bindingsDirectory=C:\dev-svn\as1\standalone\data\messagingbindings,largeMess
agesDirectory=C:\dev-svn\as1\standalone\data\messaginglargemessages,pagingDirectory=C:\dev-svn\as1\standalone\data\messagingpaging)
11:06:32,186 INFO [org.hornetq.core.server.impl.HornetQServerImpl] Waiting to obtain live lock
11:06:32,202 INFO [org.hornetq.core.persistence.impl.journal.JournalStorageManager] Using NIO Journal
11:06:32,374 INFO [org.jboss.as.server.deployment.scanner] JBAS015012: Started FileSystemDeploymentService for directory C:\dev-svn\as1\standalone\deployments
11:06:32,389 INFO [org.hornetq.core.server.impl.FileLockNodeManager] Waiting to obtain live lock
11:06:32,389 INFO [org.hornetq.core.server.impl.FileLockNodeManager] Live Server Obtained live lock
11:06:32,717 WARN [org.hornetq.core.server.cluster.impl.BroadcastGroupImpl] local-bind-address specified for broadcast group but no local-bind-port specified s
o socket will NOT be bound to a local address/port
11:06:32,764 INFO [org.hornetq.core.remoting.impl.netty.NettyAcceptor] Started Netty Acceptor version 3.2.5.Final-a96d88c localhost:5446 for CORE protocol
11:06:32,780 INFO [org.hornetq.core.server.impl.HornetQServerImpl] Server is now live
11:06:32,780 INFO [org.hornetq.core.server.impl.HornetQServerImpl] HornetQ Server version 2.2.11.Final (HQ_2_2_11_FINAL_AS7, 122) [116cef7e-6c2f-11e1-9536-18a9
05f7416d]) started
11:06:32,780 INFO [org.hornetq.core.server.impl.HornetQServerImpl] trying to deploy queue jms.queue.warlocScheduledJobsQueue
11:06:32,780 INFO [org.jboss.as.messaging] JBAS011601: Bound messaging object to jndi name java:/queue/test
11:06:32,780 INFO [org.jboss.as.messaging] JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/queue/test
11:06:32,795 INFO [org.jboss.as.messaging] JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory
11:06:32,811 INFO [org.jboss.as] JBAS015874: JBoss AS 7.1.0.Final "Thunder" started in 3406ms - Started 50 of 62 services (12 services are passive or on-demand
)
11:06:45,122 INFO [org.hornetq.core.server.cluster.impl.BridgeImpl] Bridge ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f74
16d, queue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1
-9536-18a905f7416d]]@178136a targetConnector=ServerLocatorImpl (identity=(Cluster-connection-bridge::ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68
-6c2f-11e1-b514-18a905f7416d, queue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serv
erUUID=116cef7e-6c2f-11e1-9536-18a905f7416d]]@178136a targetConnector=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorF
actory?port=5447&host=localhost], discoveryGroupConfiguration=null]]::ClusterConnectionImpl@7419572[nodeUUID=116cef7e-6c2f-11e1-9536-18a905f7416d, connector=org
-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=localhost, address=jms, server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1-9536-18a9
05f7416d])) [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5447&host=localhost], discoveryGroupConfiguration=null]] is conn
ected
11:08:45,189 WARN [org.hornetq.core.protocol.core.impl.RemotingConnectionImpl] Connection failure has been detected: Did not receive data from /127.0.0.1:3965.
It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have conf
igured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=3]
11:08:45,189 WARN [org.hornetq.core.protocol.core.impl.RemotingConnectionImpl] Connection failure has been detected: Did not receive data from /127.0.0.1:3964.
It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have conf
igured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=3]
11:08:45,189 WARN [org.hornetq.core.server.impl.ServerSessionImpl] Client connection failed, clearing up resources for session 7444e6c2-6c33-11e1-ab01-18a905f7
416d
11:08:45,205 WARN [org.hornetq.core.server.impl.ServerSessionImpl] Cleared up resources for session 7444e6c2-6c33-11e1-ab01-18a905f7416d
11:08:55,219 WARN [org.hornetq.core.server.cluster.impl.Redistributor] Timed out waiting for tasks to complete
11:08:55,625 WARN [org.hornetq.core.server.cluster.impl.BridgeImpl] ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, qu
eue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1-9536-1
8a905f7416d]]@178136a targetConnector=ServerLocatorImpl (identity=(Cluster-connection-bridge::ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68-6c2f-1
1e1-b514-18a905f7416d, queue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=
116cef7e-6c2f-11e1-9536-18a905f7416d]]@178136a targetConnector=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?
port=5447&host=localhost], discoveryGroupConfiguration=null]]::ClusterConnectionImpl@7419572[nodeUUID=116cef7e-6c2f-11e1-9536-18a905f7416d, connector=org-hornet
q-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=localhost, address=jms, server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1-9536-18a905f7416
d])) [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5447&host=localhost], discoveryGroupConfiguration=null]]::Connection fa
iled with failedOver=false-HornetQException[errorCode=2 message=Channel disconnected]: HornetQException[errorCode=2 message=Channel disconnected]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl.connectionDestroyed(ClientSessionFactoryImpl.java:380) [hornetq-core-2.2.11.Final.jar:]
at org.hornetq.core.remoting.impl.netty.NettyConnector$Listener$1.run(NettyConnector.java:711) [hornetq-core-2.2.11.Final.jar:]
at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [hornetq-core-2.2.11.Final.jar:]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_02]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_02]
at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_02]
11:08:58,672 INFO [org.hornetq.core.server.cluster.impl.BridgeImpl] Bridge ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f74
16d, queue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1
-9536-18a905f7416d]]@178136a targetConnector=ServerLocatorImpl (identity=(Cluster-connection-bridge::ClusterConnectionBridge@2e5b7b [name=sf.RS-cluster.91aa5f68
-6c2f-11e1-b514-18a905f7416d, queue=QueueImpl[name=sf.RS-cluster.91aa5f68-6c2f-11e1-b514-18a905f7416d, postOffice=PostOfficeImpl [server=HornetQServerImpl::serv
erUUID=116cef7e-6c2f-11e1-9536-18a905f7416d]]@178136a targetConnector=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorF
actory?port=5447&host=localhost], discoveryGroupConfiguration=null]]::ClusterConnectionImpl@7419572[nodeUUID=116cef7e-6c2f-11e1-9536-18a905f7416d, connector=org
-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=localhost, address=jms, server=HornetQServerImpl::serverUUID=116cef7e-6c2f-11e1-9536-18a9
05f7416d])) [initialConnectors=[org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5447&host=localhost], discoveryGroupConfiguration=null]] is conn
ected
The standalone configuration files from each of the JBoss installations are attached. They only differ in the port-offset value on line 138.