0 Replies Latest reply on Mar 12, 2012 10:07 AM by richard.spurr

    Bridge connection failures. (noticed on Windows XP, but not on Mac OSX)

    richard.spurr

      We 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.