[
https://issues.apache.org/jira/browse/LOG4J2-1297?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15257360#comment-15257360
]
Remko Popma edited comment on LOG4J2-1297 at 4/26/16 5:02 AM:
--------------------------------------------------------------
I suspect the big drop in throughput has to do with locking: how much of the
critical path is in a synchronized section. Generally there are four stages to
synchronous logging with pattern layout:
# populating the log event (params, MDC snapshot)
# converting the log event into text (Once you start measuring you'll find this
stage to be surprisingly expensive. Many optimizations possible. Dates are one
example but it is crucial to profile/measure and focus on the biggest
bottleneck first.)
# encoding the text to bytes
# File I/O in the appender (Surprisingly fast on modern hardware & OS-es.
Buffering and smart batching .)
Ideally _only the last stage_ should be in a synchronized section.
was (Author: rem...@yahoo.com):
I suspect the big drop in throughput has to do with locking: how much of the
critical path is in a synchronized section. Generally there are four stages to
synchronous logging with pattern layout:
# populating the log event (params, MDC snapshot)
# converting the log event into text
# encoding the text to bytes
# File I/O in the appender
Ideally only that last stage should be in a synchronized section.
> Document "gc-free" configuration and performance
> ------------------------------------------------
>
> Key: LOG4J2-1297
> URL: https://issues.apache.org/jira/browse/LOG4J2-1297
> Project: Log4j 2
> Issue Type: New Feature
> Components: Documentation
> Affects Versions: 2.5
> Reporter: Remko Popma
> Assignee: Remko Popma
> Fix For: 2.6
>
> Attachments: LatencyHistogram.png,
> garbage-free2.6-SyncThroughputLinux.png, log4j-2.5-FlightRecording.png,
> log4j-2.6-FlightRecording.png
>
>
> Update the site with a description of which configurations are GC-free (i.e.,
> that don't create temporary objects in steady running state).
> Currently that means
> * Loggers are all asynchronous (Log4jContextSelector is set to
> org.apache.logging.log4j.core.async.AsyncLoggerContextSelector).
> * The configuration does not contain a <Properties> section.
> * The "steady-state" appenders are either RandomAccessFile or
> RollingRandomAccessFile Appenders (logging to any other appender will cause
> temporary objects to be created - including ConsoleAppender).
> * The Layout is a PatternLayout that uses one of the pre-defined date
> formats, does not have any regular expression replacements, and does not have
> lookups (TODO: may need to restrict this further).
> * The thread name is cached (this is the
> [default|https://issues.apache.org/jira/browse/LOG4J2-467]). Running with
> -DAsyncLogger.ThreadNameStrategy=UNCACHED will create garbage.
> * In user code, when logging a parameterized message, the number of
> parameters is no more than ... (TBD pending discussion in LOG4J2-1278).
> * In user code, when logging a parameterized message, parameters of primitive
> type are boxed in a reused StringBuilder (Log4j provides a utility to make
> this relatively painless).
> Even with the above restrictions, Log4j may occasionally create garbage:
> * Initially StringBuilders are presized to 128 characters. They may grow for
> larger messages (contributing to garbage in Old Gen). If the StringBuilder
> grows beyond 512 characters it is trimmed back to 512 characters to prevent
> memory leaks from excessively long messages. (TODO: the resizing algorithm is
> {{size = value.length * 2 + 2}}, so a better cutoff value is 518.)
> * Messages containing {{"$\{"}} will be converted to a String and
> StrSubstitutor will be used to replace occurences of variables with their
> matching values. Multiple temporary objects are created during this process.
> Furthermore, we need to explain that some of this functionality depends on
> ThreadLocals and so is disabled by default in web applications to prevent
> memory leaks. The page should also explain how to manually switch off the use
> of ThreadLocals.
> Finally, the page should show a performance test comparison similar to the
> [performance
> section|http://logging.apache.org/log4j/2.x/manual/async.html#Performance] on
> the Async Loggers page. I'm thinking a comparison between Logback, Log4j-1,
> Log4j-2.0, Log4j-2.6 "classic" and Log4j-2.6 "gc-free" would be ideal.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
