opensearch-project/OpenSearch

[Logging Improvement] Using lambda invocations instead of checking debug/trace isEnabled explicitly

Open

#8646 aperta il 11 lug 2023

Vedi su GitHub
 (19 commenti) (0 reazioni) (1 assegnatario)Java (1505 fork)batch import
distributed frameworkenhancementgood first issue

Metriche repository

Star
 (8123 star)
Metriche merge PR
 (Merge medio 5g 9h) (266 PR mergiate in 30 g)

Descrizione

Is your feature request related to a problem? Please describe. Debug and trace logging presently makes a call to isDebugEnabled()/isTraceEnabled() before computing the strings inside the debug/trace logs. This is because those string concatenations are expensive operations and we don't want to unnecessarily compute them everytime.

OpenSearch % grep -r "isDebugEnabled()" * | wc -l
      76
OpenSearch % grep -r "isTraceEnabled()" * | wc -l
     122

Describe the solution you'd like

Present scenario:

if (logger.isTraceEnabled()) {
    logger.trace("Some long-running operation returned {}", expensiveOperation());
}

Replace the existing checking of trace/debug logging before actual logging with lambda invocations within the debug/trace loggers:

logger.trace("Some long-running operation returned {}", () -> expensiveOperation());

This achieves the same lazy logging without having to check for logger levels. the performance improvements won't be huge as we are letting go of a single isDebug/isTrace method call.

The improvements however may arise with the way we construct our strings in most of our logger messages. At multiple places, we utilize string concatenation using + operator which is inefficient, specifically at places where more than 2 strings are combined. With this above proposed change, we can let go of unoptimized string interpolations (eg. string1 + string2 + string3, which creates multiple string objects upon each concatenation) to get more optimized string builder formats in logging (eg. "{}{}{}", ()->string1, ()->string2, ()->string3).

Added slight benefit of readability as well with no lingering checks of trace/debug and optimized string constructions, although this is least of a concern.

Describe alternatives you've considered References used: https://logging.apache.org/log4j/2.0/manual/api.html#Java_8_lambda_support_for_lazy_logging

Additional context Add any other context or screenshots about the feature request here.

Suggesting breaking the implementation into 2 phases:

  1. Scrubbing away all the invocations to isDebugEnabled/isTraceEnabled and replacing them with lambda invocations.
  2. Additionally, other log places should get rid of string concatenations using + operator and replace them with StringBuilder/placeholder formats.

Guida contributor