Java虚拟线程调用System.out.println出现异常输出问题

运行一段从Java虚拟线程中调用System.out.println方法的示例程序时，出现了异常输出结果。示例程序如下：

import java.math.BigInteger;
import java.time.LocalDateTime;

public class VirtualThreadTest {

    public static void main(String[] args) {
        for(int i = 1; i <= 200; i+=1) {
            Thread.ofVirtual().start(() -> {
                System.out.println(LocalDateTime.now());
                System.out.flush();
                expensiveTask();
            });
        }

        sleepMainThread();
    }

    private static void expensiveTask() {
        var bi = BigInteger.ONE;
        for(int i = 2; i < 50_000; i+=1) {
            bi = bi.multiply(BigInteger.valueOf(i));
        }
    }

    private static void sleepMainThread() {
        try {
            Thread.sleep(60_000);
        } catch(Exception e) { e.printStackTrace(); }
    }
}

程序初期会按时间递增顺序打印当前时间，但一段时间后会输出早于当前的时间值，例如：

2024-05-08T14:17:34.925188363
2024-05-08T14:17:34.925920200
2024-05-08T14:17:34.925993640
2024-05-08T14:17:34.926365126
...
2024-05-08T14:17:50.927143298
2024-05-08T14:17:51.136285346
2024-05-08T14:17:34.925684196  // 打印了过去的时间值
2024-05-08T14:17:51.251390867
2024-05-08T14:17:51.309471812

请问该异常情况的原因是什么？

这个异常输出的核心原因是虚拟线程的阻塞挂起机制，结合System.out.println的线程安全锁竞争，导致时间值的计算和打印被严重延迟分离：

• 时间计算与打印的分离：代码中System.out.println(LocalDateTime.now())会先计算出当前时间值，再调用println方法输出。如果某个虚拟线程在算出时间后，因锁竞争无法立刻打印，这个时间值会被暂存，直到锁可用才会输出。
• 虚拟线程的阻塞挂起特性：当虚拟线程等待System.out的同步锁时，Java虚拟线程调度器会把它挂起，让出底层平台线程给其他虚拟线程使用。
• 计算密集型任务占用平台线程：那些抢到锁完成打印的虚拟线程，紧接着会执行耗时的expensiveTask——这是计算密集型操作，虚拟线程执行这类任务时会绑定到平台线程，直到计算完成才释放。大量这类线程会长时间占用平台线程，导致之前被挂起等待锁的虚拟线程无法被及时调度。
• 延迟打印的旧时间值：被挂起的虚拟线程可能要等十几秒，直到占用平台线程的计算任务全部完成，才会被重新调度执行打印。此时它输出的是十几秒前计算好的时间值，自然会出现在已经打印的、更晚的时间之后，看起来像是"过去的时间"。

内容的提问来源于stack exchange，提问作者user9532210