GoXDCR: Delay in replication

Build

4.0.0-1977

Testcase
--------
./testrunner -i INI_FILE get-cbcollect-info=True,get-logs=False,stop-on-failure=False,get-coredumps=True,demand_encryption=1,GROUP=ALL -t xdcr.rebalanceXDCR.Rebalance.async_rebalance_out_master,items=10000,rdirection=bidirection,ctopology=chain,update=C1-C2,delete=C1-C2,rebalance=C1

test_30 in http://qa.sc.couchbase.com/view/BY%20COMPONENT/job/cen006-p1-xxdcr-vset07-01-goxdcr-rebalance-ssl/9/consoleFull

Steps

1. C1 [.157,.158] <--> C2[.159,.160]
2. Load 10K on C1 and C2.
3. Rebalance out .157 from C1
3. Perform updates and deletes on C1 and C2.

[2015-05-01 00:58:50,176] - [task:462] INFO - rebalancing was completed with progress: 100% in 124.999613047 sec

[2015-05-01 00:59:47,231] - [xdcrnewbasetests:2007] INFO - Saw: vb_active_curr_items 14000 == 14000 expected on C1, default bucket
[2015-05-01 00:59:47,282] - [xdcrnewbasetests:2041] INFO - Saw: vb_replica_curr_items 0 == 0 expected on C1, default bucket
[2015-05-01 00:59:47,421] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 00:59:52,526] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 00:59:57,655] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:02,748] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:07,866] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:12,985] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:18,083] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:23,193] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:28,298] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:33,391] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:38,499] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:43,593] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:48,710] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:53,808] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:00:58,919] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:04,042] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:09,198] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:14,332] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:19,464] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:24,610] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:29,732] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:34,900] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:40,023] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:45,137] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:50,259] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:01:55,381] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:00,473] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:05,597] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:10,704] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:15,816] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:20,920] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:26,991] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:32,084] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:37,233] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:42,341] - [xdcrnewbasetests:1996] WARNING - Not Ready: vb_active_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:47,346] - [xdcrnewbasetests:2000] ERROR - ERROR: Timed-out waiting for active item count to match
[2015-05-01 01:02:47,488] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:50,593] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:53,701] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:56,809] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:02:59,926] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:03,217] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:06,331] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:09,430] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:12,529] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:15,606] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:18,715] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:21,828] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:24,977] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:28,118] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:31,228] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:34,356] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:37,476] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:40,591] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:43,697] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:46,812] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:49,910] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:53,042] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:56,167] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:03:59,268] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:02,371] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:05,464] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:08,558] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:11,672] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:14,798] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:17,911] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:21,050] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:24,156] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:27,755] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:30,892] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:33,988] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:37,108] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:40,202] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:43,298] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:46,386] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:49,468] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:52,587] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:55,705] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:04:58,817] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:01,922] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:05,035] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:08,151] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:11,280] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:14,400] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:17,506] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:20,622] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:23,780] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 12000 == 14000 expected on C2, default bucket
[2015-05-01 01:05:26,904] - [xdcrnewbasetests:2029] WARNING - Not Ready: vb_replica_curr_items 13536 == 14000 expected on C2, default bucket
[2015-05-01 01:05:30,023] - [xdcrnewbasetests:2041] INFO - Saw: vb_replica_curr_items 14000 == 14000 expected on C2, default bucket

6 mins to replicate last 2000 keys.