Java8 parallerStream导致Spring项目启动线程阻塞(死锁)

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:标识为Bean
  • ApplicationContextAware:为类注入Spring容器
  • @PostConstruct:完成Bean的一些初始化操作,执行时机晚于@Autowired

在注册badService这个Bean的时候,实例化完初始化时,使用@PostConstructlist属性赋值,其中使用了并发流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

  1. 启动arthas
  2. 查看阻塞状态的线程
  3. 找出当前阻塞其他线程的线程
"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服务启动过程中,尽量避免多线程并发操作

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值