[SERVER-6554] Windows unhandled exception filter should print stack trace Created: 22/Jul/12  Updated: 11/Jul/16  Resolved: 31/Jul/12

Status: Closed
Project: Core Server
Component/s: Logging
Affects Version/s: 2.2.0-rc0
Fix Version/s: 2.2.0-rc1

Type: Bug Priority: Major - P3
Reporter: Tad Marshall Assignee: Tad Marshall
Resolution: Done Votes: 0
Labels: Windows
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows


Backwards Compatibility: Fully Compatible
Operating System: Windows
Participants:

 Description   

The unhandled exception filter in the Windows version of mongod is not calling printStackTrace(); it really should, so the log file has the information we need to debug access violations.



 Comments   
Comment by auto [ 31/Jul/12 ]

Author:

{u'date': u'2012-07-30T15:33:08-07:00', u'email': u'tad@10gen.com', u'name': u'Tad Marshall'}

Message: SERVER-6554 Windows unhandled exception filter print stack trace

Modify the Windows stack trace printing code to accept a "context",
and use the context record passed to the unhandled exception filter
to start the stack trace at the faulting instruction. Collect the
context used for "normal" stack traces from inside printStackTrace.
Branch: master
https://github.com/mongodb/mongo/commit/5300139ceb188361f773c7a6f3c24f9fe9affd6a

Comment by Eric Milkie [ 22/Jul/12 ]

That's good news. Using the context from the exception will give us nice stack traces.

Comment by Tad Marshall [ 22/Jul/12 ]

The exception handling code sits at the top of the stack and appears in the stack trace, but this can be short-circuited by using the CONTEXT that is pointed to by the struct _EXCEPTION_POINTERS * parameter.

For this test, I added code to crash if the database name was "crash".

Using the "current" context:

Sun Jul 22 11:39:50 [conn1] *** unhandled exception (access violation) at 0x000000013FC5BA17, terminating
Sun Jul 22 11:39:50 [conn1] *** access violation was a write to 0x0000000000000000
Sun Jul 22 11:39:50 [conn1] writing minidump diagnostic file mongo.dmp
mongod.exe     g:\mongodb\client-mods\util\util.cpp(335)                    mongo::printWindowsStackTrace+0x10a
mongod.exe     g:\mongodb\client-mods\util\goodies.h(77)                    mongo::printStackTrace+0x28
mongod.exe     g:\mongodb\client-mods\db\db.cpp(1284)                       mongo::exceptionFilter+0x32b
kernel32.dll                                                                UnhandledExceptionFilter+0x160
ntdll.dll                                                                   MD5Final+0x1de8
ntdll.dll                                                                   _C_specific_handler+0x9c
ntdll.dll                                                                   RtlDecodePointer+0xbd
ntdll.dll                                                                   RtlUnwindEx+0xbbf
ntdll.dll                                                                   KiUserExceptionDispatcher+0x2e
mongod.exe     g:\mongodb\client-mods\db\database.cpp(293)                  mongo::Database::validDBName+0x67
mongod.exe     g:\mongodb\client-mods\db\db.h(120)                          mongo::DatabaseHolder::_todb+0x7c
mongod.exe     g:\mongodb\client-mods\db\db.h(61)                           mongo::DatabaseHolder::get+0x122
mongod.exe     g:\mongodb\client-mods\db\client.cpp(194)                    mongo::Client::Context::_finishInit+0xf4
mongod.exe     g:\mongodb\client-mods\db\client.cpp(174)                    mongo::Client::Context::Context+0xc5
mongod.exe     g:\mongodb\client-mods\db\instance.cpp(631)                  mongo::receivedInsert+0x1c1
mongod.exe     g:\mongodb\client-mods\db\instance.cpp(324)                  mongo::assembleResponse+0x623
mongod.exe     g:\mongodb\client-mods\db\db.cpp(176)                        mongo::MyMessageHandler::process+0x133
mongod.exe     g:\mongodb\client-mods\util\net\message_server_port.cpp(75)  mongo::pms::threadRun+0x3cd
mongod.exe     c:\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
mongod.exe     c:\boost\boost\bind\bind_template.hpp(21)                    boost::_bi::bind_t<void,void (__cdecl*)(mongo::MessagingPort * __ptr64),boost::_bi::list1<boost::_bi::va
lue<mongo::MessagingPort * __ptr64> > >::operator()+0x61
mongod.exe     c:\boost\boost\thread\detail\thread.hpp(57)                  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
mongod.exe     c:\boost\libs\thread\src\win32\thread.cpp(167)               boost::`anonymous namespace'::thread_start_function+0x37
MSVCR100D.dll                                                               beginthreadex+0x2d5
MSVCR100D.dll                                                               beginthreadex+0x294
kernel32.dll                                                                BaseThreadInitThunk+0xd

Using the context from the exception (and using log() instead of cout):

Sun Jul 22 13:34:13 [conn1] *** unhandled exception (access violation) at 0x000000013F8AFA69, terminating
Sun Jul 22 13:34:13 [conn1] *** access violation was a write to 0x0000000000000000
Sun Jul 22 13:34:13 [conn1] writing minidump diagnostic file mongo.dmp
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\database.cpp(294)                  mongo::Database::validDBName+0x139
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\db.h(120)                          mongo::DatabaseHolder::_todb+0x54
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\db.h(61)                           mongo::DatabaseHolder::get+0xc5
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\client.cpp(194)                    mongo::Client::Context::_finishInit+0xa1
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\client.cpp(174)                    mongo::Client::Context::Context+0xb2
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\instance.cpp(631)                  mongo::receivedInsert+0x1df
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\instance.cpp(324)                  mongo::assembleResponse+0x58e
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\db\db.cpp(176)                        mongo::MyMessageHandler::process+0x8c
Sun Jul 22 13:34:13 [conn1] mongod.exe    g:\mongodb\client-mods\util\net\message_server_port.cpp(75)  mongo::pms::threadRun+0x2b4
Sun Jul 22 13:34:13 [conn1] mongod.exe                                                                 boost::`anonymous namespace'::thread_start_function+0x21
Sun Jul 22 13:34:13 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(314)  _callthreadstartex+0x17
Sun Jul 22 13:34:13 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(292)  _threadstartex+0x7f
Sun Jul 22 13:34:13 [conn1] kernel32.dll                                                               BaseThreadInitThunk+0xd
Sun Jul 22 13:34:13 dbexit: unhandled exception

Comment by Eric Milkie [ 22/Jul/12 ]

Is the stack still intact when the unhandled exception filter gains control, or has it already been unwound?

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