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?