You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4cxx-dev@logging.apache.org by "Thorsten Schöning (JIRA)" <lo...@logging.apache.org> on 2016/03/02 09:22:18 UTC
[jira] [Commented] (LOGCXX-430) LogManager::getRootLogger is not
thread-safe
[ https://issues.apache.org/jira/browse/LOGCXX-430?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15175254#comment-15175254 ]
Thorsten Schöning commented on LOGCXX-430:
------------------------------------------
Another issue was reported on the list which looks similar to the one described here. It's a crash at exiting the process and seem to have its root cause in LogManager::getRepositorySelector():
{CODE}
log4cxx_adtyco_tpl.dll!`log4cxx::LogManager::getRepositorySelector'::`2'::`dynamic atexit destructor for 'selector''()
{CODE}
One workaround for the problem was to apply the following changes:
{CODE}
Hierarchy::~Hierarchy()
{
// LOGCXX-430
#ifndef APR_HAS_THREADS
delete loggers;
delete provisionNodes;
#endif
}
{CODE}
It's basically the same workaround like applied to APRInitializer in LOGCXX-322 and as it seems currently the only way to fix the problem for the user, I'l apply those changes with a hint to this comment. There's some destructing going on at least to the loggers when it's already too late:
{CODE}
>msvcr120.dll!abort() Line 88C
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::Logger>::~ObjectPtrT<log4cxx::Logger>() Line 102
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::Logger>::`vector deleting destructor'()
log4cxx_adtyco_tpl.dll!std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::pattern::PatternConverter>
{CODE}
The complete discussion can be found at:
http://mail-archives.apache.org/mod_mbox/logging-log4cxx-dev/201602.mbox/browser
The complete stacktrace:
{CODE}
>msvcr120.dll!abort() Line 88C
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::Logger>::~ObjectPtrT<log4cxx::Logger>() Line 102
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::Logger>::`vector deleting destructor'()
log4cxx_adtyco_tpl.dll!std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::pattern::PatternConverter> >::destroy<log4cxx::helpers::ObjectPtrT<log4cxx::pattern::PatternConverter> >(_Ptr=0x08f4df48) Line 608
log4cxx_adtyco_tpl.dll!std::allocator_traits<std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::spi::HierarchyEventListener> > >::destroy<log4cxx::helpers::ObjectPtrT<log4cxx::spi::HierarchyEventListener> >(_Al={...}, _Ptr=0x08f4df48) Line 731
log4cxx_adtyco_tpl.dll!std::_Wrap_alloc<std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::ObjectOutputStream> > >::destroy<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::ObjectOutputStream> >(_Ptr=0x08f4df48) Line 879
log4cxx_adtyco_tpl.dll!std::_Destroy_range<std::_Wrap_alloc<std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::ObjectOutputStream> > > >(_First=0x08f4df48, _Last=0x08f4df50, _Al={...}, __formal={...}) Line 82
log4cxx_adtyco_tpl.dll!std::_Destroy_range<std::_Wrap_alloc<std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::InetAddress> > > >(_First=0x08f4df48, _Last=0x08f4df50, _Al={...}) Line 96
log4cxx_adtyco_tpl.dll!std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket> > >::_Destroy(_First=0x08f4df48, _Last=0x08f4df50) Line 1567
log4cxx_adtyco_tpl.dll!std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket> > >::_Tidy() Line 1628
log4cxx_adtyco_tpl.dll!std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket> > >::~vector<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::helpers::Socket> > >() Line 946
log4cxx_adtyco_tpl.dll!std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >::~pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >()
log4cxx_adtyco_tpl.dll!std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >::`scalar deleting destructor'()
log4cxx_adtyco_tpl.dll!std::allocator<std::_Tree_node<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >,void *> >::destroy<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >(_Ptr=0x1921d550) Line 608
log4cxx_adtyco_tpl.dll!std::allocator_traits<std::allocator<std::_Tree_node<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >,void *> > >::destroy<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >(_Al={...}, _Ptr=0x1921d550) Line 731
log4cxx_adtyco_tpl.dll!std::_Wrap_alloc<std::allocator<std::_Tree_node<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > >,void *> > >::destroy<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >(_Ptr=0x1921d550) Line 879
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::_Erase(_Rootnode=0x1921d540) Line 2083
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::_Erase(_Rootnode=0x1921da80) Line 2079
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::clear() Line 1541
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::erase(_First={...}, _Last={...}) Line 1515
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::_Tidy() Line 2231
log4cxx_adtyco_tpl.dll!std::_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >::~_Tree<std::_Tmap_traits<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > >,0> >() Line 1193
log4cxx_adtyco_tpl.dll!std::map<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > > >::~map<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > > >()
log4cxx_adtyco_tpl.dll!std::map<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > >,std::less<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::vector<log4cxx::helpers::ObjectPtrT<log4cxx::Logger>,std::allocator<log4cxx::helpers::ObjectPtrT<log4cxx::Logger> > > > > >::`scalar deleting destructor'()
log4cxx_adtyco_tpl.dll!log4cxx::Hierarchy::~Hierarchy() Line 71
log4cxx_adtyco_tpl.dll!log4cxx::Hierarchy::`vbase destructor'()
log4cxx_adtyco_tpl.dll!log4cxx::Hierarchy::`vector deleting destructor'()
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectImpl::releaseRef() Line 46
log4cxx_adtyco_tpl.dll!log4cxx::Hierarchy::releaseRef() Line 80
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>::~ObjectPtrT<log4cxx::spi::LoggerRepository>() Line 102
log4cxx_adtyco_tpl.dll!log4cxx::spi::DefaultRepositorySelector::~DefaultRepositorySelector()
log4cxx_adtyco_tpl.dll!log4cxx::spi::DefaultRepositorySelector::`vbase destructor'()
log4cxx_adtyco_tpl.dll!log4cxx::spi::DefaultRepositorySelector::`vector deleting destructor'()
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectImpl::releaseRef() Line 46
log4cxx_adtyco_tpl.dll!log4cxx::spi::DefaultRepositorySelector::releaseRef() Line 36
log4cxx_adtyco_tpl.dll!log4cxx::helpers::ObjectPtrT<log4cxx::spi::RepositorySelector>::~ObjectPtrT<log4cxx::spi::RepositorySelector>() Line 102
log4cxx_adtyco_tpl.dll!`log4cxx::LogManager::getRepositorySelector'::`2'::`dynamic atexit destructor for 'selector''()
log4cxx_adtyco_tpl.dll!_CRT_INIT(hDllHandle, dwReason, lpreserved) Line 416C
log4cxx_adtyco_tpl.dll!__DllMainCRTStartup(hDllHandle=0x0c4d0000, dwReason=0, lpreserved=0x00000001) Line 522C
log4cxx_adtyco_tpl.dll!_DllMainCRTStartup(hDllHandle=0x0c4d0000, dwReason=0, lpreserved=0x00000001) Line 472C
ntdll.dll!_LdrxCallInitRoutine@16‑()Unknown
ntdll.dll!LdrpCallInitRoutine()Unknown
ntdll.dll!LdrShutdownProcess()Unknown
ntdll.dll!RtlExitUserProcess()Unknown
AcLayers.dll!NS_FaultTolerantHeap::FthExitUserProcess‑()Unknown
AcLayers.dll!NS_FaultTolerantHeap::APIHook_RtlExitUserProcess‑()Unknown
kernel32.dll!_ExitProcessImplementation@4‑()Unknown
mscoreei.dll!RuntimeDesc::ShutdownAllActiveRuntimes‑()Unknown
mscoreei.dll!CLRRuntimeHostInternalImpl::ShutdownAllRuntimesThenExit‑()Unknown
clr.dll!EEPolicy::ExitProcessViaShim‑()Unknown
clr.dll!SafeExitProcess‑()Unknown
clr.dll!HandleExitProcessHelper()Unknown
clr.dll!EEPolicy::HandleExitProcess‑()Unknown
clr.dll!__CorExeMainInternal@0‑()Unknown
clr.dll!__CorExeMain@0‑()Unknown
mscoreei.dll!__CorExeMain@0‑()Unknown
mscoree.dll!__CorExeMain_Exported@0‑()Unknown
kernel32.dll!@BaseThreadInitThunk@12‑()Unknown
ntdll.dll!__RtlUserThreadStart()Unknown
ntdll.dll!__RtlUserThreadStart@8‑()Unknown
{CODE}
> LogManager::getRootLogger is not thread-safe
> --------------------------------------------
>
> Key: LOGCXX-430
> URL: https://issues.apache.org/jira/browse/LOGCXX-430
> Project: Log4cxx
> Issue Type: Bug
> Components: Core
> Affects Versions: 0.10.0
> Reporter: Thorsten Schöning
> Assignee: Thorsten Schöning
> Attachments: LOGCXX-430-with-mutex-1.patch, LOGCXX-430-with-mutex-2.patch, LOGCXX-430.patch
>
>
> Kaspar Fischer reported following on the user mailing list:
> > I am running into a situation where calling getRootLogger()
> > concurrently from many requests results in a EXC_BAD_ACCESS:
> > liblog4cxx.10.dylib`log4cxx::LogManager::getRootLogger():
> > 0x101f180a0: pushq %rbp
> > 0x101f180a1: movq %rsp, %rbp
> > 0x101f180a4: pushq %rbx
> > 0x101f180a5: pushq %rax
> > 0x101f180a6: movq %rdi, %rbx
> > 0x101f180a9: callq 0x101f17de0 ;
> > log4cxx::LogManager::getLoggerRepository()
> > 0x101f180ae: movq 8(%rax), %rsi
> > 0x101f180b2: movq (%rsi), %rax
> > 0x101f180b5: movq %rbx, %rdi
> > 0x101f180b8: callq *120(%rax) <<<<<< THREAD 1: EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
> > 0x101f180bb: movq %rbx, %rax
> > 0x101f180be: addq $8, %rsp
> > 0x101f180c2: popq %rbx
> > 0x101f180c3: popq %rbp
> > 0x101f180c4: ret
> > 0x101f180c5: nopw %cs:(%rax,%rax)
> > If I replace the logging statement with a statement that writes to
> > std::cerr, I do not run into any problems.
> > I am using log4cxx 0.10.0 on MacOS 10.9.1.
> The call to getRootLogger ultimately results in:
> {CODE}
> RepositorySelectorPtr& LogManager::getRepositorySelector() {
> //
> // call to initialize APR and trigger "start" of logging clock
> //
> APRInitializer::initialize();
> static spi::RepositorySelectorPtr selector;
> return selector;
> }
> {CODE}
> It looks like we have the same problem here like in LOGCXX-394, a function static which is not thread-safe. Therefore we shoudl fix this like we did in LOGCXX-394 by removing the function static.
> Problem is that for this to work we need to change the return type of the function, which shouldn't be a problem because it's private, but need to change additional functions as well: getLoggerRepository and setRepositorySelector both currently rely on the current behavior of getRepositorySelector.
> Additionally what I don't understand is why APRInitializer is called more than once even if RepositorySelector only got created once because of it's static.
> Looks ike we need to rework the whole part, maybe make it static on a class level like the guard.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)