AOP – Logging method execution time  in Java with AspectJ

This is not a walk-thru. This is just an example AspectJ class.

Note: For logging, the log singleton which I previously posted is used, but of course you can hook this up to your own logging methods or just print to the console.

This class is intended to log when a method executes and when a method ends and include the time it took for a method to execute in nanoseconds. Methods inside methods are tabbed. This is an enhancement to this post: AOP – Logging all method calls and executions

package mainExample;

import java.util.Stack;
import org.aspectj.lang.JoinPoint;

public aspect AspectLogMethodExecution
	private int tabCount = 0;
	private Stack _StartTimeStack = new Stack();

	pointcut AnyMethod() : (call(* *.*(..)) || execution(* *.*(..)))
						&& !within(AspectLogMethodExecution)
						&& !within(Log);

	before() : AnyMethod()

	after() : AnyMethod()
		Long methodExecutionTime = EvaluateExecutionTime();
		PrintMethod(thisJoinPointStaticPart, methodExecutionTime);

	private Long EvaluateExecutionTime()
		Long methodExecutionTime = System.nanoTime() - _StartTimeStack.pop();
		return methodExecutionTime;

	private void PrintMethod(JoinPoint.StaticPart inPart)
		Log.WriteLine(GetTabs() + inPart);

	private void PrintMethod(JoinPoint.StaticPart inPart, long inExecutionTime)
		Log.WriteLine(GetTabs() + inPart + " Execution Time: "
				+ inExecutionTime + " nanoseconds");

	private String GetTabs()
		String tabs = "";
		for (int i = 0; i < tabCount; i++)
			tabs += "\t";
		return tabs;

So if you have a simple Hello, World app, this is the log output.

execution(void mainExample.Main.main(String[]))
	call(void Execution Time: 112063 nanoseconds
execution(void mainExample.Main.main(String[])) Execution Time: 904636 nanoseconds

I ran it multiple times and the executions times were sporadic. I remember reading somewhere that System.nanoTime() in java was not extremely accurate, but it is accurate enough for this example.

Return to Aspected Oriented Programming – Examples

Leave a Reply

How to post code in comments?