[SERVER-10219] Assertion failure when creating text index (saveerrmsg) Created: 16/Jul/13  Updated: 10/Dec/14  Resolved: 10/Sep/13

Status: Closed
Project: Core Server
Component/s: Index Maintenance
Affects Version/s: 2.4.5
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Tom Robinson Assignee: J Rassi
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows 8 Pro 64-bit
16GB RAM
Core i7-2600


Issue Links:
Duplicate
duplicates SERVER-8241 assertion failures (saveerrmsg) durin... Closed
Related
related to SERVER-8432 Mongod can fail to output error messa... Closed
Operating System: Windows
Steps To Reproduce:

Using the following collection:

{
"serverUsed": "localhost/127.0.0.1:27020",
"db": "moreover",
"collections": 4,
"objects": 15119262,
"avgObjSize": 8359.153888595885,
"dataSize": 1.2638423774E11,
"storageSize": 1.2925953144E11,
"numExtents": 100,
"indexes": 4,
"indexSize": 5.402708976E9,
"fileSize": 1.43745089536E11,
"nsSizeMB": 16,
"dataFileVersion":

{ "major": 4, "minor": 6 }

,
"ok": 1.0
}

...and after creating a text index on one of the fields.

The output from mongod is:

Mon Jul 15 18:31:44.000 [conn21] Index: (1/3) External Sort Progress: 13554300/14065458 96%
Mon Jul 15 18:31:56.596 [conn21] Index: (1/3) External Sort Progress: 13565700/14065458 96%
Mon Jul 15 18:32:06.026 [conn21] Index: (1/3) External Sort Progress: 13578600/14065458 96%
Mon Jul 15 18:32:19.113 [conn21] moreover.system.indexes Assertion failure le && !saveerrmsg.empty() src\mongo\db\pdfile.cpp 1506
Mon Jul 15 18:32:20.830 [conn21] mongod.exe ...\src\mongo\util\stacktrace.cpp(189) mongo::printStackTrace+0x3e
Mon Jul 15 18:32:20.831 [conn21] mongod.exe ...\src\mongo\util\assert_util.cpp(114) mongo::verifyFailed+0xdc
Mon Jul 15 18:32:20.831 [conn21] mongod.exe ...\src\mongo\db\pdfile.cpp(1506) `mongo::insert_makeIndex'::`1'::catch$0+0x109
Mon Jul 15 18:32:20.831 [conn21] mongod.exe f:\dd\vctools\crt_bld\SELF_64_amd64\crt\prebuild\eh\amd64\handlers.asm(44) _CallSettingFrame+0x20
Mon Jul 15 18:32:20.831 [conn21] mongod.exe f:\dd\vctools\crt_bld\self_64_amd64\crt\prebuild\eh\frame.cpp(1337) __CxxCallCatchBlock+0xeb
Mon Jul 15 18:32:20.832 [conn21] ntdll.dll RtlRestoreContext+0x304
Mon Jul 15 18:32:20.832 [conn21] mongod.exe ...\src\mongo\db\pdfile.cpp(1485) mongo::insert_makeIndex+0x6e1
Mon Jul 15 18:32:20.832 [conn21] mongod.exe ...\src\mongo\db\pdfile.cpp(1757) mongo::DataFileMgr::insert+0xda9
Mon Jul 15 18:32:20.832 [conn21] mongod.exe ...\src\mongo\db\pdfile.cpp(1328) mongo::DataFileMgr::insertWithObjMod+0x55
Mon Jul 15 18:32:20.832 [conn21] mongod.exe ...\src\mongo\db\instance.cpp(804) mongo::checkAndInsert+0x155
Mon Jul 15 18:32:20.833 [conn21] mongod.exe ...\src\mongo\db\instance.cpp(877) mongo::receivedInsert+0xb0c
Mon Jul 15 18:32:20.833 [conn21] mongod.exe ...\src\mongo\db\instance.cpp(441) mongo::assembleResponse+0x57a
Mon Jul 15 18:32:20.833 [conn21] mongod.exe ...\src\mongo\db\db.cpp(194) mongo::MyMessageHandler::process+0xfa
Mon Jul 15 18:32:20.833 [conn21] mongod.exe ...\src\mongo\util\net\message_server_port.cpp(207) mongo::PortMessageServer::handleIncomingMsg+0x56a
Mon Jul 15 18:32:20.833 [conn21] mongod.exe ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(180) boost::`anonymous namespace'::thread_start_function+0x21
Mon Jul 15 18:32:20.833 [conn21] mongod.exe f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(314) _callthreadstartex+0x17
Mon Jul 15 18:32:20.833 [conn21] mongod.exe f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(292) _threadstartex+0x7f
Mon Jul 15 18:32:20.833 [conn21] KERNEL32.DLL BaseThreadInitThunk+0x1a
Mon Jul 15 18:32:20.850 [conn21] insert moreover.system.indexes keyUpdates:0 exception: assertion src\mongo\db\pdfile.cpp:1506 locks(micros) w:14847583537 14847745ms

Participants:

 Description   

When creating a text index on a fairly large collection, mongod crashes with an assertion and the index isn't created.



 Comments   
Comment by J Rassi [ 10/Sep/13 ]

Resolving as "cannot reproduce". Please re-open if you encounter this again.

Comment by Tom Robinson [ 17/Jul/13 ]

I had to abort the second attempt for now as it had been running for about 18 hours and was still only at 12% of stage 2.

The good news is that it got further than before and so I think it was down to running out of disk space. I cleared more space the second time around.

I'll try again but probably over the weekend.

Comment by J Rassi [ 16/Jul/13 ]

Alright. Please reply with whether your second attempt was successful (and include updated disk stats), when it finishes. Could you also post the output of db.<collection>.stats() for the collection with the index in question, in addition to the db.stats() output you provided above?

Comment by Tom Robinson [ 16/Jul/13 ]

Unfortunately I hadn't been running mongod with logging to a file enabled so can't supply the log file at the moment. But I'm re-running the ensureIndex command as I write this, to see if I can reproduce it.

I'm currently running ensureIndex again so this is going to mess up the results somewhat, but my _tmp directory is currently 17.8GB and there's 38.1GB free on the drive.

Comment by J Rassi [ 16/Jul/13 ]

Could you upload the full mongod log as an attachment to this ticket? In addition, could you answer the following disk usage questions:

  • Does the mongod dbpath contain a subdirectory called "_tmp"? What is its size in GB?
  • How much space is available on the drive hosting the mongod dbpath?
Comment by Tom Robinson [ 16/Jul/13 ]

The command run to create the index was:

> db.articles.ensureIndex(

{ "article.description.content.#cdata-section": "text" }

)

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