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

Creating index on collection named "system" can cause server to abort

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Fixed
    • Affects Version/s: 2.6.0, 2.6.1, 2.6.2
    • Fix Version/s: 2.6.4
    • Component/s: Storage
    • Labels:
      None
    • Operating System:
      ALL
    • Steps To Reproduce:
      Hide

      1. Clone the repository from https://github.com/mongoengine/mongoengine.
      2. run python setup.py test -s tests.document.instance.
      3. Mongod crashes every time, with the log given in the description.

      Show
      1. Clone the repository from https://github.com/mongoengine/mongoengine . 2. run python setup.py test -s tests.document.instance. 3. Mongod crashes every time, with the log given in the description.

      Description

      Issue Status as of Jul 18, 2014

      ISSUE SUMMARY
      In MongoDB 2.4 and earlier, creating an index on a collection with the name "system" and subsequently dropping the index leaves the database in a corrupt state. The corruption has no user-visible effects in MongoDB 2.4, but in affected versions of MongoDB 2.6 upon creation of a new index on this collection the server would detect the corruption and abort.

      USER IMPACT
      mongod shuts down upon detecting database corruption.

      WORKAROUNDS
      Running db.repairDatabase() on the affected database fixes this issue.

      AFFECTED VERSIONS
      MongoDB production releases up to 2.6.3 are affected by this issue.

      FIX VERSION
      The fix is included in the 2.6.4 production release.

      RESOLUTION DETAILS
      The fix for this issue is to add a procedure to the startup sequence that rectifies the system.namespaces collection for any affected databases. This procedure will output a log message "dropping orphaned index" for each orphan index that is found on a collection named "system".

      Original description

      I'm sorry for a vague summary, but I'm not entirely sure which operation is responsible for mongod crashing. Anyway, the important part is that the process crashes every single time (ver 2.6.1, Max OS X).

      Log from the crash:

      2014-05-16T12:23:01.833-0700 [conn1] mongoenginetest.log: clearing plan cache - collection info cache reset
      2014-05-16T12:23:01.833-0700 [conn1] Only one plan is available; it will be run but will not be cached. query: { name: "mongoenginetest.log.$_id_" } sort: {} projection: {}, planSummary: COLLSCAN
      2014-05-16T12:23:01.834-0700 [conn1] Only one plan is available; it will be run but will not be cached. query: { ns: "mongoenginetest.log", name: "_id_" } sort: {} projection: {}, planSummary: COLLSCAN
      2014-05-16T12:23:01.834-0700 [conn1] 	 dropIndexes done
      2014-05-16T12:23:01.834-0700 [conn1] Only one plan is available; it will be run but will not be cached. query: { name: "mongoenginetest.log" } sort: {} projection: {}, planSummary: COLLSCAN
      2014-05-16T12:23:01.834-0700 [conn1] command mongoenginetest.$cmd command: drop { drop: "log" } keyUpdates:0 numYields:0 locks(micros) w:29648 reslen:82 29ms
      2014-05-16T12:23:01.836-0700 [conn1] run command mongoenginetest.$cmd { drop: "system" }
      2014-05-16T12:23:01.836-0700 [conn1] CMD: drop mongoenginetest.system
      2014-05-16T12:23:01.836-0700 [conn1] command mongoenginetest.$cmd command: drop { drop: "system" } keyUpdates:0 numYields:0 locks(micros) w:80 reslen:62 0ms
      2014-05-16T12:23:01.837-0700 [conn1] run command mongoenginetest.$cmd { drop: "node" }
      2014-05-16T12:23:01.837-0700 [conn1] CMD: drop mongoenginetest.node
      2014-05-16T12:23:01.837-0700 [conn1] command mongoenginetest.$cmd command: drop { drop: "node" } keyUpdates:0 numYields:0 locks(micros) w:74 reslen:62 0ms
      2014-05-16T12:23:01.838-0700 [conn1] run command mongoenginetest.$cmd { insert: "node", ordered: true, documents: [ { _id: ObjectId('53766595ab265ddf6a6df6d2'), parameters: {} } ] }
      2014-05-16T12:23:01.838-0700 [conn1] Database::_addNamespaceToCatalog ns: mongoenginetest.node
      2014-05-16T12:23:01.838-0700 [conn1] ExtentManager::increaseStorageSize ns:mongoenginetest.node desiredSize:8192 fromFreeList: 1 eloc: 0:aae000
      2014-05-16T12:23:01.848-0700 [conn1] _reuse extent was:mongoenginetest.doc now:mongoenginetest.node
      2014-05-16T12:23:01.848-0700 [conn1] Database::_addNamespaceToCatalog ns: mongoenginetest.node.$_id_
      2014-05-16T12:23:01.848-0700 [conn1] build index on: mongoenginetest.node properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "mongoenginetest.node" }
      2014-05-16T12:23:01.848-0700 [conn1] mongoenginetest.node: clearing plan cache - collection info cache reset
      2014-05-16T12:23:01.848-0700 [conn1] allocating new extent
      2014-05-16T12:23:01.848-0700 [conn1] ExtentManager::increaseStorageSize ns:mongoenginetest.node.$_id_ desiredSize:131072 fromFreeList: 1 eloc: 0:d6e000
      2014-05-16T12:23:01.848-0700 [conn1] _reuse extent was:mongoenginetest.log.$_id_ now:mongoenginetest.node.$_id_
      2014-05-16T12:23:01.848-0700 [conn1] 	 added index to empty collection
      2014-05-16T12:23:01.848-0700 [conn1] mongoenginetest.node: clearing plan cache - collection info cache reset
      2014-05-16T12:23:01.848-0700 [conn1] insert mongoenginetest.node query: { _id: ObjectId('53766595ab265ddf6a6df6d2'), parameters: {} } ninserted:1 keyUpdates:0 numYields:0 locks(micros) w:10616 10ms
      2014-05-16T12:23:01.848-0700 [conn1] command mongoenginetest.$cmd command: insert { insert: "node", ordered: true, documents: [ { _id: ObjectId('53766595ab265ddf6a6df6d2'), parameters: {} } ] } keyUpdates:0 numYields:0 locks(micros) w:32 reslen:40 10ms
      2014-05-16T12:23:01.849-0700 [journal] journal WRITETODATAFILES 1
      2014-05-16T12:23:01.849-0700 [journal] journal WRITETODATAFILES 2
      2014-05-16T12:23:01.849-0700 [journal] journal WRITETODATAFILES 0.137ms
      2014-05-16T12:23:01.849-0700 [conn1] run command mongoenginetest.$cmd { insert: "system", ordered: true, documents: [ { _id: ObjectId('53766595ab265ddf6a6df6d3'), name: "system", nodes: { node: ObjectId('53766595ab265ddf6a6df6d2') } } ] }
      2014-05-16T12:23:01.849-0700 [conn1] Database::_addNamespaceToCatalog ns: mongoenginetest.system
      2014-05-16T12:23:01.849-0700 [conn1] ExtentManager::increaseStorageSize ns:mongoenginetest.system desiredSize:8192 fromFreeList: 1 eloc: 0:a92000
      2014-05-16T12:23:01.849-0700 [conn1] _reuse extent was:mongoenginetest.mongoengine.counters now:mongoenginetest.system
      2014-05-16T12:23:01.850-0700 [conn1] mongoenginetest.system Invariant failure nsi.details( descriptor->indexNamespace() ) == NULL src/mongo/db/catalog/index_catalog.cpp 450
      2014-05-16T12:23:01.858-0700 [conn1] mongoenginetest.system 0x1006ac7ab 0x1006642c2 0x100653fc9 0x1000f61e7 0x1000f69c6 0x1000f72fe 0x1000e5b1d 0x1001a36dc 0x1001a44d6 0x1001a571e 0x1001a652f 0x1001a92f7 0x1001b7605 0x1001b8101 0x1001b907c 0x1003cfc7f 0x1002a1050 0x100006854 0x100671b71 0x1006e0bb5
       0   mongod                              0x00000001006ac7ab _ZN5mongo15printStackTraceERSo + 43
       1   mongod                              0x00000001006642c2 _ZN5mongo10logContextEPKc + 114
       2   mongod                              0x0000000100653fc9 _ZN5mongo15invariantFailedEPKcS1_j + 233
       3   mongod                              0x00000001000f61e7 _ZN5mongo12IndexCatalog15IndexBuildBlock4initEv + 805
       4   mongod                              0x00000001000f69c6 _ZN5mongo12IndexCatalog11createIndexENS_7BSONObjEbNS0_16ShutdownBehaviorE + 704
       5   mongod                              0x00000001000f72fe _ZN5mongo12IndexCatalog17ensureHaveIdIndexEv + 590
       6   mongod                              0x00000001000e5b1d _ZN5mongo8Database16createCollectionERKNS_10StringDataERKNS_17CollectionOptionsEbb + 1821
       7   mongod                              0x00000001001a36dc _ZN5mongo18WriteBatchExecutor13execOneInsertEPNS0_16ExecInsertsStateEPPNS_16WriteErrorDetailE + 3592
       8   mongod                              0x00000001001a44d6 _ZN5mongo18WriteBatchExecutor11execInsertsERKNS_21BatchedCommandRequestEPSt6vectorIPNS_16WriteErrorDetailESaIS6_EE + 1334
       9   mongod                              0x00000001001a571e _ZN5mongo18WriteBatchExecutor11bulkExecuteERKNS_21BatchedCommandRequestEPSt6vectorIPNS_19BatchedUpsertDetailESaIS6_EEPS4_IPNS_16WriteErrorDetailESaISB_EE + 66
       10  mongod                              0x00000001001a652f _ZN5mongo18WriteBatchExecutor12executeBatchERKNS_21BatchedCommandRequestEPNS_22BatchedCommandResponseE + 2547
       11  mongod                              0x00000001001a92f7 _ZN5mongo8WriteCmd3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb + 645
       12  mongod                              0x00000001001b7605 _ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb + 37
       13  mongod                              0x00000001001b8101 _ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb + 2245
       14  mongod                              0x00000001001b907c _ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi + 1388
       15  mongod                              0x00000001003cfc7f _ZN5mongo11newRunQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_ + 1615
       16  mongod                              0x00000001002a1050 _ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE + 1968
       17  mongod                              0x0000000100006854 _ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE + 308
       18  mongod                              0x0000000100671b71 _ZN5mongo17PortMessageServer17handleIncomingMsgEPv + 1681
       19  mongod                              0x00000001006e0bb5 thread_proxy + 229
      2014-05-16T12:23:01.858-0700 [conn1]
       
      ***aborting after invariant() failure
       
       
      2014-05-16T12:23:01.865-0700 [conn1] SEVERE: Got signal: 6 (Abort trap: 6).
      Backtrace:0x1006ac7ab 0x1006ac50f 0x7fff912fb5aa 0 0x7fff929d4b1a 0x10065403b 0x1000f61e7 0x1000f69c6 0x1000f72fe 0x1000e5b1d 0x1001a36dc 0x1001a44d6 0x1001a571e 0x1001a652f 0x1001a92f7 0x1001b7605 0x1001b8101 0x1001b907c 0x1003cfc7f 0x1002a1050
       0   mongod                              0x00000001006ac7ab _ZN5mongo15printStackTraceERSo + 43
       1   mongod                              0x00000001006ac50f _ZN5mongo12_GLOBAL__N_110abruptQuitEi + 191
       2   libsystem_platform.dylib            0x00007fff912fb5aa _sigtramp + 26
       3   ???                                 0x0000000000000000 0x0 + 0
       4   libsystem_c.dylib                   0x00007fff929d4b1a abort + 125
       5   mongod                              0x000000010065403b _ZN5mongo15invariantFailedEPKcS1_j + 347
       6   mongod                              0x00000001000f61e7 _ZN5mongo12IndexCatalog15IndexBuildBlock4initEv + 805
       7   mongod                              0x00000001000f69c6 _ZN5mongo12IndexCatalog11createIndexENS_7BSONObjEbNS0_16ShutdownBehaviorE + 704
       8   mongod                              0x00000001000f72fe _ZN5mongo12IndexCatalog17ensureHaveIdIndexEv + 590
       9   mongod                              0x00000001000e5b1d _ZN5mongo8Database16createCollectionERKNS_10StringDataERKNS_17CollectionOptionsEbb + 1821
       10  mongod                              0x00000001001a36dc _ZN5mongo18WriteBatchExecutor13execOneInsertEPNS0_16ExecInsertsStateEPPNS_16WriteErrorDetailE + 3592
       11  mongod                              0x00000001001a44d6 _ZN5mongo18WriteBatchExecutor11execInsertsERKNS_21BatchedCommandRequestEPSt6vectorIPNS_16WriteErrorDetailESaIS6_EE + 1334
       12  mongod                              0x00000001001a571e _ZN5mongo18WriteBatchExecutor11bulkExecuteERKNS_21BatchedCommandRequestEPSt6vectorIPNS_19BatchedUpsertDetailESaIS6_EEPS4_IPNS_16WriteErrorDetailESaISB_EE + 66
       13  mongod                              0x00000001001a652f _ZN5mongo18WriteBatchExecutor12executeBatchERKNS_21BatchedCommandRequestEPNS_22BatchedCommandResponseE + 2547
       14  mongod                              0x00000001001a92f7 _ZN5mongo8WriteCmd3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb + 645
       15  mongod                              0x00000001001b7605 _ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb + 37
       16  mongod                              0x00000001001b8101 _ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb + 2245
       17  mongod                              0x00000001001b907c _ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi + 1388
       18  mongod                              0x00000001003cfc7f _ZN5mongo11newRunQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_ + 1615
       19  mongod                              0x00000001002a1050 _ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE + 1968

        Attachments

          Activity

            People

            • Votes:
              1 Vote for this issue
              Watchers:
              15 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: