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

[System Test] Memcached crashed on one KV node - invariant failed: new value (25228) breaks invariant on current value (25228)

    XMLWordPrintable

Details

    Description

      Build : 7.1.0-1231
      Test : -test tests/integration/cheshirecat/test_cheshirecat_kv_gsi_coll_xdcr_backup_sgw_fts_itemct_txns_eventing_cbas_scale3.yml -scope tests/integration/cheshirecat/scope_cheshirecat_with_backup.yml (Couchstore Legacy Longevity Test)
      Scale : 3
      Iteration : 1st

      Seeing the following stack trace in the memcached logs on 172.23.121.77 :

      2021-09-01T22:47:00.000009-07:00 INFO 870: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:c8d6d8f25cda683ba7b72ca7868d55cd:18 - (vb:794) (sid:2) ActiveStream::transitionState: Transitioning from backfilling to in-memory
      2021-09-01T22:47:00.000780-07:00 INFO 89: [ {"ip":"127.0.0.1","port":43694} - {"ip":"127.0.0.1","port":11209} (System, <ud>@ns_server</ud>) ] Updated cluster configuration for bucket [WAREHOUSE]. New revision: {"epoch":1,"revno":48714}
      2021-09-01T22:47:00.001737-07:00 INFO Pushing new cluster config for bucket:[WAREHOUSE] revision:{"epoch":1,"revno":48714}
      2021-09-01T22:47:00.002602-07:00 INFO 870: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:c8d6d8f25cda683ba7b72ca7868d55cd:18 - (vb:795) (sid:2) Backfill complete, 902 items read from disk, 1046 from memory, last seqno read: 24870, pendingBackfill : False
      2021-09-01T22:47:00.004099-07:00 INFO 870: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:c8d6d8f25cda683ba7b72ca7868d55cd:18 - (vb:796) (sid:2) Backfill complete, 895 items read from disk, 1010 from memory, last seqno read: 25220, pendingBackfill : False
      2021-09-01T22:47:00.029155-07:00 INFO 870: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:c8d6d8f25cda683ba7b72ca7868d55cd:18 - (vb:796) (sid:2) ActiveStream::transitionState: Transitioning from backfilling to in-memory
      2021-09-01T22:47:00.029374-07:00 INFO 870: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:c8d6d8f25cda683ba7b72ca7868d55cd:18 - (vb:795) (sid:2) ActiveStream::transitionState: Transitioning from backfilling to in-memory
      2021-09-01T22:47:00.031914-07:00 CRITICAL *** Fatal error encountered during exception handling ***
      2021-09-01T22:47:00.032010-07:00 CRITICAL Caught unhandled std::exception-derived exception. what(): Monotonic<m> (ActiveStream(vb:796)::lastReadSeqno) invariant failed: new value (25228) breaks invariant on current value (25228)
      2021-09-01T22:47:00.032024-07:00 CRITICAL Exception thrown from:
      2021-09-01T22:47:00.032098-07:00 CRITICAL     #0  /opt/couchbase/bin/memcached() [0x400000+0x95a35]
      2021-09-01T22:47:00.032113-07:00 CRITICAL     #1  /opt/couchbase/bin/memcached() [0x400000+0xdb828]
      2021-09-01T22:47:00.032137-07:00 CRITICAL     #2  /opt/couchbase/bin/memcached() [0x400000+0x47eca9]
      2021-09-01T22:47:00.032161-07:00 CRITICAL     #3  /opt/couchbase/bin/memcached() [0x400000+0x47ef47]
      2021-09-01T22:47:00.032182-07:00 CRITICAL     #4  /opt/couchbase/bin/memcached() [0x400000+0x47f6a4]
      2021-09-01T22:47:00.032195-07:00 CRITICAL     #5  /opt/couchbase/bin/memcached() [0x400000+0x47f734]
      2021-09-01T22:47:00.032207-07:00 CRITICAL     #6  /opt/couchbase/bin/memcached() [0x400000+0x485b09]
      2021-09-01T22:47:00.032227-07:00 CRITICAL     #7  /opt/couchbase/bin/memcached() [0x400000+0x615ae2]
      2021-09-01T22:47:00.032247-07:00 CRITICAL     #8  /opt/couchbase/bin/memcached() [0x400000+0x612c05]
      2021-09-01T22:47:00.032269-07:00 CRITICAL     #9  /opt/couchbase/bin/memcached() [0x400000+0x770410]
      2021-09-01T22:47:00.032297-07:00 CRITICAL     #10 /opt/couchbase/bin/memcached() [0x400000+0x7581ca]
      2021-09-01T22:47:00.032705-07:00 CRITICAL     #11 /opt/couchbase/bin/memcached() [0x400000+0x7733c9]
      2021-09-01T22:47:00.032729-07:00 CRITICAL     #12 /opt/couchbase/bin/memcached() [0x400000+0x612784]
      2021-09-01T22:47:00.032798-07:00 CRITICAL     #13 /opt/couchbase/bin/../lib/libstdc++.so.6() [0x7f708c273000+0xcdd40]
      2021-09-01T22:47:00.032814-07:00 CRITICAL     #14 /lib64/libpthread.so.0() [0x7f708e15a000+0x7e65]
      2021-09-01T22:47:00.032853-07:00 CRITICAL     #15 /lib64/libc.so.6(clone+0x6d) [0x7f708b98b000+0xfe88d]
      2021-09-01T22:47:00.228839-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) Creating stream with start seqno 23369 and end seqno 18446744073709551615; requested end seqno was 18446744073709551615, collections-filter-size:1 sid:2
      2021-09-01T22:47:00.229124-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) ActiveStream::scheduleBackfill_UNLOCKED register cursor with name "eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8sid:2" backfill:true, seqno:24672
      2021-09-01T22:47:00.230895-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) Scheduling backfill from 23370 to 24671, reschedule flag : False
      2021-09-01T22:47:00.232881-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) ActiveStream::markDiskSnapshot: Sending disk snapshot with start 23369, end 25218, and high completed none, max visible none
      2021-09-01T22:47:00.233211-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) ActiveStream::registerCursor name "eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8sid:2", backfill:false, seqno:25219
      2021-09-01T22:47:00.268149-07:00 INFO 893: (WAREHOUSE) DCP (Producer) eq_dcpq:cbas:Local:WAREHOUSE:cb9f24a0220708b4d2aac9927ba8700c:8 - (vb:288) (sid:2) Backfill complete, 824 items read from disk, 1022 from memory, last seqno read: 25218, pendingBackfill : False
      2021-09-01T22:47:00.512064-07:00 INFO 327: (No Engine) DCP (Producer) eq_dcpq:secidx:getfailoverlog-bucket7-14218174957054739115 - Removing connection [ {"ip":"172.23.97.148","port":41922} - {"ip":"172.23.121.77","port":11210} (System, <ud>@index</ud>) ]
      2021-09-01T22:47:00.515965-07:00 INFO 344: Client {"ip":"127.0.0.1","port":56697} authenticated as <ud>@ns_server</ud>
      

      The core dump generated is copied over to /root/core_dumps dir on 172.23.121.77 since it was too large to be attached here.

      [root@localhost core_dumps]# pwd; ls -lah
      /root/core_dumps
      total 6.7G
      drwxr-xr-x. 2 root root 23 Sep 2 12:19 .
      dr-xr-x---. 8 root root 4.0K Sep 2 12:19 ..
      rw------. 1 root root 11G Sep 2 12:21 core.27597

      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:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty