class Test {
@override
public String a(){
b();
d();
}
private String b() {
c();
}
private String c(){
d();
}
private String d(){}
}
I want to intercept each methods of class Test that is been called from overridden method A() and want to know how much time each method like b(), c() took while processing some business logic separately.
How can I achieve it using Spring AOP or Aspectj?
In order to
you need to switch from Spring AOP (proxy-based, many limitations, slow) to AspectJ using LTW (load-time weaving) as described in the Spring manual.
Here is an example in pure AspectJ (no Spring, Just Java SE) which you can easily adapt to your needs:
Sample interface
package de.scrum_master.app;
public interface TextTransformer {
String transform(String text);
}
Class implementing interface incl. main
method:
As you can see, I made up an example like yours and also made the methods spend time in order to have something to measure in the aspect later:
package de.scrum_master.app;
public class Application implements TextTransformer {
@Override
public String transform(String text) {
String geekSpelling;
try {
geekSpelling = toGeekSpelling(text);
return toUpperCase(geekSpelling);
} catch (InterruptedException e) {
throw new RuntimeException(e);
}
}
private String toGeekSpelling(String text) throws InterruptedException {
Thread.sleep(100);
return replaceVovels(text).replaceAll("[lL]", "1");
}
private String replaceVovels(String text) throws InterruptedException {
Thread.sleep(75);
return text.replaceAll("[oO]", "0").replaceAll("[eE]", "Ɛ");
}
private String toUpperCase(String text) throws InterruptedException {
Thread.sleep(50);
return text.toUpperCase();
}
public static void main(String[] args) throws InterruptedException {
System.out.println(new Application().transform("Hello world!"));
}
}
Aspect:
package de.scrum_master.aspect;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import static java.lang.System.currentTimeMillis;
@Aspect
public class TimingAspect {
@Around("execution(* *(..)) && cflow(execution(* de.scrum_master.app.TextTransformer.*(..)))")
public Object measureExecutionTime(ProceedingJoinPoint thisJoinPoint) throws Throwable {
long startTime = currentTimeMillis();
Object result = thisJoinPoint.proceed();
System.out.println(thisJoinPoint + " -> " + (currentTimeMillis() - startTime) + " ms");
return result;
}
}
Console log:
execution(String de.scrum_master.app.Application.replaceVovels(String)) -> 75 ms
execution(String de.scrum_master.app.Application.toGeekSpelling(String)) -> 189 ms
execution(String de.scrum_master.app.Application.toUpperCase(String)) -> 63 ms
execution(String de.scrum_master.app.Application.transform(String)) -> 252 ms
HƐ110 W0R1D!
You can also exclude the transform(..)
method by just changing the pointcut from cflow()
to cflowbelow()
:
@Around("execution(* *(..)) && cflowbelow(execution(* de.scrum_master.app.TextTransformer.*(..)))")
Then the console log is just:
execution(String de.scrum_master.app.Application.replaceVovels(String)) -> 77 ms
execution(String de.scrum_master.app.Application.toGeekSpelling(String)) -> 179 ms
execution(String de.scrum_master.app.Application.toUpperCase(String)) -> 62 ms
HƐ110 W0R1D!
Incidentally, please do read an AspectJ and/or Spring AOP manual.