You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2015/08/19 11:41:45 UTC
[jira] [Created] (LOG4J2-1096) Performance improvement for
PatternMessage.format
Remko Popma created LOG4J2-1096:
-----------------------------------
Summary: Performance improvement for PatternMessage.format
Key: LOG4J2-1096
URL: https://issues.apache.org/jira/browse/LOG4J2-1096
Project: Log4j 2
Issue Type: Improvement
Components: API, Layouts
Affects Versions: 2.3
Reporter: Remko Popma
Assignee: Remko Popma
Fix For: 2.4
Doing some profiling for log4j2 synchronous logging I found that the PatternConverters are hot methods. Improving these should have large impact on logging performance.
At the top of the list was {{ParameterizedMessage.format}}. (screenshot to follow)
I experimented a little and got a nice improvement by using a char[] array instead of a StringBuilder in this method. Explanation of the below benchmark results:
* format0 = use char[] array instead of StringBuilder
* format0_inline = format0 + refactor to call small methods
* format0_inline2 = format0_inline + avoid index check inside loop
* format0_inline3 = refactored format0_inline2 to make all methods 35 byte codes or less (not very readable any more...)
{noformat}
Windows:
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.ParameterizedMessageBenchmark.baseline sample 122654 27.628 ± 0.894 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format sample 130088 364.905 ± 20.410 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0 sample 121087 188.281 ± 1.772 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline sample 123966 195.806 ± 23.696 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline2 sample 128577 186.900 ± 1.724 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline3 sample 124877 190.462 ± 2.061 ns/op
Linux
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.ParameterizedMessageBenchmark.baseline sample 2934379 30.959 ± 0.035 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format sample 2630377 361.414 ± 1.960 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0 sample 2030686 240.816 ± 2.143 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline sample 2296404 221.649 ± 4.264 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline2 sample 2113582 234.008 ± 1.939 ns/op
o.a.l.l.p.j.ParameterizedMessageBenchmark.format0_inline3 sample 3618971 270.600 ± 3.689 ns/op
{noformat}
Code (sorry, I will move this into a benchmark in git when I get home):
{code}
public static String format0_inlined2(final String messagePattern,
final String[] arguments) {
int len = 0;
if (messagePattern == null || (len = messagePattern.length()) == 0
|| arguments == null || arguments.length == 0) {
return messagePattern;
}
return format0_inlined22(messagePattern, len, arguments);
}
private static String format0_inlined22(final String messagePattern,
final int len, final String[] arguments) {
final char[] result = new char[len + totalLength(arguments)];
int pos = 0;
int escapeCounter = 0;
int currentArgument = 0;
int i = 0;
for (; i < len - 1; i++) {
final char curChar = messagePattern.charAt(i);
if (curChar == ESCAPE_CHAR) {
escapeCounter++;
} else {
if (isDelimPair(messagePattern, i, curChar)) {
i++;
// write escaped escape chars
pos = format0_writeEscapedEscapeChars(escapeCounter,
result, pos);
if (isEscapeCounterOdd(escapeCounter)) {
// i.e. escaped
// write escaped escape chars
pos = format0_writeDelimPair(result, pos);
} else {
// unescaped
pos = format0_appendArg(arguments, currentArgument,
result, pos);
currentArgument++;
}
} else {
pos = format0_handleLiteralChar(result, pos, escapeCounter,
curChar);
}
escapeCounter = 0;
}
}
pos = format0_handleMaybeLastChar(messagePattern, len, result, pos,
escapeCounter, i);
return new String(result, 0, pos);
}
// 27 bytes
private static int totalLength(String[] arguments) {
int result = 0;
for (int i = 0; i < arguments.length; i++) {
result += arguments[i].length();
}
return result;
}
// 22 bytes
private static boolean isDelimPair(final String messagePattern, int i,
final char curChar) {
return curChar == DELIM_START
&& messagePattern.charAt(i + 1) == DELIM_STOP;
}
private static int format0_handleMaybeLastChar(final String messagePattern,
final int len, final char[] result, int pos, int escapeCounter,
int i) {
if (i == len - 1) {
final char curChar = messagePattern.charAt(i);
pos = format0_handleLastChar(result, pos, escapeCounter, curChar);
}
return pos;
}
private static int format0_handleLastChar(final char[] result, int pos,
int escapeCounter, final char curChar) {
if (curChar == ESCAPE_CHAR) {
pos = format0_writeUnescapedEscapeChars(escapeCounter + 1, result,
pos);
} else {
pos = format0_handleLiteralChar(result, pos, escapeCounter, curChar);
}
return pos;
}
private static int format0_handleLiteralChar(final char[] result, int pos,
int escapeCounter, final char curChar) {
// any other char beside ESCAPE or DELIM_START/STOP-combo
// write unescaped escape chars
pos = format0_writeUnescapedEscapeChars(escapeCounter, result, pos);
result[pos++] = curChar;
return pos;
}
private static int format0_writeDelimPair(final char[] result, int pos) {
result[pos++] = DELIM_START;
result[pos++] = DELIM_STOP;
return pos;
}
private static boolean isEscapeCounterOdd(int escapeCounter) {
return (escapeCounter & 1) == 1;
}
private static int format0_writeEscapedEscapeChars(int escapeCounter,
char[] result, int pos) {
final int escapedEscapes = escapeCounter >> 1; // divide by two
return format0_writeUnescapedEscapeChars(escapedEscapes, result, pos);
}
private static int format0_writeUnescapedEscapeChars(int escapeCounter,
char[] result, int pos) {
while (escapeCounter > 0) {
result[pos++] = ESCAPE_CHAR;
escapeCounter--;
}
return pos;
}
private static int format0_appendArg(final String[] arguments,
int currentArgument, final char[] result, int pos) {
if (currentArgument < arguments.length) {
pos = format0_appendArg0(arguments, currentArgument, result, pos);
} else {
pos = format0_writeDelimPair(result, pos);
}
return pos;
}
private static int format0_appendArg0(final String[] arguments,
int currentArgument, final char[] result, int pos) {
final String arg = arguments[currentArgument];
final int argLen = arg.length();
arg.getChars(0, argLen, result, pos);
return pos + argLen;
}
{code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org