分类 Troubleshooting 相关 下的文章

Java 远程 debug

本地 Debug 很容易, 那么远程 debug 是怎么做的, 又有哪些坑呢?

一般应用程序 debug

这里的一般应用程序就是一个 main 函数, 不是 web 应用程序. 首先, 这个应用在远程某主机上能运行, 只要启动的时候, 添加远程 debug 参数就可以了.

比如有如下代码, 为了让它慢一点可以 debug, 加入了一个循环和睡眠:

public class Debugger {
    
    public int loop(int count) {
        int sum = 0;
        for (int i = 0; i < count; i++) {
            sum += i;
            try {
                System.out.println(i + "/" + count + " current sum: " + sum);
                Thread.sleep(5L);
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
        return sum;
    }
    
    public static void main(String[] args) {
        Debugger debugger = new Debugger();
        int sum = debugger.loop(10000);
        System.out.println("sum is " + sum);
    }

}

在远程编译, 启动, 并且加入监听端口为了方便远程debug:

$ javac Debugger.java
$ java -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=0.0.0.0:8000 Debugger 

这里注意的是, 我们对于地址使用的是: 0.0.0.0:8000, 有些地方你看到的直接是 8000 端口, 没有主机ip部分. 这会导致这个端口只是开在 localhost, 你如果使用 netstat 查看, 能看到 8000 端口是开着的, 但是远程无法连接.
在远程可以使用 telnet 或者 curl 来测试这个端口是不是可以远程连接. 但是注意这个端口只能有一个远端能连接成功, 假如你已经使用 curl 连接上, 那么你远端的其它 IDE 就不能连接了.

我本地的 Eclipse 连接的过程是: 在菜单 Run 里面选择 Debug Configurations, 然后新建 Remote Java Application, 然后输入远程的 IP 和 端口. 如下:
remote_debug.png

连接后, Eclipse 会显示连接成功, 然后点击 暂停, 就会暂停远程的应用了.
debug_pause.png

debug 远程 tomcat 里面的应用

在 Tomcat 的 catalina.sh 里面, 添加如下环境变量设置:

export JPDA_ADDRESS=0.0.0.0:8000
export JPDA_TRANSPORT=dt_socket

然后启动时候, 添加 jdpa 参数, 就可以了

./catalina.sh jpda start

debug 远程基于 Spring boot 的应用

其实 Spring boot 是做的 fat jar, 它的远程debug 方式跟一般的应用是一样的, 就是在启动参数里面加上. 例子如下:

java -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=0.0.0.0:8000 -jar myApp.jar 

隧道技术

有时候远程机器隔着防火墙, 你不能直接连, 但是你可以通过 ssh 登录, 那么就可以用过隧道技术, 使用 ssh 做隧道, 然后远程 debug.
首先, 我们假设远程机器的 debug 开在 8000 端口上:

java -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=0.0.0.0:8000 -jar myApp.jar 

然后在本地机器上建立隧道:

ssh -L 5000:localhost:8000 user@remote_ip

这里的意思是: 在本地启动5000端口, 它所有的数据原封不动的转到远程 remote_ip 的8000 端口. 我们登录远程 remote_ip 的用户名是 user, 这里它会让你输入 ssh user 的密码. 连接成功后, 隧道建立.

这时候, 在本地和之前的一样, 只是把远程机器的ip 改成本地机器localhost, 端口改成 5000. 就能借助隧道进行远程 debug 了.

jps 无法显示 Java 进程号

对于 Java 应用的诊断, 一直以来都是使用 JDK 自带的 Jps 命令来查看 Java 进程 ID, 最近在一个生产环境的的某个 Kubernetes pod 里面 Jps 一直无法给出对应的进程 ID, 什么输出都没有.

I have no name!@mypod:~$ jps
I have no name!@mypod:~$

初步检查

在 JDK 里面, 很多小工具的命令都搬迁到 jcmd 命令, 如果 jcmd 命令不带任何参数, 其实就相当于 Jps 命令. 于是尝试 jcmd 命令, 结果是一样的.

I have no name!@mypod:~$ jcmd
I have no name!@mypod:~$

以前在 VM 时代, 遇到过类似的问题. 原因是当前运行 bash 的用户和对应的 Java 进程不属于同一个用户, 要切换到对应 Java 进程运行的用户才能看到该进程 ID. 但是这次当前 Bash 的用户和对应 Java 进程的用户本来就是同一个用户.

I have no name!@mypod:~$ ps aux
USER        PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
84289        53  1.7  1.5 48923744 6226704 ?    Sl   Dec02 527:44 /prod/app/jre/bin/java -Xms4096m -Xmx4096m myApp

I have no name!@mypod:~$ id
uid=84289 gid=84677 groups=84677

怀疑当前 pod 的 JDK 文件有啥特别设置(为了减小JDK 大小和不必要文件, 他们把 JDK bin 去掉了, 有需要的移动到了 /jre/bin/ 目录去了). 于是从本地复制一个同版本的 JDK 到目标 pod, 并解压使用, 发现 JpsJcmd 是一样的结果.

但是这时候发现, 如果给 jcmd 命令一个进程ID, 它就能正常运行, 只是无法发现当前 Pod 的其它 Java 进程.

I have no name!@mypod:~$ jcmd 53 help
53:
The following commands are available:
Compiler.CodeHeap_Analytics
GC.class_histogram
GC.finalizer_info
GC.heap_dump
GC.heap_info
GC.run
GC.run_finalization
Thread.print
...

进一步检查

这时候去 Google 了一下, 发现有人说要给 Jps 命令添加一个参数: -J-Djava.io.tmpdir=/tmp/ 告诉它临时文件夹所在的地方. 去试了一下, 发现没有任何改进.
https://stackoverflow.com/questions/3805376/jps-returns-no-output-even-when-java-processes-are-running

于是想使用源码 debug 一下, 于是找到 Jps 的代码: https://github.com/AdoptOpenJDK/openjdk-jdk11/blob/master/src/jdk.jcmd/share/classes/sun/tools/jps/Jps.java
其实就是2个类, 于是合并一下, 并入到一个类里面, 然后复制到到远程 pod 里面, 命名为: JpsTest.java

import java.util.*;
import java.io.*;
import java.net.*;
import sun.jvmstat.monitor.*;

/**
 * Application to provide a listing of monitorable java processes.
 *
 * @author Brian Doherty
 * @since 1.5
 */
public class JpsTest {

    private static Arguments arguments;

    public static void main(String[] args) {
        try {
            arguments = new Arguments(args);
        } catch (IllegalArgumentException e) {
            System.err.println(e.getMessage());
            Arguments.printUsage(System.err);
            System.exit(1);
        }

        if (arguments.isHelp()) {
            Arguments.printUsage(System.err);
            System.exit(0);
        }
    System.err.println(arguments.hostId());
        try {
            HostIdentifier hostId = arguments.hostId();
            MonitoredHost monitoredHost =
                    MonitoredHost.getMonitoredHost(hostId);
        System.err.println(monitoredHost);
            // get the set active JVMs on the specified host.
            Set<Integer> jvms = monitoredHost.activeVms();
        System.err.println(jvms);
            for (Integer jvm: jvms) {
                StringBuilder output = new StringBuilder();
                Throwable lastError = null;
        System.err.println(jvm);
                int lvmid = jvm;

                output.append(String.valueOf(lvmid));

                if (arguments.isQuiet()) {
                    System.out.println(output);
                    continue;
                }

                MonitoredVm vm = null;
                String vmidString = "//" + lvmid + "?mode=r";

                String errorString = null;

                try {
                    // Note: The VM associated with the current VM id may
                    // no longer be running so these queries may fail. We
                    // already added the VM id to the output stream above.
                    // If one of the queries fails, then we try to add a
                    // reasonable message to indicate that the requested
                    // info is not available.

                    errorString = " -- process information unavailable";
                    VmIdentifier id = new VmIdentifier(vmidString);
                    vm = monitoredHost.getMonitoredVm(id, 0);

                    errorString = " -- main class information unavailable";
                    output.append(' ').append(MonitoredVmUtil.mainClass(vm,
                            arguments.showLongPaths()));

                    if (arguments.showMainArgs()) {
                        errorString = " -- main args information unavailable";
                        String mainArgs = MonitoredVmUtil.mainArgs(vm);
                        if (mainArgs != null && mainArgs.length() > 0) {
                            output.append(' ').append(mainArgs);
                        }
                    }
                    if (arguments.showVmArgs()) {
                        errorString = " -- jvm args information unavailable";
                        String jvmArgs = MonitoredVmUtil.jvmArgs(vm);
                        if (jvmArgs != null && jvmArgs.length() > 0) {
                          output.append(' ')
                            .append(
                                // multi-line args are permitted
                                jvmArgs.replace("\n", "\\n").replace("\r", "\\r")
                            );
                        }
                    }
                    if (arguments.showVmFlags()) {
                        errorString = " -- jvm flags information unavailable";
                        String jvmFlags = MonitoredVmUtil.jvmFlags(vm);
                        if (jvmFlags != null && jvmFlags.length() > 0) {
                            output.append(' ').append(jvmFlags);
                        }
                    }

                    errorString = " -- detach failed";
                    monitoredHost.detach(vm);

                    System.out.println(output);

                    errorString = null;
                } catch (URISyntaxException e) {
                    // unexpected as vmidString is based on a validated hostid
                    lastError = e;
                    assert false;
                } catch (Exception e) {
                    lastError = e;
                } finally {
                    if (errorString != null) {
                        /*
                         * we ignore most exceptions, as there are race
                         * conditions where a JVM in 'jvms' may terminate
                         * before we get a chance to list its information.
                         * Other errors, such as access and I/O exceptions
                         * should stop us from iterating over the complete set.
                         */
                        output.append(errorString);
                        if (arguments.isDebug()) {
                            if ((lastError != null)
                                    && (lastError.getMessage() != null)) {
                                output.append("\n\t");
                                output.append(lastError.getMessage());
                            }
                        }
                        System.out.println(output);
                        if (arguments.printStackTrace()) {
                            lastError.printStackTrace();
                        }
                        continue;
                    }
                }
            }
        } catch (MonitorException e) {
            if (e.getMessage() != null) {
                System.err.println(e.getMessage());
            } else {
                Throwable cause = e.getCause();
                if ((cause != null) && (cause.getMessage() != null)) {
                    System.err.println(cause.getMessage());
                } else {
                    e.printStackTrace();
                }
            }
            System.exit(1);
        }
    }
}

/**
 * Class for processing command line arguments and providing method
 * level access to the command line arguments.
 *
 * @author Brian Doherty
 * @since 1.5
 */
class Arguments {

    private static final boolean debug = Boolean.getBoolean("jps.debug");
    private static final boolean printStackTrace = Boolean.getBoolean(
            "jps.printStackTrace");

    private boolean help;
    private boolean quiet;
    private boolean longPaths;
    private boolean vmArgs;
    private boolean vmFlags;
    private boolean mainArgs;
    private String hostname;
    private HostIdentifier hostId;

    public static void printUsage(PrintStream ps) {
      ps.println("usage: jps [--help]");
      ps.println("       jps [-q] [-mlvV] [<hostid>]");
      ps.println();
      ps.println("Definitions:");
      ps.println("    <hostid>:      <hostname>[:<port>]");
      ps.println("    -? -h --help -help: Print this help message and exit.");
    }

    public Arguments(String[] args) throws IllegalArgumentException {
        int argc = 0;

        if (args.length == 1) {
            if ((args[0].compareTo("-?") == 0)
                || (args[0].compareTo("-h")== 0)
                || (args[0].compareTo("--help")== 0)
                // -help: legacy.
                || (args[0].compareTo("-help")== 0)) {
              help = true;
              return;
            }
        }

        for (argc = 0; (argc < args.length) && (args[argc].startsWith("-"));
                argc++) {
            String arg = args[argc];

            if (arg.compareTo("-q") == 0) {
              quiet = true;
            } else if (arg.startsWith("-")) {
                for (int j = 1; j < arg.length(); j++) {
                    switch (arg.charAt(j)) {
                    case 'm':
                        mainArgs = true;
                        break;
                    case 'l':
                        longPaths = true;
                        break;
                    case 'v':
                        vmArgs = true;
                        break;
                    case 'V':
                        vmFlags = true;
                        break;
                    default:
                        throw new IllegalArgumentException("illegal argument: "
                                                           + args[argc]);
                    }
                }
            } else {
                throw new IllegalArgumentException("illegal argument: "
                                                   + args[argc]);
            }
        }

        switch (args.length - argc) {
        case 0:
            hostname = null;
            break;
        case 1:
            hostname = args[args.length - 1];
            break;
        default:
            throw new IllegalArgumentException("invalid argument count");
        }

        try {
            hostId = new HostIdentifier(hostname);
        } catch (URISyntaxException e) {
            IllegalArgumentException iae =
                    new IllegalArgumentException("Malformed Host Identifier: "
                                                 + hostname);
            iae.initCause(e);
            throw iae;
        }
    }
    public boolean isDebug() {
        return debug;
    }
    public boolean printStackTrace() {
        return printStackTrace;
    }
    public boolean isHelp() {
        return help;
    }
    public boolean isQuiet() {
        return quiet;
    }
    public boolean showLongPaths() {
        return longPaths;
    }
    public boolean showVmArgs() {
        return vmArgs;
    }
    public boolean showVmFlags() {
        return vmFlags;
    }
    public boolean showMainArgs() {
        return mainArgs;
    }
    public String hostname() {
        return hostname;
    }
    public HostIdentifier hostId() {
        return hostId;
    }
}

当前的 JDK 版本是17, 涉及JDK 内部类: sun.jvmstat.monitor, 所以需要特殊的编译运行命令:

# 编译
/tmp/jdk/bin/javac --add-exports jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED JpsTest.java
# 运行
/tmp/jdk/bin/java --add-exports jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED  JpsTest

在上面的类代码里面加入了几处打印信息, 发现对于 //localhost 给出的进程 ID 是一个空列表. 顺着代码去找, 发现这些代码: https://github.com/AdoptOpenJDK/openjdk-jdk11/blob/master/src/jdk.internal.jvmstat/share/classes/sun/jvmstat/perfdata/monitor/protocol/local/LocalVmManager.java#L129

仔细研究一下, 其实是从 临时文件夹去找特定的文件. 文件夹的命名习惯是: https://github.com/AdoptOpenJDK/openjdk-jdk11/blob/master/src/jdk.internal.jvmstat/share/classes/sun/jvmstat/perfdata/monitor/protocol/local/PerfDataFile.java#L61C54-L61C65

于是找到一个本地 Java 应用, 然后去对应的临时文件夹去找对应文件夹, 结果找到如下(本地运行在 container 里面的 Neo4j 的应用):
/tmp/hsperfdata_neo4j/7

hsperfdata_neo4j 是一个文件夹, 里面只有 7 这个文件, 它里面有很多该进程的元数据信息(截取部分如下):

�����7�R �8J0sun.rt._sync_Inflations@8J0sun.rt._sync_Deflations@J8sun.rt._sync_ContendedLockAttempts8J0sun.rt._sync_FutileWakeups0J(sun.rt._sync_Parks~8J0sun.rt._sync_Notificationsw8J0sun.rt._sync_MonExtant8J0sun.rt.createVmBeginTime�bs�8J0sun.rt.createVmEndTimebds�8J0sun.rt.vmInitDoneTime�cs�8J0java.threads.started*0J(java.threads.live'8J0java.threads.livePeak(0J(java.threads.daemon8J0sun.rt.safepointSyncTime�wJ0J(sun.rt.safepoints)8J0sun.rt.safepointTime�c�8J0sun.rt.applicationTimeߪ*DE�0J(sun.rt.jvmVersiopAB+sun.rt.jvmCapabilities11000000000000000000000000000000000000000000000000000000000000008J0java.cls.loadedClasses�(8J0java.cls.unloadedClasses@J8java.cls.sharedLoadedClasses�@J8java.cls.sharedUnloadedClasses0J(sun.cls.loadedBytes��G8J0sun.cls.unloadedBytes8J0sun.cls.sharedLoadedBytes�-8J0sun.cls.sharedUnloadedBytes0J(sun.cls.methodBytes��0J(sun.cls.timet�D[8J0sun.cls.classInitTime��*K8J0sun.cls.classInitTime.
......
sel@sun.classloader.parentDelegationTime8J0sun.classloader.findClasses@J8sun.classloader.findClassTimeHJ@sun.urlClassLoader.readClassBytesTime0J(sun.zip.zipFiles�8J0sun.zip.zipFile.openTime

于是想到对应的 pod 里面在 /tmp/目录新建了 /tmp/hsperfdata_test/53 空文件, 并再次运行 jps. 这次给出了 53 这个进程ID, 只不过没有更多信息.

I have no name!@mypod:~$ jps
53 -- process information unavailable

这时候才发现一开始就忽略了一个信息: 以前运行 Jps 的时候, 至少会出现当前 Jps 本身一行, 一般还有另外一个目标 Java 进程.

回过头来, 我们研究临时文件夹里面的这个文件夹: hsperfdata_neo4j, 它的后半部分其实是运行进程的用户名, 而一开始, 我们就看到我们在生产环境里面的, bash 给我们一直抱怨 I have no name!. 正是因为无法确认当前用户名, 只有用户ID, 才导致在临时目录的 hsperfdata_<user name> 无法创建出来, 最终导致 Jps 失效.

于是去问 chatGPT 关于临时文件夹里面的 hsperfdata_ 文件夹:

在 Java 进程运行的系统上,hsperfdata_ 开头的目录是用于存储 Java 虚拟机(JVM)性能数据的临时目录。这些目录和文件由 JVM 创建,用于支持 Java 性能监控和分析工具,例如 jstat。

这些文件的产生时机和机制:

创建时机:
当 JVM 启动时,它会在系统的临时目录中创建一个以 hsperfdata_ 开头的目录。这个目录的名称通常是 hsperfdata_<username>,其中 <username> 是运行 Java 进程的用户的用户名。
在这个目录中,JVM 会为每个 Java 进程创建一个性能数据文件,其文件名为该进程的 PID(进程标识符)。
创建机制:

JVM 使用这些文件来存储与进程相关的性能数据,例如内存使用情况、垃圾回收统计信息和线程状态等。
这些文件是通过共享内存的方式实现的,允许性能监控工具在不干扰 Java 应用程序运行的情况下访问这些数据。
这些文件在 JVM 进程终止时通常会被自动删除。不过,在某些情况下(例如非正常退出),这些文件可能会残留在系统中。

使用这些文件的工具:

jstat: Java 统计监控工具,用于显示 Java 应用程序的各种运行时统计信息。jstat 工具利用这些性能数据文件来获取 JVM 的性能指标。
其他可能使用这些数据文件的工具包括 jps(Java 进程状态工具)和 jconsole(Java 监控与管理控制台)。
这些性能数据文件对于调试和性能分析非常有用,但在某些情况下,可能需要手动清理残留的 hsperfdata_ 目录,特别是在非正常关闭的情况下。

所以, 正如之前 Google 到的那个问答一样, 最终原因是在临时文件夹下面无法创建出 hsperfdata_ 目录导致的. 这是在早期写 Java 性能监控和分析工具的人无法预料到竟然有的系统上面只能看到用户ID, 不能获得用户名.

由 ServiceLoader 引发的CPU 100%

最近遇到2次由于 ServiceLoader 引起的 CPU 100%, 导致业务线程不能正常运行.

什么是 Service Loader

Spring 里面有个核心的概念, 就是依赖注入: 我期望有个服务, 但是一开始我并不指定具体的实现类, 等到我真正需要的时候, 这个依赖根据运行时自动注入. 同样, JDK 6 也引入了一个一样的实现框架, 就是 ServiceLoader. 它的实现也很简单. 使用的方法如下:

ServiceLoader<ServiceAPI> serviceLoader =ServiceLoader.load(ServiceAPI.class);
Iterator<ServiceAPI> iterator = serviceLoader.iterator();
while (iterator.hasNext()) {
    ServiceAPI impl = iterator.next();
}

它的主要作用就是: 你需要那个服务的具体实现, 让我来帮你找, 可能找到一个或多个, 或找不到. 结果返回的是一个 Iterator.

如何找到具体的实现的?

如果某个 Jar 包提供某个服务的具体实现, 按照 JDK 定义的规则, 它就会在在 Jar 包的 META-INFO/services 文件夹提供一个名为某个service的文件, 文件的内容就是具体的实现类.
比如 xerceslmpl-x.x.x.jar 提供了 javax.xml.datatype.DatatypeFactory 的具体实现:
xerceslmpl.png

文件的内容就是本 jar 包里面的具体实现类的全名.
所以, 可以通过判断当前 jar 包里面的 META-INFO 文件夹下面是不是包含某个service 文件名来判断是不是有这个实现.

如何出问题的?

出问题的就是下面这行代码:

javax.xml.datatype.DatatypeFactory df = javax.xml.datatype.DatatypeFactory.newInstance();

就是要初始化一个xml 转换成 Java对象的类型工厂类, 如果去 JDK 里面查看这个类的源代码, 会发现其实它是一个抽象 Service. 运行时它有4种查找具体实现类的方法. 前2种都是通过配置, 第三种就是通过 ServiceLoader 去查找它的具体实现.

出问题的方式就是通过 ServiceLoader 的方式, 这种方式就是通过 ClassLoader 去查找所有的 Jar 包, 一个个去看有没有某个 jar 的 META-INFO/services 文件夹下面包含这么一个 service 的具体实现.

通常的实现的一个具体栈:

java.lang.Thread.State: RUNNABLE
    at java.util.zip.ZipCoder.getBytes(ZipCoder.java:77)
    at java.util.zip.ZipFile.getEntry(ZipFile.java:325)
    - locked <0x00000007157ac988> (a java.util.jar.JarFile)
    at java.util.jar.JarFile.getEntry(JarFile.java:253)
    at java.util.jar.JarFile.getJarEntry(JarFile.java:236)
    at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:1084)
    at sun.misc.URLClassPath$JarLoader.findResource(URLClassPath.java:1062)
    at sun.misc.URLClassPath$1.next(URLClassPath.java:281)
    at sun.misc.URLClassPath$1.hasMoreElements(URLClassPath.java:291)
    at java.net.URLClassLoader$3$1.run(URLClassLoader.java:609)
    at java.net.URLClassLoader$3$1.run(URLClassLoader.java:607)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader$3.next(URLClassLoader.java:606)
    at java.net.URLClassLoader$3.hasMoreElements(URLClassLoader.java:631)
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:45)
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:54)
    at java.util.ServiceLoader$LazyIterator.hasNextService(ServiceLoader.java:354)
    at java.util.ServiceLoader$LazyIterator.hasNext(ServiceLoader.java:393)
    at java.util.ServiceLoader$1.hasNext(ServiceLoader.java:474)
    at javax.xml.datatype.FactoryFinder$1.run(FactoryFinder.java:296)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.xml.datatype.FactoryFinder.findServiceProvider(FactoryFinder.java:292)
    at javax.xml.datatype.FactoryFinder.find(FactoryFinder.java:268)
    at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:144)

通过上面的栈, 我们可以看到, 它其实是到 jar 到文件里面去看有没有这个项目, 没有就继续查找下一个.
这种方式相对消耗CPU到, 因为每次都要查找所有的jar 包, 一个个去查看压缩jar里面有没有这个文件. 如果以线上项目有2百多个jar, 查找一次要消耗即使毫秒.

但是, 即便这样, 还打不到让CPU很高的程度.

如何推高 CPU 的?

如果大家查看上面的线程栈, 其实在遍历某个jar 之前, 外层的遍历其实是遍历一些 ClassLoader, 然后每个 ClassLoader 都会有一些 Jar, 然后再遍历这些 jar.
其实真正出问题的是在 TomcatEmbeddedWebappClassLoader 里面. 这个 ClassLoader 在遍历每个Jar 的时候, 如果没有对应的 service 具体实现的 META-INFO/services 文件, 它会抛出一个 FileNotFoundException, 既然有 Exception, 就会有回溯栈, 就会非常耗时, 甚至进入C 代码. 看下面的火焰图:
flame.png

Java 内存分析工具 MAT 使用技巧

本文列出作者在日常使用 Java 内存分析工具 MAT 的过程中用到的一些技巧

导出长字符串

有时候我们经常要从 heap 中复制出某些很长的字符串, 来观察它到底有哪些数据. 通常我们通过: 在某个字符串上点击右键 - Copy -> Value. 但是通常这个复制出的内容都有长度限制.

比如下面的例子, 我想从 HTTP request 的 HeapByteBuffer 复制出它已经读取请求的内容, 但是通过上面的方法只能复制出几千的字符:
copy.png

但是如果其内容远超这个数量, 拿到的就是部分数据, 根据部分数据可能得出错误的结论.
如何完全导出其内容?
在上面的菜单中选择 -> Save Value To File. 就能导出全部内容.

不过对于上面例子中的 HeapByteBuffer 要特别注意, 它是通过当前的位置(pos)来标记那里是有效数据的, pos 位置之后可能还有数据, 只不过是无效数据.

根据字段值分组统计

SQL 里面有 select * from table_0 group by column_0. 可是 OQL 里面却没有这个语句. 但是MAT 却提供了这样的功能.
根据下面的菜单栏, 就能找到 Group By Value 选项.
groupBy.png

然后填入你想分组的类名字和要分组的字段. 下面以 java.util.regex.PatternnormalizedPattern 来分组:
pattern.png

最终看到每个 normalizedPattern 的统计个数:

p_result.png

为什么一个简单的 Java 进程的 core dump 那么大

写了一个非常简单的 java main 函数, 然后运行, 然后做 core dump, 竟然发现 core dump 竟然有 6.6G.

Java 程序:

public class ErrorExample {
    public static void main(String[] args) throws InterruptedException {
        Thread.sleep(600000);
    }
}

做 core dump 和 2种不同的 heap dump.

gcore <pid>

$ ls -lah 
-rw-rw-r-- 1 supra supra 6.6G Apr 30 00:26 core.276268
-rw-rw-r-- 1 supra supra  67M Apr 30 00:26 core.276268.gz
-rw-rw-r-- 1 supra supra 1.3M Apr 30 01:02 heap.bin
-rw-rw-r-- 1 supra supra 334K Apr 30 01:02 heap.bin.gz
-rw------- 1 supra supra 2.8M Apr 30 01:01 heap.hprof
-rw------- 1 supra supra 855K Apr 30 01:01 heap.hprof.gz

上面分别是使用不同工具得到的不同 dump 及进一步压缩过后的:

  1. gcore 276268 得到 core.276268
  2. jhsdb jmap --binaryheap --pid 280038 得到 heap.bin
  3. jcmd 280038 GC.heap_dump heap.hprof 得到 heap.hprof.

可以看到 jhsdb 做出的最小, core dump 最大. 这很有可能是 JVM 保留了很多想用但是还没用到的内存.

查看JVM 当前使用的内存, 发现其实使用的很小:

$ jcmd 281746 GC.heap_info
281746:
 garbage-first heap   total 258048K, used 1744K [0x0000000707e00000, 0x0000000800000000)
  region size 1024K, 2 young (2048K), 0 survivors (0K)
 Metaspace       used 155K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 6K, capacity 386K, committed 512K, reserved 1048576K

然后查看使用的启动参数, 可以看到保留的最大的堆是将近4G(MaxHeapSize=4162846720), 保留的代码缓存区是240M(ReservedCodeCacheSize=251658240), 再加上其它, 比如 JDK 库, 元数据区等, 可能达到6G多.

$ jcmd 281746 VM.flags
281746:
-XX:CICompilerCount=4 -XX:ConcGCThreads=2 -XX:G1ConcRefinementThreads=8 -XX:G1HeapRegionSize=1048576 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=262144000 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=4162846720 -XX:MaxNewSize=2497708032 -XX:MinHeapDeltaBytes=1048576 -XX:NonNMethodCodeHeapSize=5836300 -XX:NonProfiledCodeHeapSize=122910970 -XX:ProfiledCodeHeapSize=122910970 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC

如果使用 pmap 查看这个进程的虚拟内存使用情况, 可以发现确实使用了6.6G(最后一行):

$ pmap -x 280038
280038:   java ErrorExample
Address           Kbytes     RSS   Dirty Mode  Mapping
0000000707e00000  256000     328     328 rw---   [ anon ]
0000000717800000 2758656       0       0 -----   [ anon ]
00000007c0000000 1048576       0       0 -----   [ anon ]
............ 省略 ....................
00007f39c513e000       8       8       0 r---- ld-linux-x86-64.so.2
00007f39c5178000       8       8       8 rw--- ld-linux-x86-64.so.2
00007ffc854ed000     132      32      32 rw---   [ stack ]
ffffffffff600000       4       0       0 --x--   [ anon ]
---------------- ------- ------- -------
total kB         6821276   37464   10660