MongoDB prints inconsistent warning messages for index creation.

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Works as Designed
    • Priority: Major - P3
    • None
    • Affects Version/s: 6.0 Required, 7.0 Required
    • Component/s: None
    • None
    • ALL
    • Hide

      How to reproduce.

      1. Deploy a simple configuration. For further reference:

      > db.version()
      6.0.15
      $ mongosh --version
      2.3.0
      

      Tested the same behavior on 7.0.12

       

      2. Create some dummy structure:

      replset [direct: primary] admin> use foo
      switched to db foo
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').insertOne({"name": "Joe", "age": 98})
      {
        acknowledged: true,
        insertedId: ObjectId('676358306ae75f8fcc95c3ab')
      }
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').find()
      [ { _id: ObjectId('676358306ae75f8fcc95c3ab'), name: 'Joe', age: 98 } ]
      
      replset [direct: primary] foo> db.dummy.getIndexes()
      [ { v: 2, key: { _id: 1 }, name: '_id_' } ]

       

      3. Let's create a new index for age:

      db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1});
      age_1

       

      4. So far, so good; Index created:

      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').getIndexes()
      [
        { v: 2, key: { _id: 1 }, name: '_id_' },
        { v: 2, key: { age: 1 }, name: 'age_1' }
      ]

      5. Now, let's create a new one on age but passing a collation parameter. But before that, let's increase the log and then create the index:

      replset [direct: primary] foo> db.setLogLevel(5)
      --- logs ---
      {"t":{"$date":"2024-12-18T20:32:06.749-03:00"},"s":"D2", "c":"COMMAND",  "id":21965,   "ctx":"conn21","msg":"About to run the command","attr":{"db":"foo","client":"127.0.0.1:44266","commandArgs":{"createIndexes":"dummy","indexes":[{"collation":{"locale":"simple","strength":1},"name":"age_1","key":{"age":1}}],"lsid":{"id":{"$uuid":"03196d93-9a7e-4971-81c4-3e0314801e15"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1734564702,"i":1}},"signature":{"hash":{"$binary":{"ba
      se64":"rfdHUyasHlu2GLtKomzt7Zq3hRQ=","subType":"0"}},"keyId":7392671011805593608}},"$readPreference":{"mode":"primaryPreferred"},"$db":"foo"}}}
      {"t":{"$date":"2024-12-18T20:32:06.749-03:00"},"s":"D2", "c":"COMMAND",  "id":21955,   "ctx":"conn21","msg":"Applying default readConcern on command","attr":{"readConcernDefault":{"readConcern":{"level":"local"}},"command":"createIndexes"}}
      {"t":{"$date":"2024-12-18T20:32:06.749-03:00"},"s":"D2", "c":"REPL",     "id":22548,   "ctx":"conn21","msg":"Applying default writeConcern on {cmdObj_firstElementFieldName} of {wcDefault}","attr":{"cmdObj_firstElementFieldName":"createIndexes","wcDefault":{"w":"majority","wtimeout":0}}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D2", "c":"REPL",     "id":22549,   "ctx":"conn21","msg":"Waiting for write concern. OpTime: {replOpTime}, write concern: {writeConcern}","attr":{"replOpTime":{"ts":{"$timestamp":{"t":1734564722,"i":1}},"t":20},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"implicitDefault"}}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D3", "c":"STORAGE",  "id":22414,   "ctx":"conn21","msg":"WT begin_transaction","attr":{"snapshotId":141782,"readSource":"kNoTimestamp"}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D3", "c":"STORAGE",  "id":22413,   "ctx":"conn21","msg":"WT rollback_transaction","attr":{"snapshotId":141782}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D4", "c":"STORAGE",  "id":22419,   "ctx":"JournalFlusher","msg":"flushed journal"}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn21","msg":"Slow query","attr":{"type":"command","ns":"foo.$cmd","appName":"mongosh 2.3.0","command":{"createIndexes":"dummy","indexes":[{"collation":{"locale":"simple","strength":1},"name":"age_1","key":{"age":1}}],"lsid":{"id":{"$uuid":"03196d93-9a7e-4971-81c4-3e0314801e15"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1734564702,"i":1}},"signature":{"hash":{"$binary":{
      "base64":"rfdHUyasHlu2GLtKomzt7Zq3hRQ=","subType":"0"}},"keyId":7392671011805593608}},"$readPreference":{"mode":"primaryPreferred"},"$db":"foo"},"numYields":0,"reslen":242,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":4}},"FeatureCompatibilityVersion":{"acquireCount":{"r":6}},"ReplicationStateTransition":{"acquireCount":{"w":6}},"Global":{"acquireCount":{"r":6}},"Database":{"acquireCount":{"r":4}},"Collection":{"acquireCount":{"r":4}},"Mutex":{"acquireCount":{"r
      ":4}}},"readConcern":{"level":"local","provenance":"implicitDefault"},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"implicitDefault"},"storage":{},"remote":"127.0.0.1:44266","protocol":"op_msg","durationMillis":0}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D2", "c":"QUERY",    "id":22783,   "ctx":"conn21","msg":"Received interrupt request for unknown op","attr":{"opId":64944,"knownOps":[]}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D3", "c":"-",        "id":5127803, "ctx":"conn21","msg":"Released the Client","attr":{"client":"conn21"}}
      {"t":{"$date":"2024-12-18T20:32:06.750-03:00"},"s":"D3", "c":"-",        "id":5127801, "ctx":"conn21","msg":"Setting the Client","attr":{"client":"conn21"}}
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1},{collation:{"locale":"simple","strength":1}});
      age_1

      From both ends, it seems it created that new index.

      But if you have paid attention you saw the same index name: age_1

       

      Then checking, no new index was created:

      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').getIndexes()
      [
        { v: 2, key: { _id: 1 }, name: '_id_' },
        { v: 2, key: { age: 1 }, name: 'age_1' }
      ]

      6. Now, let's try to use a similar command but passing an index name this time:

      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1},{collation:{"locale":"simple","strength":1},name: "some_name"});
      MongoServerError[IndexOptionsConflict]: Index already exists with a different name: age_1

      In that method, we see Mongo erroring out due to conflict.

       

      Proposed fix.

      • Mongo should handle both scenarios equally.
        • Creating an index without a name on a field that already holds a similar index structure should trigger the same IndexOptionsConflict
          color: Color value is invalid

          message

          .

       

      In the current condition, without an error conflict, the user can have a wrong understanding that the index was created because no error happened.

      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1},{name: "some_name"});
      MongoServerError[IndexOptionsConflict]: Index already exists with a different name: age_1
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1});
      age_1
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1});
      age_1
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1});
      age_1
      
      replset [direct: primary] foo> db.getSiblingDB('foo').getCollection('dummy').createIndex({age: 1});
      age_1

      Both scenarios should be treated equally

      Show
      How to reproduce. 1. Deploy a simple configuration. For further reference: > db.version() 6.0.15 $ mongosh --version 2.3.0 Tested the same behavior on 7.0.12   2. Create some dummy structure: replset [direct: primary] admin> use foo switched to db foo replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).insertOne({ "name" : "Joe" , "age" : 98}) {   acknowledged: true ,   insertedId: ObjectId( '676358306ae75f8fcc95c3ab' ) } replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).find() [ { _id: ObjectId( '676358306ae75f8fcc95c3ab' ), name: 'Joe' , age: 98 } ] replset [direct: primary] foo> db.dummy.getIndexes() [ { v: 2, key: { _id: 1 }, name: '_id_' } ]   3. Let's create a new index for age: db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1}); age_1   4. So far, so good; Index created: replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).getIndexes() [   { v: 2, key: { _id: 1 }, name: '_id_' },   { v: 2, key: { age: 1 }, name: 'age_1' } ] 5. Now, let's create a new one on age but passing a collation parameter. But before that, let's increase the log and then create the index: replset [direct: primary] foo> db.setLogLevel(5) --- logs --- { "t" :{ "$date" : "2024-12-18T20:32:06.749-03:00" }, "s" : "D2" , "c" : "COMMAND" ,   "id" :21965,   "ctx" : "conn21" , "msg" : "About to run the command" , "attr" :{ "db" : "foo" , "client" : "127.0.0.1:44266" , "commandArgs" :{ "createIndexes" : "dummy" , "indexes" :[{ "collation" :{ "locale" : "simple" , "strength" :1}, "name" : "age_1" , "key" :{ "age" :1}}], "lsid" :{ "id" :{ "$uuid" : "03196d93-9a7e-4971-81c4-3e0314801e15" }}, "$clusterTime" :{ "clusterTime" :{ "$timestamp" :{ "t" :1734564702, "i" :1}}, "signature" :{ "hash" :{ "$binary" :{"ba se64 ":" rfdHUyasHlu2GLtKomzt7Zq3hRQ= "," subType ":" 0 "}}," keyId ":7392671011805593608}}," $readPreference ":{" mode ":" primaryPreferred "}," $db ":" foo"}}} { "t" :{ "$date" : "2024-12-18T20:32:06.749-03:00" }, "s" : "D2" , "c" : "COMMAND" ,   "id" :21955,   "ctx" : "conn21" , "msg" : "Applying default readConcern on command" , "attr" :{ "readConcernDefault" :{ "readConcern" :{ "level" : "local" }}, "command" : "createIndexes" }} { "t" :{ "$date" : "2024-12-18T20:32:06.749-03:00" }, "s" : "D2" , "c" : "REPL" ,     "id" :22548,   "ctx" : "conn21" , "msg" : "Applying default writeConcern on {cmdObj_firstElementFieldName} of {wcDefault}" , "attr" :{ "cmdObj_firstElementFieldName" : "createIndexes" , "wcDefault" :{ "w" : "majority" , "wtimeout" :0}}} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D2" , "c" : "REPL" ,     "id" :22549,   "ctx" : "conn21" , "msg" : "Waiting for write concern. OpTime: {replOpTime}, write concern: {writeConcern}" , "attr" :{ "replOpTime" :{ "ts" :{ "$timestamp" :{ "t" :1734564722, "i" :1}}, "t" :20}, "writeConcern" :{ "w" : "majority" , "wtimeout" :0, "provenance" : "implicitDefault" }}} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D3" , "c" : "STORAGE" ,   "id" :22414,   "ctx" : "conn21" , "msg" : "WT begin_transaction" , "attr" :{ "snapshotId" :141782, "readSource" : "kNoTimestamp" }} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D3" , "c" : "STORAGE" ,   "id" :22413,   "ctx" : "conn21" , "msg" : "WT rollback_transaction" , "attr" :{ "snapshotId" :141782}} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D4" , "c" : "STORAGE" ,   "id" :22419,   "ctx" : "JournalFlusher" , "msg" : "flushed journal" } { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "I" ,   "c" : "COMMAND" ,   "id" :51803,   "ctx" : "conn21" , "msg" : "Slow query" , "attr" :{ "type" : "command" , "ns" : "foo.$cmd" , "appName" : "mongosh 2.3.0" , "command" :{ "createIndexes" : "dummy" , "indexes" :[{ "collation" :{ "locale" : "simple" , "strength" :1}, "name" : "age_1" , "key" :{ "age" :1}}], "lsid" :{ "id" :{ "$uuid" : "03196d93-9a7e-4971-81c4-3e0314801e15" }}, "$clusterTime" :{ "clusterTime" :{ "$timestamp" :{ "t" :1734564702, "i" :1}}, "signature" :{ "hash" :{ "$binary" :{ "base64" : "rfdHUyasHlu2GLtKomzt7Zq3hRQ=" , "subType" : "0" }}, "keyId" :7392671011805593608}}, "$readPreference" :{ "mode" : "primaryPreferred" }, "$db" : "foo" }, "numYields" :0, "reslen" :242, "locks" :{ "ParallelBatchWriterMode" :{ "acquireCount" :{ "r" :4}}, "FeatureCompatibilityVersion" :{ "acquireCount" :{ "r" :6}}, "ReplicationStateTransition" :{ "acquireCount" :{ "w" :6}}, "Global" :{ "acquireCount" :{ "r" :6}}, "Database" :{ "acquireCount" :{ "r" :4}}, "Collection" :{ "acquireCount" :{ "r" :4}}, "Mutex" :{ "acquireCount" :{"r ":4}}}," readConcern ":{" level ":" local "," provenance ":" implicitDefault "}," writeConcern ":{" w ":" majority "," wtimeout ":0," provenance ":" implicitDefault "}," storage ":{}," remote ":" 127.0.0.1:44266 "," protocol ":" op_msg "," durationMillis":0}} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D2" , "c" : "QUERY" ,     "id" :22783,   "ctx" : "conn21" , "msg" : "Received interrupt request for unknown op" , "attr" :{ "opId" :64944, "knownOps" :[]}} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D3" , "c" : "-" ,         "id" :5127803, "ctx" : "conn21" , "msg" : "Released the Client" , "attr" :{ "client" : "conn21" }} { "t" :{ "$date" : "2024-12-18T20:32:06.750-03:00" }, "s" : "D3" , "c" : "-" ,         "id" :5127801, "ctx" : "conn21" , "msg" : "Setting the Client" , "attr" :{ "client" : "conn21" }} replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1},{collation:{ "locale" : "simple" , "strength" :1}}); age_1 From both ends, it seems it created that new index. But if you have paid attention you saw the same index name: age_1   Then checking, no new index was created: replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).getIndexes() [   { v: 2, key: { _id: 1 }, name: '_id_' },   { v: 2, key: { age: 1 }, name: 'age_1' } ] 6 . Now, let's try to use a similar command but passing an index name this time: replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1},{collation:{ "locale" : "simple" , "strength" :1},name: "some_name" }); MongoServerError[IndexOptionsConflict]: Index already exists with a different name: age_1 In that method, we see Mongo erroring out due to conflict.   Proposed fix. Mongo should handle both scenarios equally. Creating an index without a name on a field that already holds a similar index structure should trigger the same IndexOptionsConflict color: Color value is invalid message .   In the current condition, without an error conflict, the user can have a wrong understanding that the index was created because no error happened. replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1},{name: "some_name" }); MongoServerError[IndexOptionsConflict]: Index already exists with a different name: age_1 replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1}); age_1 replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1}); age_1 replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1}); age_1 replset [direct: primary] foo> db.getSiblingDB( 'foo' ).getCollection( 'dummy' ).createIndex({age: 1}); age_1 Both scenarios should be treated equally
    • None
    • 3
    • None
    • None
    • None
    • None
    • None
    • None

      When creating an index in MongoDB, you can fail in a conflict scenario if a similar index already exists. 

      But that message doesn't happen for all conflicting scenarios.

            Assignee:
            Benjamin Ulmer
            Reporter:
            Jean da Silva
            Votes:
            1 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: