[SERVER-15784] mmapv1 ASSERT failure advancing btree bucket Created: 22/Oct/14  Updated: 24/Jan/15  Resolved: 09/Jan/15

Status: Closed
Project: Core Server
Component/s: Concurrency, Storage
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Quentin Conner Assignee: Geert Bosch
Resolution: Duplicate Votes: 0
Labels: 28qa
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Attachments: File mongoperf-win-20141022.log.gz    
Issue Links:
Depends
Duplicate
duplicates SERVER-15539 Invariant failure keyOffset >= 0 duri... Closed
Backwards Compatibility: Fully Compatible
Operating System: Windows
Steps To Reproduce:

install mongo-perf.
run Remove.v2.IntNonIdIndex test.
If that fails to repro, run the full suite.

Participants:

 Description   

while running mongo-perf against commit 3340ca09d383bcdf257402bc9b264529429ea97a
during the Remove.v2.IntNonIdIndex test
we saw mongod abend with ASSERT failure advancing btree bucket

Please see attached server log for complete story.

2014-10-22T20:02:33.749+0100 I COMMANDS [conn17226] CMD: drop test3.Remove_v2.IntNonIdIndex
2014-10-22T20:02:34.147+0100 I INDEXING [conn17226] build index on: test3.Remove_v2.IntNonIdIndex properties: { v: 1, key: { x: 1.0 }, name: "x_1", ns: "test3.Remove_v2.IntNonIdIndex" }
2014-10-22T20:02:34.147+0100 I INDEXING [conn17226]      building index using bulk method
2014-10-22T20:02:34.150+0100 I INDEXING [conn17226] build index done.  scanned 1000 total records. 0 secs
2014-10-22T20:02:34.151+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49832 #29437 (2 connections now open)
2014-10-22T20:02:34.152+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49833 #29438 (3 connections now open)
2014-10-22T20:02:34.152+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49834 #29439 (4 connections now open)
2014-10-22T20:02:34.152+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49835 #29440 (5 connections now open)
2014-10-22T20:02:34.152+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49836 #29441 (6 connections now open)
2014-10-22T20:02:34.153+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49837 #29442 (7 connections now open)
2014-10-22T20:02:34.153+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49838 #29443 (8 connections now open)
2014-10-22T20:02:34.153+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49839 #29444 (9 connections now open)
2014-10-22T20:02:34.153+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49840 #29445 (10 connections now open)
2014-10-22T20:02:34.153+0100 I NETWORK  [conn29437] end connection 127.0.0.1:49832 (9 connections now open)
2014-10-22T20:02:35.559+0100 I INDEXING [conn29438] ASSERT failure advancing btree bucket
2014-10-22T20:02:35.559+0100 I INDEXING [conn29438]   thisLoc: 0:31000
2014-10-22T20:02:35.559+0100 I INDEXING [conn29438]   keyOfs: -1 n:124 direction: 1
2014-10-22T20:02:35.559+0100 I -        [conn29438] Invariant failure false src\mongo\db\storage\mmap_v1\btree\btree_logic.cpp 2300
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\util\stacktrace_win.cpp(175)                         mongo::printStackTrace+0x43
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\util\log.cpp(136)                                    mongo::logContext+0x8f
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\util\assert_util.cpp(145)                            mongo::invariantFailed+0xfb
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\storage\mmap_v1\btree\btree_logic.cpp(2300)       mongo::BtreeLogic<mongo::BtreeLayoutV1>::advance+0x475
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\storage\mmap_v1\btree\btree_logic.cpp(683)        mongo::BtreeLogic<mongo::BtreeLayoutV1>::advance+0x3b
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\storage\mmap_v1\btree\btree_interface.cpp(198)    mongo::BtreeInterfaceImpl<mongo::BtreeLayoutV1>::Cursor::advance+0x26
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\exec\index_scan.cpp(186)                          mongo::IndexScan::work+0x197
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\exec\fetch.cpp(72)                                mongo::FetchStage::work+0x9c
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\exec\delete.cpp(81)                               mongo::DeleteStage::work+0xc3
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\query\plan_executor.cpp(272)                      mongo::PlanExecutor::getNext+0x93
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\query\plan_executor.cpp(373)                      mongo::PlanExecutor::executePlan+0x5f
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\ops\delete_executor.cpp(185)                      mongo::DeleteExecutor::execute+0x158
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\commands\write_commands\batch_executor.cpp(1283)  mongo::multiRemove+0x571
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\commands\write_commands\batch_executor.cpp(896)   mongo::WriteBatchExecutor::execRemove+0xa9
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\commands\write_commands\batch_executor.cpp(771)   mongo::WriteBatchExecutor::bulkExecute+0x26f
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\commands\write_commands\batch_executor.cpp(264)   mongo::WriteBatchExecutor::executeBatch+0x5b2
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\commands\write_commands\write_commands.cpp(145)   mongo::WriteCmd::run+0x16a
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\dbcommands.cpp(1158)                              mongo::_execCommand+0x72
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\dbcommands.cpp(1374)                              mongo::Command::execCommand+0xd84
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\dbcommands.cpp(1450)                              mongo::_runCommands+0x437
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\query\new_find.cpp(125)                           mongo::runCommands+0x43
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\query\new_find.cpp(529)                           mongo::newRunQuery+0x412
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\instance.cpp(272)                                 mongo::receivedQuery+0x359
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\instance.cpp(445)                                 mongo::assembleResponse+0x310
2014-10-22T20:02:35.974+0100 I -        [conn29438] mongod.exe    ...\src\mongo\db\db.cpp(184)                                       mongo::MyMessageHandler::process+0xdd
2014-10-22T20:02:35.975+0100 I -        [conn29438] mongod.exe    ...\src\mongo\util\net\message_server_port.cpp(235)                mongo::PortMessageServer::handleIncomingMsg+0x5df
2014-10-22T20:02:35.975+0100 I -        [conn29438] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(185)    boost::`anonymous namespace'::thread_start_function+0x21
2014-10-22T20:02:35.975+0100 I -        [conn29438] mongod.exe    f:\dd\vctools\crt\crtw32\startup\threadex.c(376)                   _callthreadstartex+0x17
2014-10-22T20:02:35.975+0100 I -        [conn29438] mongod.exe    f:\dd\vctools\crt\crtw32\startup\threadex.c(354)                   _threadstartex+0x102
2014-10-22T20:02:35.975+0100 I -        [conn29438] kernel32.dll                                                                     BaseThreadInitThunk+0xd
2014-10-22T20:02:35.975+0100 I -        [conn29438] 
2014-10-22T20:02:35.975+0100 I -        [conn29438] 



 Comments   
Comment by Daniel Pasette (Inactive) [ 29/Dec/14 ]

likely solved with SERVER-15539

Comment by Quentin Conner [ 10/Dec/14 ]

This symptom is one of two symptoms seen with mongo-perf when corrupt index files are discovered.

I have seen either this Assert or I've seen the Invariant in SERVER-15539.

Reproduction is the same for this ticket. I was planning to re-test once we determine SERVER-15539 is fixed. Have entered a dependency link to help track.

Comment by Quentin Conner [ 23/Nov/14 ]

Re-opening since it's not clear corrective action was taken, and SERVER-15539 turned up again with 2.8.0-rc1 (609a149).

Comment by Quentin Conner [ 20/Nov/14 ]

still good at c0a623c

Comment by Quentin Conner [ 10/Nov/14 ]

I noticed at git hash f91d3efd69a154d46a73caf2e6b5a5f632b56061 (in master) that we aren't seeing the assert any longer.

I have not bisected to see which checkin fixed it, but have several complete (good) mongo-perf runs with MMAPv1 (same two-socket hardware).

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