Spring 批处理的并行线程处理数上限为 10
Number of parallel threads processing is capped to 10 with Spring Batch
我有以下任务执行器,用于 运行 带有分区的 10 秒睡眠时间小任务:
<bean id="taskExecutor" class="org.springframework.core.task.SimpleAsyncTaskExecutor">
<property name="concurrencyLimit" value="${concurrency_limit}"/>
</bean>
<batch:step id="stepWait">
<batch:partition partitioner="partitionerWait">
<batch:handler grid-size="1" task-executor="taskExecutor"/>
<batch:step>
<batch:tasklet ref="taskletWait"/>
</batch:step>
</batch:partition>
</batch:step>
public class TaskletWait implements Tasklet {
private final Logger logger = LoggerFactory.getLogger(TaskletWait.class);
@Override
public RepeatStatus execute(StepContribution contribution, ChunkContext chunkContext){
String stepName = contribution.getStepExecution().getStepName();
logger.info("starting step: " + stepName);
try {
TimeUnit.SECONDS.sleep(10);
} catch (InterruptedException e) {
logger.error(e.getMessage());
}
contribution.setExitStatus(ExitStatus.COMPLETED);
return RepeatStatus.FINISHED;
}
}
并行的线程数运行正在根据我在application.properties中设置的值正确调整,直到达到10。无论我设置10、15、25还是100,都只有10线程 运行 并行。 concurrency_limit=15
示例:
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-12] [execute] starting step: stepWait:4
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-2] [execute] starting step: stepWait:30
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-1] [execute] starting step: stepWait:26
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-9] [execute] starting step: stepWait:17
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-3] [execute] starting step: stepWait:15
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-8] [execute] starting step: stepWait:11
2021-07-06 13:31:34.939 INFO [SimpleAsyncTaskExecutor-10] [execute] starting step: stepWait:7
2021-07-06 13:31:34.940 INFO [SimpleAsyncTaskExecutor-5] [execute] starting step: stepWait:1
2021-07-06 13:31:34.941 INFO [SimpleAsyncTaskExecutor-15] [execute] starting step: stepWait:5
2021-07-06 13:31:34.943 INFO [SimpleAsyncTaskExecutor-14] [execute] starting step: stepWait:23
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-6] [execute] starting step: stepWait:32
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-4] [execute] starting step: stepWait:19
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-7] [execute] starting step: stepWait:16
2021-07-06 13:31:44.942 INFO [SimpleAsyncTaskExecutor-11] [execute] starting step: stepWait:13
2021-07-06 13:31:44.943 INFO [SimpleAsyncTaskExecutor-13] [execute] starting step: stepWait:20
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-2] [execute] Step: [stepWait:30] executed in 10s21ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-8] [execute] Step: [stepWait:11] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-5] [execute] Step: [stepWait:1] executed in 10s21ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-9] [execute] Step: [stepWait:17] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-14] [execute] Step: [stepWait:23] executed in 10s18ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-10] [execute] Step: [stepWait:7] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-1] [execute] Step: [stepWait:26] executed in 10s22ms
2021-07-06 13:31:44.951 INFO [SimpleAsyncTaskExecutor-3] [execute] Step: [stepWait:15] executed in 10s22ms
2021-07-06 13:31:44.958 INFO [SimpleAsyncTaskExecutor-12] [execute] Step: [stepWait:4] executed in 10s29ms
2021-07-06 13:31:44.959 INFO [SimpleAsyncTaskExecutor-15] [execute] Step: [stepWait:5] executed in 10s27ms
2021-07-06 13:31:44.961 INFO [SimpleAsyncTaskExecutor-16] [execute] starting step: stepWait:6
2021-07-06 13:31:44.962 INFO [SimpleAsyncTaskExecutor-17] [execute] starting step: stepWait:9
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-18] [execute] starting step: stepWait:24
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-19] [execute] starting step: stepWait:27
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-20] [execute] starting step: stepWait:3
2021-07-06 13:31:54.944 INFO [SimpleAsyncTaskExecutor-21] [execute] starting step: stepWait:10
2021-07-06 13:31:54.946 INFO [SimpleAsyncTaskExecutor-23] [execute] starting step: stepWait:33
2021-07-06 13:31:54.947 INFO [SimpleAsyncTaskExecutor-22] [execute] starting step: stepWait:12
2021-07-06 13:31:54.948 INFO [SimpleAsyncTaskExecutor-7] [execute] Step: [stepWait:16] executed in 20s19ms
2021-07-06 13:31:54.951 INFO [SimpleAsyncTaskExecutor-13] [execute] Step: [stepWait:20] executed in 20s20ms
2021-07-06 13:31:54.952 INFO [SimpleAsyncTaskExecutor-6] [execute] Step: [stepWait:32] executed in 20s22ms
2021-07-06 13:31:54.954 INFO [SimpleAsyncTaskExecutor-24] [execute] starting step: stepWait:2
2021-07-06 13:31:54.954 INFO [SimpleAsyncTaskExecutor-4] [execute] Step: [stepWait:19] executed in 20s25ms
2021-07-06 13:31:54.955 INFO [SimpleAsyncTaskExecutor-11] [execute] Step: [stepWait:13] executed in 20s25ms
2021-07-06 13:31:54.957 INFO [SimpleAsyncTaskExecutor-25] [execute] starting step: stepWait:22
2021-07-06 13:31:54.967 INFO [SimpleAsyncTaskExecutor-16] [execute] Step: [stepWait:6] executed in 10s13ms
2021-07-06 13:31:54.968 INFO [SimpleAsyncTaskExecutor-17] [execute] Step: [stepWait:9] executed in 10s13ms
[...]
11号到15号好像是启动了但是要等一个线程结束才真正执行,可以看出它们的执行时间都是20s
当前日志是在 windows 上用 java 11 生成的。
我尝试使用 org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor
而不是 SimpleAsyncTaskExecutor
但结果相同。
我在 Windows 和 Linux 上都试过了,但结果相同
什么会导致此限制,我怎样才能使 运行 超过 10 个并行线程?
编辑:
大部分时间并行只有10运行s,但有时只有9
EDIT2: 我正在添加 ConcurrencyThrottleSupport
的调试日志
2021-07-06 17:24:04.860 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 0
2021-07-06 17:24:04.860 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 1
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 2
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 3
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 4
2021-07-06 17:24:04.862 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 5
2021-07-06 17:24:04.864 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 6
2021-07-06 17:24:04.864 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 7
2021-07-06 17:24:04.865 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 8
2021-07-06 17:24:04.865 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 9
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 10
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:04.867 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:04.867 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:04.868 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-9] [execute] starting step: wait:3
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-7] [execute] starting step: wait:7
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-2] [execute] starting step: wait:11
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-3] [execute] starting step: wait:2
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-5] [execute] starting step: wait:16
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-12] [execute] starting step: wait:4
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-10] [execute] starting step: wait:34
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-11] [execute] starting step: wait:27
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-4] [execute] starting step: wait:18
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-1] [execute] starting step: wait:29
2021-07-06 17:24:14.873 INFO [SimpleAsyncTaskExecutor-6] [execute] starting step: wait:33
2021-07-06 17:24:14.873 INFO [SimpleAsyncTaskExecutor-13] [execute] starting step: wait:0
2021-07-06 17:24:14.875 INFO [SimpleAsyncTaskExecutor-15] [execute] starting step: wait:25
2021-07-06 17:24:14.875 INFO [SimpleAsyncTaskExecutor-14] [execute] starting step: wait:13
2021-07-06 17:24:14.882 INFO [SimpleAsyncTaskExecutor-8] [execute] starting step: wait:6
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-3] [execute] Step: [wait:2] executed in 10s23ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-11] [execute] Step: [wait:27] executed in 10s18ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-5] [execute] Step: [wait:16] executed in 10s22ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-9] [execute] Step: [wait:3] executed in 10s19ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-12] [execute] Step: [wait:4] executed in 10s18ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-10] [execute] Step: [wait:34] executed in 10s19ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-7] [execute] Step: [wait:7] executed in 10s20ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-2] [execute] Step: [wait:11] executed in 10s24ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-1] [execute] Step: [wait:29] executed in 10s25ms
2021-07-06 17:24:14.886 DEBUG [SimpleAsyncTaskExecutor-3] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:14.887 DEBUG [SimpleAsyncTaskExecutor-12] [afterAccess] Returning from throttle at concurrency count 13
2021-07-06 17:24:14.887 DEBUG [SimpleAsyncTaskExecutor-9] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.887 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.888 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:14.888 DEBUG [SimpleAsyncTaskExecutor-10] [afterAccess] Returning from throttle at concurrency count 13
2021-07-06 17:24:14.888 DEBUG [SimpleAsyncTaskExecutor-5] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.888 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [SimpleAsyncTaskExecutor-7] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [SimpleAsyncTaskExecutor-2] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.890 DEBUG [SimpleAsyncTaskExecutor-11] [afterAccess] Returning from throttle at concurrency count 11
2021-07-06 17:24:14.890 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:14.890 DEBUG [SimpleAsyncTaskExecutor-1] [afterAccess] Returning from throttle at concurrency count 11
2021-07-06 17:24:14.890 INFO [SimpleAsyncTaskExecutor-4] [execute] Step: [wait:18] executed in 10s29ms
2021-07-06 17:24:14.890 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:14.890 INFO [SimpleAsyncTaskExecutor-16] [execute] starting step: wait:30
2021-07-06 17:24:14.891 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:14.892 INFO [SimpleAsyncTaskExecutor-17] [execute] starting step: wait:12
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:14.893 DEBUG [SimpleAsyncTaskExecutor-4] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:14.893 INFO [SimpleAsyncTaskExecutor-18] [execute] starting step: wait:28
2021-07-06 17:24:14.893 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:14.894 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:14.894 INFO [SimpleAsyncTaskExecutor-19] [execute] starting step: wait:24
2021-07-06 17:24:14.899 INFO [SimpleAsyncTaskExecutor-21] [execute] starting step: wait:23
2021-07-06 17:24:24.878 INFO [SimpleAsyncTaskExecutor-20] [execute] starting step: wait:1
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-22] [execute] starting step: wait:32
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-23] [execute] starting step: wait:15
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-24] [execute] starting step: wait:10
2021-07-06 17:24:24.884 INFO [SimpleAsyncTaskExecutor-6] [execute] Step: [wait:33] executed in 20s19ms
2021-07-06 17:24:24.884 INFO [SimpleAsyncTaskExecutor-13] [execute] Step: [wait:0] executed in 20s17ms
2021-07-06 17:24:24.885 INFO [SimpleAsyncTaskExecutor-15] [execute] Step: [wait:25] executed in 20s17ms
2021-07-06 17:24:24.885 INFO [SimpleAsyncTaskExecutor-25] [execute] starting step: wait:17
2021-07-06 17:24:24.894 INFO [SimpleAsyncTaskExecutor-14] [execute] Step: [wait:13] executed in 20s26ms
2021-07-06 17:24:24.894 INFO [SimpleAsyncTaskExecutor-8] [execute] Step: [wait:6] executed in 20s29ms
2021-07-06 17:24:24.897 DEBUG [SimpleAsyncTaskExecutor-6] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.898 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.898 DEBUG [SimpleAsyncTaskExecutor-13] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.899 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.899 INFO [SimpleAsyncTaskExecutor-16] [execute] Step: [wait:30] executed in 10s12ms
2021-07-06 17:24:24.899 DEBUG [SimpleAsyncTaskExecutor-15] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.899 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.900 INFO [SimpleAsyncTaskExecutor-17] [execute] Step: [wait:12] executed in 10s12ms
Indeed I do not reproduce with your code sample. Here is an example that reproduces the error: github.com/AlexandreChi/spring-batch-lab/tree/main/issues/…. The only difference with your code sample is the annotation SpringBootApplication instead of Configuration.
所以我断定这与引导自动配置有关。
I think I am getting close, associating EnableAutoConfiguration and implementation 'com.h2database:h2:1.4.198' is generating the issue. It seems it creates an autowired datasource which has a limited number of simultaneous connections
确实,在日志中我看到:
DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................10
这是使用 HikariCP 的最大池大小的默认值。这意味着 15 个线程无法获取超过 10 个数据库连接,因此一次只能运行 并行处理其中的 10 个。
通过添加以下 属性 将最大池大小增加到 15 修复了问题:
spring.datasource.hikari.maximum-pool-size=15
我相应地更新了repo所以你可以检查结果。
我有以下任务执行器,用于 运行 带有分区的 10 秒睡眠时间小任务:
<bean id="taskExecutor" class="org.springframework.core.task.SimpleAsyncTaskExecutor">
<property name="concurrencyLimit" value="${concurrency_limit}"/>
</bean>
<batch:step id="stepWait">
<batch:partition partitioner="partitionerWait">
<batch:handler grid-size="1" task-executor="taskExecutor"/>
<batch:step>
<batch:tasklet ref="taskletWait"/>
</batch:step>
</batch:partition>
</batch:step>
public class TaskletWait implements Tasklet {
private final Logger logger = LoggerFactory.getLogger(TaskletWait.class);
@Override
public RepeatStatus execute(StepContribution contribution, ChunkContext chunkContext){
String stepName = contribution.getStepExecution().getStepName();
logger.info("starting step: " + stepName);
try {
TimeUnit.SECONDS.sleep(10);
} catch (InterruptedException e) {
logger.error(e.getMessage());
}
contribution.setExitStatus(ExitStatus.COMPLETED);
return RepeatStatus.FINISHED;
}
}
并行的线程数运行正在根据我在application.properties中设置的值正确调整,直到达到10。无论我设置10、15、25还是100,都只有10线程 运行 并行。 concurrency_limit=15
示例:
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-12] [execute] starting step: stepWait:4
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-2] [execute] starting step: stepWait:30
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-1] [execute] starting step: stepWait:26
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-9] [execute] starting step: stepWait:17
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-3] [execute] starting step: stepWait:15
2021-07-06 13:31:34.937 INFO [SimpleAsyncTaskExecutor-8] [execute] starting step: stepWait:11
2021-07-06 13:31:34.939 INFO [SimpleAsyncTaskExecutor-10] [execute] starting step: stepWait:7
2021-07-06 13:31:34.940 INFO [SimpleAsyncTaskExecutor-5] [execute] starting step: stepWait:1
2021-07-06 13:31:34.941 INFO [SimpleAsyncTaskExecutor-15] [execute] starting step: stepWait:5
2021-07-06 13:31:34.943 INFO [SimpleAsyncTaskExecutor-14] [execute] starting step: stepWait:23
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-6] [execute] starting step: stepWait:32
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-4] [execute] starting step: stepWait:19
2021-07-06 13:31:44.941 INFO [SimpleAsyncTaskExecutor-7] [execute] starting step: stepWait:16
2021-07-06 13:31:44.942 INFO [SimpleAsyncTaskExecutor-11] [execute] starting step: stepWait:13
2021-07-06 13:31:44.943 INFO [SimpleAsyncTaskExecutor-13] [execute] starting step: stepWait:20
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-2] [execute] Step: [stepWait:30] executed in 10s21ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-8] [execute] Step: [stepWait:11] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-5] [execute] Step: [stepWait:1] executed in 10s21ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-9] [execute] Step: [stepWait:17] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-14] [execute] Step: [stepWait:23] executed in 10s18ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-10] [execute] Step: [stepWait:7] executed in 10s20ms
2021-07-06 13:31:44.950 INFO [SimpleAsyncTaskExecutor-1] [execute] Step: [stepWait:26] executed in 10s22ms
2021-07-06 13:31:44.951 INFO [SimpleAsyncTaskExecutor-3] [execute] Step: [stepWait:15] executed in 10s22ms
2021-07-06 13:31:44.958 INFO [SimpleAsyncTaskExecutor-12] [execute] Step: [stepWait:4] executed in 10s29ms
2021-07-06 13:31:44.959 INFO [SimpleAsyncTaskExecutor-15] [execute] Step: [stepWait:5] executed in 10s27ms
2021-07-06 13:31:44.961 INFO [SimpleAsyncTaskExecutor-16] [execute] starting step: stepWait:6
2021-07-06 13:31:44.962 INFO [SimpleAsyncTaskExecutor-17] [execute] starting step: stepWait:9
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-18] [execute] starting step: stepWait:24
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-19] [execute] starting step: stepWait:27
2021-07-06 13:31:44.963 INFO [SimpleAsyncTaskExecutor-20] [execute] starting step: stepWait:3
2021-07-06 13:31:54.944 INFO [SimpleAsyncTaskExecutor-21] [execute] starting step: stepWait:10
2021-07-06 13:31:54.946 INFO [SimpleAsyncTaskExecutor-23] [execute] starting step: stepWait:33
2021-07-06 13:31:54.947 INFO [SimpleAsyncTaskExecutor-22] [execute] starting step: stepWait:12
2021-07-06 13:31:54.948 INFO [SimpleAsyncTaskExecutor-7] [execute] Step: [stepWait:16] executed in 20s19ms
2021-07-06 13:31:54.951 INFO [SimpleAsyncTaskExecutor-13] [execute] Step: [stepWait:20] executed in 20s20ms
2021-07-06 13:31:54.952 INFO [SimpleAsyncTaskExecutor-6] [execute] Step: [stepWait:32] executed in 20s22ms
2021-07-06 13:31:54.954 INFO [SimpleAsyncTaskExecutor-24] [execute] starting step: stepWait:2
2021-07-06 13:31:54.954 INFO [SimpleAsyncTaskExecutor-4] [execute] Step: [stepWait:19] executed in 20s25ms
2021-07-06 13:31:54.955 INFO [SimpleAsyncTaskExecutor-11] [execute] Step: [stepWait:13] executed in 20s25ms
2021-07-06 13:31:54.957 INFO [SimpleAsyncTaskExecutor-25] [execute] starting step: stepWait:22
2021-07-06 13:31:54.967 INFO [SimpleAsyncTaskExecutor-16] [execute] Step: [stepWait:6] executed in 10s13ms
2021-07-06 13:31:54.968 INFO [SimpleAsyncTaskExecutor-17] [execute] Step: [stepWait:9] executed in 10s13ms
[...]
11号到15号好像是启动了但是要等一个线程结束才真正执行,可以看出它们的执行时间都是20s
当前日志是在 windows 上用 java 11 生成的。
我尝试使用 org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor
而不是 SimpleAsyncTaskExecutor
但结果相同。
我在 Windows 和 Linux 上都试过了,但结果相同
什么会导致此限制,我怎样才能使 运行 超过 10 个并行线程?
编辑: 大部分时间并行只有10运行s,但有时只有9
EDIT2: 我正在添加 ConcurrencyThrottleSupport
的调试日志2021-07-06 17:24:04.860 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 0
2021-07-06 17:24:04.860 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 1
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 2
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 3
2021-07-06 17:24:04.861 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 4
2021-07-06 17:24:04.862 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 5
2021-07-06 17:24:04.864 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 6
2021-07-06 17:24:04.864 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 7
2021-07-06 17:24:04.865 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 8
2021-07-06 17:24:04.865 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 9
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 10
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:04.866 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:04.867 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:04.867 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:04.868 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-9] [execute] starting step: wait:3
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-7] [execute] starting step: wait:7
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-2] [execute] starting step: wait:11
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-3] [execute] starting step: wait:2
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-5] [execute] starting step: wait:16
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-12] [execute] starting step: wait:4
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-10] [execute] starting step: wait:34
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-11] [execute] starting step: wait:27
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-4] [execute] starting step: wait:18
2021-07-06 17:24:04.869 INFO [SimpleAsyncTaskExecutor-1] [execute] starting step: wait:29
2021-07-06 17:24:14.873 INFO [SimpleAsyncTaskExecutor-6] [execute] starting step: wait:33
2021-07-06 17:24:14.873 INFO [SimpleAsyncTaskExecutor-13] [execute] starting step: wait:0
2021-07-06 17:24:14.875 INFO [SimpleAsyncTaskExecutor-15] [execute] starting step: wait:25
2021-07-06 17:24:14.875 INFO [SimpleAsyncTaskExecutor-14] [execute] starting step: wait:13
2021-07-06 17:24:14.882 INFO [SimpleAsyncTaskExecutor-8] [execute] starting step: wait:6
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-3] [execute] Step: [wait:2] executed in 10s23ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-11] [execute] Step: [wait:27] executed in 10s18ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-5] [execute] Step: [wait:16] executed in 10s22ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-9] [execute] Step: [wait:3] executed in 10s19ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-12] [execute] Step: [wait:4] executed in 10s18ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-10] [execute] Step: [wait:34] executed in 10s19ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-7] [execute] Step: [wait:7] executed in 10s20ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-2] [execute] Step: [wait:11] executed in 10s24ms
2021-07-06 17:24:14.885 INFO [SimpleAsyncTaskExecutor-1] [execute] Step: [wait:29] executed in 10s25ms
2021-07-06 17:24:14.886 DEBUG [SimpleAsyncTaskExecutor-3] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:14.887 DEBUG [SimpleAsyncTaskExecutor-12] [afterAccess] Returning from throttle at concurrency count 13
2021-07-06 17:24:14.887 DEBUG [SimpleAsyncTaskExecutor-9] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.887 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.888 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:14.888 DEBUG [SimpleAsyncTaskExecutor-10] [afterAccess] Returning from throttle at concurrency count 13
2021-07-06 17:24:14.888 DEBUG [SimpleAsyncTaskExecutor-5] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.888 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [SimpleAsyncTaskExecutor-7] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.889 DEBUG [SimpleAsyncTaskExecutor-2] [afterAccess] Returning from throttle at concurrency count 12
2021-07-06 17:24:14.890 DEBUG [SimpleAsyncTaskExecutor-11] [afterAccess] Returning from throttle at concurrency count 11
2021-07-06 17:24:14.890 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:14.890 DEBUG [SimpleAsyncTaskExecutor-1] [afterAccess] Returning from throttle at concurrency count 11
2021-07-06 17:24:14.890 INFO [SimpleAsyncTaskExecutor-4] [execute] Step: [wait:18] executed in 10s29ms
2021-07-06 17:24:14.890 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 11
2021-07-06 17:24:14.890 INFO [SimpleAsyncTaskExecutor-16] [execute] starting step: wait:30
2021-07-06 17:24:14.891 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 12
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 13
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:14.892 INFO [SimpleAsyncTaskExecutor-17] [execute] starting step: wait:12
2021-07-06 17:24:14.892 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:14.893 DEBUG [SimpleAsyncTaskExecutor-4] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:14.893 INFO [SimpleAsyncTaskExecutor-18] [execute] starting step: wait:28
2021-07-06 17:24:14.893 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:14.894 DEBUG [main] [beforeAccess] Concurrency count 15 has reached limit 15 - blocking
2021-07-06 17:24:14.894 INFO [SimpleAsyncTaskExecutor-19] [execute] starting step: wait:24
2021-07-06 17:24:14.899 INFO [SimpleAsyncTaskExecutor-21] [execute] starting step: wait:23
2021-07-06 17:24:24.878 INFO [SimpleAsyncTaskExecutor-20] [execute] starting step: wait:1
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-22] [execute] starting step: wait:32
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-23] [execute] starting step: wait:15
2021-07-06 17:24:24.879 INFO [SimpleAsyncTaskExecutor-24] [execute] starting step: wait:10
2021-07-06 17:24:24.884 INFO [SimpleAsyncTaskExecutor-6] [execute] Step: [wait:33] executed in 20s19ms
2021-07-06 17:24:24.884 INFO [SimpleAsyncTaskExecutor-13] [execute] Step: [wait:0] executed in 20s17ms
2021-07-06 17:24:24.885 INFO [SimpleAsyncTaskExecutor-15] [execute] Step: [wait:25] executed in 20s17ms
2021-07-06 17:24:24.885 INFO [SimpleAsyncTaskExecutor-25] [execute] starting step: wait:17
2021-07-06 17:24:24.894 INFO [SimpleAsyncTaskExecutor-14] [execute] Step: [wait:13] executed in 20s26ms
2021-07-06 17:24:24.894 INFO [SimpleAsyncTaskExecutor-8] [execute] Step: [wait:6] executed in 20s29ms
2021-07-06 17:24:24.897 DEBUG [SimpleAsyncTaskExecutor-6] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.898 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.898 DEBUG [SimpleAsyncTaskExecutor-13] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.899 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.899 INFO [SimpleAsyncTaskExecutor-16] [execute] Step: [wait:30] executed in 10s12ms
2021-07-06 17:24:24.899 DEBUG [SimpleAsyncTaskExecutor-15] [afterAccess] Returning from throttle at concurrency count 14
2021-07-06 17:24:24.899 DEBUG [main] [beforeAccess] Entering throttle at concurrency count 14
2021-07-06 17:24:24.900 INFO [SimpleAsyncTaskExecutor-17] [execute] Step: [wait:12] executed in 10s12ms
Indeed I do not reproduce with your code sample. Here is an example that reproduces the error: github.com/AlexandreChi/spring-batch-lab/tree/main/issues/…. The only difference with your code sample is the annotation SpringBootApplication instead of Configuration.
所以我断定这与引导自动配置有关。
I think I am getting close, associating EnableAutoConfiguration and implementation 'com.h2database:h2:1.4.198' is generating the issue. It seems it creates an autowired datasource which has a limited number of simultaneous connections
确实,在日志中我看到:
DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................10
这是使用 HikariCP 的最大池大小的默认值。这意味着 15 个线程无法获取超过 10 个数据库连接,因此一次只能运行 并行处理其中的 10 个。
通过添加以下 属性 将最大池大小增加到 15 修复了问题:
spring.datasource.hikari.maximum-pool-size=15
我相应地更新了repo所以你可以检查结果。