Effect of logging on Apache's performence

Question

Hello everyone.

I am developing an Apache module. During development I found it convenient to use logging functions at various points in my code. For example after opening a file, I would log an error if the operation was not successful so that I may know exactly where the problem occurred in my code.

Now, I am about to deliver my module to my boss (I am on an internship). I wanted to what are the best practices regarding logging. Is it good for maintenance purposes or is it bad because it may hamper the response time of the server.

Answer 1

It really depends on how you wrote those logging instructions. If you wrote:

logger.debug(computeSomeCostlyDebugOutput());

You might affect performance badly if the logger is not set on a DEBUG level (computeSomeCostlyDebugOutput will always take time to execute and its result will then be ignored by the logger if not matching the DEBUG level).

If you write it like this instead:

if (logger.isDebugEnabled()) {
  logger.debug(computeSomeCostlyDebugOutput());
}

then the costly operations and logging will occur only if the correct logger level is set (i.e. the logger won't ignore it). It basically acts like another switch for the logger, the first switch being the configured logger level.

As Andrzej Doyle very well pointed out, the logger will check its level internally, but this happens in the debug method, after time was already wasted in the computeSomeCostlyDebugOutput. If you waste time in computeSomeCostlyDebugOutput, you better do it when you know that its result won't be in vain.

A lot of software ships with logging instructions which you can activate if you need more details into the inner workings of the thing, execution path and stuff. Just make sure they can be deactivated and only take computing time if the appropriate level is set.

Answer 2

One of the design goals of Log4J (for good reason) was performance; Ceki Gulku wanted the library to be usable in production, enterprise software and the overhead of Log4J itself is actually pretty minimal (measured on my own webapp project with a profiler).

Two things that are liable to take some time though, are:

1. Forming the arguments to pass into the logging method, for some calls. As dpb says, this should be avoided by wrapping any computation of complex output in a logging check so you're not deriving complex debug output when the logger's going to throw it away as it's set to only record errors.
2. The sheer I/O required to record the log data. If you've got your application logging 200Mb of debug logs per second (it might sound infeasible, but it's happened to me before) then that's likely to put a strain on how fast it runs, as IIRC the file writing happens synchronously. In various webapp-type projects I've developed, I can usually actually notice a slight difference in responsiveness when I set the logs to debug level (and IMO this is a good thing, as you should be generating a lot of output when you ask for debug logs).