http://qa.hq.northscale.net/job/windows32_rebalance-kv/9/consoleFull
./testrunner -i /tmp/4-w-32.ini get-cbcollect-info=True -t rebalancetests.IncrementalRebalanceOut.test_load,replica=1,delete-ratio=0,expiry-ratio=0
password=password&ejectedNodes=&user=Administrator&knownNodes=ns_1%4010.3.2.179%2Cns_1%4010.3.2.185%2Cns_1%4010.3.2.178%2Cns_1%4010.3.2.183
[2013-05-16 04:40:53,799] - [rest_client:929] INFO - rebalance operation started
[2013-05-16 04:40:53,991] - [rest_client:1031] INFO - rebalance percentage : 0 %
[2013-05-16 04:40:55,037] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:40:57,191] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:40:58,428] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:40:59,674] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:00,790] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:02,902] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:04,931] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:06,048] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:08,102] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:10,423] - [rest_client:1031] INFO - rebalance percentage : 0.0 %
[2013-05-16 04:41:11,575] - [rest_client:1014] ERROR -
{u'status': u'none', u'errorMessage': u'Rebalance failed. See logs for detailed reason. You can try rebalance again.'}
- rebalance failed
[2013-05-16 04:41:11,575] - [rest_client:1015] INFO - Latest logs from UI:
[2013-05-16 04:41:11,736] - [rest_client:1016] ERROR - {u'node': u'ns_1@10.3.2.178', u'code': 2, u'text': u"Rebalance exited with reason {bulk_set_vbucket_state_failed,\n [{'ns_1@10.3.2.179',\n {'EXIT',\n {{badmatch,wrong_rebalancer_pid},\n [
{janitor_agent,set_vbucket_state,7},\n {janitor_agent,\n '-bulk_set_vbucket_state/4-fun-0-',4},\n {misc,'-parallel_map/3-fun-0-',4}]}}}]}\n", u'shortText': u'message', u'module': u'ns_orchestrator', u'tstamp': 1368704449014, u'type': u'info'}
[2013-05-16 04:41:11,736] -
[rest_client:1016] ERROR - {u'node': u'ns_1@10.3.2.178', u'code': 0, u'text': u"<0.8010.5> exited with {bulk_set_vbucket_state_failed,\n [{'ns_1@10.3.2.179',\n {'EXIT',\n {{badmatch,wrong_rebalancer_pid},\n [{janitor_agent,set_vbucket_state,7}
,\n
{janitor_agent,\n '-bulk_set_vbucket_state/4-fun-0-',4}
,\n
{misc,'-parallel_map/3-fun-0-',4}
]}}}]}", u'shortText': u'message', u'module': u'ns_vbucket_mover', u'tstamp': 1368704446155, u'type': u'critical'}
[2013-05-16 04:41:11,736] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.179', u'code': 0, u'text': u'Port server memcached on node \'babysitter_of_ns_1@127.0.0.1\' exited with status 255. Restarting. Messages: Thu May 16 04:29:32.201380 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Schedule the backfill for vbucket 427\nThu May 16 04:29:32.201380 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Sending TAP_OPAQUE with command "opaque_enable_auto_nack" and vbucket 0\nThu May 16 04:29:32.208215 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Sending TAP_OPAQUE with command "enable_checkpoint_sync" and vbucket 0\nThu May 16 04:29:32.213098 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Sending TAP_OPAQUE with command "initial_vbucket_stream" and vbucket 427\nThu May 16 04:29:32.222863 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Backfill is completed with VBuckets 427, \nThu May 16 04:29:32.222863 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Sending TAP_OPAQUE with command "close_backfill" and vbucket 427\nThu May 16 04:29:32.267782 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.183\' - Sending TAP_OPAQUE with command "opaque_enable_auto_nack" and vbucket 0\nThu May 16 04:29:32.267782 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.183\' - Sending TAP_OPAQUE with command "enable_checkpoint_sync" and vbucket 0\nThu May 16 04:29:32.315630 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:32.553896 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - disconnected, keep alive for 300 seconds\nThu May 16 04:29:32.565614 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Connection is closed by force\nThu May 16 04:29:32.693536 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - Sending TAP_OPAQUE with command "opaque_enable_auto_nack" and vbucket 0\nThu May 16 04:29:32.693536 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - Sending TAP_OPAQUE with command "enable_checkpoint_sync" and vbucket 0\nThu May 16 04:29:32.693536 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - Sending TAP_VBUCKET_SET with vbucket 427 and state "pending"\nThu May 16 04:29:32.694512 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1608"\nThu May 16 04:29:32.697442 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.185\' - Clear the tap queues by force\nThu May 16 04:29:32.705254 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 774, cookie 044D50E0\nThu May 16 04:29:32.708183 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - VBucket <427> is going dead to complete vbucket takeover\nThu May 16 04:29:32.715995 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - Sending TAP_VBUCKET_SET with vbucket 427 and state "active"\nThu May 16 04:29:32.719901 Pacific Daylight Time 3: (bucket-0) TAP takeover is completed. Disconnecting tap stream <eq_tapq:rebalance_427>\nThu May 16 04:29:32.720878 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - disconnected\nThu May 16 04:29:32.723807 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:rebalance_427"\nThu May 16 04:29:32.724784 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:rebalance_427 - Clear the tap queues by force\nThu May 16 04:29:32.742361 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.183\' - disconnected, keep alive for 300 seconds\nThu May 16 04:29:32.751149 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.183\' - Connection is closed by force\nThu May 16 04:29:32.817551 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1609 - disconnected\nThu May 16 04:29:32.983556 Pacific Daylight Time 3: (bucket-0) Deletion of vbucket 427 was completed.\nThu May 16 04:29:33.097807 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1612 - disconnected\nThu May 16 04:29:33.214010 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1610"\nThu May 16 04:29:33.214010 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1609"\nThu May 16 04:29:33.214010 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_building_427_\'ns_1@10.3.2.183\' - Clear the tap queues by force\nThu May 16 04:29:33.214010 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:33.214010 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1612"\nThu May 16 04:29:33.335096 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1611 - disconnected\nThu May 16 04:29:33.348767 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1611"\nThu May 16 04:29:33.401498 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 772, cookie 044D4960\nThu May 16 04:29:33.546020 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1614 - disconnected\nThu May 16 04:29:33.734485 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1613 - disconnected\nThu May 16 04:29:33.883889 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1613"\nThu May 16 04:29:33.883889 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1614"\nThu May 16 04:29:33.883889 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:33.900490 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1615 - disconnected\nThu May 16 04:29:34.011811 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1615"\nThu May 16 04:29:34.022552 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 771, cookie 044D4D20\nThu May 16 04:29:34.139732 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:34.308667 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1616 - disconnected\nThu May 16 04:29:34.412176 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1616"\nThu May 16 04:29:34.445377 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 770, cookie 044D5860\nThu May 16 04:29:34.524473 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1618 - disconnected\nThu May 16 04:29:34.547909 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1617 - disconnected\nThu May 16 04:29:34.793011 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1617"\nThu May 16 04:29:34.793011 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1618"\nThu May 16 04:29:34.793011 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:34.805705 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 769, cookie 044D5860\nThu May 16 04:29:34.942415 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1619 - disconnected\nThu May 16 04:29:34.976593 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1619"\nThu May 16 04:29:35.003935 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1620 - disconnected\nThu May 16 04:29:35.162128 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1621 - disconnected\nThu May 16 04:29:35.178728 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1620"\nThu May 16 04:29:35.178728 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1621"\nThu May 16 04:29:35.178728 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:35.595694 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:31:37.747055 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:31:37.747055 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=234 rev=2\nThu May 16 04:34:13.673599 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:13.673599 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=269 rev=4\nThu May 16 04:34:27.262573 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:27.262573 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=702 rev=3\nThu May 16 04:34:37.990402 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:37.990402 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=816 rev=4\nThu May 16 04:34:41.872966 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:41.872966 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=865 rev=4\nThu May 16 04:40:07.491773 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - disconnected, keep alive for 300 seconds\nThu May 16 04:40:07.538645 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1027 - disconnected\nThu May 16 04:40:07.594306 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1027"\nThu May 16 04:40:07.600165 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_4 - disconnected\nThu May 16 04:40:07.602118 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_18 - disconnected\nThu May 16 04:40:07.623601 Pacific Daylight Time 3: (bucket-0) Shutting down tap connections!\nThu May 16 04:40:07.623601 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_4"\nThu May 16 04:40:07.624577 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.183"\nThu May 16 04:40:07.625554 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.178"\nThu May 16 04:40:07.625554 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.183 - Clear the tap queues by force\nThu May 16 04:40:07.625554 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_18"\nThu May 16 04:40:07.626530 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.185"\nThu May 16 04:40:07.626530 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.178 - Clear the tap queues by force\nThu May 16 04:40:07.627507 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Clear the tap queues by force\nThu May 16 04:40:33.087881 Pacific Daylight Time 3: (bucket-0) Warning: failed to load the engine session stats due to IO exception "basic_ios::clear"\nThu May 16 04:40:33.087881 Pacific Daylight Time 3: (bucket-0) Failed to load mutation log, falling back to key dump\nThu May 16 04:40:33.087881 Pacific Daylight Time 3: Extension support isn\'t implemented in this version of bucket_engine\nThu May 16 04:40:33.088858 Pacific Daylight Time 3: (bucket-0) metadata loaded in 1236 usec\nThu May 16 04:40:33.089834 Pacific Daylight Time 3: (bucket-0) warmup completed in 1709 usec\nThu May 16 04:40:35.654123 Pacific Daylight Time 3: (bucket-0) Connection closed by mccouch\nThu May 16 04:40:35.654123 Pacific Daylight Time 3: (bucket-0) Resetting connection to mccouch, lastReceivedCommand = notify_vbucket_update lastSentCommand = notify_vbucket_update currentCommand =notify_vbucket_update\nMUTEX ERROR: Failed to acquire lock: Invalid argument\n\nThis application has requested the Runtime to terminate it in an unusual way.\nPlease contact the application\'s support team for more information.\nThu May 16 04:40:36.013475 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1622 - Reset vbucket 938 was completed succecssfully.\nThu May 16 04:40:36.444112 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1623 - Reset vbucket 682 was completed succecssfully.\nThu May 16 04:40:43.419251 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1624 - Reset vbucket 937 was completed succecssfully.', u'shortText': u'message', u'module': u'ns_log', u'tstamp': 1368704444183, u'type': u'info'}
[2013-05-16 04:41:11,737] - [rest_client:1016] ERROR - {u'node': u'ns_1@10.3.2.179', u'code': 4, u'text': u"Control connection to memcached on 'ns_1@10.3.2.179' disconnected: {badmatch,\n {error,\n closed}}", u'shortText': u'message', u'module': u'ns_memcached', u'tstamp': 1368704444167, u'type': u'info'}
[2013-05-16 04:41:11,737] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.183', u'code': 0, u'text': u'Port server memcached on node \'babysitter_of_ns_1@127.0.0.1\' exited with status 255. Restarting. Messages: Thu May 16 04:29:15.442145 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3313 - disconnected\nThu May 16 04:29:15.624751 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 87, cookie 044041E0\nThu May 16 04:29:15.669670 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3317 - disconnected\nThu May 16 04:29:15.862040 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3316 - disconnected\nThu May 16 04:29:16.100306 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3320 - disconnected\nThu May 16 04:29:16.126672 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3313"\nThu May 16 04:29:16.127648 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3316"\nThu May 16 04:29:16.128625 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:16.133507 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3317"\nThu May 16 04:29:16.135460 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3320"\nThu May 16 04:29:16.220416 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 86, cookie 04405860\nThu May 16 04:29:16.252640 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3315 - disconnected\nThu May 16 04:29:17.141255 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3315"\nThu May 16 04:29:17.169574 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 433, cookie 04404B40\nThu May 16 04:29:17.269177 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:17.290660 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3319 - disconnected\nThu May 16 04:29:17.524043 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3319"\nThu May 16 04:29:17.652941 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3321 - disconnected\nThu May 16 04:29:17.821876 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3318 - disconnected\nThu May 16 04:29:18.312079 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3318"\nThu May 16 04:29:18.312079 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3321"\nThu May 16 04:29:18.312079 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:19.443842 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 432, cookie 04404B40\nThu May 16 04:29:19.913539 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 85, cookie 044052C0\nThu May 16 04:29:19.920374 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3322 - disconnected\nThu May 16 04:29:19.941857 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 431, cookie 04405680\nThu May 16 04:29:20.106886 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3323 - disconnected\nThu May 16 04:29:20.277773 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3325 - disconnected\nThu May 16 04:29:20.415460 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3322"\nThu May 16 04:29:20.416436 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3323"\nThu May 16 04:29:20.416436 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3325"\nThu May 16 04:29:20.416436 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Sending TAP_OPAQUE with command "complete_vb_filter_change" and vbucket 0\nThu May 16 04:29:20.758211 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3324 - disconnected\nThu May 16 04:29:21.398795 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3326 - disconnected\nThu May 16 04:29:21.637061 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3324"\nThu May 16 04:29:21.637061 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3326"\nThu May 16 04:29:21.936847 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3327 - disconnected\nThu May 16 04:29:22.640903 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3327"\nThu May 16 04:29:23.123294 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3328 - disconnected\nThu May 16 04:29:23.646698 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3328"\nThu May 16 04:29:24.432781 Pacific Daylight Time 3: (bucket-0) Notified the completion of checkpoint persistence for vbucket 427, cookie 04405860\nThu May 16 04:29:24.720848 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3329 - disconnected\nThu May 16 04:29:25.651453 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3329"\nThu May 16 04:31:32.042777 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:31:32.042777 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=70 rev=3\nThu May 16 04:32:06.188053 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:32:06.188053 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=345 rev=3\nThu May 16 04:32:14.777347 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:32:14.777347 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=391 rev=3\nThu May 16 04:32:32.463715 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:32:32.463715 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=504 rev=3\nThu May 16 04:32:43.120259 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:32:43.120259 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=567 rev=3\nThu May 16 04:32:43.849705 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:32:43.849705 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=574 rev=4\nThu May 16 04:34:08.487842 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:08.487842 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=154 rev=4\nThu May 16 04:34:40.688906 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:40.689883 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=454 rev=4\nThu May 16 04:34:41.123449 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:41.123449 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=456 rev=4\nThu May 16 04:34:51.585670 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:51.586646 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=511 rev=5\nThu May 16 04:34:52.812154 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:52.812154 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=518 rev=4\nThu May 16 04:34:59.385952 Pacific Daylight Time 3: (bucket-0) Received error[86] from mccouch for unknown\nThu May 16 04:34:59.386928 Pacific Daylight Time 3: (bucket-0) Retry notify CouchDB of update, vbucket=550 rev=5\nThu May 16 04:39:57.487966 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - disconnected, keep alive for 300 seconds\nThu May 16 04:39:57.588545 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.179 - disconnected, keep alive for 300 seconds\nThu May 16 04:39:57.780916 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_2904 - disconnected\nThu May 16 04:39:57.783845 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.178 - disconnected, keep alive for 300 seconds\nThu May 16 04:39:57.788728 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_1541 - disconnected\nThu May 16 04:39:57.826811 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_131 - disconnected\nThu May 16 04:39:57.913720 Pacific Daylight Time 3: (bucket-0) Shutting down tap connections!\nThu May 16 04:39:57.913720 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.178"\nThu May 16 04:39:57.913720 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_131"\nThu May 16 04:39:57.913720 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.178 - Clear the tap queues by force\nThu May 16 04:39:57.914696 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_1541"\nThu May 16 04:39:57.914696 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.179"\nThu May 16 04:39:57.916649 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_2904"\nThu May 16 04:39:57.916649 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.179 - Clear the tap queues by force\nThu May 16 04:39:57.916649 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:replication_ns_1@10.3.2.185"\nThu May 16 04:39:57.919579 Pacific Daylight Time 3: (bucket-0) TAP (Producer) eq_tapq:replication_ns_1@10.3.2.185 - Clear the tap queues by force\nThu May 16 04:40:23.080161 Pacific Daylight Time 3: (bucket-0) Warning: failed to load the engine session stats due to IO exception "basic_ios::clear"\nThu May 16 04:40:23.080161 Pacific Daylight Time 3: (bucket-0) Failed to load mutation log, falling back to key dump\nThu May 16 04:40:23.080161 Pacific Daylight Time 3: Extension support isn\'t implemented in this version of bucket_engine\nThu May 16 04:40:23.081137 Pacific Daylight Time 3: (bucket-0) metadata loaded in 1162 usec\nThu May 16 04:40:23.082114 Pacific Daylight Time 3: (bucket-0) warmup completed in 1738 usec\nThu May 16 04:40:26.572125 Pacific Daylight Time 3: (bucket-0) Connection closed by mccouch\nThu May 16 04:40:26.572125 Pacific Daylight Time 3: (bucket-0) Resetting connection to mccouch, lastReceivedCommand = notify_vbucket_update lastSentCommand = notify_vbucket_update currentCommand =notify_vbucket_update\nMUTEX ERROR: Failed to acquire lock: Invalid argument\n\nThis application has requested the Runtime to terminate it in an unusual way.\nPlease contact the application\'s support team for more information.\nThu May 16 04:40:26.785978 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3330 - Reset vbucket 596 was completed succecssfully.\nThu May 16 04:40:37.310695 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3331 - Reset vbucket 595 was completed succecssfully.\nThu May 16 04:40:37.419087 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3331 - disconnected\nThu May 16 04:40:37.419087 Pacific Daylight Time 3: (bucket-0) TAP (Consumer) eq_tapq:anon_3330 - disconnected\nThu May 16 04:40:38.198334 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3330"\nThu May 16 04:40:38.198334 Pacific Daylight Time 3: (bucket-0) Schedule cleanup of "eq_tapq:anon_3331"', u'shortText': u'message', u'module': u'ns_log', u'tstamp': 1368704438866, u'type': u'info'}
[2013-05-16 04:41:11,738] - [rest_client:1016] ERROR - {u'node': u'ns_1@10.3.2.183', u'code': 4, u'text': u"Control connection to memcached on 'ns_1@10.3.2.183' disconnected: {badmatch,\n {error,\n closed}}", u'shortText': u'message', u'module': u'ns_memcached', u'tstamp': 1368704438788, u'type': u'info'}
[2013-05-16 04:41:11,738] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.185', u'code': 1, u'text': u'Bucket "bucket-0" loaded on node \'ns_1@10.3.2.185\' in 0 seconds.', u'shortText': u'message', u'module': u'ns_memcached', u'tstamp': 1368704436520, u'type': u'info'}
[2013-05-16 04:41:11,739] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.185', u'code': 3, u'text': u'Node ns_1@10.3.2.185 joined cluster', u'shortText': u'message', u'module': u'ns_cluster', u'tstamp': 1368704435895, u'type': u'info'}
[2013-05-16 04:41:11,741] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.185', u'code': 4, u'text': u"Node 'ns_1@10.3.2.185' saw that node 'ns_1@10.3.2.183' came up. Tags: []", u'shortText': u'node up', u'module': u'ns_node_disco', u'tstamp': 1368704435895, u'type': u'info'}
[2013-05-16 04:41:11,742] - [rest_client:1016] ERROR -
{u'node': u'ns_1@10.3.2.185', u'code': 4, u'text': u"Node 'ns_1@10.3.2.185' saw that node 'ns_1@10.3.2.179' came up. Tags: []", u'shortText': u'node up', u'module': u'ns_node_disco', u'tstamp': 1368704435707, u'type': u'info'}
ERROR
Task
Major