AOP + annotation problem

[isaac_asensio]

Hi everybody,

I have a weird problem with annotations. I have created a dummy service with LiveMonitoring annotation. Spring AOP catch all method invocations marked with this annotation (with Around advice). For some reason I'm seeing the system output twice. Any ideas?


My dummy Service:

public class ServiceImpl implements Service {
	
	/* (non-Javadoc)
	 * @see org.enterprise.example.instrumentation.Service#doSomething()
	 */
	@LiveInstrumentation
	public void doSomething(){
		System.out.println("Do Something!!!");
	}
}

My Annotation:

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

My Service:

@Aspect
public class AspectLiveMonitoring {
	
	@Around("@annotation(org.enterprise.example.instrumentation.LiveInstrumentation)")
	public void live(ProceedingJoinPoint jp) throws Throwable{
		StopWatch watch = new StopWatch();
		watch.start();		
		jp.proceed();
		watch.stop();
		System.out.println("Method " + jp.getSignature().toLongString() + " executed in " + watch.getLastTaskTimeMillis() + " millis");
	}
	
}

Console Output:

Do Something!!!
Method public abstract void org.enterprise.example.instrumentation.Service.doSomething() executed in 0 millis
Method public abstract void org.enterprise.example.instrumentation.Service.doSomething() executed in 0 millis

Why does this trace appear twice?

Thanks in advance!

Isaac

[Marten Deinum]

My guess is due to double proxying..

[denis.zhdanov]

Hi everybody,

I have a weird problem with annotations. I have created a dummy service with LiveMonitoring annotation. Spring AOP catch all method invocations marked with this annotation (with Around advice). For some reason I'm seeing the system output twice. Any ideas?


My dummy Service:

public class ServiceImpl implements Service {
	
	/* (non-Javadoc)
	 * @see org.enterprise.example.instrumentation.Service#doSomething()
	 */
	@LiveInstrumentation
	public void doSomething(){
		System.out.println("Do Something!!!");
	}
}

My Annotation:

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

My Service:

@Aspect
public class AspectLiveMonitoring {
	
	@Around("@annotation(org.enterprise.example.instrumentation.LiveInstrumentation)")
	public void live(ProceedingJoinPoint jp) throws Throwable{
		StopWatch watch = new StopWatch();
		watch.start();		
		jp.proceed();
		watch.stop();
		System.out.println("Method " + jp.getSignature().toLongString() + " executed in " + watch.getLastTaskTimeMillis() + " millis");
	}
	
}

Console Output:

Do Something!!!
Method public abstract void org.enterprise.example.instrumentation.Service.doSomething() executed in 0 millis
Method public abstract void org.enterprise.example.instrumentation.Service.doSomething() executed in 0 millis

Why does this trace appear twice?

Thanks in advance!

Isaac

Hi Isaac,

Sorry but your question doesn't allow to reproduce the problem at local environemnt, hence, provide a solution to it. Please prepare minimal but complete standalone example that represents the problem and post it here.

[Tomiito]

Hi Isaac,

Can you post the aspect configuration file,
Maybe you are double proxying your aspects as Marten Deinum saids..

You can test the following:
Put a breakpoint in the adviced method and run a test in debug mode.
You can check there if the method is called twice, if not you can suspect from
your logging configuration..

[isaac_asensio]

Hi everyone,

Marten you're right.

It's due to a double declaration of aop:aspectj-autoproxy tag. I have several XML files in the webapp and I lost sight of this repeated tag.

Thanks!