Hi, I tested the out-of-the-box version of latest log4cxx CVS, without modification, built by ant with all dependencies, I still observed the growth of memory usage when using DOMConfigurator::configure. So I added the bug report into jira (http://issues.apache.org/jira/browse/LOGCXX-145?page=all). I didn't add the valgrind reports, because as you said the pool usage should be OK and another bug can cause the memory usage growth.
Best regards Martin Balik -----Original Message----- From: Curt Arnold [mailto:[EMAIL PROTECTED] Sent: Monday, June 12, 2006 4:52 PM To: Log4CXX Dev Subject: Re: Log4cxx memory leaks in reconfiguration. On Jun 12, 2006, at 6:59 AM, Balik, Martin wrote: > Hi, > > I tried to investigate possible memleaks in log4cxx, and I found > one using many reconfigurations in endless loop. I made small > program like this: > > #include <log4cxx/logger.h> > #include <log4cxx/xml/domconfigurator.h> > > using namespace log4cxx; > int main() > { > do { > log4cxx::xml::DOMConfigurator::configure("../config/ > log_stdconf.xml"); > } while (1==1); > > > return 0; > } > > > compiled it using CVS head, run it, and watched memory usage by > qps. The memory usage grew (1 MB/ sec). After some investigation > with valgrind: > > valgrind --log-file=leaks.txt --num-callers=26 --tool=memcheck -- > leak-check=yes --show-reachable=yes --leak-resolution=high --show- > below-main=yes ./BasicTest > > I found these interesting places of log4cxx which caused the leaks: > > ==8287== 8192 bytes in 1 blocks are still reachable in loss record > 86 of 88 > ==8287== at 0x1B905B7C: malloc (in /usr/lib/valgrind/ > vgpreload_memcheck.so) > ==8287== by 0x1B932ABB: allocator_alloc (apr_pools.c:300) > ==8287== by 0x1B932F19: apr_pool_create_ex (apr_pools.c:800) > ==8287== by 0x1B933B70: apr_pool_initialize (apr_pools.c:524) > ==8287== by 0x1B933EBE: apr_initialize (start.c:55) > ==8287== by 0x80BF70F: > log4cxx::helpers::APRInitializer::APRInitializer() > (aprinitializer.cpp:30) > ==8287== by 0x80BF7C3: > log4cxx::helpers::APRInitializer::getInstance() (aprinitializer.cpp: > 53) > ==8287== by 0x80BF7F6: > log4cxx::helpers::APRInitializer::initialize() (aprinitializer.cpp:59) > ==8287== by 0x809AB6A: log4cxx::helpers::ObjectImpl::ObjectImpl > () (objectimpl.cpp:25) > ==8287== by 0x808D582: log4cxx::Level::Level(int, char const*, > int) (level.cpp:67) > ==8287== by 0x808CFDC: log4cxx::Level::getOff() (level.cpp:28) > ==8287== by 0x808DAFC: __static_initialization_and_destruction_0 > (int, int) (level.cpp:206) > ==8287== by 0x808DE30: _GLOBAL__I__ZNK7log4cxx5Level8getClassEv > (level.cpp:75) > ==8287== by 0x80E9A68: (within /home/bal/leak-workspace/ > BasicTest/Debug/BasicTest) > ==8287== by 0x804B580: (within /home/bal/leak-workspace/ > BasicTest/Debug/BasicTest) > ==8287== by 0x80E9A10: __libc_csu_init (in /home/bal/leak- > workspace/BasicTest/Debug/BasicTest) > ==8287== by 0x1BA5BE2D: __libc_start_main (in /lib/tls/libc.so.6) > ==8287== by 0x804C2B0: ??? (start.S:119) > ==8287== This one isn't surprising. This call stack represents the initialization of APR. Since the application is apparently forcibly terminated there is not the corresponding call to apr_terminate. > ==8287== > ==8287== 319488 bytes in 39 blocks are still reachable in loss > record 87 of 88 > ==8287== at 0x1B905B7C: malloc (in /usr/lib/valgrind/ > vgpreload_memcheck.so) > ==8287== by 0x1B932ABB: allocator_alloc (apr_pools.c:300) > ==8287== by 0x1B932F19: apr_pool_create_ex (apr_pools.c:800) > ==8287== by 0x805CCE1: log4cxx::helpers::Pool::Pool() (pool.cpp:29) > ==8287== by 0x805033B: > _ZN7log4cxx3xml15DOMConfigurator28parseChildrenOfLoggerElementEP12apr_ > xml_elemNS_7helpers10ObjectPtrTINS_6LoggerEEEbP11apr_xml_docRSt3mapISs > NS5_INS_8AppenderEEESt4lessISsESaISt4pairIKSsSC_EEE > (domconfigurator.cpp:453) > ==8287== by 0x804FB5F: > _ZN7log4cxx3xml15DOMConfigurator9parseRootEP12apr_xml_elemP11apr_xml_d > ocRSt3mapISsNS_7helpers10ObjectPtrTINS_8AppenderEEESt4lessISsESaISt4pa > irIKSsSA_EEE (domconfigurator.cpp:399) > ==8287== by 0x8053B3F: > _ZN7log4cxx3xml15DOMConfigurator5parseEP12apr_xml_elemP11apr_xml_docRS > t3mapISsNS_7helpers10ObjectPtrTINS_8AppenderEEESt4lessISsESaISt4pairIK > SsSA_EEE (domconfigurator.cpp:824) > ==8287== by 0x8052C08: log4cxx::xml::DOMConfigurator::doConfigure > (log4cxx::File const&, > log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>&) > (domconfigurator.cpp:692) > ==8287== by 0x8052D1F: log4cxx::xml::DOMConfigurator::configure > (std::string const&) (domconfigurator.cpp:700) > ==8287== by 0x804C39B: main (main.cpp:8) > ==8287== by 0x1BA5BE7F: __libc_start_main (in /lib/tls/libc.so.6) > ==8287== by 0x804C2B0: ??? (start.S:119) > > > It appears that the cause of leaks is some error in memory pool > deallocation (temprary data reside in pools longer than they > should). When I changed the pool to be attribute of > DOMConfigurator class, and put this newly created pool instead of > the temporary one declared in the function, valgrind showed me > another places in DOMConfigurator where the leak occurs. When I > changed these, I found another leaks in other classes. I realized > that the problem is widespread. > > Is it possible to review the pool usage, or create some pool > cleaning function ? The Pool destructor which should be called when exiting DOMConfigurator::parseChildrenOfLoggerElement should cause apr_pool_destroy to be called. At that point, any memory allocated from should be released. It may be that the overhead memory for the pool might not be recovered until the global memory pool (the implied parent pool) is recovered Do you still get reported leaks if you set a fixed number of iterations and let the test application finish normally? If so, then it isn't really a leakage problem as memory would be (eventually) reclaimed on normal termination. The application may growing its working set during execution which is undesirable, but a different type of problem.
