4

In short, my problem is that my annotation is ignored if the annotated method isn't public, but it's recognized if another method in the same class is annotated.

I am trying to write an annotation to log the execution time of a method, as described in this answer.

This is my annotation:

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecutionTime
{

}

My aspect:

@Component
@Aspect
public class LogTimeAspect
{

    @Around(value = "@annotation(annotation)")
    public Object logExecutionTime(final ProceedingJoinPoint joinPoint, final LogExecutionTime annotation) throws Throwable
    {
        final long startingTime = System.currentTimeMillis();
        try
        {
            System.out.println("Starting timed method");
            final Object retval = joinPoint.proceed();
            return retval;
        }
        finally
        {
            System.out.println("Finished. Timed method " + joinPoint.toShortString() + " took: " + (System.currentTimeMillis() - startingTime) + "ms.");
        }
    }
}

My class in which I use the annotation:

@Component("classToBeAnnotated")
public class ClassToBeAnnotated {

    @LogExecutionTime
    public void operate() throws InterruptedException {
        System.out.println("Performing operation");
        Thread.sleep(1000);
    }
}

And the test class:

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(locations = { "/DefaultApplicationContext.xml" })
public class TestLauncher
{

    @Autowired
    private ClassToBeAnnotated classToBeAnnotated;

    @Test
    public void test() throws InterruptedException
    {
        classToBeAnnotated.operate();
    }

}

If I run the code shown above, I get

Starting timed method
Performing operation
Finished. Timed method execution(operate) took: 1025ms.

So far so good. But if I remove the public from the method with the annotation

@LogExecutionTime
void operate() throws InterruptedException

The annotation is ignored, and I just get:

Performing operation

No errors, no warnings, just doesn't run. But what strikes me the most is that if I add another method to the same class, and I make it public and annotate it, I get the same output as with the initial conditions, even if that extra method isn't called or related to the original one in any way besides having the same annotation.

@Component("classToBeAnnotated")
public class ClassToBeAnnotated {

    @LogExecutionTime
    public void someOtherMethod()
    {

    }

    @LogExecutionTime
    void operate() throws InterruptedException {
        System.out.println("Performing operation");
        Thread.sleep(1000);
    }
}

Output:

Starting timed method
Performing operation
Finished. Timed method execution(operate) took: 1029ms.

Can somebody explain why this happens?

Community
  • 1
  • 1
user4408343
  • 541
  • 5
  • 9

3 Answers3

1

Spring AOP is an "AOP lite" framework relying on

  • JDK dynamic proxies (works for all classes implementing one or more interfaces) or
  • CGLIB dynamic proxies (also works for classes not implementing any interfaces).

Methods defined by an interface are by definition public, so consequently JDK dynamic proxies can only proxy public methods as well.

CGLIB dynamic proxies work by subclassing an existing class, putting the proxy into the same package as the base class. So it can access public, protected and package-protected methods, but not private ones. Anyway, Spring tries to treat both variants uniformly, restricting AOP to public, non-static methods only.

The good news is that Spring has a very nice native AspectJ integration, usually activated via LTW (load-time weaving), see manual section 9.8 Using AspectJ with Spring applications. But CTW (compile-time weaving) is also possible. Check out the AspectJ manuals for more information. With full AspectJ you can intercept non-public methods, constructors, member read/write access etc. And while Spring AOP only works for Spring Beans/Components, AspectJ works for any class and does not need any proxies, making it more efficient. So you have many choices and can use the best of both worlds.

kriegaex
  • 63,017
  • 15
  • 111
  • 202
0

Because of the proxy-based nature of Spring AOP. But you can use Instrumentation. From OOD its wrong to use annotations, they should be or contain metadata, they should not be used as markers.

Grim
  • 1,938
  • 10
  • 56
  • 123
  • You could say as well that APO is wrong from OOP standpoint. Annotations based AOP is imho the only reasonable way of defining aspects. When you see @Transactional it clear what it stands for. It's also easy to find all classes that are going to be instrumented. Unlike @Before("com.myapp.System.operation() && args(account,..)"). Spring does not handle well many pointcuts. Load time and memory consumption suffers drastically (spring tries all pointcats on all beans so you get n^2 complexity). So it's better to have one pointcut for an annotation and many annotated classes than many pointcuts. – woru Jan 14 '15 at 15:59
  • @PeterRader ranker ? – Ben George Aug 04 '16 at 04:47
  • @woru You misunderstood me, AOP is neither wrong from OOD nor OOP in general. But marker-only-Annotations are wrong from OOD/OOP! `@Transactional` has metadata and is *not* a marker-annotation! But `@LogExecutionTime` is a bad thing, it has no OO amount because if you drop that annotation the OOD does neither change to bad nor good. Hey what exactly does the annotation and its pointcut? It logs execution-time and gives ideas for performance leaks, it may help in the decision to use a Thread or not, so its more a occasional job. – Grim Aug 04 '16 at 07:10
0

The reason is that spring uses an optimization to check which classes are going to be advised.

When a bean is instantiated AopUtils.canApply checks if any pointcut can be applied to any public method of a bean class.

So when there are no public method annotated with @LogExecutionTime in your class spring will not instrument it.

In your case when there's an empty public method, class is instrumented and because your class does not implement any interface and jdk proxy cannot be used your protected method is instrumented by accident.

woru
  • 1,420
  • 9
  • 17