JAVA性能排查方式与工具

655 阅读5分钟

1. FullGC频繁问题复盘-不可达内存高

线上出现堆内存不断提高,到4个G(设置的最大内存为4个G);触发fullGC后,降低,再重新提高。 下载dump文件mat分析后,发现对内存使用只用350M,使用的内存去哪里了,mat中有一项是 Unreachable Objects,发现占用了3G多,去除基本类型后,大部分是com.alibaba.druid.stat.JdbcSqlStat使用的 查阅相关资料,是因为sqlStatMap.put(sql, sqlStat);JdbcSqlStat是被一个Map持有,大对象直接回存入老年代,所以fullGC才会触发。

解决方案:关闭druid的监控功能,注释掉下边配置

<property name="filters" value="stat" />

原因分析:

大对象直接进入老年区[old],积累越来越多,最终触发fullGC;Youg gc清理eden和survivor,不会清理老年代;

2. CPU占用高造成网络重传高问题复盘

我们的系统有个worker类应用,通过远端RPC调用对方服务,我们的服务器并不多,调用量也比较恒定;对方反馈TCP重传比较高,当时我认为应该和我们没有关系,因为我们的服务器数量远远小于服务提供方服务器数量,我们这点量对于服务提供方根本不算什么;

原因: 经过验证,最后真的是我们系统的问题。

原因分析: 我们系统的Worker通过多线程来做固定任务,为了节省服务器,我们服务器并不多,通过多线程把CPU利用的很高(80%+),如果cpu利用过高,那么就会有任务排队,会造成一些和服务器连接的任务来不及处理,这样可能会把服务端拖死,现象为网络重传高。

借鉴: 不管是服务端,还是客户端,最好都不要把CPU打的过高,可能会把对方拖死。

3. JAVA的CPU过高问题排查

执行模拟程序

本文中,我们会通过测试程序模拟java占用CPU过高,然后通过工具排查出原因。环境:jdk8 centos7。

测试程序如下MaxCpuMain.java,模拟了一个高耗CPU线程,5个低耗CPU线程:

import java.util.concurrent.TimeUnit;

public class MaxCpuMain {
    public static void main(String[] args) throws InterruptedException {
        new Thread(() -> {
            runMaxCpuCal();
        }).start();

        for (int i = 0; i < 5; i++) {
            new Thread(() -> {
                runMinCpuCal();
            }).start();
        }

        while (true) {
            Thread.sleep(100);
        }
    }

    public static void runMaxCpuCal() {
        long count = 0;
        while (true) {
            count++;
            double a = Integer.MAX_VALUE + Math.random() * Integer.MAX_VALUE;
            long b = ("sdf" + a).hashCode();
            if (count % (10000 * 10000) == 0) {
                System.out.println("runMaxCpuCal run" + count);
            }
        }
    }

    public static void runMinCpuCal() {
        long count = 0;
        while (true) {
            count++;
            try {
                TimeUnit.SECONDS.sleep(1);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            if (count % (30) == 0) {
                System.out.println("runMinCpuCal run" + count);
            }
        }
    }
}

编译运行程序:

[root@centos-7 test]# javac MaxCpuMain.java 
[root@centos-7 test]# java MaxCpuMain
runMinCpuCal run30
runMinCpuCal run30
runMinCpuCal run30
runMinCpuCal run30
runMinCpuCal run30
runMaxCpuCal run100000000

1. TOP确定进程PID

通过top(输入大写P按cpu排序)查占用CPU多的pid;查到进程2505。

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND     
 2505 root      20   0 2141720  34020  12112 S 98.3  5.8   2:01.56 java        
    1 root      20   0  128204   4992   3136 S  0.0  0.9   0:01.16 systemd     
    2 root      20   0       0      0      0 S  0.0  0.0   0:00.00 kthreadd    
    3 root      20   0       0      0      0 S  0.0  0.0   0:00.04 ksoftirqd/0 
    4 root      20   0       0      0      0 S  0.0  0.0   0:00.00 kworker/0:0 
    5 root       0 -20       0      0      0 S  0.0  0.0   0:00.00 kworker/0:0H
    6 root      20   0       0      0      0 S  0.0  0.0   0:00.00 kworker/u64+
    7 root      rt   0       0      0      0 S  0.0  0.0   0:00.00 migration/0 
    8 root      20   0       0      0      0 S  0.0  0.0   0:00.00 rcu_bh   

2. TOP确认线程Id

通过进程pid查看占用CPU高的线程, top -Hp 2505,查到2515线程

top -Hp 2505
  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND     
 2515 root      20   0 2141720  11976    576 S 89.4  2.1   4:28.63 java        
 2507 root      20   0 2141720  11976    576 R  6.3  2.1   0:14.82 java        
 2505 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.00 java        
 2506 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.16 java        
 2508 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.00 java        
 2509 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.00 java        
 2510 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.00 java        
 2511 root      20   0 2141720  11976    576 S  0.0  2.1   0:00.10 java        
  

3. jstack确定代码

首先转换出线程id的16进制

 printf '%x' 2515
 9d3

从线程堆栈中追查是哪个线程,执行jstack2505,并在结果搜索9d3线程。

jstack 2505

太长,只列出部分

"Thread-1" #9 prio=5 os_prio=0 tid=0x00007fc1ac0f8800 nid=0x9d4 waiting on condition [0x00007fc1b0d2a000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at java.lang.Thread.sleep(Thread.java:340)
	at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
	at MaxCpuMain.runMinCpuCal(MaxCpuMain.java:37)
	at MaxCpuMain.lambda$main$1(MaxCpuMain.java:11)
	at MaxCpuMain$$Lambda$2/303563356.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

"Thread-0" #8 prio=5 os_prio=0 tid=0x00007fc1ac0f6800 nid=0x9d3 runnable [0x00007fc1b0e2b000]
   java.lang.Thread.State: RUNNABLE
	at sun.misc.FloatingDecimal$BinaryToASCIIBuffer.access$100(FloatingDecimal.java:259)
	at sun.misc.FloatingDecimal.getBinaryToASCIIConverter(FloatingDecimal.java:1785)
	at sun.misc.FloatingDecimal.getBinaryToASCIIConverter(FloatingDecimal.java:1738)
	at sun.misc.FloatingDecimal.appendTo(FloatingDecimal.java:89)
	at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:736)
	at java.lang.StringBuilder.append(StringBuilder.java:226)
	at MaxCpuMain.runMaxCpuCal(MaxCpuMain.java:25)
	at MaxCpuMain.lambda$main$0(MaxCpuMain.java:6)
	at MaxCpuMain$$Lambda$1/471910020.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007fc1ac0b5000 nid=0x9d1 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

从下面的堆栈中查找9d3,可以得知MaxCpuMain.runMaxCpuCal(MaxCpuMain.java:25)是耗费性能的代码。

附1:Centos 安装Jdk过程

本文使用系统为centos7,jdk版本为jdk8。

下载解压JDK

oracle官网下载jdk,本文下载的jdk-8u271-linux-x64.tar.gz

创建安装目录,本文安装在/export下,进入export:

cd /export/

解压:

tar -zxvf jdk-8u271-linux-x64.tar.gz

设置环境变量

使用vi /etc/profile编辑profile文件

在/etc/profile底部加入如下内容

JAVA_HOME=/export/jdk1.8.0_271
JRE_HOME=/export/jdk1.8.0_271/jre
CLASSPATH=.:$JAVA_HOME/lib:/dt.jar:$JAVA_HOME/lib/tools.jar
PATH=$JAVA_HOME/bin:$PATH
export PATH=$PATH:/usr/local/go/bin
export  JAVA_HOME
export  JRE_HOME
export  CLASSPATH
export  PATH

环境变量生效:

source /etc/profile

测试

执行命令,测试安装成功:

[root@centos-7 Downloads]# java -version
java version "1.8.0_271"
Java(TM) SE Runtime Environment (build 1.8.0_271-b09)
Java HotSpot(TM) 64-Bit Server VM (build 25.271-b09, mixed mode)

扩展知识:为什么需要设置环境变量?

我们最后再命令行执行的命令java -version,系统怎么知道从哪里执行这个命令呢?答案就是环境变量,系统会从环境变量指定的路径中按顺序寻找java命令,然后执行,所以我们设置PATH=$JAVA_HOME/bin环境变量后,就可以再任何路径下执行/bin下的所有命令。