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

System Test : Memcached disconnect seen during a rebalance operation

    XMLWordPrintable

Details

    Description

      Build : 6.5.0-2647
      Test : -test tests/2i/test_idx_rebalance_replica_vulcan_kv_opt.yml -scope tests/2i/scope_idx_rebalance_replica_vulcan.yml
      Scale : 3
      Iteration : 2nd

      During the rebalance operation where 2 indexer nodes were being removed from the cluster, a memcached disconnect was seen on a data node. The rebalance operation wasn't impacted however.

      Following error is seen in the diag logs on the UI:

      Control connection to memcached on 'ns_1@172.23.104.18' disconnected: {{nocatch,
      {error,
      closed}},
      [{mc_binary,
      recv_with_data,
      4,
      [{file,
      "src/mc_binary.erl"},
      {line,
      45}]},
      {mc_binary,
      quick_stats_recv,
      3,
      [{file,
      "src/mc_binary.erl"},
      {line,
      52}]},
      {mc_binary,
      quick_stats_loop_enter,
      5,
      [{file,
      "src/mc_binary.erl"},
      {line,
      104}]},
      {mc_binary,
      quick_stats,
      5,
      [{file,
      "src/mc_binary.erl"},
      {line,
      89}]},
      {ns_memcached,
      do_handle_call,
      3,
      [{file,
      "src/ns_memcached.erl"},
      {line,
      568}]},
      {ns_memcached,
      worker_loop,
      3,
      [{file,
      "src/ns_memcached.erl"},
      {line,
      226}]},
      {proc_lib,
      init_p_do_apply,
      3,
      [{file,
      "proc_lib.erl"},
      {line,
      247}]}]}
      

      On 172.23.104.18, around the same time, following is seen in babysitter.log :

      memcached<0.106.0>: 2019-03-19T19:30:34.989884-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:1005
       
      [ns_server:info,2019-03-19T19:30:35.587-07:00,babysitter_of_ns_1@127.0.0.1:<0.106.0>:ns_port_server:log:224]memcached<0.106.0>: 2019-03-19T19:30:35.385056-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:772
      memcached<0.106.0>: 2019-03-19T19:30:35.385903-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:772
      memcached<0.106.0>: 2019-03-19T19:30:35.388878-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:772
      memcached<0.106.0>: 2019-03-19T19:30:35.395777-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:772
      memcached<0.106.0>: 2019-03-19T19:30:35.396811-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:772
      memcached<0.106.0>: 2019-03-19T19:30:35.396863-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:1005
       
      [ns_server:info,2019-03-19T19:30:35.908-07:00,babysitter_of_ns_1@127.0.0.1:<0.106.0>:ns_port_server:log:224]memcached<0.106.0>: 2019-03-19T19:30:35.707057-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:1005
      memcached<0.106.0>: 2019-03-19T19:30:35.773643-07:00 WARNING (other-1) Slow runtime for 'Updating stat snapshot on disk' on thread writer_worker_2: 401 ms
       
      [ns_server:info,2019-03-19T19:30:36.347-07:00,babysitter_of_ns_1@127.0.0.1:<0.106.0>:ns_port_server:log:224]memcached<0.106.0>: 2019-03-19T19:30:36.144529-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:1005
       
      [ns_server:info,2019-03-19T19:30:36.755-07:00,babysitter_of_ns_1@127.0.0.1:<0.106.0>:ns_port_server:log:224]memcached<0.106.0>: 2019-03-19T19:30:36.553860-07:00 WARNING (default) Slow runtime for 'Backfilling items for a DCP Connection' on thread auxIO_worker_0: 409 ms
       
      [ns_server:info,2019-03-19T19:30:37.326-07:00,babysitter_of_ns_1@127.0.0.1:<0.106.0>:ns_port_server:log:224]memcached<0.106.0>: 2019-03-19T19:30:37.124989-07:00 WARNING 74: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:46349 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":8,"cas":0,"datatype":"raw","extlen":0,"keylen":8,"magic":"ClientRequest","opaque":0,"opcode":"STAT","vbucket":0},"refcount":0}] - closing connection ([ 127.0.0.1:46349 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): CheckpointIterator *() index is pointing to 'end'
      memcached<0.106.0>: 2019-03-19T19:30:37.200027-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:796
      memcached<0.106.0>: 2019-03-19T19:30:37.202857-07:00 WARNING (other-2) getAllItemsForCursor(): Caller had a null cursor vb:796
      

      Attachments

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

        Activity

          People

            mihir.kamdar Mihir Kamdar (Inactive)
            mihir.kamdar Mihir Kamdar (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty