Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-18078

logOp fassert when running mapReduce during primary step-down

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 3.1.2
    • Affects Version/s: None
    • Component/s: Replication
    • Labels:
    • Fully Compatible
    • ALL
    • Hide
      'use strict';
      
      load('jstests/libs/parallelTester.js');
      
      function stepDownWorkload() {
          var conn = new Mongo();
      
          while (true) {
              try {
                  conn.getDB('admin').runCommand({replSetStepDown: 1, force: true});
              } catch (e) {
                  // ignore
              }
      
              sleep(2000);
          }
      }
      
      function mapReduceWorkload() {
          var conn = new Mongo();
      
          var mapper = function() {
              emit(1, {});
          };
      
          while (true) {
              var testDB = conn.getDB('test');
      
              try {
                  testDB.foo.insert({});
                  testDB.foo.mapReduce(mapper, Function.prototype, {out: 'foo2'});
                  testDB.dropDatabase();
              } catch (e) {
                  // ignore
              }
          }
      }
      
      // set up the replica set
      var rs = new ReplSetTest({nodes: 1, startPort: 27017});
      rs.startSet();
      rs.initiate();
      
      // start the workload threads
      var threads = [];
      
      for (var i = 0; i < 10; i++) {
          var t;
      
          if (i === 0) {
              t = new ScopedThread(stepDownWorkload);
          } else {
              t = new ScopedThread(mapReduceWorkload);
          }
      
          threads.push(t);
          t.start();
      }
      
      threads.forEach(function(t) {
          t.join();
      });
      
      Show
      'use strict'; load('jstests/libs/parallelTester.js'); function stepDownWorkload() { var conn = new Mongo(); while (true) { try { conn.getDB('admin').runCommand({replSetStepDown: 1, force: true}); } catch (e) { // ignore } sleep(2000); } } function mapReduceWorkload() { var conn = new Mongo(); var mapper = function() { emit(1, {}); }; while (true) { var testDB = conn.getDB('test'); try { testDB.foo.insert({}); testDB.foo.mapReduce(mapper, Function.prototype, {out: 'foo2'}); testDB.dropDatabase(); } catch (e) { // ignore } } } // set up the replica set var rs = new ReplSetTest({nodes: 1, startPort: 27017}); rs.startSet(); rs.initiate(); // start the workload threads var threads = []; for (var i = 0; i < 10; i++) { var t; if (i === 0) { t = new ScopedThread(stepDownWorkload); } else { t = new ScopedThread(mapReduceWorkload); } threads.push(t); t.start(); } threads.forEach(function(t) { t.join(); });
    • RPL 2 04/24/15

      This bug was introduced by the changes from SERVER-17573, so it only affects master.

       F REPL     [conn29] logOp() but can't accept write to collection test.$cmd
       I -        [conn29] Fatal Assertion 17405
      
      * thread #62: tid = 0x604d6e, 0x00007fff92390d1d libsystem_pthread.dylib`__mtx_droplock + 279
        * frame #0: 0x00007fff92390d1d libsystem_pthread.dylib`__mtx_droplock + 279
          frame #1: 0x00007fff92390b4e libsystem_pthread.dylib`pthread_mutex_unlock + 63
          frame #2: 0x00007fff8e7eb0df libsystem_c.dylib`fwrite + 194
          frame #3: 0x00007fff963f9d2a libc++.1.dylib`std::__1::__stdoutbuf<char>::overflow(int) + 82
          frame #4: 0x00007fff963ef91d libc++.1.dylib`std::__1::basic_streambuf<char, std::__1::char_traits<char> >::xsputn(char const*, long) + 73
          frame #5: 0x00007fff963f694c libc++.1.dylib`std::__1::basic_ostream<char, std::__1::char_traits<char> >::write(char const*, long) + 72
          frame #6: 0x0000000106e53205 mongod`mongo::operator<<(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, mongo::StringData)(stream=0x00007fff7e3ac2f8, value=(_data = "-       ", _size = 8)) + 69 at string_data.cpp:57
          frame #7: 0x0000000107a603bc mongod`mongo::logger::operator<<(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, mongo::logger::LogComponent)(os=0x00007fff7e3ac2f8, component=(_value = kDefault)) + 60 at log_component.cpp:158
          frame #8: 0x0000000107a6a0fd mongod`mongo::logger::MessageEventDetailsEncoder::encode(this=0x00007fd6dab02710, event=0x000000011bafd0d0, os=0x00007fff7e3ac2f8) + 221 at message_event_utf8_encoder.cpp:62
          frame #9: 0x000000010745dd1d mongod`mongo::logger::ConsoleAppender<mongo::logger::MessageEventEphemeral, mongo::Console>::append(this=0x00007fd6dab02df0, event=0x000000011bafd0d0) + 173 at console_appender.h:54
          frame #10: 0x0000000107a6ae6e mongod`mongo::logger::LogDomain<mongo::logger::MessageEventEphemeral>::append(this=0x00007fd6dab01138, event=0x000000011bafd0d0) + 574 at log_domain-impl.h:60
          frame #11: 0x0000000107a66e67 mongod`mongo::logger::LogstreamBuilder::~LogstreamBuilder(this=0x000000011bafd458) + 1287 at logstream_builder.cpp:134
          frame #12: 0x0000000107a674e5 mongod`mongo::logger::LogstreamBuilder::~LogstreamBuilder(this=0x000000011bafd458) + 21 at logstream_builder.cpp:128
          frame #13: 0x0000000107d5566e mongod`mongo::fassertFailed(msgid=17405) + 238 at assert_util.cpp:168
          frame #14: 0x00000001077a802d mongod`mongo::repl::_logOp(txn=0x000000011bb02710, opstr=0x00000001088a96e4, ns=0x000000011bafdb29, obj=0x000000011bafda38, o2=0x0000000000000000, fromMigrate=false) + 765 at oplog.cpp:260
          frame #15: 0x00000001074d6fc1 mongod`mongo::OpObserver::onCreateCollection(this=0x00007fd6da9012d0, txn=0x000000011bb02710, collectionName=0x000000011bafdef0, options=0x000000011bafe738) + 1057 at op_observer.cpp:114
          frame #16: 0x00000001070afd3b mongod`mongo::Database::createCollection(this=0x00007fd6d8d0e710, txn=0x000000011bb02710, ns=(_data = "test.tmp.mr.foo_16_inc", _size = 22), options=0x000000011bafe738, createIdIndex=true) + 2363 at database.cpp:539
          frame #17: 0x000000010716c2c5 mongod`mongo::mr::State::prepTempCollection(this=0x000000011baffb70) + 469 at mr.cpp:384
          frame #18: 0x00000001071833b1 mongod`mongo::mr::MapReduceCommand::run(this=0x0000000108b1b1e0, txn=0x000000011bb02710, dbname=0x000000011bb005e0, cmd=0x000000011bb00ea0, (null)=0, errmsg=0x000000011bb00200, result=0x000000011bb01200, fromRepl=false) + 2289 at mr.cpp:1329
          frame #19: 0x00000001072352f5 mongod`mongo::_execCommand(txn=0x000000011bb02710, c=0x0000000108b1b1e0, dbname=0x000000011bb005e0, cmdObj=0x000000011bb00ea0, queryOptions=0, errmsg=0x000000011bb00200, result=0x000000011bb01200, fromRepl=false) + 149 at dbcommands.cpp:1139
          frame #20: 0x00000001072373a1 mongod`mongo::Command::execCommand(txn=0x000000011bb02710, c=0x0000000108b1b1e0, queryOptions=0, cmdns=0x00007fd6d9883a14, cmdObj=0x000000011bb00ea0, result=0x000000011bb01200, fromRepl=false) + 7473 at dbcommands.cpp:1357
          frame #21: 0x0000000107238024 mongod`mongo::_runCommands(txn=0x000000011bb02710, ns=0x00007fd6d9883a14, _cmdobj=0x000000011bb01330, b=0x000000011bb01260, anObjBuilder=0x000000011bb01200, fromRepl=false, queryOptions=0) + 2132 at dbcommands.cpp:1431
          frame #22: 0x0000000107238510 mongod`mongo::runCommands(txn=0x000000011bb02710, ns=0x00007fd6d9883a14, jsobj=0x000000011bb01330, curop=0x00007fd6dc809a08, b=0x000000011bb01260, anObjBuilder=0x000000011bb01200, fromRepl=false, queryOptions=0) + 96 at dbcommands.cpp:1461
          frame #23: 0x0000000107462009 mongod`mongo::receivedCommand(txn=0x000000011bb02710, nss=0x000000011bb023b0, client=0x00007fd6da804130, dbResponse=0x000000011bb02688, message=0x000000011bb02cf0) + 1417 at instance.cpp:244
          frame #24: 0x000000010745fbef mongod`mongo::assembleResponse(txn=0x000000011bb02710, m=0x000000011bb02cf0, dbresponse=0x000000011bb02688, remote=0x000000011bb02668) + 2447 at instance.cpp:482
          frame #25: 0x0000000106e1e248 mongod`mongo::MyMessageHandler::process(this=0x00007fd6da901860, m=0x000000011bb02cf0, port=0x00007fd6d8d0e630, le=0x00007fd6da805e00) + 392 at db.cpp:171
          frame #26: 0x0000000107dae1ba mongod`mongo::PortMessageServer::handleIncomingMsg(arg=0x00007fd6d8d0e630) + 2762 at message_server_port.cpp:230
          frame #27: 0x0000000107dac704 mongod`boost::detail::thread_data<std::__1::__bind<void* (*)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*> >::run() [inlined] decltype(__f=0x00007fd6d8d17390, __args=0x00007fd6d8d17398)(void*)>(fp)(std::__1::forward<mongo::(anonymous namespace)::MessagingPortWithHandler*&>(fp0))) std::__1::__invoke<void* (*&)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*&>(void* (*&&&)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*&&&) + 164 at __functional_base:413
          frame #28: 0x0000000107dac6e1 mongod`boost::detail::thread_data<std::__1::__bind<void* (*)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*> >::run() [inlined] std::__1::__bind_return<void* (*)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>, std::__1::tuple<>, _is_valid_bind_return<void* (*)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>, std::__1::tuple<> >::value>::type std::__1::__apply_functor<void* (__f=0x00007fd6d8d17390, __bound_args=0x00007fd6d8d17398, (null)=__tuple_indices<0> at 0x000000011bb02e18, __args=0x000000011bb02dd8)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>, 0ul, std::__1::tuple<> >(void* (*&)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>&, std::__1::__tuple_indices<0ul>, std::__1::tuple<>&&) + 48 at functional:2023
          frame #29: 0x0000000107dac6b1 mongod`boost::detail::thread_data<std::__1::__bind<void* (*)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*> >::run() [inlined] std::__1::__bind_return<void* (*)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>, std::__1::tuple<>, _is_valid_bind_return<void* (*)(void*), std::__1::tuple<mongo::(anonymous namespace)::MessagingPortWithHandler*>, std::__1::tuple<> >::value>::type std::__1::__bind<void* (this=0x00007fd6d8d17390)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*>::operator()<>() + 34 at functional:2086
          frame #30: 0x0000000107dac68f mongod`boost::detail::thread_data<std::__1::__bind<void* (*)(void*), mongo::(anonymous namespace)::MessagingPortWithHandler*> >::run(this=0x00007fd6d8d17190) + 47 at thread.hpp:115
          frame #31: 0x0000000107ecd3e5 mongod`boost::(anonymous namespace)::thread_proxy(param=0x00007fd6d8d17190) + 133 at thread.cpp:173
          frame #32: 0x00007fff92392268 libsystem_pthread.dylib`_pthread_body + 131
          frame #33: 0x00007fff923921e5 libsystem_pthread.dylib`_pthread_start + 176
          frame #34: 0x00007fff9239041d libsystem_pthread.dylib`thread_start + 13
      

      Version: e02bc3b1738

            Assignee:
            matt.dannenberg Matt Dannenberg
            Reporter:
            kamran.khan Kamran K.
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: