How much does logging/sysout statements affect application performance?

We (developers) have a common tendency to write System.out.println() and Log statements through out the application, but never really concerned about how much impact it’ll have on application performance – we will now discuss how that’s going to effect application performance with a small experiment.

Let’s write a sample code which calculates roughly how much time a Sysout statement might take.

Step 1 – Without any statements

	public static void main(String[] args) {
		long startTime = System.nanoTime();
		long endTime = System.nanoTime();

		System.out.println(endTime - startTime);
	}

Nothing fancy here, I just wrote two consecutive statements to get the nanoTime and print the difference. Now lets take an average of 10 executions

200
100
200
200
100
100
100
200
100
200

This gives us roughly 150 nano seconds on an average.

Step 2 – With one blocking statement

Now let us add a Sysout statement between the startTime and endTime statements

	public static void main(String[] args) {
		long startTime = System.nanoTime();
		System.out.println("am a blocker");
		long endTime = System.nanoTime();

		System.out.println(endTime - startTime);
	}

To my shock, it just took 7,43,900 nano seconds to execute single Sysout statement.

Lets run the same code 10 times and calculate the average.

am a blocker
686600
am a blocker
32800
am a blocker
29000
am a blocker
41100
am a blocker
29500
am a blocker
25100
am a blocker
40300
am a blocker
64800
am a blocker
36200
am a blocker
50200


the average of above 10 results is 1,03,560.

So now it has been established that, just one sysout statement pushed down performance of our code by 103560 – 150 = 103410 nano seconds.

Step 3 – With a non-blocking statement

We can reuse the same code, but replace the Sysout statement with non-blocking code like arithmetic statements.

	public static void main(String[] args) {
		int a = 1, b = 2;
		long startTime = System.nanoTime();
		int c = a + b;
		long endTime = System.nanoTime();

		System.out.println(endTime - startTime);
	}

// output: 300
300
200
300
200
500
200
200
200
100

The first run took 300 nano seconds, and the average of above 10 executions – which is around 250.

From the above experiment one thing is clear that the arithmetic statement was not blocking the execution so the average execution time is not far from the step 1. Whereas the Sysout statement is blocking so it took more than 100,000 nano seconds.

I’ll work on same experiment on logging as well once I get time, but I recommend you to do it on your own. However it’s clear that sysouts & logging statements will drag the application performance if they used excessively.

If these statements used in loops then it’ll cause the maximum damage since those statements will be executed repeatedly.

Thanks for reading this article, If you find it helpful please let me know in the comments.