Attachment 907101 Details for Bug 1107579 – server log

server log

server.log (text/x-log), 28.25 KB, created by Filip Brychta on 2014-06-10 09:18:07 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Filip Brychta

Created: 2014-06-10 09:18:07 UTC

Size: 28.25 KB

patch

obsolete

>04:46:11,476 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] (http-/0.0.0.0:7080-63) Agent [fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com][4.9.0.JON320GA(0620403)] would like to connect to this server
>04:46:11,594 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] (http-/0.0.0.0:7080-63) Agent [fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com] has connected to this server at Tue Jun 10 04:46:11 EDT 2014
>04:46:46,012 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-61) Linking Resource[id=10224, uuid=dd5a39fb-13c4-49b7-8127-5b1c433763d3, type={RHQStorage}RHQ Storage Node, key=RHQ Storage Node(fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com), name=RHQ Storage Node(fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com), parent=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, version=4.9.0.JON320GA] to storage node at fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com
>04:46:46,023 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-61) Did not find storage node with address [fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com] Searching by IP address [10.16.23.63]
>04:46:46,037 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-61) Scheduling cluster maintenance to deploy StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=INSTALLED, mtime=1402390006035] into the storage cluster...
>04:46:46,037 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-61) Deploying StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=INSTALLED, mtime=1402390006035]
>04:46:46,049 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (http-/0.0.0.0:7080-61) Announcing StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ANNOUNCE, mtime=1402390006035] to storage node cluster.
>04:46:46,052 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (http-/0.0.0.0:7080-61) Announcing StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ANNOUNCE, mtime=1402390006035] to cluster node StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>04:46:47,602 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Announcing StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ANNOUNCE, mtime=1402390006035] to cluster node StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389391081]
>04:46:49,060 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 5) Announcing StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ANNOUNCE, mtime=1402390006035] to cluster node StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389702627]
>04:46:49,954 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] (EJB default - 2) fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com took [43]ms to reload global cache
>04:46:50,032 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] (EJB default - 2) fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com took [55]ms to reload cache for 1 agents
>04:46:50,754 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 1) Successfully announced new storage node to storage cluster
>04:46:50,884 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 1) Preparing to bootstrap StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=BOOTSTRAP, mtime=1402390006035] into cluster...
>04:46:59,746 INFO  [com.datastax.driver.core.Cluster] (Scheduled Tasks-0) New Cassandra host /10.16.23.63 added
>04:46:59,797 INFO  [org.rhq.server.metrics.StorageSession] (Scheduled Tasks-0) /10.16.23.63 added
>04:46:59,797 INFO  [org.rhq.enterprise.server.storage.StorageClusterMonitor] (Scheduled Tasks-0) Storage node at 10.16.23.63 is up
>04:46:59,799 INFO  [org.rhq.server.metrics.StorageSession] (Cassandra Java Driver worker-5) /10.16.23.63 is down
>04:46:59,799 INFO  [org.rhq.enterprise.server.storage.StorageClusterMonitor] (Cassandra Java Driver worker-5) Storage node at 10.16.23.63 is down
>04:47:19,949 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] (EJB default - 5) fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com took [49]ms to reload global cache
>04:47:20,038 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] (EJB default - 5) fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com took [63]ms to reload cache for 1 agents
>04:47:21,876 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) The prepare for bootstrap operation completed successfully for StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=BOOTSTRAP, mtime=1402390006035]
>04:47:25,208 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Running addNodeMaintenance for storage node StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ADD_MAINTENANCE, mtime=1402390006035]
>04:47:26,444 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Finished running add node maintenance for StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=ADD_MAINTENANCE, mtime=1402390006035]
>04:47:26,451 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Running addNodeMaintenance for storage node StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>04:48:02,879 ERROR [com.datastax.driver.core.AbstractReconnectionHandler] (Reconnection-1) Authentication error on host /10.16.23.63: Username and/or password are incorrect
>04:48:02,881 ERROR [com.datastax.driver.core.AbstractReconnectionHandler] (Reconnection-1) Retry against /10.16.23.63 have been suspended. It won't be retried unless the node is restarted.
>04:50:44,579 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Finished running add node maintenance for StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>04:50:44,589 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Running addNodeMaintenance for storage node StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389391081]
>04:55:01,597 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 9) Finished running add node maintenance for StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389391081]
>04:55:01,604 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 9) Running addNodeMaintenance for storage node StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389702627]
>04:59:02,041 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) Finished running add node maintenance for StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389702627]
>04:59:02,047 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) Finished running add node maintenance on all cluster nodes
>04:59:33,350 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (http-/0.0.0.0:7080-9) Preparing to decommission StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389702627]
>04:59:36,662 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (http-/0.0.0.0:7080-9) Preparing to decommission StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402390006035]
>04:59:40,128 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (http-/0.0.0.0:7080-9) Preparing to decommission StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402389391081]
>04:59:52,395 ERROR [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Undeployment has been aborted due to failed operation [Decommission] on Resource[id=10090, uuid=377893fe-fa64-41c0-a53b-61272f72445f, type={RHQStorage}RHQ Storage Node, key=RHQ Storage Node(fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com), name=RHQ Storage Node(fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com), parent=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, version=4.9.0.JON320GA]: java.lang.Exception: Decommission operation failed: org.mc4j.ems.connection.EmsInvocationException:Exception on invocation of [decommission]javax.management.RuntimeMBeanException: java.lang.UnsupportedOperationException: data is currently moving to this node; unable to leave the ring -> javax.management.RuntimeMBeanException:java.lang.UnsupportedOperationException: data is currently moving to this node; unable to leave the ring -> java.lang.UnsupportedOperationException:data is currently moving to this node; unable to leave the ring
>	at org.rhq.core.pc.operation.OperationInvocation.run(OperationInvocation.java:278)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>	at java.lang.Thread.run(Thread.java:744)
>
>05:00:00,035 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Data Purge Job STARTING
>05:00:00,051 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Measurement data compression starting at Tue Jun 10 05:00:00 EDT 2014
>05:00:15,495 INFO  [com.datastax.driver.core.Cluster] (Scheduled Tasks-0) Cassandra host /10.16.23.185 removed
>05:00:15,519 INFO  [org.rhq.server.metrics.StorageSession] (Scheduled Tasks-0) /10.16.23.185 has been removed
>05:00:15,519 INFO  [org.rhq.enterprise.server.storage.StorageClusterMonitor] (Scheduled Tasks-0) Storage node at 10.16.23.185 has been removed from the cluster
>05:00:17,399 INFO  [org.rhq.server.metrics.MetricsServer] (RHQScheduler_Worker-4) Finished computing aggregates for table [raw_metrics]17346 ms
>05:00:20,175 INFO  [org.rhq.server.metrics.MetricsServer] (RHQScheduler_Worker-4) Finished computing aggregates for table [one_hour_metrics] 0 ms
>05:00:20,175 INFO  [org.rhq.server.metrics.MetricsServer] (RHQScheduler_Worker-4) Finished computing aggregates for table [six_hour_metrics] 0 ms
>05:00:20,176 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Measurement data compression completed in [20125]ms
>05:00:20,176 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Measurement calltime data purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,214 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging calltime data that is older than Sat May 10 05:00:20 EDT 2014
>05:00:20,247 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Calltime purged [0] - completed in [71]ms
>05:00:20,248 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Event data purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,248 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging event data older than Tue May 27 05:00:20 EDT 2014
>05:00:20,297 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Event data purged [0] - completed in [49]ms
>05:00:20,298 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert data purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,298 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging alert data older than Sat May 10 05:00:20 EDT 2014
>05:00:20,349 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert data purged [0] - completed in [52]ms
>05:00:20,350 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert definition unused purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,369 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert definitions purged [0] - completed in [19]ms
>05:00:20,370 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert condition orphan purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,379 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purged [0] orphan alert conditions - completed in [9]ms
>05:00:20,380 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Alert notification orphan purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,386 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purged [0] orphan alert notifications - completed in [6]ms
>05:00:20,387 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Trait data purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,387 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging traits that are older than Mon Jun 10 05:00:20 EDT 2013
>05:00:20,430 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Traits data purged [0] - completed in [43]ms
>05:00:20,431 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Availability data purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,431 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging availablities that are older than Mon Jun 10 05:00:20 EDT 2013
>05:00:20,493 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Availability data purged [0] - completed in [63]ms
>05:00:20,494 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Drift file orphan purge starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,494 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purging orphaned drift files older than Sat May 10 05:00:20 EDT 2014
>05:00:20,542 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Purged [0] orphaned drift files - completed in [48]ms
>05:00:20,543 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Database maintenance starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,570 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Performing hourly database maintenance
>05:00:20,577 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Database maintenance completed in [34]ms
>05:00:20,578 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Auto-calculation of baselines starting at Tue Jun 10 05:00:20 EDT 2014
>05:00:20,588 INFO  [org.rhq.enterprise.server.measurement.MeasurementBaselineManagerBean] (RHQScheduler_Worker-4) Calculating auto baselines
>05:00:20,589 INFO  [org.rhq.enterprise.server.measurement.MeasurementBaselineManagerBean] (RHQScheduler_Worker-4) Deleting baselines computations older than Sat Jun 07 05:00:20 EDT 2014
>05:00:20,589 INFO  [org.rhq.enterprise.server.measurement.MeasurementBaselineManagerBean] (RHQScheduler_Worker-4) Inserting new baselines using last 7 days of 1H data
>05:00:20,595 INFO  [org.rhq.enterprise.server.measurement.MeasurementBaselineManagerBean] (RHQScheduler_Worker-4) Removed [0] old baselines - they will now be recalculated (6)ms
>05:00:21,157 INFO  [com.datastax.driver.core.Cluster] (Scheduled Tasks-0) Cassandra host /10.16.23.63 removed
>05:00:21,171 INFO  [org.rhq.server.metrics.StorageSession] (Scheduled Tasks-0) /10.16.23.63 has been removed
>05:00:21,171 INFO  [org.rhq.enterprise.server.storage.StorageClusterMonitor] (Scheduled Tasks-0) Storage node at 10.16.23.63 has been removed from the cluster
>05:00:43,033 INFO  [org.rhq.enterprise.server.measurement.MeasurementBaselineManagerBean] (RHQScheduler_Worker-4) Calculated and inserted [2123] new baselines. (22438)ms
>05:00:43,070 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Auto-calculation of baselines completed in [22492]ms
>05:00:43,070 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Auto-calculation of OOBs starting
>05:00:43,084 INFO  [org.rhq.enterprise.server.measurement.MeasurementOOBManagerBean] (RHQScheduler_Worker-4) Removed [0] outdated OOBs
>05:00:43,094 INFO  [org.rhq.enterprise.server.measurement.MeasurementOOBManagerBean] (RHQScheduler_Worker-4) Computing OOBs
>05:00:45,575 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Successfully decommissioned StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=DECOMMISSION, mtime=1402389702627]
>05:00:45,716 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Running remove node maintenance for storage node StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:00:48,797 INFO  [org.rhq.enterprise.server.measurement.MeasurementOOBManagerBean] (RHQScheduler_Worker-4) Finished calculating 30 OOBs in 5703 ms
>05:00:48,798 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Auto-calculation of OOBs completed in [5728]ms
>05:00:48,799 INFO  [org.rhq.enterprise.server.scheduler.jobs.DataPurgeJob] (RHQScheduler_Worker-4) Data Purge Job FINISHED [48764]ms
>05:00:50,201 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] (EJB default - 2) fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com took [281]ms to reload cache for 4 agents
>05:00:50,248 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Finished remove node maintenance for StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:00:50,254 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Finished running remove node maintenance on all cluster nodes
>05:00:50,353 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Unannouncing StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402389702627]
>05:00:50,523 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 4) Successfully decommissioned StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=DECOMMISSION, mtime=1402390006035]
>05:00:50,663 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 4) Running remove node maintenance for storage node StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:00:53,044 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Successfully unannounced StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402389702627] to storage cluster
>05:00:53,127 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Uninstalling StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389702627]
>05:00:55,884 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Successfully uninstalled StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389702627] from disk
>05:00:55,910 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Removing storage node resource Resource[id=10200, uuid=d244a215-38ed-465d-a027-ac0939a10725, type={RHQStorage}RHQ Storage Node, key=RHQ Storage Node(fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com), name=RHQ Storage Node(fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com), parent=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, version=4.9.0.JON320GA] from inventory
>05:00:56,066 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) Removing storage node entity StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389702627] from database
>05:00:56,067 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 2) StorageNode[id=10002, address=fbr-jon32-dr1-2.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389702627] has been undeployed
>05:00:56,207 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 5) Finished remove node maintenance for StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:00:56,212 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 5) Finished running remove node maintenance on all cluster nodes
>05:00:56,351 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 5) Unannouncing StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402390006035]
>05:00:57,354 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 8) Successfully unannounced StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402390006035] to storage cluster
>05:00:57,437 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 8) Uninstalling StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402390006035]
>05:01:00,132 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) Successfully uninstalled StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402390006035] from disk
>05:01:00,165 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) Removing storage node resource Resource[id=10224, uuid=dd5a39fb-13c4-49b7-8127-5b1c433763d3, type={RHQStorage}RHQ Storage Node, key=RHQ Storage Node(fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com), name=RHQ Storage Node(fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com), parent=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, version=4.9.0.JON320GA] from inventory
>05:01:00,291 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) Removing storage node entity StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402390006035] from database
>05:01:00,291 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 6) StorageNode[id=10003, address=fbr-jon32-dr1-3.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402390006035] has been undeployed
>05:01:15,511 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-40) Retrieved unacked alerts for StorageNode[id=10001, address=null, cqlPort=0, operationMode=null, mtime=0] in 765
>05:01:15,948 INFO  [org.rhq.enterprise.server.cloud.StorageNodeManagerBean] (http-/0.0.0.0:7080-9) Retrieved load metrics for StorageNode[id=10001, address=null, cqlPort=0, operationMode=null, mtime=0] in 228 ms
>05:01:36,812 INFO  [org.rhq.enterprise.server.scheduler.jobs.AsyncResourceDeleteJob] (RHQScheduler_Worker-1) Async resource deletion - 32 successful, 0 failed, took [16731] ms
>05:02:19,372 INFO  [com.datastax.driver.core.Cluster] (Scheduled Tasks-0) Cassandra host /10.16.23.156 removed
>05:02:19,386 INFO  [org.rhq.server.metrics.StorageSession] (Scheduled Tasks-0) /10.16.23.156 has been removed
>05:02:19,386 INFO  [org.rhq.enterprise.server.storage.StorageClusterMonitor] (Scheduled Tasks-0) Storage node at 10.16.23.156 has been removed from the cluster
>05:02:49,574 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 1) Successfully decommissioned StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=DECOMMISSION, mtime=1402389391081]
>05:02:49,718 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 1) Running remove node maintenance for storage node StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:02:54,470 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Finished remove node maintenance for StorageNode[id=1001, address=fbr-jon32-cp2-ora.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=NORMAL, mtime=1402388451947]
>05:02:54,476 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Finished running remove node maintenance on all cluster nodes
>05:02:54,608 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 10) Unannouncing StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402389391081]
>05:02:56,307 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 8) Successfully unannounced StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNANNOUNCE, mtime=1402389391081] to storage cluster
>05:02:56,397 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 8) Uninstalling StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389391081]
>05:02:57,269 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Successfully uninstalled StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389391081] from disk
>05:02:57,297 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Removing storage node resource Resource[id=10090, uuid=377893fe-fa64-41c0-a53b-61272f72445f, type={RHQStorage}RHQ Storage Node, key=RHQ Storage Node(fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com), name=RHQ Storage Node(fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com), parent=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, version=4.9.0.JON320GA] from inventory
>05:02:57,465 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) Removing storage node entity StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389391081] from database
>05:02:57,465 INFO  [org.rhq.enterprise.server.storage.StorageNodeOperationsHandlerBean] (EJB default - 7) StorageNode[id=10001, address=fbr-jon32-dr1.bc.jonqe.lab.eng.bos.redhat.com, cqlPort=9142, operationMode=UNINSTALL, mtime=1402389391081] has been undeployed
>05:06:39,341 INFO  [org.rhq.enterprise.server.scheduler.jobs.AsyncResourceDeleteJob] (RHQScheduler_Worker-3) Async resource deletion - 78 successful, 0 failed, took [19237] ms
>

Actions: View

Attachments on bug 1107579: 907101