Best way to log exceptions

[Hin4t3n2D]

In my application I log exception using the pattern layout and provide additional information. Something like below,

logger.info("I got an exception and additional details:{}", details, exception);

I am wondering what is the best way to log exceptions? Above method can lead to high object allocation rate especially with printing full stack trace and using the pattern layout. Is there a better way and also is there some kind of throttling for logger to avoid logging exceptions at a high rate ?

[tcmot]

I have the same question, but after my investigation, there is no way to avoid it.

[ppkarwasz]

If you use Log4j Core as the backend for the Log4j API, the method:

logger.info("I got an exception and additional details:{}", details, exception);

does not allocate any object regardless whether the INFO level is enabled or not. There are of course conditions for garbage-free logging (cf. documentation), but some of them will be lifted in the upcoming 3.x release (you'll be able to disable thread locals and maintain garbage free).

Logback on the other hand will allocate new objects.

Disclaimer: I don't count as allocation the creation of new exceptions, since they will be allocated regardless whether you log them or not. Exceptions are generally heavy to create (it depends on the JVM) and should be "exceptional". If your application is generating exceptions at a high rate, you should look into the business logic.

[garydgregory]

I agree with @ppkarwasz

[Hin4t3n2D]

If I understood correctly we do allocate string objects for the exceptions and use StringBuilder to build the pattern provided right ? I agree we do allocate exception objects but at least through allocation profiling it seems like we see the string objects allocated through log4j to be more than the exception objects being created.

[vy]

@mind-fuzzy, no, you should not be allocating anything except for Throwable#getStackTrace() I explained below. Could you share your log4j2.xml and the profiling result?

[vy]

Above method can lead to high object allocation rate especially with printing full stack trace and using the pattern layout.

@mind-fuzzy, not necessarily. If you choose a layout (e.g., PatternLayout, JsonTemplateLayout) and appender combination that supports garbage-free logging and configure them right (not all configuration options are garbage-free), you will have a blazing fast logging that is not possible with any other Log4j competitors.

As a matter of fact, JsonTemplateLayout has no allocations itself while serializing stack traces except while getting the stack trace using Throwable#getStackTrace(), which incurs a clone operation in JDK where no Log4j has no influence on. (PatternLayout doesn't has this optimization for stack traces.)

Is there a better way and also is there some kind of throttling for logger to avoid logging exceptions at a high rate ?

@mind-fuzzy, @tcmot, some appenders provide built-in throttling, e.g., log4j2-redis-appender. For those which don't have such a support, you can use the Log4j BurstFilter.