JVM – CheungQ

起因是前几天看的一篇文章，里面贴了一段代码，大意如下

public class SafePointTest {

    public static AtomicInteger num = new AtomicInteger(0);

    public static void main(String[] args) throws InterruptedException {
        Runnable runnable = ()->{
            for (int i = 0; i < 1000000000; i++) {
                num.getAndAdd(1);
            }
            System.out.println(Thread.currentThread().getName()+"执行结束!");
        };

        Thread t1 = new Thread(runnable);
        Thread t2 = new Thread(runnable);
        t1.start();
        t2.start();
        Thread.sleep(1000);
        System.out.println("num = " + num);
    }
}

执行之后输出如下，环境为Java8，没有添加其他jvm参数

从上面的结果可以看到，主线程在`Thread.sleep(1000)`的睡眠1秒之后并没有能直接执行下一步的sout代码，来输出num的的值，而是一直“阻塞”等到两个线程的for循环结束之后，才执行了sout输出代码。所以，我们可以很明显的猜测到，是这两个for循环的执行，对主线程的Thread.sleep产生了影响，让主线程未能从sleep的TIMED_WAITING状态返回RUNNABLE状态，我们可以改造下代码，观察下主线程的状态

略有点粗糙的改造，不过可以大致看到Thread.sleep之后主线程的状态变化，代码如下

public class SafePointTest {

    public static AtomicInteger num = new AtomicInteger(0);

    public static void main(String[] args) {
        Runnable runnable = new Runnable() {
            @Override
            public void run() {
                Runnable r = () -> {
                    for (int i = 0; i < 1000000000; i++) {
                        num.getAndAdd(1);
                    }
                    System.out.println(Thread.currentThread().getName() + "执行结束!");
                };
                Thread t1 = new Thread(r);
                Thread t2 = new Thread(r);
                t1.start();
                t2.start();
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                System.out.println("num = " + num);
            }
        };
        long time = System.currentTimeMillis();
        Thread t = new Thread(runnable);
        System.out.println((System.currentTimeMillis()-time) +" \t"+ t.getState());
        t.start();
        System.out.println((System.currentTimeMillis()-time) +" \t"+ t.getState());
        Thread.State state = t.getState();
        while (t.isAlive()){
            Thread.State currentState = t.getState();
            if (state.compareTo(currentState) != 0){
                System.out.println((System.currentTimeMillis()-time) +" \t"+ currentState);
                state = currentState;
            }
        }
        System.out.println((System.currentTimeMillis()-time) +" \t"+ t.getState());
    }
}

运行得到结果如下

也有可能获取到主线程（t）最后进入到BLOCKED状态的情况，如下

看下Thread.State的源码，BLOCKED状态的说明，我们可以看到如下注释内容，竞争锁资源的失败，加入等待锁的同步阻塞队列，进入阻塞状态。

Thread state for a thread blocked waiting for a monitor lock. A thread in the blocked state is waiting for a monitor lock to enter a synchronized block/method or reenter a synchronized block/method after calling

看到锁，回头来看下刚才的代码，那么我们很自然的想到了sout方法中其实是有个锁的

那么这里出现主线程（t）BLOCKED状态很明显就是在和子线程（t1、t2）以及当前的main函数的线程，3个线程同时竞争打印锁的时候没有竞争成功而进入了阻塞状态。测试下，把t线程和t1、t2线程中的sout方法同时注释掉。这样就只有main函数的线程需要占用打印锁，多次运行之后均没有发现t线程出现BLOCKED状态的情况，在没有注释之前，主线程（t）进入BLOCKED的情况还是比较频繁容易出现的。

好了，BLOCKED的问题搞清楚之后，我们重新回到原来的问题之上，根据输出的内容，我们可以看到主线程（t）在sleep之后进入TIMED_WAITING状态，直到两个子线程（t1、t2）都执行结束的时候才恢复到RUNNABLE状态。

不卖关子，我们直接说结论

SafePoint

这就是产生这个现象的原因，JVM有个参数-XX:GuaranteedSafepointInterval，作用是控制所有线程进入SafePoint的时间间隔，默认是

-XX:GuaranteedSafepointInterval=1000

即每隔1000毫秒，所有线程进入一次SafePoint。如果有线程无法进入SafePoint，那么其他线程一直等待，直到所有线程都进入SafePoint了，再立刻从SafePoint中恢复。那么，什么是SafePoint呢？

Safepoint 可以理解成是在代码执行过程中的一些特殊位置，当线程执行到这些位置的时候，线程可以暂停。线程在执行的时候，如果JVM要STW，暂停线程的执行，线程并不是可以在任意地方立刻暂停下来的，这可能和我们直觉有点不一样，在日常开发中，我们可以在代码的任意地方添加断点，从而让程序在断点的地方停下来。这个断点其实就是我们在代码中强制添加的SafePoint，稍后我们会再提到。

在我们的Java代码编写完之后，开始执行代码，理论上，JVM可以在每条字节码的边界都可以放一个SafePoint，但是更多的SafePoint就意味着需要更多的占用内存空间，因为在SafePoint中需要保存当前线程的各种上下文信息，因为随时可能在这个SafePoint处暂停。同时也会生成polling代码询问JVM是否要“进入SafePoint”，而polling操作也是有开销的。不同的 JVM 选用不同的位置放置 SafePoint。

通过JIT的优化，只在部分地方放置SafePoint。其中一个情况需要事先了解下，比如我们上面的例子中的for循环的counted loop的循环（可数循环），特指这种for ( int )的循环，相应的long类型的并不是，算作是uncounted loop（不可数循环），在我们使用的Java8版本中，JIT会认为counted loop较小，不会再循环中添加SafePoint。所以我们知道上面的代码中for (int i = 0; i < 1000000000; i++)的循环体内部是没有SafePoint的。

当然也有其他需要添加SafePoint的情况，根据之前RednaxelaFX的说法（see https://www.zhihu.com/question/29268019/answer/43762165）

而在JIT编译的代码里，HotSpot会在所有方法的临返回之前，以及所有非counted loop的循环的回跳之前放置safepoint。

另外我们需要知道一点（see https://zhuanlan.zhihu.com/p/161710652）

当运行 native 代码时，VM 线程略过这个线程，但是给这个线程设置 poll armed，让它在执行完 native 代码之后，它会检查是否 poll armed，如果还需要停在 SafePoint，则直接 block

回到我们当前的代码中，我们看原来的第一版代码，主线程在t1、t2线程启动之后，执行了一个Thread.sleep(1000);，而Thread.sleep方法就是一个native方法，进入native方法后主线程不受JVM控制，而等待1000毫秒

1000毫秒之后。尝试回到JVM环境的控制中，需要检查SafePoint的状态，但是根据JVM的默认设定-XX:GuaranteedSafepointInterval=1000，每1000毫秒所有线程应当进入SafePoint一次，那么当前主线程应当进入SafePoint，此时两个子线程t1、t2还在进行1000000000的循环当中，这里的循环当中没有SafePoint，无法暂停，必须等到循环结束。

所以此时主线程就一直卡在当前这个状态，直到t1、t2两个线程执行完for循环进入了SafePoint。

为了验证上面的想法，我们再次修改下初版的代码，如下

public class SafePointTest {

    public static AtomicInteger num = new AtomicInteger(0);

    public static void main(String[] args) throws InterruptedException {
        Runnable runnable = () -> {
            for (int i = 0; i < 1000000000; i++) {
                num.getAndAdd(1);
            }
            System.out.println(Thread.currentThread().getName() + "执行结束!");
        };

        Thread t1 = new Thread(runnable);
        Thread t2 = new Thread(runnable);
        t1.start();
        t2.start();
        tryMakeSafePoint();
        System.out.println("num = " + num);
    }

    private static void tryMakeSafePoint() {
        int i = 0;
        for (; i < 10000000; i++) {
        }
        System.out.println(1);
    }
}

我们新增了一个tryMakeSafePoint方法，尝试强制添加一个SafePoint，怎么添加呢？我们在System.out.println(1);这里打上一个断点。同时，为了不触发这个断点，我们给这个断点设置一个条件

当i==0的时候才触发断点，那么根据当前的条件，这个断点永远都不会触发。在这里我们需要知道，我们打的断点，本质上就是强制在对应代码行的位置添加了一个SafePoint，并让当前程序运行的时候停止在这个SafePoint。所以在这个SafePoint的位置，我们可以通过debug查看到当前线程的上下文，各种变量等。另外为了排除定时进入SafePoint参数的影响，我们给JVM添加参数-XX:GuaranteedSafepointInterval=100000，把定时进入SafePoint的时间配置为100秒，排除这项的影响，因为子线程t1、t2最终执行完也只需要不到30秒

所以主线程在现在的断点位置进入SafePoint，并停在SafePoint，等待其他线程进入SafePoint。

那么接下来跑一下debug看下结果。

可以看到，结果确实如我们所预测的那样

下一步，我们重新回到初版代码，再进一步验证，我们给JVM在添加两个新的参数，现在的参数如下（默认定时每1000毫秒进入一次SafePoint）

-XX:+SafepointTimeout
-XX:SafepointTimeoutDelay=1000

这两个参数用于控制启用进入SafePoint的超时提示机制，以及超时的时间。运行得到如下结果

从打印出来的结果，可以看到JVM检测到两个线程（Thread-0和Thread-1）在尝试定时进入SafePoint的时候超时了，并不包含主线程，因为主线程从native代码回来后直接进入SafePoint了。

再一次修改JVM参数，如下

-XX:+SafepointTimeout
-XX:SafepointTimeoutDelay=1000
-XX:+PrintSafepointStatistics
-XX:PrintSafepointStatisticsCount=1

我们新增了PrintSafepointStatistics参数，-XX:+PrintSafepointStatistics –XX:PrintSafepointStatisticsCount=1这两个参数可以强制JVM打印safepoint的一些统计信息，运行后可以看到如下结果

打印出来的spin值指的是SafepointSynchronize在同步每个线程时做的自旋。(see https://www.cnblogs.com/liboware/p/15431232.html)即，主线程等待两个子线程t1、t2进入SafePoint的时候进行自旋花费了25.8秒，又主线程之前sleep了1000毫秒，总时间也就是这边显示的大概26.9秒

不过从上面的结果中我们还看到了在SafePoint中进行的一些其他操作EnableBiasedLocking、RevokeBias，这两个就是JVM在SafePoint中进行的启用和取消偏向锁相关的操作

摒除这部分信息，我们在JVM参数中再加一条

-XX:-UseBiasedLocking

再跑一遍加了断点的代码看下，可以看到

多了ForceSafepoint，不过ForceSafepoint的相关信息我搜了下却非常少，不过这也是我断定打的断点就是强制在对应的代码处添加了SafePoint的原因，有兴趣的同学可以继续深入探索下。

饶了几圈兜兜转转，我们再次回到这个问题本身，要解决这个问题也很简单，

把int的for循环修改为long的就可以，因为long的属于uncounted loop（不可数循环），其中可以插入SafePoint
使用-XX:+UseCountedLoopSafepoints 参数去强制在可数循环中也放置安全点，不过这个参数在 JDK 8 下有 Bug，有导致虚拟机崩溃的风险
居官方说法，JDK10之后修复了这个问题，我电脑上只有18，索性我就直接拿18跑了下看下

输出字符集有点问题，不过不影响我们看到结果主线程在sleep了1000毫秒后正确输出了结果

另外还看到了一个有趣的操作，又想加SafePoint，又不想让代码每次都检查SafePoint，在遍历循环中，手动插入能进入SafePoint的代码，并只在一定的情况下才进入这个SafePoint，这也是我写本文的起因

而进行相关搜索的时候我也发现有文章提到STW时间过长，发现清理时间其实很短，但是等待某些线程进入SafePoint的时间很长，而导致整个STW时间过长的问题

近期文章

分类

文章归档

标签： JVM

Javassist结合JavaAgent修改Java.class文件字节码实践

创建Agent Jar包

一个SafePoint和STW的问题