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

Logic for checking namespace name length for new collection is faulty

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Critical - P2 Critical - P2
    • 2.5.5
    • 2.2.0, 2.5.1
    • Internal Code
    • None
    • ALL

    Description

      In testing a code review submission for SERVER-7017, I played with creating long collection names. It doesn't work quite the way it should.

      I started with a fresh database named "foo" and tried to create a collection with a 130 character name, which failed as expected with "ns name too long, max size is 128". I then shortened the name by one character repeatedly and watched what happened.

      At 123 characters, the "foo" files were created (foo.ns, foo.0, foo.1) and the log showed:

      Fri Oct 05 13:20:14 [FileAllocator] allocating new datafile c:/data/db/foo.ns, filling with zeroes...
      Fri Oct 05 13:20:14 [FileAllocator] creating directory c:/data/db/_tmp
      Fri Oct 05 13:20:14 [FileAllocator] done allocating datafile c:/data/db/foo.ns, size: 16MB,  took 0.078 secs
      Fri Oct 05 13:20:14 [FileAllocator] allocating new datafile c:/data/db/foo.0, filling with zeroes...
      Fri Oct 05 13:20:14 [FileAllocator] done allocating datafile c:/data/db/foo.0, size: 64MB,  took 0.311 secs
      Fri Oct 05 13:20:14 [conn1] datafileheader::init initializing c:/data/db/foo.0 n:0
      Fri Oct 05 13:20:14 [FileAllocator] allocating new datafile c:/data/db/foo.1, filling with zeroes...
      Fri Oct 05 13:20:14 [conn1] build index foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123 { _id: 1 }
      Fri Oct 05 13:20:14 [conn1] insert foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123 keyUpdates:0 exception: ns name too long, max size is 128 code:10080 locks(micros) w:402592 402ms
      Fri Oct 05 13:20:15 [FileAllocator] done allocating datafile c:/data/db/foo.1, size: 128MB,  took 0.624 secs

      In the shell, I still got the "ns name too long, max size is 128" error and the collection was not created. The database name ("foo"), a period, and the 123 character collection name should have been of length 127, so the error message is misleading/incorrect.

      Trying shorter names, I got the same error message in the shell until I brought the collection name length down to 117 characters. For each "failing" attempt, the log showed that it was creating an index, but no message in the log indicated any error.

      Fri Oct 05 13:29:47 [conn1] build index foo.a2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012 { _id: 1 }
      Fri Oct 05 13:30:05 [conn1] build index foo.a234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901 { _id: 1 }
      Fri Oct 05 13:30:11 [conn1] build index foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890 { _id: 1 }
      Fri Oct 05 13:30:15 [conn1] build index foo.a2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789 { _id: 1 }
      Fri Oct 05 13:30:26 [conn1] build index foo.a234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678 { _id: 1 }
      Fri Oct 05 13:30:32 [conn1] build index foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567 { _id: 1 }
      Fri Oct 05 13:30:32 [conn1] build index done.  scanned 0 total records. 0.002 secs

      The collection and _id index were successfully created:

      > db["a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567"].insert({})
      > db.getCollectionNames()
      [
              "a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567",
              "system.indexes"
      ]
      > db.system.indexes.find()
      { "v" : 1, "key" : { "_id" : 1 }, "ns" : "foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567", "name" : "_id_" }

      Testing the new code from the patch for SERVER-7017, it cuts me off at a lower limit than the initial creation of the collection did, so I can't rename my 117 character collection to another 117 character name; the limit it imposes is 110 characters for the full namespace name, so 106 for the collection name.

      > db.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567.renameCollection("b2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567")
      {
              "errmsg" : "exception: collection name length of 111 exceeds maximum length of 110, allowing for index names",
              "code" : 16437,
              "ok" : 0
      }
      > db.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567.renameCollection("b234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456")
      { "ok" : 1 }
      >

      But this length generate assertions on the server:

      Fri Oct 05 13:54:18 [conn1] Assertion: 10348:$extra: ns name too long
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\util\stacktrace.cpp(161)                        mongo::printStackTrace+0x5b
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\util\log.cpp(435)                               mongo::logContext+0x72
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\util\assert_util.cpp(154)                       mongo::msgasserted+0x171
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\namespace-inl.h(45)                          mongo::Namespace::extraName+0x114
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(465)                   mongo::NamespaceIndex::kill_ns+0xf0
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(819)                   mongo::renameNamespace+0x1d6
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(868)                   mongo::renameNamespace+0x926
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\cloner.cpp(800)                              mongo::CmdRenameCollection::run+0x882
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(1879)                         mongo::_execCommand+0xb4
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(2037)                         mongo::execCommand+0x1113
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(2090)                         mongo::_runCommands+0x3c4
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\ops\query.cpp(43)                            mongo::runCommands+0x7b
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\ops\query.cpp(933)                           mongo::runQuery+0x46a
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\instance.cpp(244)                            mongo::receivedQuery+0x155
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\instance.cpp(390)                            mongo::assembleResponse+0x37d
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\db\db.cpp(193)                                  mongo::MyMessageHandler::process+0x133
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\mongo\util\net\message_server_port.cpp(86)            mongo::pms::threadRun+0x638
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\third_party\boost\boost\bind\bind.hpp(254)            boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> >::operator()<void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list0>+0x56
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\third_party\boost\boost\bind\bind_template.hpp(21)    boost::_bi::bind_t<void,void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> > >::operator()+0x61
      Fri Oct 05 13:54:21 [conn1] mongod.exe  ...\src\third_party\boost\boost\thread\detail\thread.hpp(63)  boost::detail::thread_data<boost::_bi::bind_t<void,void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> > > >::run+0x2f
      Fri Oct 05 13:54:21 [conn1] caught exception in kill_ns
      Fri Oct 05 13:54:21 [conn1] Assertion: 10348:$extra: ns name too long
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\util\stacktrace.cpp(161)                        mongo::printStackTrace+0x5b
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\util\log.cpp(435)                               mongo::logContext+0x72
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\util\assert_util.cpp(154)                       mongo::msgasserted+0x171
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\namespace-inl.h(45)                          mongo::Namespace::extraName+0x114
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(465)                   mongo::NamespaceIndex::kill_ns+0xf0
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(819)                   mongo::renameNamespace+0x1d6
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\namespace_details.cpp(868)                   mongo::renameNamespace+0x926
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\cloner.cpp(800)                              mongo::CmdRenameCollection::run+0x882
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(1879)                         mongo::_execCommand+0xb4
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(2037)                         mongo::execCommand+0x1113
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\dbcommands.cpp(2090)                         mongo::_runCommands+0x3c4
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\ops\query.cpp(43)                            mongo::runCommands+0x7b
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\ops\query.cpp(933)                           mongo::runQuery+0x46a
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\instance.cpp(244)                            mongo::receivedQuery+0x155
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\instance.cpp(390)                            mongo::assembleResponse+0x37d
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\db\db.cpp(193)                                  mongo::MyMessageHandler::process+0x133
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\mongo\util\net\message_server_port.cpp(86)            mongo::pms::threadRun+0x638
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\third_party\boost\boost\bind\bind.hpp(254)            boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> >::operator()<void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list0>+0x56
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\third_party\boost\boost\bind\bind_template.hpp(21)    boost::_bi::bind_t<void,void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> > >::operator()+0x61
      Fri Oct 05 13:54:22 [conn1] mongod.exe  ...\src\third_party\boost\boost\thread\detail\thread.hpp(63)  boost::detail::thread_data<boost::_bi::bind_t<void,void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list1<boost::_bi::value<mongo::MessagingPort * __ptr64> > > >::run+0x2f
      Fri Oct 05 13:54:22 [conn1] caught exception in kill_ns
      Fri Oct 05 13:54:22 [conn1] command admin.$cmd command: { renameCollection: "foo.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567", to: "foo.b234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456", dropTarget: undefined } ntoreturn:1 keyUpdates:0 locks(micros) W:3594106 reslen:37 3593ms

      Despite the errors shown on the server, things look right in the shell:

      > db.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567.renameCollection("b2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567")
      {
              "errmsg" : "exception: collection name length of 111 exceeds maximum length of 110, allowing for index names",
              "code" : 16437,
              "ok" : 0
      }
      > db.a23456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567.renameCollection("b234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456")
      { "ok" : 1 }
      > db.getCollectionNames()
      [
              "b234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456",
              "system.indexes"
      ]
      > db.system.indexes.find()
      { "v" : 1, "key" : { "_id" : 1 }, "ns" : "foo.b234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456", "name" : "_id_" }
      >

      Summary of issues:

      1. Data files should not be created until after validation of the collection name
      2. Index creation should not begin until after validation of the collection name
      3. Index creation failures should be logged on the server
      4. Name length checking should be consistent between collection creation and rename
      5. Error assertions should specify the actual limit and show the length that triggered the assertion so the user knows how many characters have to be removed
      6. Rename operations shown as successful to the user should not generate assertions in the logs
      7. Assertions logged on the server as "Assertion: 10348:$extra: ns name too long" should show the name and its length

      The assertions mentioned in last two points are probably fallout from the inconsistency between the creation and rename lengths, but I'm guessing.

      Attachments

        Activity

          People

            mathias@mongodb.com Mathias Stearn
            tad Tad Marshall
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: