[SERVER-7282] Logic for checking namespace name length for new collection is faulty Created: 05/Oct/12  Updated: 11/Jul/16  Resolved: 30/Jan/14

Status: Closed
Project: Core Server
Component/s: Internal Code
Affects Version/s: 2.2.0, 2.5.1
Fix Version/s: 2.5.5

Type: Bug Priority: Critical - P2
Reporter: Tad Marshall Assignee: Mathias Stearn
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-9416 ns name too long leads to Fatal Asser... Closed
Related
is related to SERVER-7017 Rename of DB can cause overflow of na... Closed
Operating System: ALL
Participants:

 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.



 Comments   
Comment by Githook User [ 30/Jan/14 ]

Author:

{u'username': u'RedBeard0531', u'name': u'Mathias Stearn', u'email': u'mathias@10gen.com'}

Message: SERVER-7282 Clean up namespace name length checks
Branch: master
https://github.com/mongodb/mongo/commit/71de42f9467449e35016b3ba59b5149ba7c6e3c0

Generated at Thu Feb 08 03:14:05 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.