0

Im new to AOP and have created a simple SpringBoot project to learn it. I've created a logging aspect which simple logs a message before triggering a get method that returns String. Upon adding wildcards (so it triggers for all get methods, regardless of return-type), im seeing an odd behavior - it seems to be triggering for internal method calls spring uses to load the context and then runs into an NPE. Not sure how to resolve this, code is below:

@SpringBootApplication
@ComponentScan
@EnableAutoConfiguration
public class AspectOrientedProgrammingApplication implements ApplicationContextAware {

    private static ApplicationContext applicationContext;

    public static void main(String[] args) {
        SpringApplication.run(AspectOrientedProgrammingApplication.class, args);
        ShapeService shapeService = applicationContext.getBean(ShapeService.class);
        System.out.println(shapeService.getCircle().getName());
    }

    @Override
    public void setApplicationContext(ApplicationContext context) throws BeansException {
        applicationContext = context;
    }
}

My Circle class:

@Component
public class Circle {
    @Value("${spring.app.circleName}")
    private String name;

    public String getName() {
        return name;
    }

    public void setName(String name) {
        this.name = name;
    }
}

ShapeService class:

@Component
public class ShapeService {
    @Autowired
    private Triangle triangle;

    @Autowired
    private Circle circle;

    public Triangle getTriangle() {
        return triangle;
    }

    public void setTriangle(Triangle triangle) {
        this.triangle = triangle;
    }

    public Circle getCircle() {
        return circle;
    }

    public void setCircle(Circle circle) {
        this.circle = circle;
    }
}

Aspect class:

@Aspect
@Component
public class LoggingAspect {

    @Before("execution(public * get*())") // works fine with "execution(public String getName())"
    public void loggingAdvice(){
        System.out.println("Advice run: Get method called");
    }
}

Running this results in following:

Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.springframework.cglib.core.ReflectUtils (file:/C:/Users/Arslan/.m2/repository/org/springframework/spring-core/5.3.15/spring-core-5.3.15.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
WARNING: Please consider reporting this to the maintainers of org.springframework.cglib.core.ReflectUtils
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
2022-02-06 08:14:28.566  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.boot.web.servlet.RegistrationBean.onStartup(javax.servlet.ServletContext) throws javax.servlet.ServletException] because it is marked as final: Consider using interface-based JDK proxies instead!
Advice run: Get method called
2022-02-06 08:14:29.163  INFO 8004 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-02-06 08:14:29.179  INFO 8004 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-02-06 08:14:29.179  INFO 8004 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.56]
2022-02-06 08:14:29.327  INFO 8004 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-02-06 08:14:29.327  INFO 8004 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2959 ms
Advice run: Get method called
2022-02-06 08:14:29.339  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.OncePerRequestFilter.doFilter(javax.servlet.ServletRequest,javax.servlet.ServletResponse,javax.servlet.FilterChain) throws javax.servlet.ServletException,java.io.IOException] because it is marked as final: Consider using interface-based JDK proxies instead!
2022-02-06 08:14:29.339  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.GenericFilterBean.init(javax.servlet.FilterConfig) throws javax.servlet.ServletException] because it is marked as final: Consider using interface-based JDK proxies instead!
2022-02-06 08:14:29.363  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.OncePerRequestFilter.doFilter(javax.servlet.ServletRequest,javax.servlet.ServletResponse,javax.servlet.FilterChain) throws javax.servlet.ServletException,java.io.IOException] because it is marked as final: Consider using interface-based JDK proxies instead!
2022-02-06 08:14:29.363  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.GenericFilterBean.init(javax.servlet.FilterConfig) throws javax.servlet.ServletException] because it is marked as final: Consider using interface-based JDK proxies instead!
2022-02-06 08:14:29.391  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.OncePerRequestFilter.doFilter(javax.servlet.ServletRequest,javax.servlet.ServletResponse,javax.servlet.FilterChain) throws javax.servlet.ServletException,java.io.IOException] because it is marked as final: Consider using interface-based JDK proxies instead!
2022-02-06 08:14:29.391  INFO 8004 --- [           main] o.s.aop.framework.CglibAopProxy          : Unable to proxy interface-implementing method [public final void org.springframework.web.filter.GenericFilterBean.init(javax.servlet.FilterConfig) throws javax.servlet.ServletException] because it is marked as final: Consider using interface-based JDK proxies instead!
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
Advice run: Get method called
2022-02-06 08:14:29.548 ERROR 8004 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Exception starting filter [requestContextFilter]

java.lang.NullPointerException: null
    at org.springframework.web.filter.GenericFilterBean.init(GenericFilterBean.java:241) ~[spring-web-5.3.15.jar:5.3.15]
    at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:272) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:106) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4613) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5256) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1396) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1386) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140) ~[na:na]
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:919) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1396) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1386) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140) ~[na:na]
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:919) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardService.startInternal(StandardService.java:432) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:927) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.apache.catalina.startup.Tomcat.start(Tomcat.java:486) ~[tomcat-embed-core-9.0.56.jar:9.0.56]
    at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.initialize(TomcatWebServer.java:123) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.<init>(TomcatWebServer.java:104) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory.getTomcatWebServer(TomcatServletWebServerFactory.java:478) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory.getWebServer(TomcatServletWebServerFactory.java:211) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory$$FastClassBySpringCGLIB$$9c83fa9f.invoke(<generated>) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:783) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:753) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:753) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:698) ~[spring-aop-5.3.15.jar:5.3.15]
    at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory$$EnhancerBySpringCGLIB$$e5201eaa.getWebServer(<generated>) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.createWebServer(ServletWebServerApplicationContext.java:182) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.onRefresh(ServletWebServerApplicationContext.java:160) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:577) ~[spring-context-5.3.15.jar:5.3.15]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:732) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:414) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:302) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1303) ~[spring-boot-2.6.3.jar:2.6.3]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1292) ~[spring-boot-2.6.3.jar:2.6.3]
    at com.arslan.javabrains.AspectOrientedProgrammingApplication.main(AspectOrientedProgrammingApplication.java:20) ~[classes/:na]

2022-02-06 08:14:29.548 ERROR 8004 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Exception starting filter [characterEncodingFilter]
kriegaex
  • 63,017
  • 15
  • 111
  • 202
arslan sana
  • 101
  • 1
  • 8
  • Hmm, I just realized I can get it to work If I put in the full package name within the "execution" statement. But it should work without that as well, no? – arslan sana Feb 06 '22 at 14:45

1 Answers1

1

It is a feature, not a bug of AOP that you can implement cross-cutting concerns which have a wide scope. The wide scope is a default, if you do not limit it. This applies to both native AspectJ and Spring AOP. We are talking about the latter here.

It is a typical AOP beginner's mistake to "weave the world", i.e. to write too widely-scoped pointcuts. In Spring AOP this can lead to intercepting internal Spring components or third-party ones, and sometimes that might be exactly what you want, depending on your aspect's purpose. In many cases, however, you simply want to apply the aspect to your own application, which hopefully lives in its own base package such as org.acme.myapp. Then you simply add && within(org.acme.myapp..*) to your pointcut in order to focus on everything in those packages (and their subpackages by virtue of ..*) as potential AOP targets.

So for your simple logging advice, it would look like this:

@Before("execution(public * get*()) && within(org.acme.myapp..*)")
public void loggingAdvice(JoinPoint joinPoint) {
  // Instead of a static message, log what we are actually intercepting
  System.out.println(joinPoint);
}

Of course, like you noticed, you could also extend the execution pointcut in order to add some scope, but firstly that makes the pointcut a bit harder to read and secondly it does not help you for pointcuts other than execution.

kriegaex
  • 63,017
  • 15
  • 111
  • 202