Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-14861

GoXDCR: Key left undeleted for > 20 mins

    XMLWordPrintable

Details

    • Bug
    • Resolution: Duplicate
    • Blocker
    • 4.0.0
    • 4.0.0
    • XDCR
    • Security Level: Public
    • None

    Description

      Build


      4.0.0-2070

      Testcase
      --------
      ./testrunner -i INI_FILE.ini get-cbcollect-info=True,get-logs=True,stop-on-failure=False,demand_encryption=1,items=500000,GROUP=CHAIN -t xdcr.uniXDCR.unidirectional.load_with_async_ops_with_warmup_master,rdirection=unidirection,ctopology=chain,sasl_buckets=2,update=C1,delete=C1,warm=C2

      Steps


      1. C1[.45,.46] --> C2[.47,.48]
      2. 3 buckets - default, sasl_bucket_1, sasl_bucket_2 with ssl replication
      3. Load 500K keys on C1
      4. warm up master on C2 (.47), Warmed up: 500000 items
      5. Perform updates and deletes on C1.

      One key is not deleted in sasl_bucket_1 on C2 for more than 20 mins.

      Testlog

       
      Test Input params: 
      {'item_count_timeout': '600', 'logs_folder': '/jenkins/workspace/cen006-p0-xxdcr-vset00-01-goxdcr-unixdcr-ssl/logs/testrunner-15-May-04_15-27-22/test_9', 'GROUP': 'CHAIN', 'demand_encryption': '1', 'items': '500000', 'warm': 'C2', 'case_number': 9, 'update': 'C1', 'conf_file': 'conf/py-xdcr-unidirectional.conf', 'num_nodes': 6, 'cluster_name': 'INI_FILE', 'ctopology': 'chain', 'rdirection': 'unidirection', 'stop-on-failure': 'False', 'ini': 'INI_FILE.ini', 'replication_type': 'xmem', 'get-logs': 'True', 'sasl_buckets': '2', 'get-cbcollect-info': 'True', 'spec': 'py-xdcr-unidirectional', 'delete': 'C1'} 
      [2015-05-04 20:47:57,735] - [xdcrnewbasetests:2238] INFO - ==== XDCRNewbasetests setup is started for test #9 load_with_async_ops_with_warmup_master ==== 
      [2015-05-04 20:47:57,736] - [xdcrnewbasetests:1053] INFO - removing xdcr/nodes settings 
      [2015-05-04 20:47:58,453] - [xdcrnewbasetests:1063] INFO - cleanup [ip:172.23.106.45 port:8091 ssh_username:root, ip:172.23.106.46 port:8091 ssh_username:root] 
      [2015-05-04 20:47:58,467] - [bucket_helper:137] INFO - deleting existing buckets [] on 172.23.106.45 
      [2015-05-04 20:47:58,509] - [cluster_helper:78] INFO - waiting for ns_server @ 172.23.106.45:8091 
      [2015-05-04 20:47:58,517] - [cluster_helper:80] INFO - ns_server @ 172.23.106.45:8091 is running 
      [2015-05-04 20:47:58,532] - [bucket_helper:137] INFO - deleting existing buckets [] on 172.23.106.46 
      [2015-05-04 20:47:58,559] - [cluster_helper:78] INFO - waiting for ns_server @ 172.23.106.46:8091 
      [2015-05-04 20:47:58,566] - [cluster_helper:80] INFO - ns_server @ 172.23.106.46:8091 is running 
      [2015-05-04 20:47:58,566] - [xdcrnewbasetests:1053] INFO - removing xdcr/nodes settings 
      [2015-05-04 20:47:58,604] - [xdcrnewbasetests:1063] INFO - cleanup [ip:172.23.106.47 port:8091 ssh_username:root, ip:172.23.106.48 port:8091 ssh_username:root] 
      [2015-05-04 20:47:58,614] - [bucket_helper:137] INFO - deleting existing buckets [] on 172.23.106.47 
      [2015-05-04 20:47:58,648] - [cluster_helper:78] INFO - waiting for ns_server @ 172.23.106.47:8091 
      [2015-05-04 20:47:58,655] - [cluster_helper:80] INFO - ns_server @ 172.23.106.47:8091 is running 
      [2015-05-04 20:47:58,667] - [bucket_helper:137] INFO - deleting existing buckets [] on 172.23.106.48 
      [2015-05-04 20:47:58,697] - [cluster_helper:78] INFO - waiting for ns_server @ 172.23.106.48:8091 
      [2015-05-04 20:47:58,705] - [cluster_helper:80] INFO - ns_server @ 172.23.106.48:8091 is running 
      [2015-05-04 20:47:58,706] - [xdcrnewbasetests:2402] INFO - Initializing all clusters... 
      [2015-05-04 20:47:58,729] - [rest_client:1181] INFO - /diag/eval status on 172.23.106.45:8091: True content: [4,0] command: cluster_compat_mode:get_compat_version(). 
      [2015-05-04 20:47:58,748] - [rest_client:747] INFO - settings/web params on 172.23.106.45:8091:username=Administrator&password=password&port=8091 
      [2015-05-04 20:47:58,776] - [rest_client:784] INFO - pools/default params : memoryQuota=2069 
      [2015-05-04 20:47:58,796] - [rest_client:747] INFO - settings/web params on 172.23.106.46:8091:username=Administrator&password=password&port=8091 
      [2015-05-04 20:47:58,817] - [rest_client:784] INFO - pools/default params : memoryQuota=2069 
      [2015-05-04 20:47:59,825] - [task:346] INFO - adding node 172.23.106.46:8091 to cluster 
      [2015-05-04 20:47:59,826] - [rest_client:947] INFO - adding remote node @172.23.106.46:8091 to this cluster @172.23.106.45:8091 
      [2015-05-04 20:48:02,818] - [rest_client:1165] INFO - rebalance params : password=password&ejectedNodes=&user=Administrator&knownNodes=ns_1%40172.23.106.46%2Cns_1%40172.23.106.45 
      [2015-05-04 20:48:02,833] - [rest_client:1169] INFO - rebalance operation started 
      [2015-05-04 20:48:02,843] - [rest_client:1287] INFO - rebalance percentage : 0.00 % 
      [2015-05-04 20:48:12,869] - [task:462] INFO - rebalancing was completed with progress: 100% in 10.0361378193 sec 
      [2015-05-04 20:48:12,885] - [rest_client:1181] INFO - /diag/eval status on 172.23.106.47:8091: True content: [4,0] command: cluster_compat_mode:get_compat_version(). 
      [2015-05-04 20:48:13,769] - [rest_client:747] INFO - settings/web params on 172.23.106.47:8091:username=Administrator&password=password&port=8091 
      [2015-05-04 20:48:13,795] - [rest_client:784] INFO - pools/default params : memoryQuota=2069 
      [2015-05-04 20:48:13,814] - [rest_client:747] INFO - settings/web params on 172.23.106.48:8091:username=Administrator&password=password&port=8091 
      [2015-05-04 20:48:13,838] - [rest_client:784] INFO - pools/default params : memoryQuota=2069 
      [2015-05-04 20:48:14,846] - [task:346] INFO - adding node 172.23.106.48:8091 to cluster 
      [2015-05-04 20:48:14,847] - [rest_client:947] INFO - adding remote node @172.23.106.48:8091 to this cluster @172.23.106.47:8091 
      [2015-05-04 20:48:17,620] - [rest_client:1165] INFO - rebalance params : password=password&ejectedNodes=&user=Administrator&knownNodes=ns_1%40172.23.106.47%2Cns_1%40172.23.106.48 
      [2015-05-04 20:48:17,629] - [rest_client:1169] INFO - rebalance operation started 
      [2015-05-04 20:48:17,638] - [rest_client:1287] INFO - rebalance percentage : 0.00 % 
      [2015-05-04 20:48:27,659] - [task:462] INFO - rebalancing was completed with progress: 100% in 10.0296499729 sec 
      [2015-05-04 20:48:27,905] - [rest_client:1687] INFO - http://172.23.106.45:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=default&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=None 
      [2015-05-04 20:48:27,917] - [rest_client:1709] INFO - 0.01 seconds to create bucket default 
      [2015-05-04 20:48:27,917] - [bucket_helper:305] INFO - waiting for memcached bucket : default in 172.23.106.45 to accept set ops 
      [2015-05-04 20:48:29,170] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 20:48:29,306] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 20:48:29,471] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 20:48:29,590] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 20:48:30,277] - [task:230] INFO - bucket 'default' was created with per node RAM quota: 523 
      [2015-05-04 20:48:31,302] - [rest_client:1687] INFO - http://172.23.106.45:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=sasl_bucket_1&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=password
      [2015-05-04 20:48:31,310] - [rest_client:1709] INFO - 0.01 seconds to create bucket sasl_bucket_1 
      [2015-05-04 20:48:31,345] - [rest_client:1687] INFO - http://172.23.106.45:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=sasl_bucket_2&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=password
      [2015-05-04 20:48:31,405] - [rest_client:1709] INFO - 0.06 seconds to create bucket sasl_bucket_2 
      [2015-05-04 20:48:31,406] - [bucket_helper:305] INFO - waiting for memcached bucket : sasl_bucket_1 in 172.23.106.45 to accept set ops 
      [2015-05-04 20:48:36,394] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 20:48:36,520] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 20:48:36,675] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 20:48:36,807] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 20:48:37,548] - [task:230] INFO - bucket 'sasl_bucket_1' was created with per node RAM quota: 523 
      [2015-05-04 20:48:37,549] - [bucket_helper:305] INFO - waiting for memcached bucket : sasl_bucket_2 in 172.23.106.45 to accept set ops 
      [2015-05-04 20:48:37,739] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 20:48:37,870] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 20:48:38,050] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 20:48:38,171] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 20:48:38,901] - [task:230] INFO - bucket 'sasl_bucket_2' was created with per node RAM quota: 523 
      [2015-05-04 20:48:39,714] - [rest_client:1687] INFO - http://172.23.106.47:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=default&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=None 
      [2015-05-04 20:48:39,727] - [rest_client:1709] INFO - 0.01 seconds to create bucket default 
      [2015-05-04 20:48:39,728] - [bucket_helper:305] INFO - waiting for memcached bucket : default in 172.23.106.47 to accept set ops 
      [2015-05-04 20:48:40,942] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 20:48:41,079] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 20:48:41,231] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 20:48:41,324] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 20:48:41,952] - [task:230] INFO - bucket 'default' was created with per node RAM quota: 523 
      [2015-05-04 20:48:42,976] - [rest_client:1687] INFO - http://172.23.106.47:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=sasl_bucket_1&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=password
      [2015-05-04 20:48:42,987] - [rest_client:1709] INFO - 0.01 seconds to create bucket sasl_bucket_1 
      [2015-05-04 20:48:43,177] - [rest_client:1687] INFO - http://172.23.106.47:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=523&proxyPort=11211&authType=sasl&name=sasl_bucket_2&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=password
      [2015-05-04 20:48:43,206] - [rest_client:1709] INFO - 0.03 seconds to create bucket sasl_bucket_2 
      [2015-05-04 20:48:43,207] - [bucket_helper:305] INFO - waiting for memcached bucket : sasl_bucket_1 in 172.23.106.47 to accept set ops 
      [2015-05-04 20:48:51,091] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 20:48:51,197] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 20:48:51,366] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 20:48:51,482] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 20:48:52,158] - [task:230] INFO - bucket 'sasl_bucket_1' was created with per node RAM quota: 523 
      [2015-05-04 20:48:52,159] - [bucket_helper:305] INFO - waiting for memcached bucket : sasl_bucket_2 in 172.23.106.47 to accept set ops 
      [2015-05-04 20:48:52,305] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 20:48:52,404] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 20:48:52,579] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 20:48:52,705] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 20:48:53,466] - [task:230] INFO - bucket 'sasl_bucket_2' was created with per node RAM quota: 523 
      [2015-05-04 20:48:53,497] - [rest_client:1910] INFO - Update internal setting xdcrCheckpointInterval=60 
      [2015-05-04 20:48:53,519] - [rest_client:1910] INFO - Update internal setting xdcrCheckpointInterval=60 
      [2015-05-04 20:48:53,520] - [xdcrnewbasetests:2244] INFO - ==== XDCRNewbasetests setup is finished for test #9 load_with_async_ops_with_warmup_master ==== 
      [2015-05-04 20:48:53,555] - [rest_client:837] INFO - adding remote cluster hostname:172.23.106.47:8091 with username:password Administrator:password name:remote_cluster_C1-C2 to source node: 172.23.106.45:8091 
      [2015-05-04 20:48:53,683] - [rest_client:884] INFO - starting continuous replication type:xmem from default to default in the remote cluster remote_cluster_C1-C2 with settings {} 
      [2015-05-04 20:48:53,816] - [rest_client:897] INFO - Replication created with id: 66a3d7aa6f8d4d5040b7937144feeffa/default/default 
      [2015-05-04 20:48:53,825] - [rest_client:884] INFO - starting continuous replication type:xmem from sasl_bucket_1 to sasl_bucket_1 in the remote cluster remote_cluster_C1-C2 with settings {} 
      [2015-05-04 20:48:53,937] - [rest_client:897] INFO - Replication created with id: 66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1 
      [2015-05-04 20:48:53,953] - [rest_client:884] INFO - starting continuous replication type:xmem from sasl_bucket_2 to sasl_bucket_2 in the remote cluster remote_cluster_C1-C2 with settings {} 
      [2015-05-04 20:48:54,069] - [rest_client:897] INFO - Replication created with id: 66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_2/sasl_bucket_2 
      [2015-05-04 20:48:54,152] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 20:48:54,261] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 20:48:54,425] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 20:48:54,533] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 20:48:54,699] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 20:48:54,826] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:16:09,463] - [xdcrnewbasetests:2905] INFO - sleep for 10 secs. ... 
      [2015-05-04 21:16:19,474] - [remote_util:158] INFO - connecting to 172.23.106.47 with username : root password : couchbase ssh_key: 
      [2015-05-04 21:16:19,647] - [remote_util:191] INFO - Connected to 172.23.106.47 
      [2015-05-04 21:16:19,889] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: cat /proc/cpuinfo 
      [2015-05-04 21:16:19,953] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:19,954] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: df -Th 
      [2015-05-04 21:16:20,018] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:20,019] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: cat /proc/meminfo 
      [2015-05-04 21:16:20,105] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:20,106] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: hostname 
      [2015-05-04 21:16:20,195] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:20,196] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: hostname -d 
      [2015-05-04 21:16:20,282] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:20,284] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: /etc/init.d/couchbase-server stop 
      [2015-05-04 21:16:33,741] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:33,742] - [remote_util:1835] INFO - Stopping couchbase-server 
      [2015-05-04 21:16:33,742] - [remote_util:1835] INFO - [ OK ] 
      [2015-05-04 21:16:33,742] - [remote_util:1835] INFO - 
      [2015-05-04 21:16:38,747] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: /etc/init.d/couchbase-server start 
      [2015-05-04 21:16:40,180] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:16:40,180] - [remote_util:1835] INFO - Starting couchbase-server 
      [2015-05-04 21:16:40,181] - [remote_util:1835] INFO - 
      [2015-05-04 21:16:40,296] - [xdcrnewbasetests:2905] INFO - sleep for 60 secs. ... 
      [2015-05-04 21:17:40,357] - [xdcrnewbasetests:2686] INFO - Updating keys @ C1 
      [2015-05-04 21:17:40,357] - [xdcrnewbasetests:1498] INFO - At bucket 'default' @ C1: operation: update, key range 0 - 150000 
      [2015-05-04 21:17:40,457] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 21:17:41,031] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 21:17:41,119] - [xdcrnewbasetests:1498] INFO - At bucket 'sasl_bucket_1' @ C1: operation: update, key range 0 - 150000 
      [2015-05-04 21:17:41,202] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 21:17:41,296] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 21:17:41,380] - [xdcrnewbasetests:1498] INFO - At bucket 'sasl_bucket_2' @ C1: operation: update, key range 0 - 150000 
      [2015-05-04 21:17:41,509] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 21:17:41,662] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:26:28,010] - [xdcrnewbasetests:2693] INFO - Batched updates loaded to cluster(s) 
      [2015-05-04 21:26:28,011] - [xdcrnewbasetests:2699] INFO - Deleting keys @ C1 
      [2015-05-04 21:26:28,012] - [xdcrnewbasetests:1498] INFO - At bucket 'default' @ C1: operation: delete, key range 350000 - 500000 
      [2015-05-04 21:26:28,088] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 21:26:28,191] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 21:26:28,732] - [xdcrnewbasetests:1498] INFO - At bucket 'sasl_bucket_1' @ C1: operation: delete, key range 350000 - 500000 
      [2015-05-04 21:26:28,835] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 21:26:28,965] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 21:26:29,036] - [xdcrnewbasetests:1498] INFO - At bucket 'sasl_bucket_2' @ C1: operation: delete, key range 350000 - 500000 
      [2015-05-04 21:26:29,149] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 21:26:29,333] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:29:00,937] - [xdcrnewbasetests:2706] INFO - Batched deletes sent to cluster(s) 
      [2015-05-04 21:29:00,939] - [xdcrnewbasetests:2905] INFO - sleep for 30 secs. ... 
      [2015-05-04 21:29:30,989] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 21:29:31,075] - [xdcrnewbasetests:310] INFO - Warmed up: 500000 items on default on ip:172.23.106.47 port:8091 ssh_username:root 
      [2015-05-04 21:29:41,100] - [xdcrnewbasetests:2864] INFO - Merging keys for replication Replication C1:default -> C2:default 
      [2015-05-04 21:29:41,967] - [xdcrnewbasetests:2803] INFO - src_kvstore has 350000 valid and 150000 deleted keys 
      [2015-05-04 21:29:41,967] - [xdcrnewbasetests:2805] INFO - dest kvstore has 0 valid and 0 deleted keys 
      [2015-05-04 21:29:49,022] - [xdcrnewbasetests:2854] INFO - After merging: destination bucket's kv_store now has 350000 valid keys and 0 deleted keys 
      [2015-05-04 21:29:49,046] - [xdcrnewbasetests:2864] INFO - Merging keys for replication Replication C1:sasl_bucket_1 -> C2:sasl_bucket_1 
      [2015-05-04 21:29:49,932] - [xdcrnewbasetests:2803] INFO - src_kvstore has 350000 valid and 150000 deleted keys 
      [2015-05-04 21:29:49,933] - [xdcrnewbasetests:2805] INFO - dest kvstore has 0 valid and 0 deleted keys 
      [2015-05-04 21:29:56,801] - [xdcrnewbasetests:2854] INFO - After merging: destination bucket's kv_store now has 350000 valid keys and 0 deleted keys 
      [2015-05-04 21:29:56,824] - [xdcrnewbasetests:2864] INFO - Merging keys for replication Replication C1:sasl_bucket_2 -> C2:sasl_bucket_2 
      [2015-05-04 21:29:57,709] - [xdcrnewbasetests:2803] INFO - src_kvstore has 350000 valid and 150000 deleted keys 
      [2015-05-04 21:29:57,710] - [xdcrnewbasetests:2805] INFO - dest kvstore has 0 valid and 0 deleted keys 
      [2015-05-04 21:30:04,630] - [xdcrnewbasetests:2854] INFO - After merging: destination bucket's kv_store now has 350000 valid keys and 0 deleted keys 
      [2015-05-04 21:30:04,726] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:04,726] - [data_helper:293] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 21:30:04,821] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on default 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:04,822] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3863083436, 0, '') 
      [2015-05-04 21:30:04,858] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:04,858] - [data_helper:293] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 21:30:04,954] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on default 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:04,955] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3650414888, 0, '') 
      [2015-05-04 21:30:04,956] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:05,019] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:05,020] - [data_helper:293] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 21:30:05,753] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_1 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:05,755] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (985683207, 0, '') 
      [2015-05-04 21:30:05,792] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:05,792] - [data_helper:293] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 21:30:05,873] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_1 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:05,874] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3415536655, 0, '') 
      [2015-05-04 21:30:05,874] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:05,931] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:05,932] - [data_helper:293] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 21:30:06,024] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_2 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:06,025] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.45', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3058832924, 0, '') 
      [2015-05-04 21:30:06,058] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:06,058] - [data_helper:293] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:30:06,137] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_2 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:06,138] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.46', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (2514827544, 0, '') 
      [2015-05-04 21:30:06,139] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:16,197] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:16,197] - [data_helper:293] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 21:30:16,301] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on default 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:16,302] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (2939728684, 0, '') 
      [2015-05-04 21:30:16,340] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:16,341] - [data_helper:293] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 21:30:16,436] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on default 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:16,437] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3034682839, 0, '') 
      [2015-05-04 21:30:16,437] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:16,506] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:16,507] - [data_helper:293] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 21:30:16,596] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_1 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:16,598] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3249520311, 0, '') 
      [2015-05-04 21:30:16,627] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:16,628] - [data_helper:293] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 21:30:16,711] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_1 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:16,712] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (3958381954, 0, '') 
      [2015-05-04 21:30:16,712] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:16,757] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:16,757] - [data_helper:293] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 21:30:17,435] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_2 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:17,436] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.47', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (213971613, 0, '') 
      [2015-05-04 21:30:17,464] - [data_helper:292] INFO - dict:{'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'} 
      [2015-05-04 21:30:17,464] - [data_helper:293] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 21:30:17,533] - [cluster_helper:340] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10 on sasl_bucket_2 
      setting param: exp_pager_stime 10 
      [2015-05-04 21:30:17,534] - [cluster_helper:354] INFO - Setting flush param on server {'username': 'Administrator', 'ip': u'172.23.106.48', 'password': 'password', 'port': u'8091'}, exp_pager_stime to 10, result: (187138230, 0, '') 
      [2015-05-04 21:30:17,534] - [xdcrnewbasetests:1540] INFO - wait for expiry pager to run on all these nodes 
      [2015-05-04 21:30:27,729] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 21:30:27,815] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.45:8091',default bucket 
      [2015-05-04 21:30:27,838] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 21:30:27,931] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.45:8091',sasl_bucket_1 bucket 
      [2015-05-04 21:30:27,952] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 21:30:28,056] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.45:8091',sasl_bucket_2 bucket 
      [2015-05-04 21:30:28,076] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 21:30:28,184] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.46:8091',default bucket 
      [2015-05-04 21:30:28,205] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 21:30:28,287] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.46:8091',sasl_bucket_1 bucket 
      [2015-05-04 21:30:28,307] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:30:28,376] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.46:8091',sasl_bucket_2 bucket 
      [2015-05-04 21:30:28,733] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 21:30:28,821] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.47:8091',default bucket 
      [2015-05-04 21:30:28,836] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 21:30:29,556] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.47:8091',sasl_bucket_1 bucket 
      [2015-05-04 21:30:29,573] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 21:30:29,648] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.47:8091',sasl_bucket_2 bucket 
      [2015-05-04 21:30:29,664] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 21:30:29,742] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.48:8091',default bucket 
      [2015-05-04 21:30:29,755] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 21:30:29,846] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.48:8091',sasl_bucket_1 bucket 
      [2015-05-04 21:30:29,860] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 21:30:29,935] - [task:514] INFO - Saw ep_queue_size 0 == 0 expected on '172.23.106.48:8091',sasl_bucket_2 bucket 
      [2015-05-04 21:30:29,953] - [xdcrnewbasetests:2127] INFO - Waiting for dcp queue to drain on cluster node: 172.23.106.45 
      [2015-05-04 21:30:30,027] - [xdcrnewbasetests:2137] INFO - Current dcp queue size on C1 for default is 0 
      [2015-05-04 21:30:30,087] - [xdcrnewbasetests:2137] INFO - Current dcp queue size on C1 for sasl_bucket_2 is 0 
      [2015-05-04 21:30:30,087] - [xdcrnewbasetests:2127] INFO - Waiting for dcp queue to drain on cluster node: 172.23.106.47 
      [2015-05-04 21:30:30,178] - [xdcrnewbasetests:2137] INFO - Current dcp queue size on C2 for default is 0 
      [2015-05-04 21:30:30,262] - [xdcrnewbasetests:2137] INFO - Current dcp queue size on C2 for sasl_bucket_2 is 0 
      [2015-05-04 21:30:30,262] - [xdcrnewbasetests:2157] INFO - Waiting for Outbound mutation to be zero on cluster node: 172.23.106.45 
      [2015-05-04 21:30:30,277] - [rest_client:730] ERROR - http://172.23.106.45:8091/pools/default/buckets/@xdcr-default/stats?zoom=minute error 404 reason: status: 404, content: Requested resource not found. 
       Requested resource not found. 
      [2015-05-04 21:30:30,277] - [xdcrnewbasetests:2937] ERROR - No JSON object could be decoded 
      [2015-05-04 21:30:30,780] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, default bucket 
      [2015-05-04 21:30:31,488] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, sasl_bucket_1 bucket 
      [2015-05-04 21:30:32,001] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, sasl_bucket_2 bucket 
      [2015-05-04 21:30:32,492] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, default bucket 
      [2015-05-04 21:30:33,044] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, sasl_bucket_1 bucket 
      [2015-05-04 21:30:33,627] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, sasl_bucket_2 bucket 
      [2015-05-04 21:30:34,125] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:39,208] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:44,274] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:49,367] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:54,452] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:59,524] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:04,619] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:09,695] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:14,772] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:19,838] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:24,931] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:30,005] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:35,086] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:40,175] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:45,242] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:50,311] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:31:55,394] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:00,444] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:05,521] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:10,593] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:15,657] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:20,753] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:25,828] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:30,901] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:35,973] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:41,065] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:46,158] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:51,218] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:32:56,307] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:01,388] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:06,481] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:11,570] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:16,647] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:21,751] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:26,834] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:31,934] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:37,032] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:42,273] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:47,340] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:52,413] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:33:57,484] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:02,555] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:07,638] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:12,705] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:17,770] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:22,843] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:27,915] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:32,996] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:38,088] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:43,165] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:48,257] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:53,362] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:34:58,465] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:03,565] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:08,642] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:13,738] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:18,826] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:23,899] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:28,975] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:34,061] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:39,150] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:44,221] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:49,298] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:54,360] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:35:59,429] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:04,511] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:09,579] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:14,660] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:19,742] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:24,822] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:29,898] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:34,982] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:40,071] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:45,188] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:50,288] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:36:55,349] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:00,420] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:05,508] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:10,592] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:15,673] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:20,745] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:25,814] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:30,897] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:35,987] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:41,120] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:46,189] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:51,254] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:37:56,332] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:01,407] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:06,480] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:11,555] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:16,642] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:21,716] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:26,790] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:31,883] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:36,966] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:42,040] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:47,125] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:52,195] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:38:57,276] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:39:02,370] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:39:07,455] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:39:12,540] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C2, default bucket 
      [2015-05-04 21:39:13,046] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:18,152] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:23,232] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:28,321] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:33,400] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:38,513] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:43,563] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:48,649] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:53,718] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:39:58,802] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:03,868] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:08,941] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:14,023] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:19,101] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:24,196] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:29,275] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:34,281] - [xdcrnewbasetests:2024] ERROR - ERROR: Timed-out waiting for active item count to match 
      [2015-05-04 21:40:34,757] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C2, sasl_bucket_2 bucket 
      [2015-05-04 21:40:35,220] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C2, default bucket 
      [2015-05-04 21:40:35,691] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:38,754] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:41,825] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:44,914] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:47,992] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:51,065] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:54,126] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:40:57,210] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:00,278] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:03,358] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:06,449] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:09,541] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:12,631] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:15,733] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:18,819] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:21,905] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:24,992] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:28,059] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:31,141] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:34,229] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:37,308] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:40,372] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:43,445] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:46,515] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:49,605] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:52,665] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:55,735] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:41:58,820] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:01,905] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:04,995] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:08,079] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:11,175] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:14,256] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:17,341] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:20,415] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:23,494] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:26,547] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:29,618] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:32,688] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:35,770] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:38,836] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:41,914] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:44,990] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:48,062] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:51,153] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:54,231] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:42:57,297] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:00,363] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:03,443] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:06,510] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:09,602] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:12,681] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:15,750] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:18,844] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:21,913] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:24,989] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:28,070] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:31,158] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:34,240] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:37,325] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:40,403] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:43,467] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:46,521] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:49,595] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:52,671] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:55,746] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:43:58,817] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:01,878] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:04,972] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:08,044] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:11,123] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:14,196] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:17,276] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:20,356] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:23,435] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:26,508] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:29,567] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:32,641] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:35,733] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:38,812] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:41,904] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:44,966] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:48,050] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:51,139] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:54,207] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:44:57,282] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:00,362] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:03,455] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:06,531] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:09,591] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:12,640] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:15,701] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:18,787] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:21,861] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:24,925] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:27,991] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:31,070] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:34,152] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:37,233] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:40,306] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:43,364] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:46,442] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:49,519] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:52,596] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:55,711] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:45:58,786] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:01,860] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:04,938] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:08,002] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:11,065] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:14,120] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:17,187] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:20,273] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:23,360] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:26,427] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:29,511] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:32,578] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:35,658] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:38,724] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:41,793] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:44,879] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:47,963] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:51,056] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:54,147] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:46:57,214] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:00,284] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:03,363] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:06,444] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:09,539] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:12,596] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:15,687] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:18,746] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:21,830] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:24,898] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:27,986] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:31,063] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:34,157] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:37,233] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:40,318] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:43,382] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:46,445] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:49,519] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:52,585] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:55,662] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:47:58,738] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:01,809] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:04,869] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:07,948] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:11,026] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:14,084] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:17,153] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:20,237] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:23,317] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:26,394] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:29,486] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:32,586] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:35,668] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:38,748] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:41,825] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:44,902] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:47,985] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:51,073] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:54,154] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:48:57,215] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:00,294] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:03,371] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:06,458] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:09,545] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:12,626] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:15,695] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:18,764] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:21,844] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:24,913] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:27,997] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:31,066] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:34,180] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:37,279] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:40,351] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:43,404] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:46,466] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:49,537] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:52,612] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:55,711] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:49:58,769] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:01,847] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:04,932] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:08,030] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:11,114] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:14,198] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:17,280] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:20,359] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:23,426] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:26,495] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:29,563] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:32,623] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:35,627] - [xdcrnewbasetests:2057] ERROR - ERROR: Timed-out waiting for replica item count to match 
      [2015-05-04 21:50:35,628] - [remote_util:158] INFO - connecting to 172.23.106.47 with username : root password : couchbase ssh_key: 
      [2015-05-04 21:50:35,847] - [remote_util:191] INFO - Connected to 172.23.106.47 
      [2015-05-04 21:50:35,847] - [xdcrnewbasetests:2085] INFO - Executing cbvdiff for bucket default 
      [2015-05-04 21:50:36,184] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: cat /proc/cpuinfo 
      [2015-05-04 21:50:36,305] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:36,306] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: df -Th 
      [2015-05-04 21:50:36,424] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:36,425] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: cat /proc/meminfo 
      [2015-05-04 21:50:36,539] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:36,540] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: hostname 
      [2015-05-04 21:50:36,665] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:36,666] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: hostname -d 
      [2015-05-04 21:50:36,786] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:36,787] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: /opt/couchbase/bin/cbvdiff -b default 172.23.106.47:11210,172.23.106.48:11210 
      [2015-05-04 21:50:40,059] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:40,060] - [remote_util:1835] INFO - Active item count = 350000 
      [2015-05-04 21:50:40,061] - [remote_util:1835] INFO - 
      [2015-05-04 21:50:40,061] - [xdcrnewbasetests:2085] INFO - Executing cbvdiff for bucket sasl_bucket_1 
      [2015-05-04 21:50:40,061] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: /opt/couchbase/bin/cbvdiff -b sasl_bucket_1 -p password 172.23.106.47:11210,172.23.106.48:11210 
      [2015-05-04 21:50:43,608] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:43,608] - [remote_util:1835] INFO - Active item count = 350001 
      [2015-05-04 21:50:43,609] - [remote_util:1835] INFO - 
      [2015-05-04 21:50:43,609] - [xdcrnewbasetests:2085] INFO - Executing cbvdiff for bucket sasl_bucket_2 
      [2015-05-04 21:50:43,609] - [remote_util:1896] INFO - running command.raw on 172.23.106.47: /opt/couchbase/bin/cbvdiff -b sasl_bucket_2 -p password 172.23.106.47:11210,172.23.106.48:11210 
      [2015-05-04 21:50:47,898] - [remote_util:1933] INFO - command executed successfully 
      [2015-05-04 21:50:47,899] - [remote_util:1835] INFO - Active item count = 350000 
      [2015-05-04 21:50:47,899] - [remote_util:1835] INFO - 
      [2015-05-04 21:50:48,401] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C2, sasl_bucket_2 bucket 
      [2015-05-04 21:50:48,492] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 21:50:48,596] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 21:50:49,568] - [task:1333] INFO - 100000 items will be verified on default bucket 
      [2015-05-04 21:50:49,718] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 21:50:49,813] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 21:50:50,474] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:50:52,599] - [task:1333] INFO - 100000 items will be verified on sasl_bucket_1 bucket 
      [2015-05-04 21:50:52,819] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 21:50:53,057] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 21:50:53,496] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:50:55,752] - [task:1333] INFO - 100000 items will be verified on sasl_bucket_2 bucket 
      [2015-05-04 21:50:56,504] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:51:21,251] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:51:24,864] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:51:27,571] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:51:53,517] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:51:56,008] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:51:58,458] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:52:24,499] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:52:27,196] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:52:29,477] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:52:55,888] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:52:58,363] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:53:00,852] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:53:27,222] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:53:29,560] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:53:32,020] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:53:58,266] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:54:00,768] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:54:03,140] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:54:29,336] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 21:54:31,551] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 21:54:34,084] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 21:55:00,454] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 21:55:02,849] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 21:55:05,055] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 21:55:32,328] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 21:55:34,744] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 21:55:36,563] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 21:56:04,903] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 21:56:04,904] - [task:1346] INFO - 100000 items were verified in 315.335048914 sec.the average number of ops - 317.123005377 per second 
      [2015-05-04 21:56:06,213] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 21:56:06,215] - [task:1346] INFO - 100000 items were verified in 313.611476183 sec.the average number of ops - 318.865872194 per second 
      [2015-05-04 21:56:06,401] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 21:56:06,401] - [task:1346] INFO - 100000 items were verified in 310.647506952 sec.the average number of ops - 321.908263057 per second 
      [2015-05-04 21:56:06,563] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 21:56:06,699] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 21:56:07,747] - [task:1333] INFO - 100000 items will be verified on default bucket 
      [2015-05-04 21:56:07,902] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 21:56:07,917] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:56:08,146] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 21:56:11,415] - [task:1333] INFO - 100000 items will be verified on sasl_bucket_1 bucket 
      [2015-05-04 21:56:11,677] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 21:56:11,958] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 21:56:11,998] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:56:15,082] - [task:1333] INFO - 100000 items will be verified on sasl_bucket_2 bucket 
      [2015-05-04 21:56:16,006] - [task:1342] INFO - 0 items were verified 
      [2015-05-04 21:56:39,049] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:56:44,726] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:56:49,165] - [task:1342] INFO - 10000 items were verified 
      [2015-05-04 21:57:12,270] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:57:17,464] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:57:22,123] - [task:1342] INFO - 20000 items were verified 
      [2015-05-04 21:57:45,968] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:57:51,108] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:57:56,112] - [task:1342] INFO - 30000 items were verified 
      [2015-05-04 21:58:19,328] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:58:23,488] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:58:28,876] - [task:1342] INFO - 40000 items were verified 
      [2015-05-04 21:58:52,364] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:58:55,829] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:59:00,760] - [task:1342] INFO - 50000 items were verified 
      [2015-05-04 21:59:23,645] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:59:27,814] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:59:32,307] - [task:1342] INFO - 60000 items were verified 
      [2015-05-04 21:59:57,208] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 22:00:00,308] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 22:00:05,885] - [task:1342] INFO - 70000 items were verified 
      [2015-05-04 22:00:30,527] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 22:00:33,932] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 22:00:39,886] - [task:1342] INFO - 80000 items were verified 
      [2015-05-04 22:01:03,649] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 22:01:05,652] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 22:01:12,096] - [task:1342] INFO - 90000 items were verified 
      [2015-05-04 22:01:36,690] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 22:01:36,691] - [task:1346] INFO - 100000 items were verified in 328.943817139 sec.the average number of ops - 304.003275599 per second 
      [2015-05-04 22:01:37,706] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 22:01:37,707] - [task:1346] INFO - 100000 items were verified in 326.291720152 sec.the average number of ops - 306.474213992 per second 
      [2015-05-04 22:01:38,580] - [task:1342] INFO - 100000 items were verified 
      [2015-05-04 22:01:38,581] - [task:1346] INFO - 100000 items were verified in 323.498317003 sec.the average number of ops - 309.120615135 per second 
      [2015-05-04 22:01:38,611] - [xdcrnewbasetests:2769] INFO - Verifying RevIds for Couchbase Cluster: C1, Master Ip: 172.23.106.45 -> Couchbase Cluster: C2, Master Ip: 172.23.106.47, bucket default 
      [2015-05-04 22:01:38,723] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 22:01:38,835] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 22:01:39,019] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 default 
      [2015-05-04 22:01:39,130] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 default 
      [2015-05-04 22:01:39,929] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 default 
      [2015-05-04 22:01:40,026] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 default 
      [2015-05-04 22:01:41,732] - [task:1446] INFO - RevID verification: in progress for default ... 
      [2015-05-04 22:01:41,733] - [xdcrnewbasetests:2769] INFO - Verifying RevIds for Couchbase Cluster: C1, Master Ip: 172.23.106.45 -> Couchbase Cluster: C2, Master Ip: 172.23.106.47, bucket sasl_bucket_1 
      [2015-05-04 22:01:41,864] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 22:01:42,043] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 22:01:42,224] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_1 
      [2015-05-04 22:01:42,362] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_1 
      [2015-05-04 22:01:42,963] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_1 
      [2015-05-04 22:01:43,741] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_1 
      [2015-05-04 22:01:46,641] - [task:1446] INFO - RevID verification: in progress for sasl_bucket_1 ... 
      [2015-05-04 22:01:46,642] - [xdcrnewbasetests:2769] INFO - Verifying RevIds for Couchbase Cluster: C1, Master Ip: 172.23.106.45 -> Couchbase Cluster: C2, Master Ip: 172.23.106.47, bucket sasl_bucket_2 
      [2015-05-04 22:01:46,793] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 22:01:46,965] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 22:01:47,233] - [data_helper:295] INFO - creating direct client 172.23.106.45:11210 sasl_bucket_2 
      [2015-05-04 22:01:47,388] - [data_helper:295] INFO - creating direct client 172.23.106.46:11210 sasl_bucket_2 
      [2015-05-04 22:01:47,637] - [data_helper:295] INFO - creating direct client 172.23.106.47:11210 sasl_bucket_2 
      [2015-05-04 22:01:47,776] - [data_helper:295] INFO - creating direct client 172.23.106.48:11210 sasl_bucket_2 
      [2015-05-04 22:01:53,037] - [task:1446] INFO - RevID verification: in progress for sasl_bucket_2 ... 
      [2015-05-04 22:03:34,892] - [task:1484] INFO - 50000 items have been verified 
      [2015-05-04 22:03:43,565] - [task:1484] INFO - 50000 items have been verified 
      [2015-05-04 22:03:53,318] - [task:1484] INFO - 50000 items have been verified 
      [2015-05-04 22:05:27,227] - [task:1484] INFO - 100000 items have been verified 
      [2015-05-04 22:05:27,229] - [task:1454] INFO - RevId Verification : 100000 existing items have been verified 
      [2015-05-04 22:05:27,229] - [task:1456] INFO - RevId Verification : 0 deleted items have been verified 
      [2015-05-04 22:05:27,231] - [task:1459] INFO - RevId Verification : 0 keys were apparently filtered out and not found in target bucket 
      [2015-05-04 22:05:44,009] - [task:1484] INFO - 100000 items have been verified 
      [2015-05-04 22:05:44,010] - [task:1454] INFO - RevId Verification : 100000 existing items have been verified 
      [2015-05-04 22:05:44,011] - [task:1456] INFO - RevId Verification : 0 deleted items have been verified 
      [2015-05-04 22:05:44,011] - [task:1459] INFO - RevId Verification : 0 keys were apparently filtered out and not found in target bucket 
      [2015-05-04 22:05:46,450] - [task:1484] INFO - 100000 items have been verified 
      [2015-05-04 22:05:46,450] - [task:1454] INFO - RevId Verification : 100000 existing items have been verified 
      [2015-05-04 22:05:46,450] - [task:1456] INFO - RevId Verification : 0 deleted items have been verified 
      [2015-05-04 22:05:46,450] - [task:1459] INFO - RevId Verification : 0 keys were apparently filtered out and not found in target bucket 
      FAIL 
      

      For over 20 mins the delete was not replicated -

       
      [2015-05-04 21:30:30,780] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, default bucket 
      [2015-05-04 21:30:31,488] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, sasl_bucket_1 bucket 
      [2015-05-04 21:30:32,001] - [xdcrnewbasetests:2031] INFO - Saw: vb_active_curr_items 350000 == 350000 expected on C1, sasl_bucket_2 bucket 
      [2015-05-04 21:30:32,492] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, default bucket 
      [2015-05-04 21:30:33,044] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, sasl_bucket_1 bucket 
      [2015-05-04 21:30:33,627] - [xdcrnewbasetests:2065] INFO - Saw: vb_replica_curr_items 350000 == 350000 expected on C1, sasl_bucket_2 bucket 
      [2015-05-04 21:30:34,125] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:39,208] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      [2015-05-04 21:30:44,274] - [xdcrnewbasetests:2020] WARNING - Not Ready: vb_active_curr_items 350001 == 350000 expected on C2, default bucket 
      :
      : 
      [2015-05-04 21:50:32,623] - [xdcrnewbasetests:2053] WARNING - Not Ready: vb_replica_curr_items 350001 == 350000 expected on C2, sasl_bucket_1 bucket 
      [2015-05-04 21:50:35,627] - [xdcrnewbasetests:2057] ERROR - ERROR: Timed-out waiting for replica item count to match 
      

      On .45 and .46, goxdcr is unaware of this deletion mismatch for >30 mins:

      changes_left is 0

       
       
      On 45: 
       
      StatisticsManager 2015-05-04T21:38:09.069-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      : 
      : 
       
      StatisticsManager 2015-05-04T22:06:29.084-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:33.002-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:33.524-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:39.065-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:43.007-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:43.526-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:49.068-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:53.000-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:06:53.522-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
       
      StatisticsManager 2015-05-04T21:38:09.069-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T21:38:09.070-07:00 [INFO] Stats for pipeline 66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1-246984394 
      dcp_66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1_172.23.106.45:11210_0": {"deletion_received_from_dcp": 7739, "docs_received_from_dcp": 7739, "expiry_received_from_dcp": 0, "set_received_from_dcp": 0}, 
      "dcp_66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1_172.23.106.45:11210_1": {"deletion_received_from_dcp": 52, "docs_received_from_dcp": 52, "expiry_received_from_dcp": 0, "set_received_from_dcp": 0}, 
       
      Deletion received from dcp does not add to 75000 
       
      On .46 
       
      StatisticsManager 2015-05-04T21:39:08.111-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T21:39:15.596-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T21:39:18.119-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T21:39:18.785-07:00 [INFO] total_doc=400000, docs_processed=399991, changes_left=9 
      : 
      : 
       
      StatisticsManager 2015-05-04T22:09:45.604-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:09:48.116-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
      StatisticsManager 2015-05-04T22:09:48.793-07:00 [INFO] total_doc=400000, docs_processed=400000, changes_left=0 
       
      "dcp_66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1_172.23.106.46:11210_0": {"deletion_received_from_dcp": 37500, "docs_received_from_dcp": 200002, "expiry_received_from_dcp": 0, "set_received_from_dcp": 162502}, 
       "dcp_66a3d7aa6f8d4d5040b7937144feeffa/sasl_bucket_1/sasl_bucket_1_172.23.106.46:11210_1": {"deletion_received_from_dcp": 37500, "docs_received_from_dcp": 199998, "expiry_received_from_dcp": 0, "set_received_from_dcp": 162498} 
       
      here it adds up to 75000 though. There were a total of 150K deletes. 
      

      Deletion undetected for a long period of time can be considered data loss. Hence raising as blocker.

      Attachments

        Issue Links

          No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

            People

              xiaomei Xiaomei Zhang (Inactive)
              apiravi Aruna Piravi (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty