aspectj with logback and springboot deadlock happened

[walkertest]

how to reproduce

• I make a demo to reproduce the problem.
• problem: the spring project may be deadlocked by log info format message and the projcet start failed. This happened online.
• detailInfo: https://github.com/walkertest/springdemo/blob/main/doc/logbackdeadlock.md

some env

java.version: 1.8.0_361
springboot: 2.7.15
aspectjweaver: 1.9.20

I don't know how to avoid this problem, wish your response. Thanks first.

more detailInfo

• VirtualMachine attach

• a thread which use logback format message

• @Asepect in main thread to do log format message too with logback

• the deadlock happend through debug and run step over

• some stack info:

  
  Found one Java-level deadlock:
  =============================
  "pool-1-thread-1":
  waiting to lock monitor 0x000002067dd46e08 (object 0x00000005c221c3c8, a sun.misc.Launcher$AppClassLoader),
  which is held by "main"
  "main":
  waiting to lock monitor 0x000002067dfc91e8 (object 0x000000071926d5b8, a java.lang.Object),
  which is held by "pool-1-thread-1"

Java stack information for the threads listed above:

"pool-1-thread-1": at org.aspectj.weaver.loadtime.Aj.preProcess(Aj.java:99)

• waiting to lock <0x00000005c221c3c8> (a sun.misc.Launcher$AppClassLoader) at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(ClassPreProcessorAgentAdapter.java:51) at sun.instrument.TransformerManager.transform(TransformerManager.java:188) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428) at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:756) at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) at java.net.URLClassLoader.defineClass(URLClassLoader.java:473) at java.net.URLClassLoader.access$100(URLClassLoader.java:74) at java.net.URLClassLoader$1.run(URLClassLoader.java:369) at java.net.URLClassLoader$1.run(URLClassLoader.java:363) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:362) at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
• locked <0x000000071926d5b8> (a java.lang.Object) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:355) at java.lang.ClassLoader.loadClass(ClassLoader.java:351) at ch.qos.logback.classic.spi.LoggingEvent.getFormattedMessage(LoggingEvent.java:293) at ch.qos.logback.classic.spi.LoggingEvent.prepareForDeferredProcessing(LoggingEvent.java:206) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:223) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383) at ch.qos.logback.classic.Logger.info(Logger.java:591) at com.tencent.demo.logbacktest.StartLogTest$NodeStartingHandleThread.run(StartLogTest.java:34) at java.lang.Thread.run(Thread.java:750) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:750) "main": at java.lang.ClassLoader.loadClass(ClassLoader.java:400)
• waiting to lock <0x000000071926d5b8> (a java.lang.Object) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:355) at java.lang.ClassLoader.loadClass(ClassLoader.java:351) at ch.qos.logback.classic.spi.LoggingEvent.getFormattedMessage(LoggingEvent.java:293) at ch.qos.logback.classic.spi.LoggingEvent.prepareForDeferredProcessing(LoggingEvent.java:206) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:223) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:398) at ch.qos.logback.classic.Logger.info(Logger.java:583) at com.tencent.demo.logbacktest.LogInit.init(LogInit.java:13) at com.tencent.demo.logbacktest.ComponentTest.(ComponentTest.java:14) at java.lang.Class.forName0(Native Method) at java.lang.Class.forName(Class.java:348) at org.springframework.cglib.core.ReflectUtils.defineClass(ReflectUtils.java:604) at org.springframework.cglib.core.AbstractClassGenerator.generate(AbstractClassGenerator.java:363)
• locked <0x00000005c221c3c8> (a sun.misc.Launcher$AppClassLoader) at org.springframework.cglib.proxy.Enhancer.generate(Enhancer.java:585) at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:110) at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:108) at org.springframework.cglib.core.internal.LoadingCache$2.call(LoadingCache.java:54) at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266) at java.util.concurrent.FutureTask.run(FutureTask.java) at org.springframework.cglib.core.internal.LoadingCache.createEntry(LoadingCache.java:61) at org.springframework.cglib.core.internal.LoadingCache.get(LoadingCache.java:34) at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData.get(AbstractClassGenerator.java:134) at org.springframework.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:319) at org.springframework.cglib.proxy.Enhancer.createHelper(Enhancer.java:572) at org.springframework.cglib.proxy.Enhancer.createClass(Enhancer.java:419) at org.springframework.context.annotation.ConfigurationClassEnhancer.createClass(ConfigurationClassEnhancer.java:137) at org.springframework.context.annotation.ConfigurationClassEnhancer.enhance(ConfigurationClassEnhancer.java:109) at org.springframework.context.annotation.ConfigurationClassPostProcessor.enhanceConfigurationClasses(ConfigurationClassPostProcessor.java:447) at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanFactory(ConfigurationClassPostProcessor.java:268) at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:325) at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:147) at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:748) at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:564)
• locked <0x00000005c2211918> (a java.lang.Object) at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:147) at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:731) at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:408) at org.springframework.boot.SpringApplication.run(SpringApplication.java:307) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1303) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1292) at com.tencent.demo.DemoApplication.main(DemoApplication.java:10)

Found 1 deadlock.

[jstackinfo.txt](https://github.com/eclipse-aspectj/aspectj/files/12495160/26220.txt)

[kriegaex]

Can you please post some more information, for example a call stack, thread dump etc.? I am on the road and would like to understand this issue first, before having a chance to clone your repository. Thanks.

[walkertest]

Hi, I have update the issue with some more info.

[kriegaex]

Thank you for the MCVE and its documentation. Great job! 🙂

I can reproduce the problem, but only in debug mode, not when running the application normally. Either way, it looks as if there is no AspectJ issue, but the problem sits in front of the computer. You use Spring AOP incorrectly. Please change the faulty

@Aspect
@Configuration
public class ComponentTest {

to

@Aspect
@Component
public class ComponentTest {

See PR https://github.com/walkertest/springdemo/pull/1.

I see this error so often and have commented on it on Stack Overflow a lot. It seems there is one faulty source from which everyone copies and pastes their Spring AOP aspects. An aspect is a component, not a configuration class. The types of proxies created for both are different. Correct that, and the problem goes away.

P.S.: Why are you avoiding capital letters where the English language requires them? Orthography is not optional, just because we are computer nerds. It makes reading your text more difficult than necessary.

[walkertest]

Thanks your advice!

• It can be reproduced in run mode in our online env. Thats why I ask this question. But it happened by chance.
• I changed @Configuration to @Component , then the problem goes away. This method is good!
• Is there any stackoverflow link? I can see the detail issue info and I have tried to find solution by google , but i did not find any of them.
• My english language is not very good. Please forgive me.

[kriegaex]

@walkertest: https://stackoverflow.com/a/56919004/1082681