Log4cxx seems to wilt when under heavy load.

With the syslog appender enabled, the application cores when under heavy load.

When using a RollingFileAppender with an XMLLayout layout, my output file gets 
garbled:

<<<snip>>>

<log4j:event 
logger="Gateway.AuthenticationServices/ANS_AuthenticationService.cpp" 
timestamp="1191005220721" level="INFO" thread="0x61eb3b90">
<log4j:message><![CDATA[No username/password token or SAML assertion to 
process.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.MediationPipeline/MED_PipelineMessage.cpp" 
timestamp="1191005220721" level="INFO" thread="0x61eb3b90">
<log4j:message><![CDATA[No session policy set for user/group 
.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.MediationPipeline/MED_PipelineMessage.cpp" 
timestamp="1191005220721" level="DEBUG" thread="0x61eb3b90">
<log4j:message><![CDATA[Using session #2 with session policy 
DefaultPolicy.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.SessionInfra/SI_SessionManager.cpp" 
timestamp="1191005220729" level="WARN" thread="0x5ecaeb90">
<log4j:message><![CDATA[Concurrent session limit reached. Transaction is 
rejected.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.SessionInfra/SI_SessionManager.cpp" 
timestamp="1191005220729" level="ERROR" thread="0x5ecaeb90">
<log4j:message><![CDATA[User session rejected - have exceeded the maximum 
number of concurrent sessions based on the current license (0 concurrent 
sessions allowed)]]></log4j:message>
</log4j:event>
¦«    "          ´T#
ýÍÊ^˜ÌÊ^Ä        °Ñ"
ôÌÊ^µ   ‡·<T#
ÜÑ"
            XÍÊ^       <T#
ÜÑ"
À4‡·    dÐÊ^ÍÊ^§c    ´T#
    ð‡·°Ñ"
@ÍÊ^1ֆ· T#
¸Ñ"
            XÍÊ^           ôO ÔÑ"
        |ó³            hÍÊ^
   Þ$z  XÍÊ^p÷³ xÍÊ^/&L4#
z  ¸ÍÊ^Z;'°Ñ"
    ¸ÍÊ^ü(H4#
ðÍÊ^¸ÍÊ^13 Ì€ðÍÊ^ðÍÊ^            
   
   Þ$z  ÏÊ^ÄydÐÊ^ðÍÊ^    ðÍÊ^ ÏÊ^PÏÊ^XÏÊ^h         ·‹·    
1191‘À‹·20729&ô €¼ÏÊ^(ÎÊ^®Ý‹· €È €—ÎÊ^H€¼ÏÊ^H €@ €   ô5  
À€       €À€   ¼ÏÊ^xÎÊ^  €   Ðõ‹··‹·ôO À€   ˆÎÊ^@ €‹‚&   
·‹·      X~—·¨ÎÊ^5
´ dÐÊ^Þ$¸ÎÊ^ H&    çÎÊ^ÏÊ^^¥!øÎÊ^°#
ÏÊ^§c %  ôèÎÊ^ðÆ0ÐÊ^'ÏÊ^øÎÊ^ÙÃ'ÏÊ^'ÏÊ^(ÏÊ^žÇ'ÏÊ^'ÏÊ^SÏÊ^ͦ!\sA
dÐÊ^(ÏÊ^%LRÏÊ^´ÏÊ^XÏÊ^ÖÇRÏÊ^SÏÊ^RÏÊ^¶0 \sA
kÏÊ^XÏÊ^¶&$HsA
dÐÊ^ÈÏÊ^¦«0ÐÊ^Þ$xÏÊ^íÃHÐÊ^ÿÿÿÿˆÏÊ^ÄHÐÊ^l4¸ÏÊ^6ÉHÐÊ^    ó   ôO 
l4z  ÈÏÊ^e4 [EMAIL PROTECTED]  HÒÊ^ÑÊ^ÿÿÿÿ‘â³ Z;'°Ñ" j  
8ÐÊ^ü(0x5ecaeb90Ê^13 4€pÐÊ^pÐÊ^    Þ$z  HÐÊ^Í&ä6%
        4ÐÊ^4ÐÊ^    ˆÐÊ^
*à6%
LÐÊ^LÐÊ^    Üí#
Ì€˜ÐÊ^<log4j:event logger="Gateway.SessionInfra/SI_SessionManager.cpp" 
timestamp="1191005220729" level="WARN" thread="0x600b0b90">
<log4j:message><![CDATA[Concurrent session limit reached. Transaction is 
rejected.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.MediationPipeline/MED_PipelineMessage.cpp" 
timestamp="1191005220729" level="INFO" thread="0x5ecaeb90">
<log4j:message><![CDATA[Auth'ed user hitting dend. Transaction is 
rejected.]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.MediationPipeline/MED_PipelineMessage.cpp" 
timestamp="1191005220729" level="INFO" thread="0x5ecaeb90">
<log4j:message><![CDATA[Auth'ed user hitting deny-all ws]]></log4j:message>
</log4j:event>
<log4j:event logger="Gateway.SessionInfra/SI_SessionManager.cpp" 
timestamp="1191005220729" level="ERROR" thread="0x600b0b90">
<log4j:message><![CDATA[User session rejected - have exceeded the maximum 
number of concurrent sessions based on the current license (0 concurrent 
sessions allowed)]]></log4j:message>
</log4j:event>

<<<snip>>>

This output was generated with ~150 threads throwing out error messages in 
rapid succession.

I have not noted these problems when treading lightly on the system.

At this point I'm suspicious that log4cxx is overflowing some sort of output 
buffer that's fills up due to the volume. I don't believe it is a 
multithreading issue as I serialized the logging calls in my code with a mutex 
and did not note any change.

Has anyone else noted something similiar?

How is log4cxx supposed to behave when the logging volume exceeds its capacity 
to output those events?

Reply via email to