Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

With virtual threads enabled, long-running fixedDelay tasks block fixedRate tasks #33408

Open
kzander91 opened this issue Aug 19, 2024 · 2 comments
Assignees
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: waiting-for-triage An issue we've not yet triaged or decided on

Comments

@kzander91
Copy link
Contributor

kzander91 commented Aug 19, 2024

Framework: 6.1.11
Boot: 3.3.2
Reproducer: demo.zip

As discussed in #31900 and documented in the reference docs, with virtual threads enabled, fixedDelay tasks run on a single thread. However, a long-running fixedDelay task also blocks concurrent fixedRate tasks. This behaviour isn't documented and not obvious (to me at least), so I would consider this a bug.

Consider the following app:

@EnableScheduling
@SpringBootApplication
public class DemoApplication {

    private static final Logger log = LoggerFactory.getLogger(DemoApplication.class);

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

    @Scheduled(initialDelay = 10000, fixedDelay = 10000)
    public void fixedDelay() {
        log.info("fixedDelay start: Blocks concurrent fixedRate tasks");
        long start = System.nanoTime();
        while ((System.nanoTime() - start) < TimeUnit.SECONDS.toNanos(10L)) {
            // busy work
        }
        log.info("fixedDelay end, unblocking fixedRate tasks");
    }

    @Scheduled(fixedRate = 1000)
    public void fixedRate() {
        log.info("fixedRate");
    }

}

This prints:

2024-08-19T17:32:40.727+02:00  INFO 39220 --- [demo] [   scheduling-2] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:41.722+02:00  INFO 39220 --- [demo] [   scheduling-3] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:42.717+02:00  INFO 39220 --- [demo] [   scheduling-4] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:43.717+02:00  INFO 39220 --- [demo] [   scheduling-5] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:44.718+02:00  INFO 39220 --- [demo] [   scheduling-6] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:45.719+02:00  INFO 39220 --- [demo] [   scheduling-7] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:46.717+02:00  INFO 39220 --- [demo] [   scheduling-8] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:47.717+02:00  INFO 39220 --- [demo] [   scheduling-9] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:48.718+02:00  INFO 39220 --- [demo] [  scheduling-10] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:49.719+02:00  INFO 39220 --- [demo] [  scheduling-11] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:50.718+02:00  INFO 39220 --- [demo] [  scheduling-12] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:32:50.720+02:00  INFO 39220 --- [demo] [   scheduling-1] com.example.demo.DemoApplication         : fixedDelay start: Blocks concurrent fixedRate tasks
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [   scheduling-1] com.example.demo.DemoApplication         : fixedDelay end, unblocking fixedRate tasks
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-13] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-16] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-14] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-17] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-19] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-15] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-20] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-21] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-22] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:00.721+02:00  INFO 39220 --- [demo] [  scheduling-18] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:01.718+02:00  INFO 39220 --- [demo] [  scheduling-23] com.example.demo.DemoApplication         : fixedRate
2024-08-19T17:33:02.718+02:00  INFO 39220 --- [demo] [  scheduling-24] com.example.demo.DemoApplication         : fixedRate
  • The app starts and prints "fixedRate" every second, as expected.
  • After 10 seconds, the fixedDelay task kicks in and performs some work for 10 seconds. While that's going on, no further fixedRate tasks are run.
  • Finally, after 10 seconds of work, the fixedDelay task completes and we get a bunch of "fixedRate" messages again. Then, we continue with the regular schedule of one message per second.

While debugging this, I found that the SimpleAsyncTaskScheduler that is used under the covers uses its first thread, scheduling-1, both to run the fixedDelay task, and to schedule the fixedRate tasks. This means if scheduling-1 is busy running a task, it can't submit new fixedRate tasks for execution.

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Aug 19, 2024
@jhoeller jhoeller added the in: core Issues in core modules (aop, beans, core, context, expression) label Aug 20, 2024
@jhoeller jhoeller self-assigned this Aug 20, 2024
@jhoeller
Copy link
Contributor

This behavior is an immediate consequence of the single scheduler thread within the internal ScheduledThreadPoolExecutor there. The same behavior will occur with a regular ThreadPoolTaskScheduler and its default pool size 1. In the latter case, you may configure a higher pool size exactly to avoid such contention on the scheduler thread. That option is not available on SimpleAsyncTaskScheduler since it is hard-coded to a single internal scheduler thread.

Arguably fixed-delay tasks are just not idiomatic on SimpleAsyncTaskScheduler and specifically with virtual threads. However, if there is a need for its hand-off behavior for regular triggers in combination with a higher number of scheduler threads for executing fixed-delay tasks, we can consider making the internal scheduler pool size configurable.

Do you see yourself using SimpleAsyncTaskScheduler in such a scenario, configuring a higher number of internal scheduler threads if the option was available?

@kzander91
Copy link
Contributor Author

kzander91 commented Aug 21, 2024

Do you see yourself using SimpleAsyncTaskScheduler in such a scenario, configuring a higher number of internal scheduler threads if the option was available?

I guess so, but wouldn't it be possible for the scheduling infrastructure to auto-detect the number of scheduling threads required to run all the registered tasks without blocking each other? SimpleAsyncTaskScheduler could call setCorePoolSize(n) on the wrapped executor where n=numFixedDelayTasks + 1 (this could grow out-of-hand though if we have a large number of fixed-delay tasks...).
Or, implement fixed-delay tasks differently if virtual threads are enabled, something like this pseudo code:

scheduleWithFixedDelay(task, delay) {
    executor.execute(() -> {
       while(!cancelled) {
           task.run();
           sleep(delay);
       }
    });
}

This should allow an arbitrary number of fixed-delay and fixed-rate tasks to run concurrently without blocking each other.


As additional context on why I feel there's definitely room for improvement, here's how I got here (and I imagine I'm not the only one):

  1. We have a WebMVC app built with Spring Boot, the project started before JDK21. The app has various @Scheduled methods, with cron, fixedRate and fixedDelay triggers. We quickly realized that the single scheduler thread only allowed one of these methods to run at a time, so we increased the number of scheduler threads with spring.task.scheduling.pool.size.
  2. JDK21 comes along and Boot's easy "enable VTs" switch: We upgrade and enable VTs with spring.threads.virtual.enabled. Everything seems to work fine at first, Tomcat handles requests on VTs, scheduled methods still run concurrently. At some point though, the scheduled methods weren't called anymore. Turns out they were all blocked by a single fixedDelay task that sometimes can take significant time.
  3. spring.task.scheduling.pool.size doesn't have an effect anymore with VTs enabled, so there isn't something we can do with just configuration to remedy this situation. So we had to disable VTs again for the entire app, just because of that one fixedDelay task.

Backing up a bit, I can totally accept that SimpleAsyncTaskScheduler has these limitations, it's called "Simple", after all 😉, and Framework has alternative implementations to work around them.
It's just that that's what Spring Boot auto-configures for me when I enable virtual threads (maybe Boot should allow more granular control about where I want VTs to apply instead of the current all-or-nothing approach).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: waiting-for-triage An issue we've not yet triaged or decided on
Projects
None yet
Development

No branches or pull requests

3 participants