AspectJ LTW не работает с Spring Boot в неуправляемых классах

Я столкнулся с проблемой в крупномасштабном приложении, использующем SpringBoot и AspectJ для целей ведения журнала. Ведение журнала отлично работает для Spring Beans, но не работает для неуправляемых классов (тех, которые я создаю с помощью «новых»).

Я создал пример приложения, в котором вы можете увидеть возникающую проблему, вы можете получить к нему доступ здесь:

https://bitbucket.org/tomkro/stack_question

Приложение довольно простое, файл Gradle является общим для стандартных стартеров Spring Boot.

Здесь есть 5 соответствующих классов.

Application.java, который является основным классом:

@EnableAspectJAutoProxy
@EnableLoadTimeWeaving(aspectjWeaving= EnableLoadTimeWeaving.AspectJWeaving.ENABLED)
@SpringBootApplication(scanBasePackages = "com.test.*")
public class Application {

    public static void main(final String[] args) {
        SpringApplication.run(Application.class, args);
    }
}

Файл AspectConfig (который для простоты также определяет RestController, может быть легко разделен на файлы)

@RestController
@Configuration
@ComponentScan(basePackages = {"com.test"})
public class AspectConfig {

    @Bean
    public TestLogger testLogger(){
        return new TestLogger();
    }

    @Autowired
    TestClass testClass;

    @RequestMapping("/")
    public int get() {
        return testClass.methodFromClass1();
    }

}

TestLogger, который определяет аспект для этого приложения:

@Aspect
public class TestLogger {

    public TestLogger() {
    }

    @Around("execution( * com.test.classes..*.*(..))")
    public Object aroundExecution(ProceedingJoinPoint pjp) throws Throwable {
        String packageName = pjp.getSignature().getDeclaringTypeName();
        String methodName = pjp.getSignature().getName();
        long start = System.currentTimeMillis();

        System.out.println(packageName + "." + methodName + " - Starting execution ");

        Object output = pjp.proceed();
        Long elapsedTime = System.currentTimeMillis() - start;

        System.out.println(packageName + "." + methodName + " - Ending execution ["+elapsedTime+" ms]");
        return output;
    }

}

И затем есть два файла, один из которых управляется Spring, а другой нет:

ТестКласс1:

@Component
public class TestClass {

    public int methodFromClass1() {
        TestClass2 test = new TestClass2();
        return test.methodFromClass2();
    }

}

ТестКласс2

public class TestClass2 {
    public int methodFromClass2() {
        int a = 10;
        int b = 5;

        return b + a;
    }
}

Также в META-INF есть файл aop.xml, в котором указан аспект

<!DOCTYPE aspectj PUBLIC "-//AspectJ//DTD//EN" "http://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>
    <weaver option="-debug">
        <!-- only weave classes in our application-specific packages -->
        <include within="com.test.*"/>
    </weaver>

    <aspects>
        <!-- weave in just this aspect -->
        <aspect name="com.test.utilities.TestLogger"/>
    </aspects>

</aspectj>

Я выполнил большую часть этой сборки, используя учебник по документации Spring здесь , и я уже два дня ломаю голову и не могу понять, что происходит. Управляемый Bean регистрируется нормально, но неуправляемый не регистрируется.

Я использую run.bat, включенный в проект, для запуска, в основном он делает это:

call gradle build
java -javaagent:.\src\main\resources\aspectjweaver.jar -javaagent:.\src\main\resources\spring-instrument.jar -jar build\libs\Test-0.0.1-SNAPSHOT.jar

Обе банки самые последние. Обычно вам нужны только JAR, но я видел, как кто-то использует оба, и попробовал. Это вывод после запуска и выполнения вызова «localhost: 8080».

[LaunchedURLClassLoader@6d8a00e3] warning javax.* types are not being woven because the weaver option '-Xset:weaveJavaxPackages=true' has not been specified

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.3.0.RELEASE)

2016-04-08 15:21:44.116  INFO 20400 --- [           main] com.test.Application                     : Starting Application on PC000BR23205 with PID 20400 (C:\git\Test\build\libs\Test-0.0.1-SNAPSHOT.jar started by tkroth in C:\git\T
est)
2016-04-08 15:21:44.120  INFO 20400 --- [           main] com.test.Application                     : No profiles are active
2016-04-08 15:21:44.294  INFO 20400 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@2cd72cea: startup date [Fri Ap
r 08 15:21:44 BRT 2016]; root of context hierarchy
2016-04-08 15:21:44.950  INFO 20400 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Overriding bean definition for bean 'beanNameViewResolver' with a different definition: replacing [Root bean: class [null]; scope
=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration; fa
ctoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration.class]]
 with [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.WebMvcAutoConfiguration$W
ebMvcAutoConfigurationAdapter; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/WebMvcAutoConfiguration$WebMvcAut
oConfigurationAdapter.class]]
2016-04-08 15:21:45.872  INFO 20400 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2016-04-08 15:21:45.888  INFO 20400 --- [           main] o.apache.catalina.core.StandardService   : Starting service Tomcat
2016-04-08 15:21:45.891  INFO 20400 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.0.28
2016-04-08 15:21:45.987  INFO 20400 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2016-04-08 15:21:45.987  INFO 20400 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1695 ms
2016-04-08 15:21:46.342  INFO 20400 --- [ost-startStop-1] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'dispatcherServlet' to [/]
2016-04-08 15:21:46.347  INFO 20400 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'characterEncodingFilter' to: [/*]
2016-04-08 15:21:46.348  INFO 20400 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2016-04-08 15:21:46.349  INFO 20400 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2016-04-08 15:21:46.349  INFO 20400 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'requestContextFilter' to: [/*]
2016-04-08 15:21:46.439  INFO 20400 --- [           main] o.s.c.w.DefaultContextLoadTimeWeaver     : Found Spring's JVM agent for instrumentation
2016-04-08 15:21:46.455  INFO 20400 --- [           main] o.s.c.w.DefaultContextLoadTimeWeaver     : Found Spring's JVM agent for instrumentation
[LaunchedURLClassLoader@6d8a00e3] warning javax.* types are not being woven because the weaver option '-Xset:weaveJavaxPackages=true' has not been specified
2016-04-08 15:21:46.781  INFO 20400 --- [           main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@2cd72cea:
startup date [Fri Apr 08 15:21:44 BRT 2016]; root of context hierarchy
2016-04-08 15:21:46.874  INFO 20400 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/]}" onto public int com.test.configuration.AspectConfig.get()
2016-04-08 15:21:46.877  INFO 20400 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.sp
ringframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2016-04-08 15:21:46.878  INFO 20400 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoco
nfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest)
2016-04-08 15:21:46.912  INFO 20400 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2016-04-08 15:21:46.912  INFO 20400 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2016-04-08 15:21:47.030  INFO 20400 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler
]
2016-04-08 15:21:47.133  INFO 20400 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2016-04-08 15:21:47.204  INFO 20400 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2016-04-08 15:21:47.210  INFO 20400 --- [           main] com.test.Application                     : Started Application in 3.481 seconds (JVM running for 4.306)
2016-04-08 15:21:51.680  INFO 20400 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring FrameworkServlet 'dispatcherServlet'
2016-04-08 15:21:51.680  INFO 20400 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
2016-04-08 15:21:51.704  INFO 20400 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 23 ms
com.test.classes.TestClass.methodFromClass1 - Starting execution
com.test.classes.TestClass.methodFromClass1 - Ending execution [15 ms]

Как видите, TestClass2 никогда не регистрируется, хотя вызывается. Что мне здесь не хватает?

Реальный вопрос заключается в том, как я могу заставить LTW обрабатывать не-бины в среде SpringBoot? Не стесняйтесь вносить изменения в репозиторий, который я указал выше.


person Tomás Kroth    schedule 08.04.2016    source источник
comment
Добавьте -showWeaveInfo и -verbose к aspect.xml, как в этом ответе [stackoverflow.com/a/34427785/2699901], чтобы получить больше Подробно о процессе плетения.   -  person Nándor Előd Fekete    schedule 09.04.2016
comment
Это не дало никакой полезной информации о проблеме. Только некоторая звездная информация о загружаемом ClassLoader, но она не читается (только toString в ссылке на класс)   -  person Tomás Kroth    schedule 11.04.2016
comment
У вас должны быть аналогичные записи журнала в стандартном выводе о тканых точках соединения, как в указанном ответе. Если вы пропустите эти записи в журнале, либо ваши точки не соответствуют вашему коду, либо плетение во время загрузки не работает должным образом.   -  person Nándor Előd Fekete    schedule 11.04.2016