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

Initial sync of a hidden node (buildIndex: False) triggers Index alreadyExists

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Unresolved
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 3.6.3
    • Component/s: Replication
    • Replication
    • ALL
    • Hide

      Create a replica set with 2 nodes,

      One hidden: 
      node =

      {'host': 'test-mongo-hid.dummy.eu:27018', 'buildIndexes': false, 'hidden': true, 'priority': 0, 'votes': 0}

      The other PRIMARY.

      Mongorestore the dummy database:

      mongorestore --dir dummy --db dummy --drop

      Stop the hidden node

      sudo systemctl stop mongod@my-repl

      Delete all data on the hidden node

      rm -rf /srv/path/to/data/my-repl/*

       

      Start the node

       sudo systemctl start mongod@my-repl

       Enjoy the stacktrace.

       

      A dummy database is in attachment. This database as more than 1 index.

      Show
      Create a replica set with 2 nodes, One hidden:  node = {'host': 'test-mongo-hid.dummy.eu:27018', 'buildIndexes': false, 'hidden': true, 'priority': 0, 'votes': 0} The other PRIMARY. Mongorestore the dummy database: mongorestore --dir dummy --db dummy --drop Stop the hidden node sudo systemctl stop mongod@my-repl Delete all data on the hidden node rm -rf /srv/path/to/data/my-repl/*   Start the node  sudo systemctl start mongod@my-repl  Enjoy the stacktrace.   A dummy database is in attachment. This database as more than 1 index.
    • Repl 2018-06-04

      Hello,

      When I try to sync a hidden node (BuildIndex: false) from scratch, the process crash with the above stacktrace. The hidden node try to sync databases with more than 1 index.

      From scratch mean I perform a:

       

      rm rf /srv/mongodb/my-repl/*
sudo systemctl start mongod@my-repl

       

       

      May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] Starting initial sync (attempt 10 of 10)
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] Finishing collection drop for local.temp_oplog_buffer (no UUID).
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] createCollection: local.temp_oplog_buffer with no UUID.
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] sync source candidate: test-mongo-re1.test.dummy.eu:27017
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] dropAllDatabasesExceptLocal 4
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-0] CollectionCloner::start called, on ns:admin.system.roles
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 9] createCollection: admin.system.roles with provided UUID: 002f28c7-b0df-4f98-a9f0-101dbeeeb195
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 9] build index on: admin.system.roles properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "admin.system.roles" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 9]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 11] CollectionCloner ns:admin.system.roles finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 11] CollectionCloner::start called, on ns:admin.system.users
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 13] createCollection: admin.system.users with provided UUID: 1e30d209-454f-474e-898e-77bf2ef7ac58
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 13] build index on: admin.system.users properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "admin.system.users" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 13]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 15] CollectionCloner ns:admin.system.users finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 15] CollectionCloner::start called, on ns:admin.system.version
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 7] createCollection: admin.system.version with provided UUID: 1de6ed2e-0d67-4e6b-b615-20762c7ff84a
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 7] build index on: admin.system.version properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "admin.system.version" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 7]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] setting featureCompatibilityVersion to 3.6
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] Skip closing connection for connection # 3
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] Skip closing connection for connection # 2
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] Skip closing connection for connection # 1
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] CollectionCloner ns:admin.system.version finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 5] CollectionCloner::start called, on ns:admin.system.keys
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 3] createCollection: admin.system.keys with provided UUID: 1830a91b-c4f7-48ad-bf99-d69ff10066e7
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 3] build index on: admin.system.keys properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "admin.system.keys" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 3]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 2] CollectionCloner ns:admin.system.keys finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-0] CollectionCloner::start called, on ns:config.system.sessions
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 0] createCollection: config.system.sessions with provided UUID: a2741332-f793-497a-829d-e7abc4d4f785
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 0] build index on: config.system.sessions properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "config.system.sessions" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 0]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 10] _insertDocumentsCallback, but no documents to insert for ns:config.system.sessions
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 10] CollectionCloner ns:config.system.sessions finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 10] CollectionCloner::start called, on ns:config.transactions
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [NetworkInterfaceASIO-RS-0] Connecting to test-mongo-re1.test.dummy.eu:27017
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 8] createCollection: config.transactions with provided UUID: 338bda00-b652-44ce-90fd-e3902995e63c
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 8] build index on: config.transactions properties: { v: 2, key: { _id: 1 }, name: "_id_", ns: "config.transactions" }
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 8]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 14] _insertDocumentsCallback, but no documents to insert for ns:config.transactions
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 14] CollectionCloner ns:config.transactions finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [replication-1] CollectionCloner::start called, on ns:dummy.prometheus_exporter
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 12] createCollection: dummy.prometheus_exporter with provided UUID: 1a6a1775-5291-4d1e-94ad-2b2739fac25c
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [NetworkInterfaceASIO-RS-0] Successfully connected to test-mongo-re1.test.dummy.eu:27017, took 30ms (3 connections now open to test-mongo-re1.test.dummy.eu:27017)
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 6] CollectionCloner ns:dummy.prometheus_exporter finished cloning with status: OK
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 6] CollectionCloner::start called, on ns:dummy.mongo_exporter.chunks
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 4] createCollection: dummy.mongo_exporter.chunks with provided UUID: ca1c7156-3f29-486e-a0a1-de6493bfbf61
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 4] CollectionCloner ns:dummy.mongo_exporter.chunks finished cloning with status: IndexAlreadyExists: no indexes per repl
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 4] collection clone for 'dummy.mongo_exporter.chunks' failed due to IndexAlreadyExists: While cloning collection 'dummy.mongo_exporter.chunks' there was an error 'no indexes per repl'
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 4] CollectionCloner::start called, on ns:dummy.mongo_exporter.files
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 1] createCollection: dummy.mongo_exporter.files with provided UUID: e36b38de-0a72-47bc-952c-dd41409e8090
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 1] CollectionCloner ns:dummy.mongo_exporter.files finished cloning with status: IndexAlreadyExists: no indexes per repl
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 1] collection clone for 'dummy.mongo_exporter.files' failed due to IndexAlreadyExists: While cloning collection 'dummy.mongo_exporter.files' there was an error 'no indexes per repl'
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 1] database 'dummy' (3 of 3) clone failed due to InitialSyncFailure: Failed to clone 2 collection(s) in 'dummy' from test-mongo-re1.test.dummy.eu:27017
May 04 08:35:54 test-mongo-hid.test.dummy.eu mongod.27017[5093]: [repl writer worker 1] Finished cloning data: InitialSyncFailure: Failed to clone 2 collection(s) in 'dummy' from test-mongo-re1.test.dummy.eu:27017. Beginning oplog replay.
May 04 08:35:54 test-mongo-hid.test.dummy.eu systemd[1]: mongod@aptest-rs1.service: Main process exited, code=exited, status=14/n/a
May 04 08:35:54 test-mongo-hid.test.dummy.eu systemd[1]: mongod@aptest-rs1.service: Unit entered failed state.
May 04 08:35:54 test-mongo-hid.test.dummy.eu systemd[1]: mongod@aptest-rs1.service: Failed with result 'exit-code'.

       

      It seems that in the code, if buildIndexes is false and we are not on the _id index, you return a Status with the message on the stacktrace

      https://github.com/mongodb/mongo/blob/b1cc960cb5de30861b00bf72057c5dfa0733c1fb/src/mongo/db/catalog/index_catalog_impl.cpp

        1. dummy_db.tar.gz
          19 kB
          Dugast Fabien

            Assignee:
            backlog-server-repl [DO NOT USE] Backlog - Replication Team
            Reporter:
            Insolite Dugast Fabien
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated: