[LOG4J2-1125] Reuse StringBuilder to improve performance for PatternLayout

• Type: Improvement
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.3
• Fix Version/s: 2.4
• Component/s: Layouts
• Assignee: Remko Popma
• Reporter: Remko Popma
• Created: 20/Sep/15 06:59
• Updated: 16/Jun/16 04:40
• Resolved: 22/Sep/15 19:14

Description

As part of the investigation for LOG4J2-930 (PatternLayout performance), I found that in PatternLayout.toSerializable(), instead of creating a new StringBuilder each time this method is called, caching and reusing a ThreadLocal<StringBuilder> makes a huge difference in performance.

Before (new StringBuilder instance for each event)

Benchmark                                                 Mode  Samples     Score    Error  Units
o.a.l.l.p.j.PatternLayoutComparisonBenchmark.log4j2     sample   125646  1413.362 ± 33.806  ns/op
o.a.l.l.p.j.PatternLayoutComparisonBenchmark.logback    sample   128680  1383.201 ± 33.076  ns/op

After (reuse ThreadLocal<StringBuilder>)

Benchmark                                                 Mode  Samples     Score    Error  Units
o.a.l.l.p.j.PatternLayoutComparisonBenchmark.log4j2     sample   156816  1138.547 ± 20.290  ns/op
o.a.l.l.p.j.PatternLayoutComparisonBenchmark.logback    sample   127978  1355.166 ± 19.462  ns/op

org.apache.logging.log4j.PerformanceComparison results indicate this improves overall performance:
Before (new StringBuilder instance for each event)

Log4j    : 1501
Logback  : 1208
Log4j 2.0: 1646
###############################################
Log4j    : 1487
Logback  : 1165
Log4j 2.0: 1566
###############################################
Log4j    : 1490
Logback  : 1170
Log4j 2.0: 1485
###############################################
Log4j    : 1392
Logback  : 1143
Log4j 2.0: 1629

After (reuse ThreadLocal<StringBuilder>)

Log4j    : 1498
Logback  : 1202
Log4j 2.0: 1213
###############################################
Log4j    : 1394
Logback  : 1057
Log4j 2.0: 1290
###############################################
Log4j    : 1240
Logback  : 1109
Log4j 2.0: 1335
###############################################
Log4j    : 1310
Logback  : 1146
Log4j 2.0: 1210

There are more changes for LOG4J2-930, so I am splitting off this item into a separate ticket so I can address it and close it.

Issue Links

• Blocked: LOG4J2-1434 StringBuffer in ThreadLocal can cause excessive memory usage after large log messages
• breaks: LOG4J2-1142 ThreadLocals in Layout implementations may cause memory leaks in web containers
• is cloned by: LOG4J2-1128 Reuse StringBuilder to improve performance for String-based layouts: CSV, GELF, HTML, RFC524, Syslog