1   /*
2    * ProfilingWithAspectJ - Profiling with AspectJ
3    * Copyright (C) 2007 Christian Schenk
4    *
5    * This program is free software; you can redistribute it and/or
6    * modify it under the terms of the GNU General Public License
7    * as published by the Free Software Foundation; either version 2
8    * of the License, or (at your option) any later version.
9    * 
10   * This program is distributed in the hope that it will be useful,
11   * but WITHOUT ANY WARRANTY; without even the implied warranty of
12   * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
13   * GNU General Public License for more details.
14   * 
15   * You should have received a copy of the GNU General Public License
16   * along with this program; if not, write to the Free Software
17   * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA
18   */
19  package org.christianschenk.aspectj.profiling;
20  
21  import java.util.HashMap;
22  import java.util.Map;
23  
24  import org.apache.log4j.Logger;
25  import org.aspectj.lang.JoinPoint;
26  import org.aspectj.lang.ProceedingJoinPoint;
27  import org.aspectj.lang.annotation.After;
28  import org.aspectj.lang.annotation.Around;
29  import org.aspectj.lang.annotation.Aspect;
30  import org.aspectj.lang.annotation.Pointcut;
31  
32  /**
33   * This is a simple aspect that can be used for profiling. Subclass a new aspect
34   * from here, implement the profile method and define the methods that should be
35   * profiled in a pointcut.
36   * 
37   * @author Christian Schenk
38   */
39  @Aspect
40  public abstract class AbstractProfilingAspect {
41  
42  	private static final Logger log = Logger.getLogger("profiling");
43  	/** Stores the method names and the corresponding execution time */
44  	private final Map<String, Long> methodTimes;
45  	/** The top level method which calls the methods that should be profiled */
46  	private final String topLevelMethod;
47  
48  	public AbstractProfilingAspect(final String topLevelMethod) {
49  		this.methodTimes = new HashMap<String, Long>();
50  		this.topLevelMethod = topLevelMethod;
51  	}
52  
53  	/**
54  	 * Implement this method and define a proper pointcut for it.
55  	 */
56  	@Pointcut
57  	protected abstract void profile();
58  
59  	/**
60  	 * This is the stop watch that takes the time of those methods that should
61  	 * be profiled.
62  	 */
63  	@Around("profile()")
64  	public void aroundProfileMethods(final ProceedingJoinPoint thisJoinPoint) throws Throwable {
65  		final long start, end;
66  		start = System.nanoTime();
67  		thisJoinPoint.proceed();
68  		end = System.nanoTime();
69  		this.methodTimes.put(this.getJoinPointName(thisJoinPoint), ((end - start) / 1000) / 1000);
70  	}
71  
72  	/**
73  	 * Prints the gathered statistics once the top level method is finished.
74  	 */
75  	@After("profile()")
76  	public void afterTopLevelMethod(final JoinPoint joinPoint) {
77  		if (this.topLevelMethod.equals(this.getJoinPointName(joinPoint)) == false) return;
78  
79  		final long overallTime = this.methodTimes.get(this.topLevelMethod);
80  		log.debug("Results for " + this.topLevelMethod + " (" + overallTime + "ms)");
81  		for (final String method : this.methodTimes.keySet()) {
82  			if (method.equals(this.topLevelMethod)) continue;
83  			final long methodTime = this.methodTimes.get(method);
84  			final double percent = Math.round(((double) methodTime / (double) overallTime) * 100);
85  			log.debug("Method: " + method + "() took " + methodTime + "ms (" + percent + "%)");
86  		}
87  	}
88  
89  	/**
90  	 * Convenience method that returns the class- and method-name for a given
91  	 * join point.
92  	 */
93  	private final String getJoinPointName(final JoinPoint joinPoint) {
94  		return joinPoint.getThis().getClass().getSimpleName() + "." + joinPoint.getSignature().getName();
95  	}
96  }