<style>
/* Changing the layout to use less space for mobiles */
@media screen and (max-device-width: 480px), screen and (-webkit-min-device-pixel-ratio: 2) {
#email-body { min-width: 30em !important; }
#email-page { padding: 8px !important; }
#email-banner { padding: 8px 8px 0 8px !important; }
#email-avatar { margin: 1px 8px 8px 0 !important; padding: 0 !important; }
#email-fields { padding: 0 8px 8px 8px !important; }
#email-gutter { width: 0 !important; }
}
</style>
<div id="email-body">
<table id="email-wrap" align="center" border="0" cellpadding="0" cellspacing="0" style="background-color:#f0f0f0;color:#000000;width:100%;">
<tr valign="top">
<td id="email-page" style="padding:16px !important;">
<table align="center" border="0" cellpadding="0" cellspacing="0" style="background-color:#ffffff;border:1px solid #bbbbbb;color:#000000;width:100%;">
<tr valign="top">
<td bgcolor="#003366" style="background-color:#003366;color:#ffffff;font-family:Arial,FreeSans,Helvetica,sans-serif;font-size:12px;line-height:1;"><img src="http://jira.qos.ch/s/en_USb9v8he-418945332/850/25/_/jira-logo-scaled.png" alt="" style="vertical-align:top;" /></td>
</tr><tr valign="top">
<td id="email-banner" style="padding:32px 32px 0 32px;">
<table align="left" border="0" cellpadding="0" cellspacing="0" width="100%" style="width:100%;">
<tr valign="top">
<td style="color:#505050;font-family:Arial,FreeSans,Helvetica,sans-serif;padding:0;">
<img id="email-avatar" src="http://jira.qos.ch/secure/useravatar?avatarId=10122" alt="" height="48" width="48" border="0" align="left" style="padding:0;margin: 0 16px 16px 0;" />
<div id="email-action" style="padding: 0 0 8px 0;font-size:12px;line-height:18px;">
<a class="user-hover" rel="opinali" id="email_opinali" href="http://jira.qos.ch/secure/ViewProfile.jspa?name=opinali" style="color:#326ca6;">Osvaldo Pinali Doederlein</a>
commented on <img src="http://jira.qos.ch/images/icons/issuetypes/improvement.png" height="16" width="16" border="0" align="absmiddle" alt="Improvement"> <a style='color:#326ca6;text-decoration:none;' href='http://jira.qos.ch/browse/LOGBACK-643'>LOGBACK-643</a>
</div>
<div id="email-summary" style="font-size:16px;line-height:20px;padding:2px 0 16px 0;">
<a style='color:#326ca6;text-decoration:none;' href='http://jira.qos.ch/browse/LOGBACK-643'><strong>performance issue</strong></a>
</div>
</td>
</tr>
</table>
</td>
</tr>
<tr valign="top">
<td id="email-fields" style="padding:0 32px 32px 32px;">
<table border="0" cellpadding="0" cellspacing="0" style="padding:0;text-align:left;width:100%;" width="100%">
<tr valign="top">
<td id="email-gutter" style="width:64px;white-space:nowrap;"></td>
<td>
<table border="0" cellpadding="0" cellspacing="0" width="100%">
<tr valign="top">
<td colspan="2" style="color:#000000;font-family:Arial,FreeSans,Helvetica,sans-serif;font-size:12px;padding:0 0 16px 0;width:100%;">
<div class="comment-block" style="background-color:#edf5ff;border:1px solid #dddddd;color:#000000;padding:12px;"><p>I was also looking at this code because it turns out to be a relatively high CPU consumer in a test:</p>
<p>CPU SAMPLES BEGIN (total = 4077726) Fri Aug 22 18:54:48 2014<br/>
rank self accum count trace method<br/>
1 59.97% 59.97% 2445241 301175 io.netty.channel.epoll.Native.epollWait<br/>
2 26.54% 86.51% 1082218 301216 io.netty.channel.epoll.Native.writevAddresses<br/>
3 4.85% 91.36% 197836 301205 java.net.SocketInputStream.socketRead0<br/>
4 1.91% 93.26% 77790 301261 io.netty.channel.epoll.Native.readAddress<br/>
5 0.49% 93.76% 20139 301591 java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss<br/>
6 0.16% 93.92% 6606 301660 ch.qos.logback.classic.LoggerContext.getTurboFilterChainDecision_0_3OrMore</p>
<p>This is a real-time ad bidder handling 20Kqps on a 8-core machine, so almost all CPU goes to low-level networking, partially thanks to JVM overheads with native I/O etc. So if I disregard the top 4 methods (93.26% accum), scaling the remaining application CPU usage (6.74% -> 100%), then the 0.16% absolute CPU used by getTurboFilterChainDecision_0_3OrMore() scales to ~2.4% of all CPU usage from the rest of my app; that seems to be a high overhead for logging decisions (app has lots of logging code, but always using isXxxEnabled() guards except when the log msg is a literal string).</p>
<p>I noticed that the Object[] params is never used by any of the TurboFilters. I guess the params are passed because it's an extension point, somebody may write their own TurboFilter which considers the params, but maybe this could be handled in a different way (e.g., with a marker interface that tells a filter needs to receive the params).</p>
<p>Another inefficiency is that when you have <3 params and the logging decision is ACCEPT, the wrapper Object[] will be created twice: for example, filterAndLog_1() will first invoke getTurboFilterChainDecision_1() which creates this Object[] for invoking getTurboFilterChainDecision(), and later getTurboFilterChainDecision_1() creates its own Object[] wrapper for calling buildLoggingEventAndAppend(). This may not be very important when the event is actually logged (an extra Object[] wrapper is very small overhead compared to the full logging work), but appenders can also decide to not log, in practice I expect this to be a common scenario in apps that configure most of their loggers "open" and use the appenders as an easy on/off switch for the whole firehose.</p></div>
<div style="color:#505050;padding:4px 0 0 0;"> </div>
</td>
</tr>
</table>
</td>
</tr>
</table>
</td>
</tr>
</table>
</td><!-- End #email-page -->
</tr>
<tr valign="top">
<td style="color:#505050;font-family:Arial,FreeSans,Helvetica,sans-serif;font-size:10px;line-height:14px;padding: 0 16px 16px 16px;text-align:center;">
This message is automatically generated by JIRA.<br />
If you think it was sent incorrectly, please contact your JIRA administrators<br />
For more information on JIRA, see: <a style='color:#326ca6;' href='http://www.atlassian.com/software/jira'>http://www.atlassian.com/software/jira</a>
</td>
</tr>
</table><!-- End #email-wrap -->
</div><!-- End #email-body -->