Java Exception Handling / Performance

package com.learning;

import org.apache.commons.lang3.exception.ExceptionUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * Investigating performance issues behind exception handling / logging
 * 
 * @author Bhavani Polimetla
 * @since 06-May-2014
 */
public class ExceptionLoggingPerformance {

	private static Logger LOG = LoggerFactory.getLogger("ExceptionLoggingPerformance");

	/**
	 * @param args
	 */
	public static void main(String[] args) {

		LOG.info("-----------------------------------------------");
		long start = System.nanoTime();
		test10();
		long end = System.nanoTime();
		long test10Time = end - start;
		
		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test11();
		end = System.nanoTime();
		long test11Time = end - start;
		
		
		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test1();
		end = System.nanoTime();
		long test1Time = end - start;
		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test2();
		end = System.nanoTime();
		long test2Time = end - start;

		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test3();
		end = System.nanoTime();
		long test3Time = end - start;

		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test4();
		end = System.nanoTime();
		long test4Time = end - start;

		
		LOG.info("-----------------------------------------------");
		start = System.nanoTime();
		test20();
		end = System.nanoTime();
		long test20Time = end - start;

		
		LOG.info("-----------------------------------------------");
		long totalTime = test1Time + test2Time + test4Time + test10Time+test11Time
				+ test3Time + test20Time;

		LOG.info("test 10 catch (Exception e) e.printStackTrace(); time: "
				+ test10Time * 100 / totalTime + "%");
		LOG.info("test 11 catch (Throwable e) e.printStackTrace(); time: "
				+ test11Time * 100 / totalTime + "%");

		LOG.info("test 1 catch (Exception e) LOG.error("test1", e); time: "
				+ test1Time * 100 / totalTime + "%");
		LOG.info("test 2  catch (Throwable e) LOG.error("test2", e); time: "
				+ test2Time * 100 / totalTime + "%");
		LOG.info("test 3  catch (Exception e) LOG.error(ExceptionUtils.getStackTrace(e)); time: "
				+ test3Time * 100 / totalTime + "%");

		LOG.info("test 4 catch (Throwable e) LOG.error(ExceptionUtils.getStackTrace(e)); time: "
				+ test4Time * 100 / totalTime + "%");
		
		LOG.info("test 20 catch (Exception e) LOG.error(e.getStackTrace().toString()); time: "
				+ test20Time * 100 / totalTime + "%");

	}
	
	public static void test10() {

		try {
			int j = 1 / 0;
		} catch (Exception e) {
			e.printStackTrace();
		}
	}
	
	public static void test11() {

		try {
			int j = 1 / 0;
		} catch (Throwable e) {
			e.printStackTrace();
		}
	}

	public static void test1() {

		try {
			int j = 1 / 0;
		} catch (Exception e) {
			LOG.error("test1", e);
		}
	}

	public static void test2() {

		try {
			int j = 1 / 0;
		} catch (Throwable e) {
			LOG.error("test2", e);
		}
	}

	public static void test3() {

		try {
			int j = 1 / 0;
		} catch (Exception e) {
			LOG.error(ExceptionUtils.getStackTrace(e));
		}
	}

	public static void test4() {

		try {
			int j = 1 / 0;
		} catch (Throwable e) {
			LOG.error(ExceptionUtils.getStackTrace(e));
		}
	}
	
	public static void test20() {

		try {
			int j = 1 / 0;
		} catch (Exception e) {
			LOG.error(e.getStackTrace().toString());
		}
	}

	
}

Result
test 10 catch (Exception e) e.printStackTrace(); time: 9%
test 11 catch (Throwable e) e.printStackTrace(); time: 2%
test 1 catch (Exception e) LOG.error(“test1”, e); time: 36%
test 2 catch (Throwable e) LOG.error(“test2”, e); time: 3%
test 3 catch (Exception e) LOG.error(ExceptionUtils.getStackTrace(e)); time: 41%
test 4 catch (Throwable e) LOG.error(ExceptionUtils.getStackTrace(e)); time: 4%
test 20 catch (Exception e) LOG.error(e.getStackTrace().toString()); time: 1%

Note:
http://docs.oracle.com/javase/7/docs/api/java/lang/Throwable.html
Because performance is good, doesn’t mean that we can use catch(Throwable e).
Better not to handle Throwable, because these are for system to handle.
Also when we are not acting/checking the reason in exception block, no need to handle and swallow the important information.

Also ExceptionUtils.getStackTrace(e) had separate purpose.
No need to use this inside LOG statement to convert exception into single string.
-o-

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s