Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Fixed
-
0.9.7
-
None
-
None
-
Windows XP/2003 built with Visual Studio 2003
Description
DailyRollingFileAppender::~DailyRollingFileAppender must call finalize.
When the process is shutting down it destroys global objects.
Thus the DailyRolingFileAppender instances will be destroyed.
These inherit from FileAppender, and indirectly virtually inherit from Object.
The FileAppender within its destructor attempts to close the files (via Finalize), however the object is now already partly destroyed. In WriterAppender::close before closing the file a synchronization lock is acquired, but indirectly calling ObjectImpl::lock which has been virtually inheritted. Because the object has been partially destroyed the offset for the 'this' parameter to ObjectImpl::lock gets incorrectly calculated, and the address of the critical section object passed to EnterCriticalSection is wrong.
The synchronization uses a critical section object, which contains a spin count. Depending on the values in memory (at the now wrong address) the following are all possible:
1) Spinning CPU for some seconds
2) deadlock
A stack trace of the problem looks like this:
ntdll!RtlEnterCriticalSection
log4cxx!log4cxx::helpers::CriticalSection::lock
log4cxx!log4cxx::WriterAppender::close
log4cxx!log4cxx::FileAppender::~FileAppender
log4cxx!log4cxx::DailyRollingFileAppender::~DailyRollingFileAppender
log4cxx!log4cxx::nt::SizeLimitedDailyRollingFileAppender::`vbase destructor'
log4cxx!log4cxx::nt::SizeLimitedDailyRollingFileAppender::`vector deleting destructor'
log4cxx!log4cxx::helpers::ObjectImpl::releaseRef
log4cxx!std::_Destroy_range<log4cxx::helpers::ObjectPtrT<log4cxx::Appender>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Appender> > >
log4cxx!log4cxx::helpers::AppenderAttachableImpl::~AppenderAttachableImpl
log4cxx!log4cxx::helpers::AppenderAttachableImpl::`vector deleting destructor'
log4cxx!log4cxx::helpers::ObjectImpl::releaseRef
log4cxx!log4cxx::Logger::~Logger
log4cxx!log4cxx::Logger::`vector deleting destructor'
log4cxx!log4cxx::helpers::ObjectImpl::releaseRef
log4cxx!std::pair<std::basic_string<char,std::char_traits<char>,std::allocator<char> > const ,log4cxx::helpers::ObjectPtrT<log4cxx::Logger> >::~pair<std::basic_string<char,std::char_traits<char>,std::allocator<char> > const ,log4cxx::helpers::ObjectPtrT<log4cxx::Logger> >
log4cxx!std::_Tree<std::_Tmap_traits<std::basic_string<char,std::char_traits<char>,std::allocator<char> >,log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::less<std::basic_string<char,std::char_traits<char>,std::allocator<char> > >,std::allocator<std::pair<std::basic_string<char,std::char_traits<char>,std::allocator<char> > const ,log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,0> >::_Erase
log4cxx!std::_Tree<std::_Tmap_traits<std::basic_string<char,std::char_traits<char>,std::allocator<char> >,log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::less<std::basic_string<char,std::char_traits<char>,std::allocator<char> > >,std::allocator<std::pair<std::basic_string<char,std::char_traits<char>,std::allocator<char> > const ,log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,0> >::erase
log4cxx!log4cxx::Hierarchy::~Hierarchy
log4cxx!log4cxx::Hierarchy::`vbase destructor'
log4cxx!log4cxx::Hierarchy::`vector deleting destructor'
log4cxx!log4cxx::helpers::ObjectImpl::releaseRef
log4cxx!log4cxx::spi::DefaultRepositorySelector::`vector deleting destructor'
log4cxx!log4cxx::helpers::ObjectImpl::releaseRef
log4cxx!_CRT_INIT
log4cxx!_DllMainCRTStartup
ntdll!LdrpCallInitRoutine
ntdll!LdrShutdownProcess
kernel32!_ExitProcess
kernel32!ExitProcess
MSVCR71!__crtExitProcess
MSVCR71!_cinit
Solution:
Call finalize within DailyRollingFileAppender::~DailyRollingFileAppender just like all the other appenders do.
Also all user defined / derived appenders must do this, and it may be worth adding code to detect that it has not been done.
I can be reached at mark dot bartosik at reuters dot com