#103 [AIX] Application seems to be locked on a mutex

[Mikael Tintinger]

Hi all,

we encountered this situation not very often but only on AIX 5.3: the
application seems to be lock when calling _global_lock_common

0xd010b824 _waitlock(??, ??) + 0x27c  
0xd010bf28 _local_lock_common(??, ??, ??) + 0x138  
0xd01195b8 _mutex_lock(??, ??, ??) + 0x258  
0xdb07afa8 log4cplus::thread::Guard::Guard(pthread_mutex_t*)(0x315d49d8,
0x30215990) + 0x28  
0xdb07b180
log4cplus::helpers::AppenderAttachableImpl::appendLoopOnAppenders(const
log4cplus::spi::InternalLoggingEvent&) const(0x30215830, 0x315d4af0) +
0x48  
0xdb2332e0 log4cplus::spi::LoggerImpl::callAppenders(const
log4cplus::spi::InternalLoggingEvent&)(0x30225320, 0x315d4af0) + 0x68  
0xdb231bd8 log4cplus::spi::LoggerImpl::forcedLog(int,const
std::basic_string<char,std::char_traits<char>,std::allocator<char>
>&,const char*,int)(0x30225320, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44) +
0xc0  
0xdb068884 log4cplus::Logger::forcedLog(int,const
std::basic_string<char,std::char_traits<char>,std::allocator<char>
>&,const char*,int)(0x305d9f8c, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44) +
0x6c  
... 

This thread seems to be lock by:

0xd010c4c0 _global_lock_common(??, ??, ??) + 0x408  
0xd0381610 _rec_mutex_lock(??) + 0x160  
0xd01fb99c std::_Lock::_Wait()(??) + 0x5c  
0xd01fb8dc std::_Lockit::_Lockit(int)(??, ??) + 0x1c  
0xdb0945b4 std::basic_ostream<char,std::char_traits<char>
>::sentry::sentry(std::basic_ostream<char,std::char_traits<char>
>&)(0x5d3d1570, 0x3022c438) + 0x48  
0xdb0dae74 std::basic_ostream<char,std::char_traits<char> >&
std::operator<<<char,std::char_traits<char>,std::allocator<char>
>(std::basic_ostream<char,std::char_traits<char> >&,const
std::basic_string<char,std::char_traits<char>,std::allocator<char>
>&)(0x3022c438, 0x5d3d1600) + 0xc0  
0xdb1df660
log4cplus::pattern::PatternConverter::formatAndAppend(std::basic_ostream<char,std::char_traits<char>
>&,const log4cplus::spi::InternalLoggingEvent&)(0x3022d230, 0x3022c438,
0x5d3d1940) + 0x208  
0xdb1df7c0
log4cplus::PatternLayout::formatAndAppend(std::basic_ostream<char,std::char_traits<char>
>&,const log4cplus::spi::InternalLoggingEvent&)(0x3022cd10, 0x3022c438,
0x5d3d1940) + 0x70  
...

There are many other threads that are waiting for _global_lock_common. The situation looks like the bug 2961084 , but no SIGNAL handling there. I can't determine if the lock is due to log4cplus or AIX OS himself (or other). Please, find in the attachment file, the whole stack.

Thanks you for the help,
Mikael Tintinger

[anokl]

I don't know for sure. The only thing that I've found about dead beef is: "The register value may be set to a hexadecimal value of 0xdeadbeef.This is an initialization value assigned to all general-purpose registers at process initialization." I cant say if it means that the mutex is unitialized or something...

[anokl]

Answer to your question about xlC_r. Yes, we compile log4cplus and our application with the same compiler xlC_r.

[Mikael Tintinger]

Workaround done : in a class that inherit from streambuf, don't call log4cplus in overflow method.

[Václav Haisman]

I totally did not expect that. So, this is a reentrancy issue in IBM's C++ library? Could you tell me what version of AIX and the C++ compiler is that? I would like to put a note about this into the README file.

[Mikael Tintinger]

-bash-3.00$ uname -a
AIX pyramides2 3 5 00C934704C00
-bash-3.00$ oslevel
5.3.0.0
-bash-3.00$ lslpp -l | grep C++
vacpp.Bnd 8.0.0.0 COMMITTED IBM XL C/C++ Media Defined
vacpp.cmp.aix50.lib 8.0.0.0 COMMITTED IBM XL C/C++ Libraries for AIX
vacpp.cmp.aix50.tools 8.0.0.0 COMMITTED IBM XL C/C++ Tools for AIX 5.0
vacpp.cmp.core 8.0.0.0 COMMITTED IBM XL C/C++ Compiler
vacpp.cmp.include 8.0.0.0 COMMITTED IBM XL C/C++ Compiler Include
vacpp.cmp.lib 8.0.0.0 COMMITTED IBM XL C/C++ Libraries
vacpp.cmp.rte 8.0.0.0 COMMITTED IBM XL C/C++ Compiler
vacpp.cmp.tools 8.0.0.0 COMMITTED IBM XL C/C++ Tools
vacpp.html.common 8.0.0.0 COMMITTED IBM XL C/C++ Documentation
vacpp.html.en_US 8.0.0.0 COMMITTED IBM XL C/C++ Documentation
vacpp.lic 8.0.0.0 COMMITTED IBM XL C/C++ Licence Files
vacpp.licAgreement 8.0.0.0 COMMITTED IBM XL C++ Electronic License
vacpp.memdbg.aix50.lib 8.0.0.0 COMMITTED IBM XL C/C++ User Heap/Memory
vacpp.memdbg.aix50.rte 8.0.0.0 COMMITTED IBM XL C/C++ User Heap/Memory
vacpp.memdbg.lib 8.0.0.0 COMMITTED IBM XL C/C++ User Heap and
vacpp.memdbg.rte 8.0.0.0 COMMITTED IBM XL C/C++ User Heap and
vacpp.ndi 8.0.0.0 COMMITTED IBM XL C/C++ Non-Default
xlC.aix50.rte 10.1.0.0 COMMITTED XL C/C++ Runtime for AIX 5.3
xlC.msg.en_US.rte 10.1.0.0 COMMITTED XL C/C++ Runtime
xlC.rte 10.1.0.0 COMMITTED XL C/C++ Runtime
vacpp.cmp.core 8.0.0.0 COMMITTED IBM XL C/C++ Compiler

[Václav Haisman]

Thank you for the OS and compiler version information and for solving this. I have put a few lines about it into the README.

I am closing this are invalid, since it is not a log4cplus but a platform problem.

[Václav Haisman]

• Description has changed:

Diff:

--- old
+++ new
@@ -1,32 +1,58 @@
 Hi all,

-we encountered this situation not very often but only on AIX 5.3: the application seems to be lock when calling \_global\_lock\_common
+we encountered this situation not very often but only on AIX 5.3: the
+application seems to be lock when calling `_global_lock_common`

-0xd010b824  \_waitlock\(??, ??\) + 0x27c
-0xd010bf28  \_local\_lock\_common\(??, ??, ??\) + 0x138
-0xd01195b8  \_mutex\_lock\(??, ??, ??\) + 0x258
-0xdb07afa8  log4cplus::thread::Guard::Guard\(pthread\_mutex\_t\*\)\(0x315d49d8, 0x30215990\) + 0x28
-0xdb07b180  log4cplus::helpers::AppenderAttachableImpl::appendLoopOnAppenders\(const log4cplus::spi::InternalLoggingEvent&\) const\(0x30215830, 0x315d4af0\) + 0x48
-0xdb2332e0  log4cplus::spi::LoggerImpl::callAppenders\(const log4cplus::spi::InternalLoggingEvent&\)\(0x30225320, 0x315d4af0\) + 0x68
-0xdb231bd8  log4cplus::spi::LoggerImpl::forcedLog\(int,const std::basic\_string<char,std::char\_traits<char>,std::allocator<char> >&,const char\*,int\)\(0x30225320, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44\) + 0xc0
-0xdb068884  log4cplus::Logger::forcedLog\(int,const std::basic\_string<char,std::char\_traits<char>,std::allocator<char> >&,const char\*,int\)\(0x305d9f8c, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44\) + 0x6c
+~~~~
+0xd010b824 _waitlock(??, ??) + 0x27c  
+0xd010bf28 _local_lock_common(??, ??, ??) + 0x138  
+0xd01195b8 _mutex_lock(??, ??, ??) + 0x258  
+0xdb07afa8 log4cplus::thread::Guard::Guard(pthread_mutex_t*)(0x315d49d8,
+0x30215990) + 0x28  
+0xdb07b180
+log4cplus::helpers::AppenderAttachableImpl::appendLoopOnAppenders(const
+log4cplus::spi::InternalLoggingEvent&) const(0x30215830, 0x315d4af0) +
+0x48  
+0xdb2332e0 log4cplus::spi::LoggerImpl::callAppenders(const
+log4cplus::spi::InternalLoggingEvent&)(0x30225320, 0x315d4af0) + 0x68  
+0xdb231bd8 log4cplus::spi::LoggerImpl::forcedLog(int,const
+std::basic_string<char,std::char_traits<char>,std::allocator<char>
+>&,const char*,int)(0x30225320, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44) +
+0xc0  
+0xdb068884 log4cplus::Logger::forcedLog(int,const
+std::basic_string<char,std::char_traits<char>,std::allocator<char>
+>&,const char*,int)(0x305d9f8c, 0x4e20, 0x315d4c10, 0xdc44ae28, 0x44) +
+0x6c  
+... 
+~~~~
+ 
+This thread seems to be lock by:
+
+~~~~
+0xd010c4c0 _global_lock_common(??, ??, ??) + 0x408  
+0xd0381610 _rec_mutex_lock(??) + 0x160  
+0xd01fb99c std::_Lock::_Wait()(??) + 0x5c  
+0xd01fb8dc std::_Lockit::_Lockit(int)(??, ??) + 0x1c  
+0xdb0945b4 std::basic_ostream<char,std::char_traits<char>
+>::sentry::sentry(std::basic_ostream<char,std::char_traits<char>
+>&)(0x5d3d1570, 0x3022c438) + 0x48  
+0xdb0dae74 std::basic_ostream<char,std::char_traits<char> >&
+std::operator<<<char,std::char_traits<char>,std::allocator<char>
+>(std::basic_ostream<char,std::char_traits<char> >&,const
+std::basic_string<char,std::char_traits<char>,std::allocator<char>
+>&)(0x3022c438, 0x5d3d1600) + 0xc0  
+0xdb1df660
+log4cplus::pattern::PatternConverter::formatAndAppend(std::basic_ostream<char,std::char_traits<char>
+>&,const log4cplus::spi::InternalLoggingEvent&)(0x3022d230, 0x3022c438,
+0x5d3d1940) + 0x208  
+0xdb1df7c0
+log4cplus::PatternLayout::formatAndAppend(std::basic_ostream<char,std::char_traits<char>
+>&,const log4cplus::spi::InternalLoggingEvent&)(0x3022cd10, 0x3022c438,
+0x5d3d1940) + 0x70  
 ...
-This thread seems to be lock by :
+~~~~

-0xd010c4c0  \_global\_lock\_common\(??, ??, ??\) + 0x408
-0xd0381610  \_rec\_mutex\_lock\(??\) + 0x160
-0xd01fb99c  std::\_Lock::\_Wait\(\)\(??\) + 0x5c
-0xd01fb8dc  std::\_Lockit::\_Lockit\(int\)\(??, ??\) + 0x1c
-0xdb0945b4  std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;::sentry::sentry\(std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;&\)\(0x5d3d1570, 0x3022c438\) + 0x48
-0xdb0dae74  std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;& std::operator&lt;&lt;&lt;char,std::char\_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt;\(std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;&,const std::basic\_string&lt;char,std::char\_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt;&\)\(0x3022c438, 0x5d3d1600\) + 0xc0
-0xdb1df660  log4cplus::pattern::PatternConverter::formatAndAppend\(std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;&,const log4cplus::spi::InternalLoggingEvent&\)\(0x3022d230, 0x3022c438, 0x5d3d1940\) + 0x208
-0xdb1df7c0  log4cplus::PatternLayout::formatAndAppend\(std::basic\_ostream&lt;char,std::char\_traits&lt;char&gt; &gt;&,const log4cplus::spi::InternalLoggingEvent&\)\(0x3022cd10, 0x3022c438, 0x5d3d1940\) + 0x70
-...
+There are many other threads that are waiting for _global_lock_common. The situation looks like the bug 2961084 , but no SIGNAL handling there. I can't determine if the lock is due to log4cplus or AIX OS himself (or other). Please, find in the attachment file, the whole stack.

-There are many other threads that are waiting for \_global\_lock\_common.
-The situation looks like the bug 2961084 , but no SIGNAL handling there.
-I can't determine if the lock is due to log4cplus or AIX OS himself \(or other\).
-Please, find in the attachment file, the whole stack.
-
-Thanks you for the help,
+Thanks you for the help,  
 Mikael Tintinger