CertPal

Any system that logs vast amounts of information, needs to think about performance. The activity of logging cannot be a synchronous blocking call that returns only when the message has been logged to a persistence store. Enterprise logging systems usually make use of a message bus to carry messages asynchronously to their target persistence store. Be it a database or a file.

Talking about logging brings us to System.out.println() (Lets call is SOP for short). It is a surprisingly commonly method to “log” messages. SOP is not meant to be used as a logging system, but unfortunately there is no dearth of projects that have these statements scattered around the code base. The adverse effects that this statement can bring on the performance of the system is often not recognized as well as it should be.

Why is SOP a bottleneck for performance ? This is why…

Code excerpt from PrintStream.java:

    private void write(String s)
    {
        try
        {
            synchronized (this)
            {
                ensureOpen();
                textOut.write(s);
                textOut.flushBuffer();
                charOut.flushBuffer();
                if (autoFlush && (s.indexOf('\n') >= 0))
                    out.flush();
            }
        }
        catch (InterruptedIOException x)
        {
            Thread.currentThread().interrupt();
        }
        catch (IOException x)
        {
            trouble = true;
        }
    }

All SOP calls on a String result in a corresponding call to the private write(String s) method in PrintStream.java. The synchronized block ensures that every thread has to wait for this call to end before it can proceed. Whats more, the calls to flushBuffer() on the BufferedWriter that is textOut result in the execution of more synchronized blocks. These blocks are expensive to execute.

Here is a chart that shows how performance degrades when a program logs 100,000 messages through various threads. The rate of degradation also depends on the number of characters that are passing through the stream.

System.out.println performance:

The degradation experienced in ‘Web application X / Y’ may vary, but it cannot be discounted. Avoid using SOPs to log messages in your app. Even one or two that are left over can harm performance under the right conditions. Let us also not forget about e.printStackTrace() and other forms of writing to console output that follow the same synchronized pattern.