1、遇到的问题
启动SpringBoot项目时，服务启动过程直接卡住了，没有异常也没有提示
2、问题根因
在注册Bean的时候，会调用到DefaultSingletonBeanRegistry.getSingleton方法获取锁，在初始化(比如@PostConstruct或者afterPropertiesSet)过程中，主线程还是持有锁的。
如果在这初始化的过程中使用了parallelStream，它会默认通过ForkJoinPool去创建新的线程执行操作。
新线程如果在这时去容器中获取Bean的话，运行到getSingleton方法时，会一直等待锁，此时锁正在被主线程持有，而主线程则是在流中执行collect方法的时候一直wait新线程执行完成，形成了死锁。
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry
public class DefaultSingletonBeanRegistry extends SimpleAliasRegistry implements SingletonBeanRegistry {
/**
* Return the (raw) singleton object registered under the given name,
* creating and registering a new one if none registered yet.
* @param beanName the name of the bean
* @param singletonFactory the ObjectFactory to lazily create the singleton
* with, if necessary
* @return the registered singleton object
*/
public Object getSingleton(String beanName, ObjectFactory<?> singletonFactory) {
Assert.notNull(beanName, "Bean name must not be null");
// 获取到锁才能获取Bean，synchronized为可重入锁
synchronized (this.singletonObjects) {
Object singletonObject = this.singletonObjects.get(beanName);
if (singletonObject == null) {
if (this.singletonsCurrentlyInDestruction) {
throw new BeanCreationNotAllowedException(beanName,
"Singleton bean creation not allowed while singletons of this factory are in destruction " +
"(Do not request a bean from a BeanFactory in a destroy method implementation!)");
}
if (logger.isDebugEnabled()) {
logger.debug("Creating shared instance of singleton bean '" + beanName + "'");
}
beforeSingletonCreation(beanName);
boolean newSingleton = false;
boolean recordSuppressedExceptions = (this.suppressedExceptions == null);
if (recordSuppressedExceptions) {
this.suppressedExceptions = new LinkedHashSet<>();
}
try {
singletonObject = singletonFactory.getObject();
newSingleton = true;
}
catch (IllegalStateException ex) {
// Has the singleton object implicitly appeared in the meantime ->
// if yes, proceed with it since the exception indicates that state.
singletonObject = this.singletonObjects.get(beanName);
if (singletonObject == null) {
throw ex;
}
}
catch (BeanCreationException ex) {
if (recordSuppressedExceptions) {
for (Exception suppressedException : this.suppressedExceptions) {
ex.addRelatedCause(suppressedException);
}
}
throw ex;
}
finally {
if (recordSuppressedExceptions) {
this.suppressedExceptions = null;
}
afterSingletonCreation(beanName);
}
if (newSingleton) {
addSingleton(beanName, singletonObject);
}
}
return singletonObject;
}
}
}
java.util.concurrent.ForkJoinTask
parallelStream的工作线程
public abstract class ForkJoinTask<V> implements Future<V>, Serializable {
/**
* Blocks a non-worker-thread until completion.
* @return status upon completion
*/
private int externalAwaitDone() {
int s = ((this instanceof CountedCompleter) ? // try helping
ForkJoinPool.common.externalHelpComplete(
(CountedCompleter<?>)this, 0) :
ForkJoinPool.common.tryExternalUnpush(this) ? doExec() : 0);
if (s >= 0 && (s = status) >= 0) {
boolean interrupted = false;
do {
if (U.compareAndSwapInt(this, STATUS, s, s | SIGNAL)) {
synchronized (this) {
if (status >= 0) {
try {
// 工作线程阻塞非工作线程(主线程)，0代表永远等待
wait(0L);
} catch (InterruptedException ie) {
interrupted = true;
}
}
else
// 工作线程执行完后唤醒非工作线程(主线程)
notifyAll();
}
}
} while ((s = status) >= 0);
if (interrupted)
Thread.currentThread().interrupt();
}
return s;
}
}
3、问题复现
3.1、新建项目
ParallelApplicaiton：Spring项目启动类BadService：复现问题YourController：测试接口
- parallelstream
- src.main.java.com.luna
- controller
- YourController.java
- deadlock
- BadService.java
- ParallelApplication.java
- pom.xml
BadService
@Service：标识为BeanApplicationContextAware：为类注入Spring容器@PostConstruct：完成Bean的一些初始化操作，执行时机晚于@Autowired
在注册badService这个Bean的时候，实例化完初始化时，使用@PostConstruct为list属性赋值，其中使用了并发流parallelStream来获取容器中已加载的Bean
package com.luna.deadlock;
import org.springframework.beans.BeansException;
import org.springframework.context.ApplicationContext;
import org.springframework.context.ApplicationContextAware;
import org.springframework.lang.NonNull;
import org.springframework.stereotype.Service;
import javax.annotation.PostConstruct;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Collectors;
/**
* @author qiongying.huai（2477637880@qq.com）
* @version 1.0
* @className BadService
* @description description
* @date 15:19 2023/10/24
*/
@Service
public class BadService implements ApplicationContextAware {
private ApplicationContext applicationContext;
private List<Object> list;
@PostConstruct
public void parallel() {
list = Arrays.stream(applicationContext.getBeanDefinitionNames())
.parallel()
.filter(name -> !"badService".equals(name))
.map(applicationContext::getBean)
.collect(Collectors.toList());
System.out.println(list.size());
}
@Override
public void setApplicationContext(@NonNull ApplicationContext applicationContext) throws BeansException {
this.applicationContext = applicationContext;
}
}
YourController
简单的GET测试接口
package com.luna.controller;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
/**
* @author qiongying.huai（2477637880@qq.com）
* @version 1.0
* @className YourController
* @description description
* @date 18:57 2023/10/24
*/
@RestController
@RequestMapping("/api")
public class YourController {
@GetMapping("/su")
public String suMi() {
return "ma se";
}
}
ParallelApplication
package com.luna;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
/**
* @author qiongying.huai（2477637880@qq.com）
* @version 1.0
* @className ParallelApplication
* @description description
* @date 15:10 2023/10/24
*/
@SpringBootApplication
public class ParallelApplication {
public static void main(String[] args) {
SpringApplication.run(ParallelApplication.class, args);
}
}
3.2、启动项目
启动日志
Connected to the target VM, address: '127.0.0.1:59360', transport: 'socket'
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.5)
2023-10-24 19:15:09.964 INFO 13178 --- [ main] com.luna.ParallelApplication : Starting ParallelApplication using Java 1.8.0_271 on 111deMacBook-Pro.local with PID 13178 (/Users/111/code/mavendemo/parallelstream/target/classes started by 111 in /Users/111/code/mavendemo)
2023-10-24 19:15:09.970 INFO 13178 --- [ main] com.luna.ParallelApplication : No active profile set, falling back to 1 default profile: "default"
2023-10-24 19:15:11.089 INFO 13178 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2023-10-24 19:15:11.102 INFO 13178 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-10-24 19:15:11.102 INFO 13178 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.60]
2023-10-24 19:15:11.244 INFO 13178 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-10-24 19:15:11.244 INFO 13178 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1154 ms
请求测试接口
请求失败，服务未启动
parallerstream % curl --location --request GET 'http://localhost:8080/api/su'
curl: (7) Failed to connect to localhost port 8080 after 8 ms: Couldn't connect to server
使用arthas分析
官方文档：简介｜arthas
- 启动
arthas- 查看阻塞状态的线程
- 找出当前阻塞其他线程的线程
"main" Id=1 WAITING on java.util.stream.ReduceOps$ReduceTask@a2ddf26
at java.lang.Object.wait(Native Method)
- waiting on java.util.stream.ReduceOps$ReduceTask@a2ddf26
at java.util.concurrent.ForkJoinTask.externalAwaitDone(ForkJoinTask.java:334)
主线程被ReduceTask@a2ddf26对象阻塞住，ReduceTask对象是parallelStream的工作线程对象
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
- locked java.util.concurrent.ConcurrentHashMap@5485df50 <---- but blocks 7 other threads!
主线程又在getSingleton方法处阻塞了其他7个线程，通过阻塞状态的线程列表看，是ForkJoinPool的工作线程ForkJoinPool.commonPool-worker-1，这是parallelStream的默认线程池
parallerstream % java -jar ~/Downloads/software/arthas-packaging-3.6.2-bin/arthas-boot.jar
[INFO] arthas-boot version: 3.6.2
[INFO] Process 13412 already using port 3658
[INFO] Process 13412 already using port 8563
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 13412 com.luna.ParallelApplication
[2]: 13411 org.jetbrains.jps.cmdline.Launcher
[3]: 7411 org.jetbrains.idea.maven.server.RemoteMavenServer36
[4]: 23220
[5]: 10980 org.jetbrains.jps.cmdline.Launcher
1
[INFO] arthas home: /Users/111/Downloads/software/arthas-packaging-3.6.2-bin
[INFO] The target process already listen port 3658, skip attach.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version 3.6.2
main_class com.luna.ParallelApplication
pid 13412
time 2023-10-24 19:20:55
[arthas@13412]$
[arthas@13412]$ thread --state BLOCKED
Threads Total: 24, NEW: 0, RUNNABLE: 7, BLOCKED: 7, WAITING: 6, TIMED_WAITING: 4, TERMINATED: 0
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON
20 ForkJoinPool.commonPool-worker-1 main 5 BLOCKED 0.0 0.000 0:0.006 false true
21 ForkJoinPool.commonPool-worker-2 main 5 BLOCKED 0.0 0.000 0:0.000 false true
22 ForkJoinPool.commonPool-worker-3 main 5 BLOCKED 0.0 0.000 0:0.000 false true
23 ForkJoinPool.commonPool-worker-4 main 5 BLOCKED 0.0 0.000 0:0.000 false true
24 ForkJoinPool.commonPool-worker-5 main 5 BLOCKED 0.0 0.000 0:0.000 false true
25 ForkJoinPool.commonPool-worker-6 main 5 BLOCKED 0.0 0.000 0:0.000 false true
[arthas@13412]$
[arthas@13412]$ thread -b
"main" Id=1 WAITING on java.util.stream.ReduceOps$ReduceTask@a2ddf26
at java.lang.Object.wait(Native Method)
- waiting on java.util.stream.ReduceOps$ReduceTask@a2ddf26
at java.util.concurrent.ForkJoinTask.externalAwaitDone(ForkJoinTask.java:334)
at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:405)
at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:734)
at java.util.stream.ReduceOps$ReduceOp.evaluateParallel(ReduceOps.java:714)
at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233)
at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499)
at com.luna.deadlock.BadService.parallel(BadService.java:32)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$179/872522004.getObject(Unknown Source)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
- locked java.util.concurrent.ConcurrentHashMap@5485df50 <---- but blocks 7 other threads!
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:953)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:918)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)
- locked java.lang.Object@41d9ae78
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145)
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:740)
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:415)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:303)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1312)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1301)
at com.luna.ParallelApplication.main(ParallelApplication.java:17)
[arthas@13412]$
[arthas@13412]$ stop
Resetting all enhanced classes ...
Affect(class count: 0 , method count: 0) cost in 2 ms, listenerId: 0
Arthas Server is going to shutdown...
[arthas@13412]$ session (7d8cdf29-04f0-464e-b1c9-334dc2fd00a9) is closed because server is going to shutdown.
4、问题解决
在注册Bean的时候，初始化过程中将
parallelStream改为stream，不使用并发流
BadService
package com.luna.deadlock;
import org.springframework.beans.BeansException;
import org.springframework.context.ApplicationContext;
import org.springframework.context.ApplicationContextAware;
import org.springframework.lang.NonNull;
import org.springframework.stereotype.Service;
import javax.annotation.PostConstruct;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Collectors;
/**
* @author qiongying.huai（2477637880@qq.com）
* @version 1.0
* @className BadService
* @description description
* @date 15:19 2023/10/24
*/
@Service
public class BadService implements ApplicationContextAware {
private ApplicationContext applicationContext;
private List<Object> list;
@PostConstruct
public void parallel() {
list = Arrays.stream(applicationContext.getBeanDefinitionNames())
// .parallel()
.filter(name -> !"badService".equals(name))
.peek(applicationContext::getBean)
.collect(Collectors.toList());
System.out.println(list.size());
}
@Override
public void setApplicationContext(@NonNull ApplicationContext applicationContext) throws BeansException {
this.applicationContext = applicationContext;
}
}
启动日志
Connected to the target VM, address: '127.0.0.1:60408', transport: 'socket'
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.5)
2023-10-24 19:19:08.274 INFO 13357 --- [ main] com.luna.ParallelApplication : Starting ParallelApplication using Java 1.8.0_271 on 111deMacBook-Pro.local with PID 13357 (/Users/111/code/mavendemo/parallelstream/target/classes started by 111 in /Users/111/code/mavendemo)
2023-10-24 19:19:08.279 INFO 13357 --- [ main] com.luna.ParallelApplication : No active profile set, falling back to 1 default profile: "default"
2023-10-24 19:19:09.233 INFO 13357 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2023-10-24 19:19:09.243 INFO 13357 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-10-24 19:19:09.243 INFO 13357 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.60]
2023-10-24 19:19:09.368 INFO 13357 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-10-24 19:19:09.368 INFO 13357 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1017 ms
131
2023-10-24 19:19:09.746 INFO 13357 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2023-10-24 19:19:09.755 INFO 13357 --- [ main] com.luna.ParallelApplication : Started ParallelApplication in 1.979 seconds (JVM running for 2.496)
请求测试接口
请求成功
parallerstream % curl --location --request GET 'http://localhost:8080/api/su'
ma se%
使用arthas分析
无BLOCKED状态的线程
vuedemo % java -jar ~/Downloads/software/arthas-packaging-3.6.2-bin/arthas-boot.jar
[INFO] arthas-boot version: 3.6.2
[INFO] Process 13687 already using port 3658
[INFO] Process 13687 already using port 8563
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 13687 com.luna.ParallelApplication
[2]: 7411 org.jetbrains.idea.maven.server.RemoteMavenServer36
[3]: 23220
[4]: 10980 org.jetbrains.jps.cmdline.Launcher
[5]: 13685 org.jetbrains.jps.cmdline.Launcher
1
[INFO] arthas home: /Users/111/Downloads/software/arthas-packaging-3.6.2-bin
[INFO] The target process already listen port 3658, skip attach.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version 3.6.2
main_class com.luna.ParallelApplication
pid 13687
time 2023-10-24 19:25:45
[arthas@13687]$
[arthas@13412]$ thread --state BLOCKED
Threads Total: 29, NEW: 0, RUNNABLE: 10, BLOCKED: 0, WAITING: 15, TIMED_WAITING: 4, TERMINATED: 0
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON
[arthas@13687]$
[arthas@13412]$ thread -b
No most blocking thread found!
[arthas@13687]$
[arthas@13412]$ stop
Resetting all enhanced classes ...
Affect(class count: 0 , method count: 0) cost in 1 ms, listenerId: 0
Arthas Server is going to shutdown...
[arthas@13687]$ session (25354803-d39c-4d22-9c9f-2723c1bfc81e) is closed because server is going to shutdown.
5、注意
在Spring服务启动过程中，尽量避免多线程并发操作
403
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
