[SERVER-17056] On shutdown and database drop data files can be closed before the journal thread has finished applying Created: 26/Jan/15  Updated: 18/Sep/15  Resolved: 26/Jan/15

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 3.0.0-rc7

Type: Bug Priority: Critical - P2
Reporter: Ian Whalen (Inactive) Assignee: Kaloian Manassiev
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File closeall.js    
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

LOGS

closeall.js end test loop.  slave.foo.count:
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\stacktrace_win.cpp(175)                       mongo::printStackTrace+0x43
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\log.cpp(135)                                  mongo::logContext+0x97
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\assert_util.cpp(132)                          mongo::verifyFailed+0x12e
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_recover.cpp(304)            mongo::dur::RecoveryJob::Last::newEntry+0x19c
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_recover.cpp(325)            mongo::dur::RecoveryJob::write+0x47
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_recover.cpp(355)            mongo::dur::RecoveryJob::applyEntry+0x2fb
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_recover.cpp(380)            mongo::dur::RecoveryJob::applyEntries+0x119
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_recover.cpp(445)            mongo::dur::RecoveryJob::processSection+0x52c
 m30002| 2015-01-26T17:17:52.298+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_journal_writer.cpp(65)      mongo::dur::`anonymous namespace'::WRITETODATAFILES+0xd3
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_journal_writer.cpp(244)     mongo::dur::JournalWriter::_journalWriterThread+0x366
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(185)  boost::`anonymous namespace'::thread_start_function+0x21
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   beginthreadex+0x107
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   endthreadex+0x192
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] kernel32.dll                                                                   BaseThreadInitThunk+0xd
 m30002| 2015-01-26T17:17:52.299+0000 I CONTROL  [journal writer] 
 m30002| 2015-01-26T17:17:52.300+0000 F JOURNAL  [journal writer] dbexception in journalWriterThread causing immediate shutdown: 0 assertion src\mongo\db\storage\mmap_v1\dur_recover.cpp:304
 m30002| 2015-01-26T17:17:52.300+0000 I -        [journal writer] Invariant failure false src\mongo\db\storage\mmap_v1\dur_journal_writer.cpp 250
 m30002| 2015-01-26T17:17:52.848+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\stacktrace_win.cpp(175)                       mongo::printStackTrace+0x43
 m30002| 2015-01-26T17:17:52.848+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\log.cpp(135)                                  mongo::logContext+0x97
 m30002| 2015-01-26T17:17:52.848+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\util\assert_util.cpp(147)                          mongo::invariantFailed+0xf0
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_journal_writer.cpp(250)     `mongo::dur::JournalWriter::_journalWriterThread'::`1'::catch$0+0x8c
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   _unDNameEx+0x268
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   _BuildCatchObjectHelper+0x345
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] ntdll.dll                                                                      RtlRestoreContext+0x2e2
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] mongod.exe    ...\src\mongo\db\storage\mmap_v1\dur_journal_writer.cpp(244)     mongo::dur::JournalWriter::_journalWriterThread+0x366
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(185)  boost::`anonymous namespace'::thread_start_function+0x21
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   beginthreadex+0x107
 m30002| 2015-01-26T17:17:52.849+0000 I CONTROL  [journal writer] MSVCR120.dll                                                                   endthreadex+0x192
 m30002| 2015-01-26T17:17:52.850+0000 I CONTROL  [journal writer] kernel32.dll                                                                   BaseThreadInitThunk+0xd
 m30002| 2015-01-26T17:17:52.850+0000 I CONTROL  [journal writer] 
 m30002| 2015-01-26T17:17:52.850+0000 I -        [journal writer] 
 m30002| 
 m30002| ***aborting after invariant() failure
 m30002| 
 m30002| 



 Comments   
Comment by Githook User [ 27/Jan/15 ]

Author:

{u'username': u'kaloianm', u'name': u'Kaloian Manassiev', u'email': u'kaloian.manassiev@mongodb.com'}

Message: SERVER-17056 Consolidate data file flush and journal cleanup

(cherry picked from commit dcfc58256d43a0b9be3c697c444d0ca36084cced)
Branch: v3.0
https://github.com/mongodb/mongo/commit/7ae8300a5d7d443747702d6222f387d41db4c5f8

Comment by Githook User [ 26/Jan/15 ]

Author:

{u'username': u'kaloianm', u'name': u'Kaloian Manassiev', u'email': u'kaloian.manassiev@mongodb.com'}

Message: SERVER-17056 Consolidate data file flush and journal cleanup
Branch: master
https://github.com/mongodb/mongo/commit/dcfc58256d43a0b9be3c697c444d0ca36084cced

Comment by Kaloian Manassiev [ 26/Jan/15 ]

Correct, both are the same underlying issue. Looks like close journal files ran while the journal writer thread was running. Looking into it.

Comment by Ian Whalen (Inactive) [ 26/Jan/15 ]

and I assume this is the same, but would appreciate if you could confirm:

http://buildlogs.mongodb.org/MCI_windows-64-2k8-debug/builds/5515/test/durability_0/closeall.js

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