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

Precondition failure in jepsen run - prepare overwriting wrong seqno

    XMLWordPrintable

Details

    • Untriaged
    • Unknown

    Description

      Jepsen run: http://cv.jenkins.couchbase.com/view/Commit%20Validation/view/Jepsen/job/kv-engine-jepsen-post-commit/383/console

      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:16.108492+00:00 ERROR 39: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:42725 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe84f3f5410","ewouldblock":false,"packet":{"bodylen":46,"cas":1568131273988898816,"datatype":["JSON","Snappy"],"extlen":31,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_PREPARE","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:42725 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): GSL: Precondition failure at /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/kv_engine/engines/ep/src/durability/passive_durability_monitor.cc: 145
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:20.916162+00:00 ERROR 57: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:36344 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe84f3f5c10","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_COMMIT","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:36344 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): PassiveDurabilityMonitor::completeSyncWrite vb:83 Pending resolution for 'SW @0x7fe84f50b390 cookie:0 qi:[key:'<ud>cid:0x0:jepsen0009</ud>' seqno:3 reqs:{PersistToMajority, timeout=infinite}] maj:0 completed:0 #1stChainAcks:0 1stChainAcks:[] #2ndChainAcks:0 2ndChainAcks:[]', but received unexpected commit for key <ud>cid:0x0:jepsen0009</ud> different prepare seqno: 5
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:25.811938+00:00 ERROR 57: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:45973 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe84f3f7c10","ewouldblock":false,"packet":{"bodylen":46,"cas":1568131284842446848,"datatype":["JSON","Snappy"],"extlen":31,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_PREPARE","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:45973 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): PassiveDurabilityMonitor::addSyncWrite vb:83 Found SyncWrite 'SW @0x7fe84f50b390 cookie:0 qi:[key:'<ud>cid:0x0:jepsen0009</ud>' seqno:3 reqs:{PersistToMajority, timeout=infinite}] maj:0 completed:0 #1stChainAcks:0 1stChainAcks:[] #2ndChainAcks:0 2ndChainAcks:[]', whilst attempting to add new SyncWrite for key <ud>cid:0x0:jepsen0009</ud> with prepare seqno 13
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:30.921553+00:00 ERROR 39: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:53147 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe8646f2c10","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_COMMIT","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:53147 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): PassiveDurabilityMonitor::completeSyncWrite vb:83 Pending resolution for 'SW @0x7fe84f50b390 cookie:0 qi:[key:'<ud>cid:0x0:jepsen0009</ud>' seqno:3 reqs:{PersistToMajority, timeout=infinite}] maj:0 completed:0 #1stChainAcks:0 1stChainAcks:[] #2ndChainAcks:0 2ndChainAcks:[]', but received unexpected commit for key <ud>cid:0x0:jepsen0009</ud> different prepare seqno: 13
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:35.834525+00:00 ERROR 39: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:48501 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe86f67ec10","ewouldblock":false,"packet":{"bodylen":46,"cas":1568131289796706304,"datatype":["JSON","Snappy"],"extlen":31,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_PREPARE","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:48501 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): PassiveDurabilityMonitor::addSyncWrite vb:83 Found SyncWrite 'SW @0x7fe84f50b390 cookie:0 qi:[key:'<ud>cid:0x0:jepsen0009</ud>' seqno:3 reqs:{PersistToMajority, timeout=infinite}] maj:0 completed:0 #1stChainAcks:0 1stChainAcks:[] #2ndChainAcks:0 2ndChainAcks:[]', whilst attempting to add new SyncWrite for key <ud>cid:0x0:jepsen0009</ud> with prepare seqno 15
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:40.652005+00:00 ERROR 39: exception occurred in runloop during packet execution. Cookie info: [{"aiostat":"success","connection":"[ 127.0.0.1:35822 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]","engine_storage":"0x00007fe84f3f5810","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_COMMIT","vbucket":83},"refcount":1}] - closing connection ([ 127.0.0.1:35822 - 127.0.0.1:11209 (<ud>@ns_server</ud>) ]): PassiveDurabilityMonitor::completeSyncWrite vb:83 Pending resolution for 'SW @0x7fe84f50b390 cookie:0 qi:[key:'<ud>cid:0x0:jepsen0009</ud>' seqno:3 reqs:{PersistToMajority, timeout=infinite}] maj:0 completed:0 #1stChainAcks:0 1stChainAcks:[] #2ndChainAcks:0 2ndChainAcks:[]', but received unexpected commit for key <ud>cid:0x0:jepsen0009</ud> different prepare seqno: 15
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:40.924059+00:00 CRITICAL *** Fatal error encountered during exception handling ***
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:40.924132+00:00 CRITICAL Caught unhandled std::exception-derived exception. what(): GSL: Precondition failure at /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/kv_engine/engines/ep/src/ep_bucket.cc: 584
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.151771+00:00 CRITICAL Breakpad caught a crash (Couchbase version 9.9.9-9999). Writing crash dump to /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/var/lib/couchbase/crash/670ace39-c6f0-c061-330a7b69-08f6ae9e.dmp before terminating.
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.151816+00:00 CRITICAL Stack backtrace of crashed thread:
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.151984+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/memcached() [0x400000+0x141ee3]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.151999+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/memcached(_ZN15google_breakpad16ExceptionHandler12GenerateDumpEPNS0_12CrashContextE+0x3ce) [0x400000+0x155f2e]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152015+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/memcached(_ZN15google_breakpad16ExceptionHandler13SignalHandlerEiP9siginfo_tPv+0x94) [0x400000+0x156244]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152026+00:00 CRITICAL     /lib/x86_64-linux-gnu/libpthread.so.0() [0x7fe8a145a000+0x11390]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152064+00:00 CRITICAL     /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38) [0x7fe8a1090000+0x35428]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152108+00:00 CRITICAL     /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a) [0x7fe8a1090000+0x3702a]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152209+00:00 CRITICAL     /usr/lib/x86_64-linux-gnu/libstdc++.so.6() [0x7fe8a1b96000+0x99242]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152222+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/memcached() [0x400000+0x152025]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152299+00:00 CRITICAL     /usr/lib/x86_64-linux-gnu/libstdc++.so.6() [0x7fe8a1b96000+0xa4e86]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152374+00:00 CRITICAL     /usr/lib/x86_64-linux-gnu/libstdc++.so.6() [0x7fe8a1b96000+0xa4ed1]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152450+00:00 CRITICAL     /usr/lib/x86_64-linux-gnu/libstdc++.so.6() [0x7fe8a1b96000+0xa5105]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152460+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/../lib/ep.so() [0x7fe89c547000+0x101bb4]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152469+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/../lib/ep.so() [0x7fe89c547000+0x114c7f]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152479+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/../lib/ep.so() [0x7fe89c547000+0x15f495]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152488+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/../lib/ep.so() [0x7fe89c547000+0x15f895]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152498+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/../lib/ep.so() [0x7fe89c547000+0x158c4d]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152504+00:00 CRITICAL     /home/couchbase/jenkins/workspace/kv-engine-jepsen-post-commit/install/bin/../lib/libplatform_so.so.0.1.0() [0x7fe8a3449000+0x99c7]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152512+00:00 CRITICAL     /lib/x86_64-linux-gnu/libpthread.so.0() [0x7fe8a145a000+0x76ba]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:41.152567+00:00 CRITICAL     /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7fe8a1090000+0x10741d]
      		 
      17:33:11 ./20190910T090014.000-0700/172.28.128.136/cbcollect_info_ns_1@172.28.128.136_20190910-160135/memcached.log:2019-09-10T16:01:46.480398+00:00 ERROR (default) VBucket::commit (vb:83) failed as no HashTable item found with key:<ud>cid:0x0:jepsen0009</ud> prepare_seqno:15, commit_seqno: 16


      void PassiveDurabilityMonitor::addSyncWrite(
      		 
              queued_item item, boost::optional<int64_t> overwritingPrepareSeqno) {
      		 
         ...
      		 
          if (overwritingPrepareSeqno) {
      		 
              // Remove any trackedWrites with the same key.
      		 
              auto itr = s->trackedWrites.begin();
      		 
              while (itr != s->trackedWrites.end() &&
      		 
                     itr->getKey() != item->getKey()) {
      		 
                  itr = s->getIteratorNext(itr);
      		 
              }
      		 
              if (itr != s->trackedWrites.end()) {
      		 
                  Expects(itr->getBySeqno() == overwritingPrepareSeqno); //// HERE
      		 
                  // We have found a trackedWrite with the same key to remove. Update
      		 
                  // the HCS and HPS iterators and then remove the SyncWrite.
      		 
      ...

      Attachments

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

        Activity

          People

            james.harrison James Harrison (Inactive)
            james.harrison James Harrison (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty