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

[windows]Rebalance exited with reason {{bulk_set_vbucket_state_failed

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Duplicate
    • Affects Version/s: 2.0
    • Fix Version/s: 3.0
    • Component/s: couchbase-bucket
    • Security Level: Public
    • Labels:
      None
    • Environment:

      Description

      rebalance out 4->3 is failed

      2012-10-30 13:39:20.217 ns_orchestrator:4:info:message(ns_1@10.1.3.82) - Starting rebalance, KeepNodes = ['ns_1@10.1.3.84','ns_1@10.1.3.85',
      'ns_1@10.1.3.82'], EjectNodes = ['ns_1@10.1.3.87']

      2012-10-30 13:39:20.389 ns_rebalancer:0:info:message(ns_1@10.1.3.82) - Started rebalancing bucket bucket-0
      2012-10-30 13:39:21.108 ns_vbucket_mover:0:info:message(ns_1@10.1.3.82) - Bucket "bucket-0" rebalance does not seem to be swap rebalance
      2012-10-30 13:40:06.249 ns_memcached:4:info:message(ns_1@10.1.3.85) - Control connection to memcached on 'ns_1@10.1.3.85' disconnected: {{badmatch,
      {error,
      closed}},
      [

      {mc_client_binary, cmd_binary_vocal_recv, 5}

      ,

      {mc_client_binary, select_bucket, 2}

      ,

      {ns_memcached, ensure_bucket, 2}

      ,

      {ns_memcached, handle_info, 2}

      ,

      {gen_server, handle_msg, 5}

      ,

      {proc_lib, init_p_do_apply, 3}

      ]}
      2012-10-30 13:40:06.296 ns_port_server:0:info:message(ns_1@10.1.3.85) - Port server memcached on node 'ns_1@10.1.3.85' exited with status 255. Restarting. Messages: Tue Oct 30 13:39:43.873960 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 473, cookie 00000000059C3B80

      ...

      2012-10-30 13:40:11.546 ns_orchestrator:2:info:message(ns_1@10.1.3.82) - Rebalance exited with reason {{bulk_set_vbucket_state_failed,
      [{'ns_1@10.1.3.85',
      {'EXIT',
      {{badmatch,{error,closed,
      [

      {mc_client_binary, cmd_binary_vocal_recv,5}

      ,

      {mc_client_binary,select_bucket,2}

      ,

      {ns_memcached,ensure_bucket,2}

      ,

      {ns_memcached,handle_info,2}

      ,

      {gen_server,handle_msg,5},
      {proc_lib,init_p_do_apply,3}]},
      {gen_server,call,
      ['ns_memcached-bucket-0',
      {wait_for_checkpoint_persistence,530,2},
      infinity]}},
      {gen_server,call,
      [{'janitor_agent-bucket-0', 'ns_1@10.1.3.85'},
      {if_rebalance,<0.27039.51>,
      {update_vbucket_state,268,replica,
      undefined,'ns_1@10.1.3.82'}},
      infinity]}}}},
      {'ns_1@10.1.3.84',
      {'EXIT',
      {{{{unexpected_reason,
      badmatch,{error,closed,
      [{mc_binary,quick_stats_recv,3},
      {mc_binary,quick_stats_loop,5},
      {mc_binary,quick_stats,5},
      {mc_client_binary, get_zero_open_checkpoint_vbuckets,3},
      {ebucketmigrator_srv,handle_call,3},
      {gen_server,handle_msg,5}

      ,

      {proc_lib,init_p_do_apply,3}]}},
      [{misc,executing_on_new_process,1},
      {tap_replication_manager, change_vbucket_filter,4},
      {tap_replication_manager, '-do_set_incoming_replication_map/3-lc$^5/1-5-', 2},
      {tap_replication_manager, do_set_incoming_replication_map,3},
      {tap_replication_manager,handle_call,3},
      {gen_server,handle_msg,5},
      {proc_lib,init_p_do_apply,3}

      ]},
      {gen_server,call,
      ['tap_replication_manager-bucket-0',

      {change_vbucket_replication,268, 'ns_1@10.1.3.85'}

      ,
      infinity]}},
      {gen_server,call,
      [

      {'janitor_agent-bucket-0', 'ns_1@10.1.3.84'}

      ,
      {if_rebalance,<0.27039.51>,
      {update_vbucket_state,268,replica,
      undefined,'ns_1@10.1.3.85'}},
      infinity]}}}}]},
      [

      {janitor_agent,bulk_set_vbucket_state,4}

      ,

      {ns_vbucket_mover, update_replication_post_move,3}

      ,

      {ns_vbucket_mover,handle_info,2}

      ,

      {gen_server,handle_msg,5}

      ,

      {proc_lib,init_p_do_apply,3}

      ]}

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

        Activity

        Show
        iryna iryna added a comment - logs: cbcollect: https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info82.zip https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info83.zip https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info84.zip https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info85.zip https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info86.zip https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/info87.zip diags: https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-82.txt.gz https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-83.txt.gz https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-84.txt.gz https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-85.txt.gz https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-86.txt.gz https://s3.amazonaws.com/bugdb/jira/MB-7060/70bb8e31/ns-diag-87.txt.gz
        Hide
        alkondratenko Aleksey Kondratenko (Inactive) added a comment -

        Memcached decided to exit. Doesn't seem like assert however.

        [error_logger:error,2012-10-30T13:40:06.389,ns_1@10.1.3.85:error_logger<0.5.0>:ale_error_logger_handler:log_msg:76]** Generic server <0.13900.16> terminating

          • Last message in was {#Port<0.787088>,
            Unknown macro: {exit_status,255}

            }

          • When Server state ==
            Unknown macro: {state,#Port<0.787088>,memcached, {["Tue Oct 30 13:39:56.764585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2905 - disconnected", "Tue Oct 30 13:39:55.795835 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 268, cookie 0000000005A0E840", "Tue Oct 30 13:39:55.342710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:55.342710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:55.217710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 411", "Tue Oct 30 13:39:55.202085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 411, ", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 411", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 411", "Tue Oct 30 13:39:55.014585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:54.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2902\""], ["Tue Oct 30 13:39:43.873960 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 473, cookie 00000000059C3B80", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2890\"", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_408\"", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_408_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_408 - Clear the tap queues by force", "Tue Oct 30 13:39:44.608335 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2888 - disconnected", "Tue Oct 30 13:39:44.795835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2888\"", "Tue Oct 30 13:39:44.795835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:44.952085 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2892 - disconnected", "Tue Oct 30 13:39:45.045835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2892\"", "Tue Oct 30 13:39:45.733335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:46.139585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:46.139585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 409", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:46.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 409", "Tue Oct 30 13:39:46.686460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 409, ", "Tue Oct 30 13:39:46.686460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 409", "Tue Oct 30 13:39:46.967710 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2891 - disconnected", "Tue Oct 30 13:39:47.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:47.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2891\"", "Tue Oct 30 13:39:47.827085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:47.842710 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 474, cookie 0000000005A0F8C0", "Tue Oct 30 13:39:47.889585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Connection is closed by force.", "Tue Oct 30 13:39:48.139585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2894 - disconnected", "Tue Oct 30 13:39:48.202085 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2893 - disconnected", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_VBUCKET_SET with vbucket 409 and state \"pending\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2893\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2895\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Clear the tap queues by force", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2894\"", "Tue Oct 30 13:39:48.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - VBucket <409> is going dead to complete vbucket takeover.", "Tue Oct 30 13:39:48.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_VBUCKET_SET with vbucket 409 and state \"active\"", "Tue Oct 30 13:39:48.280210 Pacific Daylight Time 3: TAP takeover is completed. Disconnecting tap stream <eq_tapq:rebalance_409>", "Tue Oct 30 13:39:48.280210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - disconnected", "Tue Oct 30 13:39:48.405210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Connection is closed by force.", "Tue Oct 30 13:39:48.405210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - disconnected", "Tue Oct 30 13:39:48.420835 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2898 - disconnected", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2897\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_409\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2898\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Clear the tap queues by force", "Tue Oct 30 13:39:48.920835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:49.592710 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2896 - disconnected", "Tue Oct 30 13:39:49.858335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:49.858335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2896\"", "Tue Oct 30 13:39:50.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 410", "Tue Oct 30 13:39:50.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:50.530210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:50.530210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 410", "Tue Oct 30 13:39:50.561460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 410, ", "Tue Oct 30 13:39:50.561460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 410", "Tue Oct 30 13:39:50.577085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:50.967710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:50.967710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:51.842710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:51.998960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Connection is closed by force.", "Tue Oct 30 13:39:52.014585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2900 - disconnected", "Tue Oct 30 13:39:52.170835 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2899 - disconnected", "Tue Oct 30 13:39:52.389585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2903 - disconnected", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2899\"", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2900\"", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2901\"", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2903\"", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Clear the tap queues by force", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:52.608335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:52.608335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_VBUCKET_SET with vbucket 410 and state \"pending\"", "Tue Oct 30 13:39:52.623960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - VBucket <410> is going dead to complete vbucket takeover.", "Tue Oct 30 13:39:52.623960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_VBUCKET_SET with vbucket 410 and state \"active\"", "Tue Oct 30 13:39:52.639585 Pacific Daylight Time 3: TAP takeover is completed. Disconnecting tap stream <eq_tapq:rebalance_410>", "Tue Oct 30 13:39:52.639585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - disconnected", "Tue Oct 30 13:39:52.655210 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_410\"", "Tue Oct 30 13:39:52.655210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Clear the tap queues by force", "Tue Oct 30 13:39:52.670835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:52.827085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Connection is closed by force.", "Tue Oct 30 13:39:53.483335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:53.483335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2904\"", "Tue Oct 30 13:39:53.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:54.014585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:54.405210 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2902 - disconnected"]}, undefined,[],0,true}
          • Reason for termination ==
          • {abnormal,255}

        Note: diags as of now also have memcached logs at the end

        Show
        alkondratenko Aleksey Kondratenko (Inactive) added a comment - Memcached decided to exit. Doesn't seem like assert however. [error_logger:error,2012-10-30T13:40:06.389,ns_1@10.1.3.85:error_logger<0.5.0>:ale_error_logger_handler:log_msg:76] ** Generic server <0.13900.16> terminating Last message in was {#Port<0.787088>, Unknown macro: {exit_status,255} } When Server state == Unknown macro: {state,#Port<0.787088>,memcached, {["Tue Oct 30 13:39:56.764585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2905 - disconnected", "Tue Oct 30 13:39:55.795835 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 268, cookie 0000000005A0E840", "Tue Oct 30 13:39:55.342710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:55.342710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:55.217710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 411", "Tue Oct 30 13:39:55.202085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 411, ", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 411", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:55.045835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_411_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 411", "Tue Oct 30 13:39:55.014585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:54.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2902\""], ["Tue Oct 30 13:39:43.873960 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 473, cookie 00000000059C3B80", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2890\"", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_408\"", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_408_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:44.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_408 - Clear the tap queues by force", "Tue Oct 30 13:39:44.608335 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2888 - disconnected", "Tue Oct 30 13:39:44.795835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2888\"", "Tue Oct 30 13:39:44.795835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:44.952085 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2892 - disconnected", "Tue Oct 30 13:39:45.045835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2892\"", "Tue Oct 30 13:39:45.733335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:46.139585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:46.139585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 409", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:46.248960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:46.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 409", "Tue Oct 30 13:39:46.686460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 409, ", "Tue Oct 30 13:39:46.686460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 409", "Tue Oct 30 13:39:46.967710 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2891 - disconnected", "Tue Oct 30 13:39:47.170835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:47.170835 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2891\"", "Tue Oct 30 13:39:47.827085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:47.842710 Pacific Daylight Time 3: Notified the completion of checkpoint persistence for vbucket 474, cookie 0000000005A0F8C0", "Tue Oct 30 13:39:47.889585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Connection is closed by force.", "Tue Oct 30 13:39:48.139585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2894 - disconnected", "Tue Oct 30 13:39:48.202085 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2893 - disconnected", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_VBUCKET_SET with vbucket 409 and state \"pending\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2893\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2895\"", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.82' - Clear the tap queues by force", "Tue Oct 30 13:39:48.233335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2894\"", "Tue Oct 30 13:39:48.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - VBucket <409> is going dead to complete vbucket takeover.", "Tue Oct 30 13:39:48.264585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Sending TAP_VBUCKET_SET with vbucket 409 and state \"active\"", "Tue Oct 30 13:39:48.280210 Pacific Daylight Time 3: TAP takeover is completed. Disconnecting tap stream <eq_tapq:rebalance_409>", "Tue Oct 30 13:39:48.280210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - disconnected", "Tue Oct 30 13:39:48.405210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Connection is closed by force.", "Tue Oct 30 13:39:48.405210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - disconnected", "Tue Oct 30 13:39:48.420835 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2898 - disconnected", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2897\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_409\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2898\"", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_409_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:48.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_409 - Clear the tap queues by force", "Tue Oct 30 13:39:48.920835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:49.592710 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2896 - disconnected", "Tue Oct 30 13:39:49.858335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:49.858335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2896\"", "Tue Oct 30 13:39:50.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Schedule the backfill for vbucket 410", "Tue Oct 30 13:39:50.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:50.530210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:50.530210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"initial_vbucket_stream\" and vbucket 410", "Tue Oct 30 13:39:50.561460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Backfill is completed with VBuckets 410, ", "Tue Oct 30 13:39:50.561460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Sending TAP_OPAQUE with command \"close_backfill\" and vbucket 410", "Tue Oct 30 13:39:50.577085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:50.967710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:50.967710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:51.842710 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:51.998960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Connection is closed by force.", "Tue Oct 30 13:39:52.014585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2900 - disconnected", "Tue Oct 30 13:39:52.170835 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2899 - disconnected", "Tue Oct 30 13:39:52.389585 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2903 - disconnected", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2899\"", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2900\"", "Tue Oct 30 13:39:52.436460 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2901\"", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2903\"", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.82' - Clear the tap queues by force", "Tue Oct 30 13:39:52.452085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_OPAQUE with command \"opaque_enable_auto_nack\" and vbucket 0", "Tue Oct 30 13:39:52.608335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_OPAQUE with command \"enable_checkpoint_sync\" and vbucket 0", "Tue Oct 30 13:39:52.608335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_VBUCKET_SET with vbucket 410 and state \"pending\"", "Tue Oct 30 13:39:52.623960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - VBucket <410> is going dead to complete vbucket takeover.", "Tue Oct 30 13:39:52.623960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Sending TAP_VBUCKET_SET with vbucket 410 and state \"active\"", "Tue Oct 30 13:39:52.639585 Pacific Daylight Time 3: TAP takeover is completed. Disconnecting tap stream <eq_tapq:rebalance_410>", "Tue Oct 30 13:39:52.639585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - disconnected", "Tue Oct 30 13:39:52.655210 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:rebalance_410\"", "Tue Oct 30 13:39:52.655210 Pacific Daylight Time 3: TAP (Producer) eq_tapq:rebalance_410 - Clear the tap queues by force", "Tue Oct 30 13:39:52.670835 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - disconnected, keep alive for 300 seconds", "Tue Oct 30 13:39:52.827085 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Connection is closed by force.", "Tue Oct 30 13:39:53.483335 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.87 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:53.483335 Pacific Daylight Time 3: Schedule cleanup of \"eq_tapq:anon_2904\"", "Tue Oct 30 13:39:53.498960 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_building_410_'ns_1@10.1.3.84' - Clear the tap queues by force", "Tue Oct 30 13:39:54.014585 Pacific Daylight Time 3: TAP (Producer) eq_tapq:replication_ns_1@10.1.3.84 - Sending TAP_OPAQUE with command \"complete_vb_filter_change\" and vbucket 0", "Tue Oct 30 13:39:54.405210 Pacific Daylight Time 3: TAP (Consumer) eq_tapq:anon_2902 - disconnected"]}, undefined,[],0,true} Reason for termination == {abnormal,255} Note: diags as of now also have memcached logs at the end
        Hide
        chiyoung Chiyoung Seo added a comment -

        I looked at the memcached logs, but didn't find any exceptions, warning, or assertions. Looks like the actual error was masked by the exit code 255. It's quite difficult to diagnose this issue without the actual error info and code.

        Let's keep this open, but we can move it to 2.0.1 if we don't see this issue frequently on windows.

        Show
        chiyoung Chiyoung Seo added a comment - I looked at the memcached logs, but didn't find any exceptions, warning, or assertions. Looks like the actual error was masked by the exit code 255. It's quite difficult to diagnose this issue without the actual error info and code. Let's keep this open, but we can move it to 2.0.1 if we don't see this issue frequently on windows.
        Hide
        mikew Mike Wiederhold added a comment -

        I just want to note here that one way we can try to find this crash is to attach wingdb to each memcached process and wait for the crash to happen. This will allow us to get a stack trace.

        Show
        mikew Mike Wiederhold added a comment - I just want to note here that one way we can try to find this crash is to attach wingdb to each memcached process and wait for the crash to happen. This will allow us to get a stack trace.
        Hide
        mikew Mike Wiederhold added a comment -

        Duplicate of MB-7632

        Show
        mikew Mike Wiederhold added a comment - Duplicate of MB-7632
        Hide
        maria Maria McDuff (Inactive) added a comment -

        closing as dupes.

        Show
        maria Maria McDuff (Inactive) added a comment - closing as dupes.

          People

          • Assignee:
            mikew Mike Wiederhold
            Reporter:
            iryna iryna
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Gerrit Reviews

              There are no open Gerrit changes