用mvn exec:java执行Java程序出现告警日志was interrupted but is still alive after waiting at least 15000msecs

admin管理员组

文章数量:1590161

问题现象

Java代码如下，在用户主线程中启动了一个守护子线程，守护线程无限循环：

package com.thb;

import java.util.concurrent.TimeUnit;

public class Demo {

    public static void main(String[] args) throws InterruptedException {
        // 创建一个线程
        Thread threadA = new Thread(() -> {
            System.out.println("enter thread: " + Thread.currentThread().getName());
            while (true) {
                try {
                    System.out.println(Thread.currentThread().getName() + " sleep");
                    TimeUnit.SECONDS.sleep(10);
                    System.out.println(Thread.currentThread().getName() + " awakened");
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }, "threadA");
       
       // 设置为守护线程
        threadA.setDaemon(true);
        // 启动threadA
        threadA.start();

        System.out.println("current thread: " + Thread.currentThread().getName());
    }

}

我用mvn exec:java -Dexec.mainClass=com.thb.Demo执行Java程序，输出如下，其中含有告警日志：

current thread: com.thb.Demo.main()
enter thread: threadA
threadA sleep
java.lang.InterruptedException: sleep interrupted
        at java.base/java.lang.Thread.sleep0(Native Method)
        at java.base/java.lang.Thread.sleep(Thread.java:484)
        at java.base/java.lang.Thread.sleep(Thread.java:532)
        at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446)
        at com.thb.Demo.lambda$0(Demo.java:14)
        at java.base/java.lang.Thread.run(Thread.java:1623)
threadA sleep
threadA awakened
threadA sleep
[WARNING] thread Thread[#35,threadA,5,com.thb.Demo] was interrupted but is still alive after waiting at least 15000msecs
[WARNING] thread Thread[#35,threadA,5,com.thb.Demo] will linger despite being asked to die via interruption
[WARNING] NOTE: 1 thread(s) did not finish despite being asked to via interruption. This is not a problem with exec:java, it is a problem with the running code. Although not serious, it should be remedied.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  15.378 s
[INFO] Finished at: 2023-12-26T14:09:44+08:00
[INFO] ------------------------------------------------------------------------

上面的输出中，出现了三行告警信息：

[WARNING] thread Thread[#35,threadA,5,com.thb.Demo] was interrupted but is still alive after waiting at least 15000msecs
[WARNING] thread Thread[#35,threadA,5,com.thb.Demo] will linger despite being asked to die via interruption
[WARNING] NOTE: 1 thread(s) did not finish despite being asked to via interruption. This is not a problem with exec:java, it is a problem with the running code. Although not serious, it should be remedied.

排查过程

在eclipse中直接用Run As->Java Application的方式运行没有告警

从输出来看，java程序很快就运行完了，没有告警，说明java代码没有问题。

在cmd下直接用java命令运行，没有告警

运行很快就结束了：

通过debug模式跟踪+阅读代码+阅读官方文档

eclipse中，用Debug As->Maven Build：

在ExecJavaMojo文件中搜索，找到了打印告警日志的地方：

看了代码中的函数，知道了打印告警日志的原因：exec用线程的join方法，等待守护线程结束，结果在超时时间（15000msecs）内没有结束，所以打印了告警日志。

到maven的exec插件的官网查看：
https://www.mojohaus/exec-maven-plugin/usage.html

官网列出了通过exec:java这个goal执行java程序和用纯粹的命令行方式执行的差异：

• 用纯粹的命令行执行，当只剩下守护线程的时候，Java虚拟机就启动退出过程。
• 而用exec:java执行，要等守护线程结束，并设置了等待的超时时间。

处理方式

不需要解决

这个问题不需要解决，告警不影响。因为经过10几秒后，虚拟机也关闭了。
例如，我输入mvn exec:java -Dexec.mainClass=com.thb.Demo命令，回车后，赶紧用java的JConsole工具查看，此时线程存在：

但等maven的命令执行完成后（在本例中是15秒左右），JConsole工具已经连接不上java虚拟机了，说明已经不存在了：

在新建连接窗口中也看不到了：

通过参数设置不让exec清除守护进程

如果觉着不想看到这个告警。那么可以通过参数设置，不清除守护进程，可以使用-Dexec.cleanupDaemonThreads=false来设置。

https://www.mojohaus/exec-maven-plugin/java-mojo.html

上述的maven命令很快就执行完了，执行完成后，用jps和JConsole都看不到Java虚拟机了：

本文标签： 程序日志JavaExec