性能文章>这个Bug的排查之路,真的太有趣了。 #论程序员,你曾遇到关于性能的那些事#>

这个Bug的排查之路,真的太有趣了。 #论程序员,你曾遇到关于性能的那些事#原创

https://a.perfma.net/img/2382850
3年前
882637

在《深入理解Java虚拟机》一书中有这样一段代码:

public class VolatileTest {

    public static volatile int race = 0;

    public static void increase() {
        race++;
    }

    private static final int THREADS_COUNT=20;

    public static void main(String[] args) {
        Thread[] threads = new Thread[THREADS_COUNT];
        for(int i = 0; i < THREADS_COUNT; i++){
           new Thread(new Runnable() {
               @Override
               public void run() {
                   for (int i = 0; i < 10000; i++) {
                       increase();
                   }
               }
           }).start();
        }

        //等待所有累加线程都结束
        while(Thread.activeCount()>1)
            Thread.yield();

        System.out.println(race);
    }
}

你看到这段代码的第一反应是什么?

是不是关注点都在 volatile 关键字上。

甚至马上就要开始脱口而出:volatile 只保证可见性,不保证原子性。而代码中的 race++ 不是原子性的操作,巴拉巴拉巴拉…

反正我就是这样的:

当他把代码发给我,我在 idea 里面一粘贴,然后把 main 方法运行起来后,神奇的事情出现了。

这个代码真的没有执行到输出语句,也没有任何报错。

看起来就像是死循环了一样。

不信的话,你也可以放到你的 idea 里面去执行一下。

等等…

死循环?

代码里面不是就有一个死循环吗?

//等待所有累加线程都结束
while(Thread.activeCount()>1)
    Thread.yield();

这段代码能有什么小心思呢?看起来人畜无害啊。

但是程序员的直觉告诉我,这个地方就是有问题的。

活跃线程一直是大于 1 的,所以导致 while 一直在死循环。

算了,不想了,先 Debug 看一眼吧。

Debug 了两遍之后,我才发现,这个事情,有点意思了。

因为 Debug 的情况下,程序竟然正常结束了。

啥情况啊?

分析一波走起。

为啥停不下来?

我是怎么分析这个问题的呢。

我就把程序又 Run 了起来,控制台还是啥输出都没有。

我就盯着这个控制台想啊,会是啥原因呢?

这样干看着也不是办法啊。

反正我现在就是咬死这个 while 循环是有问题的,所以为了排除其他的干扰项。

我把程序简化到了这个样子:

public class VolatileTest {

    public static volatile int race = 0;

    public static void main(String[] args) {
        while(Thread.activeCount()>1)
            Thread.yield();
        System.out.println("race = " + race);
    }
}

运行起来之后,还是没有执行到输出语句,也就侧面证实了我的想法:while 循环有问题。

而 while 循环的条件就是 Thread.activeCount()>1

朝着这个方向继续想下去,就是看看当前活跃线程到底有几个。

于是程序又可以简化成这样:

直接运行看到输出结果是 2。

用 Debug 模式运行时返回的是 1。

对比这运行结果,我心里基本上就有数了。

先看一下这个 activeCount 方法是干啥的:

注意看画着下划线的地方:

返回的值是一个 estimate。

estimate 是啥?

你看,又在我这里学一个高级词汇。真是 very good。

返回的是一个预估值。

为什么呢?

因为我们调用这个方法的一刻获取到值之后,线程数还是在动态变化的。

也就是说返回的值只代表你调用的那一刻有几个活跃线程,也许当你调用完成后,有一个线程就立马嗝屁了。

所以,这个值是个预估值。

这一瞬间,我突然想到了量子力学中的测不准原理。

你不可能同时知道一个粒子的位置和它的速度,就像在多线程高并发的情况下你不可能同时知道调用 activeCount 方法得到的值和你要用这个值的时刻,这个值的真实值是多少。

你看,刚学完英语又学量子力学。

好了,回到程序里面。

虽然注释里面说了返回值是 estimate 的,但是在我们的程序中,并不存在这样的问题。

看到 activeCount 方法的实现之后:

public static int activeCount() {
    return currentThread().getThreadGroup().activeCount();
}

我又想到,既然在直接 Run 的情况下,程序返回的数是 2,那我看看到底有那些线程呢?

其实最开始我想着去 Debug 一下的,但是 Debug 的情况下,返回的数是 1。我意识到,这个问题肯定和 idea 有关,而且必须得用日志调试大法才能知道原因。

于是,我把程序改成了这样:

直接 Run 起来,可以看到,确实有两个线程。

一个是 main 线程,我们熟悉。

一个是 Monitor Ctrl-Break 线程,我不认识。

但是当我用 Debug 的方式运行的时候,有意思的事情就发生了:

Monitor Ctrl-Break 线程不见了!?

于是,我问他:

是啊,问题解决了,但是啥原因啊?

为什么 Run 不可以运行,而 Debug 可以运行呢?

当前线程有哪些?

我们先梳理一下当前线程有哪些吧。

可以使用下面的代码获取当前所有的线程:

public  static Thread[] findAllThread(){
    ThreadGroup currentGroup =Thread.currentThread().getThreadGroup();

    while (currentGroup.getParent()!=null){
        // 返回此线程组的父线程组
        currentGroup=currentGroup.getParent();
    }
    //此线程组中活动线程的估计数
    int noThreads = currentGroup.activeCount();

    Thread[] lstThreads = new Thread[noThreads];
    //把对此线程组中的所有活动子组的引用复制到指定数组中。
    currentGroup.enumerate(lstThreads);

    for (Thread thread : lstThreads) {
        System.out.println("线程数量:"+noThreads+" " +
                "线程id:" + thread.getId() + 
                " 线程名称:" + thread.getName() + 
                " 线程状态:" + thread.getState());
    }
    return lstThreads;
}

运行之后可以看到有 6 个线程:

也就是说,在 idea 里面,一个 main 方法 Run 起来之后,即使什么都不干,也会有 6 个线程运行。

这 6 个线程分别是干啥的呢?

我们一个个的说。

Reference Handler 线程:

JVM 在创建 main 线程后就创建 Reference Handler 线程,其优先级最高,为 10,它主要用于处理引用对象本身(软引用、弱引用、虚引用)的垃圾回收问题。

Finalizer 线程:

这个线程也是在 main 线程之后创建的,其优先级为10,主要用于在垃圾收集前,调用对象的 finalize() 方法。<br>关于 Finalizer 线程的几点:<br>1)只有当开始一轮垃圾收集时,才会开始调用 finalize() 方法;因此并不是所有对象的 finalize() 方法都会被执行;<br>2)该线程也是 daemon 线程,因此如果虚拟机中没有其他非 daemon 线程,不管该线程有没有执行完 finalize() 方法,JVM 也会退出;<br>3) JVM在垃圾收集时会将失去引用的对象包装成 Finalizer 对象(Reference的实现),并放入 ReferenceQueue,由 Finalizer 线程来处理;最后将该 Finalizer 对象的引用置为 null,由垃圾收集器来回收;<br>4) JVM 为什么要单独用一个线程来执行 finalize() 方法呢?如果 JVM 的垃圾收集线程自己来做,很有可能由于在 finalize() 方法中误操作导致 GC 线程停止或不可控,这对 GC 线程来说是一种灾难。

Attach Listener 线程:

Attach Listener 线程是负责接收到外部的命令,而对该命令进行执行的并且把结果返回给发送者。通常我们会用一些命令去要求 jvm 给我们一些反馈信息。<br>如:java -version、jmap、jstack 等等。如果该线程在 jvm 启动的时候没有初始化,那么,则会在用户第一次执行 jvm 命令时,得到启动。

Signal Dispatcher 线程:

前面我们提到第一个 Attach Listener 线程的职责是接收外部 jvm 命令,当命令接收成功后,会交给 signal dispather 线程去进行分发到各个不同的模块处理命令,并且返回处理结果。signal dispather 线程也是在第一次接收外部 jvm 命令时,进行初始化工作。

main 线程:

呃,这个不说了吧。大家都知道。

Monitor Ctrl-Break 线程:

先买个关子,下一小节专门聊聊这个线程。

上面线程的作用,我是从这个网页搬运过来的,还有很多其他的线程,大家可以去看看:

http://ifeve.com/jvm-thread/

我好事做到底,直接给你来个长截图,一网打尽。

你先把图片保存起来,后面慢慢看:

现在跟着我去探寻 Monitor Ctrl-Break 线程的秘密。

继续挖掘

问题解决了,但是问题背后的问题,还没有得到解决:

Monitor Ctrl-Break 线程是啥?它是怎么来的?

我们先 jstack 一把看看线程堆栈呗。

而在 idea 里面,这里的“照相机”图标,就是 jstack 一样的功能。

我把程序恢复为最初的样子,然后把“照相机”就这么轻轻的一点:

从线程堆栈里面可以看到 Monitor Ctrl-Break 线程来自于这个地方:

com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)

而这个地方,一看名称,是 idea 的源码了啊?

不属于我们的项目里面了,这咋个搞呢?

思考了一下,想到了一种可能,于是我决定用 jps 命令验证一下:

看到执行结果的时候我笑了,一切就说的通了。

果然,是用了 -javaagent 啊。

那么 javaagent 是什么?

好的,要问答好这个问题,就得另起一篇文章了,本文不讨论,先欠着。

只是简单的提一下。

你在命令行执行 java 命令,会输出一大串东西,其中就包含这个:

什么语言代理的,看不懂。

叫我们参阅 java.lang.instrument。

那它又是拿来干啥的?

简单的一句话解释就是:

使用 instrument 可以更加方便的使用字节码增强的技术,可以认为是一种 jvm 层面的截面。不需要对程序源代码进行任何侵入,就可以对其进行增强或者修改。总之,有点 AOP 内味。

-javaagent 命令后面需要紧跟一个 jar 包。

-javaagent:<jar 路径>[=<选项>]<br>

instrument 机制要求,这个 jar 包必须有 MANIFEST.MF 文件,而 MANIFEST.MF 文件里面必须有 Premain-Class 这个东西。

所以,回到我们的程序中,看一下 javaagent 后面跟的包是什么。

在哪看呢?

就这个地方:

你把它点开,命令非常的长。但是我们关心的 -javaagent 就在最开始的地方:

-javaagent:D:\Program Files\JetBrains\IntelliJ IDEA 2019.3.4\lib\idea_rt.jar=61960

可以看到,后面跟着的 jar 包是 idea_rt,按照文件目录找过去,也就是在这里:

我们解压这个 jar 包,打开它的 MANIFEST.MF 文件:

而这个类,不就是我们要找的它吗:

此时此刻,我们距离真相,只有一步之遥了。

进到对应的包里,发现有三个 class 类:

主要关注 AppMainV2.class 文件:

在这个文件里面,就有一个 startMonitor 方法:

我说过什么来着?

来,大声的跟我念一遍:源码之下无秘密。

Monitor Ctrl-Break 线程就是这里来的。

而仔细看一眼这里的代码,这个线程在干啥事呢?

Socket client = new Socket("127.0.0.1", portNumber);

啊,我的天呐,来看看这个可爱的小东西,socket 编程,太熟悉了,简直是梦回大学实验课的时候。

它是链接到 127.0.0.1 的某个端口上,然后 while(true) 死循环等待接收命令。

那么这个端口是哪个端口呢?

就是这里的 62325:

需要注意的是,这个端口并不是固定的,每次启动这个端口都会变化。

玩玩它

既然它是 Socket 编程,那么我就玩玩它呗。

先搞个程序:

public class SocketTest{

    public static void main(String[] args) throws IOException {
        ServerSocket serverSocket = new ServerSocket(12345);
        System.out.println("等待客户端连接.");
        Socket socket = serverSocket.accept();
        System.out.println("有客户端连接上了 "+ socket.getInetAddress() + ":" + socket.getPort() +"");
 
        OutputStream outputStream = socket.getOutputStream();
        Scanner scanner = new Scanner(System.in);
        while (true)
        {
            System.out.println("请输入指令: ");
            String s = scanner.nextLine();
            String message = s + "\n";
            outputStream.write(message.getBytes("US-ASCII"));
        }
    }
}

我们把服务端的端口指定为了 12345。

客户端这边的端口也得指定为 12345,那怎么指定呢?

别想复杂了,简单的一比。

把这行日志粘贴出来:

需要说明的是,我这边为了演示效果,在程序里面加了一个 for 循环。

然后我们在这里把端口改为 12345:

把文件保存为 start.bat 文件,随便放一个地方。

万事俱备。

我们先把服务端运行起来:

然后,执行 bat 文件:

在 cmd 窗口里面输出了我们的日志,说明程序正常运行。

而在服务端这边,显示有客户端连接成功。

叫我们输入指令。

输入啥指令呢?

看一下客户端支持哪些指令呗:

可以看到,支持 STOP 命令。

接受到该命令后,会退出程序。

来,搞一波,动图走起:

搞定。

好了,本文技术部分就到这里了,恭喜你知道了 idea 中的 Monitor Ctrl-Break 线程,这个学了没啥卵用的知识 。

如果要深挖的话,往 -javaagent 方向挖一挖。

应用很多的,比如耳熟能详的 Java 诊断工具 Arthas 就是基于 JavaAgent 做的。

有点意思。

本文正在参与「论程序员,你曾遇到关于性能的那些事丨 PerfMa技术征文」活动

点赞收藏
why技术
请先登录,查看3条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

随机一门技术分享之Netty

随机一门技术分享之Netty

MappedByteBuffer VS FileChannel:从内核层面对比两者的性能差异

MappedByteBuffer VS FileChannel:从内核层面对比两者的性能差异

7
3