Improve performance and avoid memory consumption if logging primitive arrays as parameters

[magicwerk]

It is one of the design goals of Log4j "to deliver excelling performance without almost any burden on the Java garbage collector."

However this is currently not true for primitive arrays, here Log4j allocates unneeded temporary strings if a primitive array is logged as parameter.

Current implementation:
Method ParameterFormatter.appendArray() delegats to java.util.Arrays.toString() which then allocates a new StringBuilder to return a String which is then added to the existing StringBuilder.

Improved implementation:
For all primitive types, a method like ParameterFormatter.appendArray(int[], StringBuilder) has been added which is called by ParameterFormatter.appendArray() and avoids the unnecessary object creation.

A JHM benchmark shows that this changes increases performance and reduces memory consumption to zero:

Benchmark                                      Mode  Cnt         Score        Error   Units
testParameterFormatterNew                     thrpt    5  10090997.276 � 758239.856   ops/s
testParameterFormatterNew:gc.alloc.rate       thrpt    5         0.001 �      0.001  MB/sec
testParameterFormatterNew:gc.alloc.rate.norm  thrpt    5        ? 10??                 B/op
testParameterFormatterNew:gc.count            thrpt    5           ? 0               counts
testParameterFormatterOld                     thrpt    5   8259447.275 � 349015.042   ops/s
testParameterFormatterOld:gc.alloc.rate       thrpt    5      1259.364 �     54.827  MB/sec
testParameterFormatterOld:gc.alloc.rate.norm  thrpt    5       160.000 �      0.001    B/op
testParameterFormatterOld:gc.count            thrpt    5        11.000               counts
testParameterFormatterOld:gc.time             thrpt    5        11.000                   ms

Tests have been added to ParameterFormatterTest

[github-actions]

Job	Requested goals	Build Tool Version	Build Outcome	Build Scan®
build-macos-latest	clean install	3.9.8	✅
build-ubuntu-latest	clean install	3.9.8	✅
build-windows-latest	clean install	3.9.8	✅

Generated by gradle/develocity-actions

[ppkarwasz]

@magicwerk,

Looks good to me.

Can you also add a benchmark to ParameterFormatterBenchmark for the old and new version? Due to scalar inlining, str.append(Arrays.toString((int[]) o)) might actually also become GC-free on some JVMs.

[ppkarwasz]

@magicwerk,

All commits in this PR must have verified signatures, so you need to:

• Add a GPG key to your GitHub account.
• Rebase your branch to resign the commits:

  git rebase --force-rebase --gpg-sign origin/2.x
  git push --force

[magicwerk]

I doubt that any JVM could optimize away the Arrays.toString() call, I have only seen more or less constants strings go.
Nevertheless I have added benchmarks to ParameterFormatterBenchmark.
I was not quite sure how you would like to implement old vs new as the old implementation is obviously gone, have a look.
I had to copy the source of a single appendArray() method as they are private and cannot be accessed.

Benchmark                                                       Mode      Cnt        Score   Error  Units
ParameterFormatterBenchmark.appendArrayStringBuilder          sample  1030560      173.057 ± 5.219  ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.00    sample                   ? 0          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.50    sample               100.000          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.90    sample               200.000          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.95    sample               300.000          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.99    sample               300.000          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.999   sample              1100.000          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p0.9999  sample             78008.192          ns/op
ParameterFormatterBenchmark.appendArrayStringBuilder:p1.00    sample            377856.000          ns/op
ParameterFormatterBenchmark.appendArrayToString               sample   920507      192.249 ± 9.528  ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.00         sample                   ? 0          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.50         sample               200.000          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.90         sample               200.000          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.95         sample               300.000          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.99         sample               300.000          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.999        sample              3600.000          ns/op
ParameterFormatterBenchmark.appendArrayToString:p0.9999       sample             75333.478          ns/op
ParameterFormatterBenchmark.appendArrayToString:p1.00         sample           1880064.000          ns/op

[magicwerk]

I tried to sign the commits by executing your command - is it ok now?

About resolving conversion: am I doing that if I have replied or you if you think my reply was ok?

[ppkarwasz]

@magicwerk,

Looks almost good to go, thanks!

One last thing: can you add a changelog entry in src/changelog/.2.x.x/. Look at the other entries for inspiration.

The change type for performance improvements are either fixed or changed.

[ppkarwasz]

@magicwerk,

Thanks, I'll merge it as soon as the required tests pass.