在 javaagent 中启动的线程阻塞退出答案

【问题标题】：thread started in javaagent blocking exit在 javaagent 中启动的线程阻塞退出
【发布时间】：2021-09-07 06:18:40
【问题描述】：

在我的 javagent 中，我启动了一个 HttpServer：

public static void premain(String agentArgs, Instrumentation inst) throws InstantiationException, IOException {

        HttpServer server = HttpServer.create(new InetSocketAddress(8000), 0);

        server.createContext("/report", new ReportHandler());
        server.createContext("/data", new DataHandler());
        server.createContext("/stack", new StackHandler());
        ExecutorService es = Executors.newCachedThreadPool(new ThreadFactory() {
            int count = 0;
            @Override
            public Thread newThread(Runnable r) {
                Thread t = new Thread(r);
                t.setDaemon(true);
                t.setName("JDBCLD-HTTP-SERVER" + count++);
                return t;
            }
            
        });
        server.setExecutor(es);
        server.start();

        // how to properly close ?
        Runtime.getRuntime().addShutdownHook(new Thread() {
            @Override
            public void run() {
                server.stop(5);
                log.info("internal httpserver has been closed.");
                es.shutdown();
                try {
                    if (!es.awaitTermination(60, TimeUnit.SECONDS)) {
                        log.warn("executor service of internal httpserver not closing in 60 seconds");
                        es.shutdownNow();
                        if (!es.awaitTermination(60, TimeUnit.SECONDS))
                            log.error("executor service of internal httpserver not closing in 120 seconds, give up");
                    }else {
                        log.info("executor service of internal httpserver closed.");
                    }
                } catch (InterruptedException ie) {
                    log.warn("thread interrupted, shutdown executor service of internal httpserver");
                    es.shutdownNow();
                    Thread.currentThread().interrupt();
                }
            }
        });

    // other instrumention code ignored ...
}

测试程序：

public class AgentTest {

    public static void main(String[] args) throws SQLException {

        HikariConfig config = new HikariConfig();
        config.setJdbcUrl("jdbc:oracle:thin:@172.31.27.182:1521/pas");
        config.setUsername("pas");
        config.setPassword("pas");

        HikariDataSource ds = new HikariDataSource(config);
        Connection c = ds.getConnection();
        Connection c1 = ds.getConnection();
        
        c.getMetaData();
        
        try {
            Thread.sleep(1000 * 60 * 10);
        } catch (InterruptedException e) {
            e.printStackTrace();
            c.close();
            c1.close();
            ds.close();
        }
        
        c.close();
        c1.close();
        
        ds.close();
        
        
    }

}

当目标 jvm 退出时，我想停止那个 HttpServer。但是当我的测试java程序完成时，主线程停止但整个jvm进程不会终止，上面代码中的关闭钩子不会执行。如果我在 Eclipse IDE 中单击“终止”按钮，Eclipse 将显示错误：但至少 jvm 会退出，并且我的关闭挂钩会被调用。

根据java.lang.Runtime的java文档：

Java 虚拟机响应两种情况而关闭事件：

程序正常退出，当最后一个非守护线程退出或当调用退出（相当于 System.exit）方法时，或虚拟机响应用户中断而终止，例如键入 ^C，或系统范围的事件，例如用户注销或系统关机。

com.sun.net.httpserver.HttpServer 将启动一个非守护进程调度线程，当HttpServer#stop 被调用时该线程将退出，所以我面临死锁。

非守护线程未完成 -> 未触发关闭挂钩 -> 不能停止服务器 -> 非守护线程未完成

有什么好主意吗？请注意，我无法修改目标应用程序的代码。

应用 kriegaex 的答案后的更新

I added some logging to watch dog thread, and here is outputs:

2021-09-22 17:30:00.967 INFO  - Connnection@1594791957 acquired by 40A4F128987F8BD9C0EE6749895D1237
2021-09-22 17:30:00.968 DEBUG - Stack@40A4F128987F8BD9C0EE6749895D1237: 
java.lang.Throwable: 
    at com.zaxxer.hikari.pool.ProxyConnection.<init>(ProxyConnection.java:102)
    at com.zaxxer.hikari.pool.HikariProxyConnection.<init>(HikariProxyConnection.java)
    at com.zaxxer.hikari.pool.ProxyFactory.getProxyConnection(ProxyFactory.java)
    at com.zaxxer.hikari.pool.PoolEntry.createProxyConnection(PoolEntry.java:97)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:192)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
    at agenttest.AgentTest.main(AgentTest.java:19)
2021-09-22 17:30:00.969 INFO  - Connnection@686560878 acquired by 464555C270688B747CA211DE489B7730
2021-09-22 17:30:00.969 DEBUG - Stack@464555C270688B747CA211DE489B7730: 
java.lang.Throwable: 
    at com.zaxxer.hikari.pool.ProxyConnection.<init>(ProxyConnection.java:102)
    at com.zaxxer.hikari.pool.HikariProxyConnection.<init>(HikariProxyConnection.java)
    at com.zaxxer.hikari.pool.ProxyFactory.getProxyConnection(ProxyFactory.java)
    at com.zaxxer.hikari.pool.PoolEntry.createProxyConnection(PoolEntry.java:97)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:192)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
    at agenttest.AgentTest.main(AgentTest.java:20)
2021-09-22 17:30:00.971 DEBUG - Connnection@1594791957 used by getMetaData
2021-09-22 17:30:01.956 DEBUG - there is still 12 active threads, keep wathcing
2021-09-22 17:30:01.956 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true HikariPool-1 connection adder#true 
2021-09-22 17:30:02.956 DEBUG - there is still 12 active threads, keep wathcing
2021-09-22 17:30:02.956 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true HikariPool-1 connection adder#true 
2021-09-22 17:30:03.957 DEBUG - there is still 12 active threads, keep wathcing
2021-09-22 17:30:03.957 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true HikariPool-1 connection adder#true 
2021-09-22 17:30:04.959 DEBUG - there is still 12 active threads, keep wathcing
2021-09-22 17:30:04.959 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true HikariPool-1 connection adder#true 
2021-09-22 17:30:05.959 DEBUG - there is still 12 active threads, keep wathcing
2021-09-22 17:30:05.960 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true HikariPool-1 connection adder#true 
2021-09-22 17:30:06.960 DEBUG - there is still 11 active threads, keep wathcing
2021-09-22 17:30:06.960 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true 
2021-09-22 17:30:07.961 DEBUG - there is still 11 active threads, keep wathcing
2021-09-22 17:30:07.961 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true 
2021-09-22 17:30:08.961 DEBUG - there is still 11 active threads, keep wathcing
2021-09-22 17:30:08.961 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true 
2021-09-22 17:30:09.962 DEBUG - there is still 11 active threads, keep wathcing
2021-09-22 17:30:09.962 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true 
2021-09-22 17:30:10.962 DEBUG - there is still 11 active threads, keep wathcing
2021-09-22 17:30:10.963 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true main#false server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true HikariPool-1 housekeeper#true 
2021-09-22 17:30:10.976 INFO  - Connnection@1594791957 released
2021-09-22 17:30:10.976 DEBUG - set connection count to 0 by stack hash 40A4F128987F8BD9C0EE6749895D1237
2021-09-22 17:30:10.976 INFO  - Connnection@686560878 released
2021-09-22 17:30:10.976 DEBUG - set connection count to 0 by stack hash 464555C270688B747CA211DE489B7730
2021-09-22 17:30:11.963 DEBUG - there is still 10 active threads, keep wathcing
2021-09-22 17:30:11.963 DEBUG - Reference Handler#true Finalizer#true Signal Dispatcher#true server-timer#true Thread-2#false jdbcld-watch-dog#false Timer-0#true oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser#true InterruptTimer#true DestroyJavaVM#false 
2021-09-22 17:30:12.964 DEBUG - there is still 10 active threads, keep wathcing

更新

我想支持各种java应用程序，包括使用servlet容器运行的web应用程序和标准的javase应用程序。

【问题讨论】：

它很脏，但是你可以启动一个后台线程来检查所有线程，看看有多少非守护线程时不时地。如果它检测到只剩下http服务器线程，它可以关闭web服务器，从而停止程序。
@kriegaex 感谢您的努力，我最近忙于重构我的代理的主要逻辑，我一定会尝试您的方法和反馈，我们正在国庆假期，所以请稍等。

标签： java javaagents

【解决方案1】：

这里有一个小MCVE 说明ewrammer 的想法。我使用小的 byte-buddy-agent 帮助库动态附加代理，以使我的示例自包含，从 main 方法启动 Java 代理。我省略了运行此示例所需的 3 个琐碎的无操作虚拟处理程序类。

package org.acme.agent;

import com.sun.net.httpserver.HttpServer;
import net.bytebuddy.agent.ByteBuddyAgent;

import java.io.IOException;
import java.lang.instrument.Instrumentation;
import java.net.InetSocketAddress;
import java.util.Random;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;

public class Agent {

  public static void premain(String agentArgs, Instrumentation inst) throws IOException {
    HttpServer httpServer = HttpServer.create(new InetSocketAddress(8000), 0);
    ExecutorService executorService = getExecutorService(httpServer);
    Runtime.getRuntime().addShutdownHook(getShutdownHook(httpServer, executorService));
    // other instrumention code ignored ...
    startWatchDog();
  }

  private static ExecutorService getExecutorService(HttpServer server) {
    server.createContext("/report", new ReportHandler());
    server.createContext("/data", new DataHandler());
    server.createContext("/stack", new StackHandler());
    ExecutorService executorService = Executors.newCachedThreadPool(new ThreadFactory() {
      int count = 0;

      @Override
      public Thread newThread(Runnable r) {
        Thread t = new Thread(r);
        t.setDaemon(true);
        t.setName("JDBCLD-HTTP-SERVER" + count++);
        return t;
      }

    });
    server.setExecutor(executorService);
    server.start();
    return executorService;
  }

  private static Thread getShutdownHook(HttpServer httpServer, ExecutorService executorService) {
    return new Thread(() -> {
      httpServer.stop(5);
      System.out.println("Internal HTTP server has been stopped");
      executorService.shutdown();
      try {
        if (!executorService.awaitTermination(60, TimeUnit.SECONDS)) {
          System.out.println("Executor service of internal HTTP server not closing in 60 seconds");
          executorService.shutdownNow();
          if (!executorService.awaitTermination(60, TimeUnit.SECONDS))
            System.out.println("Executor service of internal HTTP server not closing in 120 seconds, giving up");
        }
        else {
          System.out.println("Executor service of internal HTTP server closed");
        }
      }
      catch (InterruptedException ie) {
        System.out.println("Thread interrupted, shutting down executor service of internal HTTP server");
        executorService.shutdownNow();
        Thread.currentThread().interrupt();
      }
    });
  }

  private static void startWatchDog() {
    ThreadGroup threadGroup = Thread.currentThread().getThreadGroup();
    while (threadGroup.getParent() != null)
      threadGroup = threadGroup.getParent();
    final ThreadGroup topLevelThreadGroup = threadGroup;
    // Plus 1, because of the monitoring thread we are going to start right below
    final int activeCount = topLevelThreadGroup.activeCount() + 1;

    new Thread(() -> {
      do {
        try {
          Thread.sleep(1000);
        }
        catch (InterruptedException ignored) {}
      } while (topLevelThreadGroup.activeCount() > activeCount);
      System.exit(0);
    }).start();
  }

  public static void main(String[] args) throws IOException {
    premain(null, ByteBuddyAgent.install());
    Random random = new Random();
    for (int i = 0; i < 5; i++) {
      new Thread(() -> {
        int threadDurationSeconds = 1 + random.nextInt(10);
        System.out.println("Starting thread with duration " + threadDurationSeconds + " s");
        try {
          Thread.sleep(threadDurationSeconds * 1000);
          System.out.println("Finishing thread after " + threadDurationSeconds + " s");
        }
        catch (InterruptedException ignored) {}
      }).start();
    }
  }
}

如您所见，这基本上是您的示例代码，为了便于阅读，重构为一些辅助方法，以及新的看门狗方法。这很简单。

这会产生一个控制台日志，如下所示：

Starting thread with duration 6 s
Starting thread with duration 6 s
Starting thread with duration 8 s
Starting thread with duration 7 s
Starting thread with duration 5 s
Finishing thread after 5 s
Finishing thread after 6 s
Finishing thread after 6 s
Finishing thread after 7 s
Finishing thread after 8 s
internal httpserver has been closed.
executor service of internal httpserver closed.

【讨论】：

不适用于现实世界的用例，请参阅我的编辑。
您的用例不是真实的用例，因为没有MCVE 重现问题。然而，我发布了一个 MCVE，证明它按建议工作。我如何通过查看由我看不到的代码生成的日志输出来理解您的代码？请在 GitHub 上发布一个 MCVE，然后我可以看看。可能您只是没有根据您的情况正确调整我的代码 - 没有理由不接受我的回答。
这只是我问题中的测试程序，我测试了你的代码，它可以工作。但是当使用“-javaagent:xxxx=args”运行我的测试程序时，它不起作用
为什么我们不能只检查主线程是否存在
MCVE 这个词有什么不清楚的地方？请在 GitHub 上发布一些内容，如果您在后续问题上需要我的帮助，我需要重现您的问题。在您声称应用了我的更改后，您的日志甚至没有解释什么是错误的。请向我提供 MCVE 或接受并支持我的答案，因为它解决了您在此问题中所述的问题，然后提出一个新问题。如果我看不到并运行它，我就不能对你的代码说任何聪明的事情。