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 4pÐÊ^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?