Details
Description
18 tests failed on 3.0.0-805-rel due to cbrecovery stuck http://qa.hq.northscale.net/job/ubuntu_x64--38_01--cbrecovery-P1/6/consoleFull
./testrunner i ubuntu_x6438_01-cbrecovery-P1.ini get-cbcollect-info=True,get-logs=False,stop-on-failure=False -t cbRecoverytests.cbrecovery.restart_cbrecover_multiple_failover_swapout_reb_routine,items=100000,rdirection=bidirection,ctopology=chain,failover=source,fail_count=2,add_count=2,max_verify=10000,when_step=create_bucket_when_recovery,extra_buckets=1
2014-06-12 01:26:00 | INFO | MainProcess | Cluster_Thread | [task.execute] command was executed: '/opt/couchbase/bin/cbrecovery http://10.3.3.233:8091 http://10.3.3.141:8091 -b default -B default -u Administrator -p password -U Administrator -P password '
2014-06-12 01:26:20 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:26:40 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:27:00 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:27:21 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:27:41 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:28:01 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:28:21 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:28:41 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:29:01 | INFO | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
2014-06-12 01:29:21 | WARNING | MainProcess | Cluster_Thread | [task.check] cbrecovery progress was not changed
2014-06-12 01:29:41 | WARNING | MainProcess | Cluster_Thread | [task.check] cbrecovery progress was not changed
........
2014-06-12 01:36:01 | WARNING | MainProcess | Cluster_Thread | [task.check] cbrecovery progress was not changed
2014-06-12 01:36:21 | WARNING | MainProcess | Cluster_Thread | [task.check] cbrecovery progress was not changed
2014-06-12 01:36:22 | INFO | MainProcess | Cluster_Thread | [rest_client.print_UI_logs] Latest logs from UI on 10.3.3.141:
2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.105', u'code': 0, u'text': u'Bucket "default" loaded on node \'ns_1@172.23.106.105\' in 0 seconds.', u'shortText': u'message', u'serverTime': u'2014-06-12T01:26:54.153Z', u'module': u'ns_memcached', u'tstamp': 1402561614153, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 0, u'text': u'Bucket "default" loaded on node \'ns_1@172.23.106.106\' in 0 seconds.', u'shortText': u'message', u'serverTime': u'2014-06-12T01:26:54.127Z', u'module': u'ns_memcached', u'tstamp': 1402561614127, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 3, u'text': u'Node ns_1@172.23.106.106 joined cluster', u'shortText': u'message', u'serverTime': u'2014-06-12T01:26:36.089Z', u'module': u'ns_cluster', u'tstamp': 1402561596089, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 1, u'text': u'Couchbase Server has started on web port 8091 on node \'ns_1@172.23.106.106\'. Version: "3.0.0-805-rel-enterprise".', u'shortText': u'web start ok', u'serverTime': u'2014-06-12T01:26:36.050Z', u'module': u'menelaus_sup', u'tstamp': 1402561596050, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.105', u'code': 4, u'text': u"Node 'ns_1@172.23.106.105' saw that node 'ns_1@172.23.106.106' came up. Tags: []", u'shortText': u'node up', u'serverTime': u'2014-06-12T01:26:33.167Z', u'module': u'ns_node_disco', u'tstamp': 1402561593167, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 4, u'text': u"Node 'ns_1@172.23.106.106' saw that node 'ns_1@172.23.106.105' came up. Tags: []", u'shortText': u'node up', u'serverTime': u'2014-06-12T01:26:33.167Z', u'module': u'ns_node_disco', u'tstamp': 1402561593167, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 4, u'text': u"Node 'ns_1@172.23.106.106' saw that node 'ns_1@10.1.4.31' came up. Tags: []", u'shortText': u'node up', u'serverTime': u'2014-06-12T01:26:33.135Z', u'module': u'ns_node_disco', u'tstamp': 1402561593135, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@10.1.4.31', u'code': 4, u'text': u"Node 'ns_1@10.1.4.31' saw that node 'ns_1@172.23.106.106' came up. Tags: []", u'shortText': u'node up', u'serverTime': u'2014-06-12T01:26:33.123Z', u'module': u'ns_node_disco', u'tstamp': 1402561593123, u'type': u'info'}2014-06-12 01:36:22 | ERROR | MainProcess | Cluster_Thread | [rest_client.print_UI_logs]
{u'node': u'ns_1@172.23.106.106', u'code': 4, u'text': u"Node 'ns_1@172.23.106.106' saw that node 'ns_1@10.1.3.71' came up. Tags: []", u'shortText': u'node up', u'serverTime': u'2014-06-12T01:26:33.071Z', u'module': u'ns_node_disco', u'tstamp': 1402561593071, u'type': u'info'}2014-06-12 01:36:22 | WARNING | MainProcess | Cluster_Thread | [task.check] ns_server_tasks: [
{u'commitVBucketURI': u'/pools/default/buckets/default/controller/commitVBucket?recovery_uuid=ea94845a882f849ace4485596441e2b7', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'bucket': u'default', u'stopURI': u'/pools/default/buckets/default/controller/stopRecovery?recovery_uuid=ea94845a882f849ace4485596441e2b7', u'recoveryStatusURI': u'/pools/default/buckets/default/recoveryStatus?recovery_uuid=ea94845a882f849ace4485596441e2b7', u'recommendedRefreshPeriod': 10, u'type': u'recovery'},
{u'status': u'notRunning', u'type': u'rebalance'},
{u'status': u'running', u'docsChecked': 100167, u'target': u'/remoteClusters/7143a3670fba2caf1e2de111b6d2bb30/buckets/default', u'continuous': True, u'settingsURI': u'/settings/replications/7143a3670fba2caf1e2de111b6d2bb30%2Fdefault%2Fdefault', u'docsWritten': 100167, u'cancelURI': u'/controller/cancelXDCR/7143a3670fba2caf1e2de111b6d2bb30%2Fdefault%2Fdefault', u'source': u'default', u'maxVBReps': 80, u'replicationType': u'capi', u'errors': [u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 66. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 55. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 324. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 306. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 28. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 265. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 252. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 246. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 2. Please see logs for details.', u'2014-06-12 01:26:04 [Vb Rep] Error replicating vbucket 190. Please see logs for details.'], u'changesLeft': 1122, u'type': u'xdcr', u'id': u'7143a3670fba2caf1e2de111b6d2bb30/default/default', u'recommendedRefreshPeriod': 10}]
2014-06-12 01:36:22 | WARNING | MainProcess | Cluster_Thread | [task.check] cbrecovery progress: {u'code': u'ok', u'uuid': u'ea94845a882f849ace4485596441e2b7', u'recoveryMap': [
]}
ERROR