@AfterThrowing in Spring different behavior

Question

I have the following strange behavior.

When I use a named pointcut the advised method runs before the body of the @AfterThrowing annotated method. But if I use an inline pointcut the @AfterThrowing annotated one runs first.

Why so?

Here is the code:

@Component
@Aspect
public class CustomAspect {

    @AfterThrowing(pointcut = "execution(* throwAnException(..))", throwing = "exception")
    public void adviceForExceptionThrowing(Exception exception) {
        System.out.println("###### " + exception.getMessage() + " ######");
    }

}

results in:

INFO: Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@5a10411: startup date [Wed Jun 14 15:51:26 EEST 2017]; root of context hierarchy
###### Some message from the exception ######
Exception in thread "main" java.lang.Exception: Some message from the exception

---

2nd result:

@Component
@Aspect
public class CustomAspect {

    @Pointcut("execution(* throwAnException(..))")
    private void pointcutForException() {
    }

    @AfterThrowing(pointcut = "pointcutForException()", throwing = "exception")
    public void adviceForExceptionThrowing(Exception exception) {
        System.out.println("###### " + exception.getMessage() + " ######");
    }

}

And we get:

INFO: Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@5a10411: startup date [Wed Jun 14 15:54:38 EEST 2017]; root of context hierarchy
Exception in thread "main" java.lang.Exception: Some message from the exception
    at blog.codingideas.aspects.SomeBean.throwAnException(SomeBean.java:13)
    at blog.codingideas.aspects.SomeBean$$FastClassBySpringCGLIB$$97c62a5f.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:62)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673)
    at blog.codingideas.aspects.SomeBean$$EnhancerBySpringCGLIB$$985c5826.throwAnException(<generated>)
    at blog.codingideas.ApplicationMain.main(ApplicationMain.java:13)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:147)
###### Some message from the exception ######

Answer 1

Your code works as expected. @AfterThrown advice has been executed after the exception is thrown.

The tricky thing is with System.out.println. It calls the PrintStream under the hood. This is a buffered stream. A Buffered stream gets written to the output (console) after it fills up, or when you explicitly call flush on it.

So in your case, it depends on the internal dynamics of how much the stack is filled up and how many print statements were able to get executed before other thread printed exception stacktrace.

P.S. Try to run each of your solution couple of times, and you'll find that ###### Some message from the exception ###### is being printed before and after the main stacktrace in random order.