Attachment 681482 Details for Bug 899766 – console-log-backup-server.txt

console-log-backup-server.txt

console-log-backup-server.txt (text/plain), 16.84 KB, created by Miroslav Novak on 2012-01-23 11:42:58 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Miroslav Novak

Created: 2012-01-23 11:42:58 UTC

Size: 16.84 KB

patch

obsolete

>[jbossqa@station4 test-eap6]$ sh start-server2.sh 192.168.10.4
>=========================================================================
>
>  JBoss Bootstrap Environment
>
>  JBOSS_HOME: /mnt/shared/test-eap6/server2/jboss-eap-6.0
>
>  JAVA: java
>
>  JAVA_OPTS: -server -Xms64m -Xmx512m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Dorg.jboss.resolver.warning=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true
>
>=========================================================================
>
>12:04:43,392 INFO  [org.jboss.modules] JBoss Modules version 1.1.0.CR6-redhat-1
>12:04:45,753 INFO  [org.jboss.msc] JBoss MSC version 1.0.1.GA-redhat-1
>12:04:45,802 INFO  [org.jboss.as] JBoss EAP 6.0.0.Alpha2 (AS 7.1.0.CR1-redhat-1) starting
>12:04:50,024 INFO  [org.xnio] XNIO Version 3.0.0.GA-redhat-1
>12:04:50,024 INFO  [org.jboss.as] Creating http management service using  socket-binding (management-http)
>12:04:50,035 INFO  [org.xnio.nio] XNIO NIO Implementation Version 3.0.0.GA-redhat-1
>12:04:50,041 INFO  [org.jboss.remoting] JBoss Remoting version 3.2.0.CR8-redhat-1
>12:04:50,098 INFO  [org.jboss.as.logging] JBAS011502: Removing bootstrap log handlers
>12:04:50,099 INFO  [org.jboss.as.jacorb] (ServerService Thread Pool -- 34) Activating JacORB Subsystem
>12:04:50,109 INFO  [org.jboss.as.clustering] (ServerService Thread Pool -- 33) JBAS010300: Activating Infinispan subsystem.
>12:04:50,125 INFO  [org.jboss.as.osgi] (ServerService Thread Pool -- 45) JBAS011910: Activating OSGi Subsystem
>12:04:50,127 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 44) JBAS011800: Activating Naming Subsystem
>12:04:50,138 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 50) Activating Security Subsystem
>12:04:50,124 INFO  [org.jboss.as.clustering] (ServerService Thread Pool -- 38) JBAS010360: Activating JGroups subsystem.
>12:04:50,162 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 54) JBAS015537: Activating WebServices Extension
>12:04:50,162 INFO  [org.jboss.as.security] (MSC service thread 1-6) Picketbox version=4.0.6.Beta2-redhat-1
>12:04:50,207 INFO  [org.jboss.as.naming] (MSC service thread 1-8) JBAS011802: Starting Naming Service
>12:04:50,213 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-2) JBAS015400: Bound mail session [java:jboss/mail/Default]
>12:04:50,216 INFO  [org.jboss.as.connector] (MSC service thread 1-8) JBAS010408: Starting JCA Subsystem (JBoss IronJacamar 1.0.7.Final-redhat-1)
>12:04:50,420 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 29) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
>12:04:50,450 INFO  [org.jboss.as.remoting] (MSC service thread 1-1) Listening on /192.168.10.4:4447
>12:04:50,495 INFO  [org.jboss.as.modcluster] (MSC service thread 1-1) JBAS011704: Mod_cluster uses default load balancer provider
>12:04:50,518 INFO  [org.jboss.modcluster.ModClusterService] (MSC service thread 1-1) Initializing mod_cluster 1.2.0.Beta3-redhat-1
>12:04:50,527 INFO  [org.jboss.modcluster.advertise.impl.AdvertiseListenerImpl] (MSC service thread 1-1) Listening to proxy advertisements on 224.0.1.105:23364
>12:04:50,531 INFO  [org.apache.coyote.http11.Http11AprProtocol] (MSC service thread 1-3) Starting Coyote HTTP/1.1 on http--192.168.10.4-8080
>12:04:50,680 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-7) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
>12:04:52,124 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (MSC service thread 1-8) backup server is starting with configuration HornetQ Configuration (clustered=true,backup=true,sharedStore=true,journalDirectory=/mnt/shared/test-eap6/server2/jboss-eap-6.0/standalone/data/../../../../journalA/journal,bindingsDirectory=/mnt/shared/test-eap6/server2/jboss-eap-6.0/standalone/data/../../../../journalA/bindings,largeMessagesDirectory=/mnt/shared/test-eap6/server2/jboss-eap-6.0/standalone/data/../../../../journalA/large-messages,pagingDirectory=/mnt/shared/test-eap6/server2/jboss-eap-6.0/standalone/data/../../../../journalA/paging)
>12:04:52,125 INFO  [org.hornetq.core.server.impl.FileLockNodeManager] (Thread-67) Waiting to become backup node
>12:04:52,126 INFO  [org.hornetq.jms.server.impl.JMSServerManagerImpl] (MSC service thread 1-3) Caching command for createQueue for testQueue since the JMS Server is not active yet
>12:04:52,126 INFO  [org.hornetq.jms.server.impl.JMSServerManagerImpl] (MSC service thread 1-3) Caching command for createTopic for testTopic since the JMS Server is not active yet
>12:04:52,995 INFO  [org.hornetq.core.server.impl.FileLockNodeManager] (Thread-67) ** got backup lock
>12:04:53,026 INFO  [org.hornetq.core.persistence.impl.journal.JournalStorageManager] (Thread-67) Using NIO Journal
>12:04:53,053 WARNING [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-67) Security risk! It has been detected that the cluster admin user and password have not been changed from the installation default. Please see the HornetQ user guide, cluster chapter, for instructions on how to do this.
>12:04:53,539 DEBUG [org.hornetq.utils.UUIDGenerator] (Thread-67) using hardware address 64:31:50:18:ffffff80:-107
>12:04:53,547 INFO  [org.hornetq.core.server.cluster.impl.ClusterManagerImpl] (Thread-67) announcing backup
>12:04:53,550 DEBUG [org.hornetq.core.client.impl.Topology] (Thread-67) adding = 17700d86-45b2-11e1-a575-d48564b8e1e7:Pair[a=null, b=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=192-168-10-4]
>12:04:53,550 DEBUG [org.hornetq.core.client.impl.Topology] (Thread-67) before----------------------------------
>12:04:53,551 DEBUG [org.hornetq.core.client.impl.Topology] (Thread-67) 	nodes=0	members=0
>12:04:53,551 DEBUG [org.hornetq.core.client.impl.Topology] (Thread-67) Topology updated=true
>12:04:53,551 DEBUG [org.hornetq.core.client.impl.Topology] (Thread-67) 	17700d86-45b2-11e1-a575-d48564b8e1e7 => TopologyMember[connector=Pair[a=null, b=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=192-168-10-4]]
>	nodes=1	members=1
>12:04:53,551 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-67) HornetQ Backup Server version 2.2.7.Final (HQ_2_2_7_FINAL_AS7, 121) [17700d86-45b2-11e1-a575-d48564b8e1e7] started, waiting live to fail before it gets active
>12:04:55,023 INFO  [org.jboss.as.jacorb] (MSC service thread 1-5) CORBA ORB Service Started
>12:04:55,076 INFO  [org.jboss.as.jacorb] (MSC service thread 1-6) CORBA Naming Service Started
>12:04:55,123 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) Trying reconnection attempt 0
>12:04:55,147 DEBUG [org.hornetq.core.remoting.impl.netty.NettyConnector] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) Started Netty Connector version 3.2.3.Final-r${buildNumber}
>12:04:55,147 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) Trying to connect at the main server using connector :org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1
>12:04:55,176 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) ClientSessionFactoryImpl received backup update for live/backup pair = org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1 / null but it didn't belong to org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1
>12:04:55,177 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) ClientSessionFactoryImpl received backup update for live/backup pair = org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1 / null but it didn't belong to org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1
>12:04:55,178 INFO  [org.hornetq.core.server.cluster.impl.ClusterManagerImpl] (Thread-0 (group:HornetQ-server-threads852585928-149593329)) backup announced
>12:04:57,242 INFO  [org.jboss.ws.common.management.AbstractServerConfig] (MSC service thread 1-2) JBoss Web Services - Stack CXF Server 4.0.0.GA-redhat-1
>12:04:57,718 INFO  [org.jboss.as.remoting] (MSC service thread 1-1) Listening on /127.0.0.1:9999
>12:04:57,728 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-7) JBAS015012: Started FileSystemDeploymentService for directory /mnt/shared/test-eap6/server2/jboss-eap-6.0/standalone/deployments
>12:04:58,074 INFO  [org.jboss.as] (Controller Boot Thread) JBoss EAP 6.0.0.Alpha2 (AS 7.1.0.CR1-redhat-1) started in 15008ms - Started 146 of 254 services (103 services are passive or on-demand)
>12:05:16,492 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-1 (group:HornetQ-client-global-threads-149412448)) Trying reconnection attempt 0
>12:05:16,493 DEBUG [org.hornetq.core.remoting.impl.netty.NettyConnector] (Thread-1 (group:HornetQ-client-global-threads-149412448)) Started Netty Connector version 3.2.3.Final-r${buildNumber}
>12:05:16,494 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-1 (group:HornetQ-client-global-threads-149412448)) Trying to connect at the main server using connector :org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1
>12:05:16,496 DEBUG [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-1 (group:HornetQ-client-global-threads-149412448)) Main server is not up. Hopefully there's a backup configured now!
>12:05:16,579 DEBUG [org.hornetq.core.server.impl.FileLockNodeManager] (Thread-67) acquired live node lock state = L
>12:05:16,712 DEBUG [org.hornetq.core.paging.cursor.impl.PageCursorProviderImpl] (Thread-67) jms.queue.testQueue creating subscription 3 with filter null: java.lang.Exception: trace
>	at org.hornetq.core.paging.cursor.impl.PageCursorProviderImpl.createSubscription(PageCursorProviderImpl.java:94) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.loadJournals(HornetQServerImpl.java:1589) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.initialisePart2(HornetQServerImpl.java:1471) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.access$100(HornetQServerImpl.java:134) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl$SharedStoreBackupActivation.run(HornetQServerImpl.java:402) [hornetq-core-2.2.7.Final.jar:]
>	at java.lang.Thread.run(Thread.java:679) [:1.6.0_22]
>12:05:16,729 DEBUG [org.hornetq.core.server.management.impl.ManagementServiceImpl] (Thread-67) registered address org.hornetq.backupA:module=Core,type=Address,name="jms.queue.testQueue"
>12:05:16,735 DEBUG [org.hornetq.core.server.management.impl.ManagementServiceImpl] (Thread-67) registered queue org.hornetq.backupA:module=Core,type=Queue,address="jms.queue.testQueue",name="jms.queue.testQueue"
>12:05:16,742 WARN  [org.hornetq.core.journal.impl.JournalFilesRepository] (Thread-67) Deleting JournalFileImpl: (hornetq-data-1.hq id = 1, recordID = 1).. as it doesn't have the configured size
>12:05:16,777 WARN  [org.hornetq.core.journal.impl.JournalFilesRepository] (Thread-67) Deleting JournalFileImpl: (hornetq-data-2.hq id = 2, recordID = 2).. as it doesn't have the configured size
>12:05:18,025 INFO  [org.hornetq.jms.server.impl.JMSServerManagerImpl] (Thread-67) Running cached command for createQueue for testQueue
>12:05:18,026 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-67) trying to deploy queue jms.queue.testQueue
>12:05:18,035 INFO  [org.jboss.as.messaging] (Thread-67) JBAS011601: Bound messaging object to jndi name java:/queue/test
>12:05:18,036 INFO  [org.hornetq.jms.server.impl.JMSServerManagerImpl] (Thread-67) Running cached command for createTopic for testTopic
>12:05:18,036 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-67) trying to deploy queue jms.topic.testTopic
>12:05:18,091 DEBUG [org.hornetq.core.server.management.impl.ManagementServiceImpl] (Thread-67) registered address org.hornetq.backupA:module=Core,type=Address,name="jms.topic.testTopic"
>12:05:18,091 DEBUG [org.hornetq.core.server.management.impl.ManagementServiceImpl] (Thread-67) registered queue org.hornetq.backupA:module=Core,type=Queue,address="jms.topic.testTopic",name="jms.topic.testTopic"
>12:05:18,097 INFO  [org.jboss.as.messaging] (Thread-67) JBAS011601: Bound messaging object to jndi name java:/topic/test
>12:05:18,107 INFO  [org.hornetq.core.remoting.impl.netty.NettyAcceptor] (Thread-67) Started Netty Acceptor version 3.2.3.Final-r${buildNumber} 192.168.10.4:5446 for CORE protocol
>12:05:18,109 WARN  [org.hornetq.core.client.impl.ClientSessionFactoryImpl] (Thread-1 (group:HornetQ-client-global-threads-149412448)) Failed to connect to server.
>12:05:18,110 WARN  [org.hornetq.core.server.cluster.impl.BroadcastGroupImpl] (Thread-67) local-bind-address specified for broadcast group but no local-bind-port specified so socket will NOT be bound to a local address/port
>12:05:18,115 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-67) Backup Server is now live
>
>
>
>12:06:59,636 DEBUG [org.hornetq.core.client.impl.Topology] (Old I/O server worker (parentId: 124976074, [id: 0x0772fbca, /192.168.10.4:5446])) adding = 17700d86-45b2-11e1-a575-d48564b8e1e7:Pair[a=null, b=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1]
>12:06:59,636 DEBUG [org.hornetq.core.client.impl.Topology] (Old I/O server worker (parentId: 124976074, [id: 0x0772fbca, /192.168.10.4:5446])) before----------------------------------
>12:06:59,637 DEBUG [org.hornetq.core.client.impl.Topology] (Old I/O server worker (parentId: 124976074, [id: 0x0772fbca, /192.168.10.4:5446])) 	17700d86-45b2-11e1-a575-d48564b8e1e7 => TopologyMember[connector=Pair[a=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=192-168-10-4, b=null]]
>	nodes=1	members=1
>12:06:59,637 DEBUG [org.hornetq.core.client.impl.Topology] (Old I/O server worker (parentId: 124976074, [id: 0x0772fbca, /192.168.10.4:5446])) Topology updated=true
>12:06:59,637 DEBUG [org.hornetq.core.client.impl.Topology] (Old I/O server worker (parentId: 124976074, [id: 0x0772fbca, /192.168.10.4:5446])) 	17700d86-45b2-11e1-a575-d48564b8e1e7 => TopologyMember[connector=Pair[a=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5446&host=192-168-10-4, b=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory?port=5445&host=192-168-10-1]]
>	nodes=2	members=1
>12:07:26,117 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-1 (group:HornetQ-scheduled-threads-1196733812)) live server wants to restart, restarting server in backup
>12:07:26,120 DEBUG [org.hornetq.core.server.cluster.impl.ClusterConnectionImpl] (Thread-78) Cluster connection being stopped for node17700d86-45b2-11e1-a575-d48564b8e1e7
>12:07:26,160 FINE  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) Waiting for java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@50a0fdd1
>12:07:26,161 FINE  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) Waiting for java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@7977cdb1
>12:07:26,161 FINE  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) Waiting for java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@28615dc4
>12:07:26,161 FINE  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) Waiting for java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@10530392
>12:07:26,162 FINE  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) Waiting for java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3a0f6e9d
>12:07:26,165 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) HornetQ Server version 2.2.7.Final (HQ_2_2_7_FINAL_AS7, 121) [17700d86-45b2-11e1-a575-d48564b8e1e7] stopped
>12:07:26,165 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] (Thread-78) unable to restart server, please kill and restart manually: java.lang.IllegalArgumentException: Could not find class org.jboss.as.messaging.HornetQLoggerFactory
>	at org.hornetq.utils.ClassloadingUtil$1.run(ClassloadingUtil.java:42) [hornetq-core-2.2.7.Final.jar:]
>	at java.security.AccessController.doPrivileged(Native Method) [:1.6.0_22]
>	at org.hornetq.utils.ClassloadingUtil.safeInitNewInstance(ClassloadingUtil.java:16) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.instantiateInstance(HornetQServerImpl.java:1868) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.initialiseLogging(HornetQServerImpl.java:1301) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl.start(HornetQServerImpl.java:541) [hornetq-core-2.2.7.Final.jar:]
>	at org.hornetq.core.server.impl.HornetQServerImpl$SharedStoreBackupActivation$1FailbackChecker$1.run(HornetQServerImpl.java:430) [hornetq-core-2.2.7.Final.jar:]
>	at java.lang.Thread.run(Thread.java:679) [:1.6.0_22]
>

Actions: View

Attachments on bug 899766: 681482 | 681483 | 681484