Spring AOP Advice Called Twice

2
votes

For some reason, my Spring AOP advices are being called twice. I checked:

  1. Spring AOP advice is called twice but I am not using the Component annotation, and am declaring the aspect bean once and annotating it with @Aspect and that's it.

  2. Somewhat belatedly I realized that one of my classes was not implementing an interface yet, which caused CGLIB2 requirements. I fixed that, and the CGLIB2 problem went away, but the double invocation remains.

Edit:

Forgot to mention that I checked, and the method being advised is not called twice.

2nd edit:

I declare a class with @Aspect, and then I declare it as a bean in the application context. There are no advices or pointcuts in the XML file.

3rd edit:

Also worth noting is that I log before and after the execution of the method being advised with Around:

log.info("before");

pjp.proceed();

log.info("after");

What I see is:

before
before
after
after

Which is really weird.

This happens for both @Before and @Around advice that I have set up. I have yet to try the other types.

Here is the pointcut declaration, with changed names:

@Around("execution(public java.util.List<java.lang.String> pac.age.names.myDAO.doSomething(java.lang.String, java.lang.String))")

Any ideas?

Thanks,

Snorkel

3
javaspringaopspring-aop
Are you scanning packages? You say you are declaring the aspect bean once (in xml?) and then annotating it as well. That would cause double invocation. – user785262
I am using <aop:aspectj-autoproxy />, <context:annotation-config /> and then I have a bean with the class where the advice is implemented. AFAIK, those are the minimal steps. Thanks! – MrSilverSnorkel
If your advice is called twice but just method is called one, is it possible you are calling two different methods? – jddsantaella
Thought of that, which is why I made the pointcut apply to a specific method, invoked by name with parameters and return codes. – MrSilverSnorkel
Are you sure it's the advice being called twice or could it be your logging configuration causing the message to be printed twice (e.g. if you have explicitly attached an appender to both the root logger and to the foo.bar logger then you may find one log.info call results in two identical messages being printed). You can check this by adding a second log.info in your advice between the "before" and the proceed and seeing whether it prints messages in the order AABB (double logging) or ABAB (advice called twice). – Ian Roberts

3 Answers

3
votes

Well, it seems like this is actually an issue with the logger. This morning I checked and found that everything is being logged twice. When I replaced logger calls with regular sysout calls, everything worked fine.

1
votes

I had the same problem. My double aspect call was caused by me adding a parent to the aspect and also having an @Before annotation on a method in the parent that the child called in its own @Before. The Parent @Before was being inherited as a aop advice which also matched my pointcut. Therefore in addition to me explicitly calling from the child i.e(super.someMethod()), I also implicitly was calling it right after the child's advice finished executing. Removing parents @Before on the inherited 'someMethod()' fixed the aspect being called twice. So you can inherit advice. Long story short.

0
votes

The problem with the duplicate logs comes from the "additivity" property of the Logger implementation. You can configure your logger with additivity=false (either in XML or .property file).

log4j2.logger.youraspect-logging.name=your.package.YourAspect
log4j2.logger.youraspect-logging.level=debug
log4j2.logger.youraspect-logging.appenderRef.stdout.ref=STDOUT
log4j2.logger.youraspect-logging.additivity=false