logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Matt Sicker <boa...@gmail.com>
Subject Re: Questions about switching to async and other performance-related config
Date Mon, 06 Aug 2018 16:10:10 GMT
The %c (aka %logger) pattern uses the logger name. The %C (aka %class)
pattern does the runtime lookup which kills performance.

On Mon, 6 Aug 2018 at 11:00, Shawn Heisey <apache@elyograg.org> wrote:

> I'm a committer on the Solr project.  Recently we completed an upgrade
> to log4j2, a change that we're very happy with.  The "rotate on startup"
> option has greatly simplified our start scripts, and we're running a
> version with full community support.
> https://issues.apache.org/jira/browse/SOLR-7887
> Now we're contemplating switching to async, which is apparently how
> log4j2 achieves "insane performance."
> http://www.grobmeier.de/log4j-2-performance-close-to-insane-20072013.html
> I've been reading what I can find about how to switch, but the docs seem
> to indicate at least two ways to do it, and I can't tell by looking at
> those which approach is better.  At the end of this message is a paste
> URL with the log4j2 config that Solr ships.  Any suggestions for
> improving the config are appreciated.
> What are the potential problems of async logging?  I'm guessing that
> there's a possibility that messages will get logged out of order if it
> takes longer to process one message than it does to process another one
> that happens immediately afterwards.  If this can happen, would the
> timestamps still be accurate even if logged out of order?  Although even
> with millisecond precision, it's likely that they would have the same
> visible timestamp, so most of the time that might not actually be useful.
> I was reading about mixing async and sync loggers, and wondering whether
> that would solve any out-of-order problems for critical log messages.
> Thinking mainly about having WARN and ERROR use sync.  A properly
> functioning Solr server with a modern config logs almost nothing at WARN
> or ERROR.  Typically even if the config isn't modern, a well-functioning
> server usually only logs such messages at startup or index reload.  The
> vast majority of what Solr usually logs is at INFO.  There's a fair
> amount of DEBUG in the code, and possibly even some at a lower level,
> but the logging threshold defaults to INFO.  Solr can be a little noisy
> in its logs, but we are taking steps to reduce the verbosity.  If the
> server is particularly busy, it can generate a lot of logs quickly.
> Beyond that, I have a question about other ways that we can improve
> performance.  I've been reading that the use of %C or %c (we use %c{.1}
> in the config) causes performance to drag, because the class must be
> looked up.  But from what I can tell, it is not actually using the class
> name in the log output ... it's using the *Logger* name.  The first line
> of the below is at the top of most of the classes in Solr.  All three of
> these lines are in one particular class -- SolrCore:
>   private static final Logger log =
> LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
>   private static final Logger requestLog =
> LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
> ".Request");
>   private static final Logger slowLog =
> LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
> ".SlowRequest");
> The parameter in the first "getLogger" call is a Class, but the
> parameter in the other two is a String.  Does the performance impact for
> %c apply to String-based loggers or just Class-based loggers?  If the
> performance impact doesn't apply to a String-based logger, maybe we
> could just add .getName() to the first line.  If necessary, we could
> switch to including the class name in each log message from a static
> string in the class... would the performance impact of doing that be
> worth the time and the massive patch?  I do like the flexibility of
> having log4j shorten the class name with the suffix on our "%c{.1}"
> pattern, which would be challenging to make configurable inside Solr
> itself.
> Keep in mind that Solr is using slf4j API calls, not log4j directly.
> Our slf4j binding is log4j2.
> At the following pastes are an example of the logging output and the
> log4j2 config that produced it:
> https://apaste.info/MqMq
> https://apaste.info/tTcc
> Thanks,
> Shawn
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org

Matt Sicker <boards@gmail.com>

  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message