# 调优实战-常用工具

# 案例

# 测试代码

package com.mashibing.jvm.gc;

import java.math.BigDecimal;
import java.util.ArrayList;
import java.util.Date;
import java.util.List;
import java.util.concurrent.ScheduledThreadPoolExecutor;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * 从数据库中读取信用数据,套用模型,并把结果进行记录和传输
 */
public class T15_FullGC_Problem01 {

    private static class CardInfo {
        BigDecimal price = new BigDecimal(0.0);
        String name = "张三";
        int age = 5;
        Date birthdate = new Date();

        public void m() {}
    }

    private static ScheduledThreadPoolExecutor executor = new ScheduledThreadPoolExecutor(50,
            new ThreadPoolExecutor.DiscardOldestPolicy());

    public static void main(String[] args) throws Exception {
        executor.setMaximumPoolSize(50);

        for (;;){
            modelFit();
            Thread.sleep(100);
        }
    }

    private static void modelFit(){
        List<CardInfo> taskList = getAllCardInfo();
        taskList.forEach(info -> {
            // do something
            executor.scheduleWithFixedDelay(() -> {
                //do sth with info
                info.m();

            }, 2, 3, TimeUnit.SECONDS);
        });
    }

    private static List<CardInfo> getAllCardInfo(){
        List<CardInfo> taskList = new ArrayList<>();

        for (int i = 0; i < 100; i++) {
            CardInfo ci = new CardInfo();
            taskList.add(ci);
        }

        return taskList;
    }
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60

# 排查过程

# 启动项目

运行项目启动命令如下.

java -Xms200M -Xmx200M -XX:+PrintGC com/mashibing/jvm/c5_gc/T15_FullGC_Problem01

# 1. 查找问题进程

top 命令

一般是运维团队首先受到报警信息(CPU Memory)

top 命令观察到问题:内存不断增长 CPU占用率居高不下

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
12647 root      20   0 2244588 133860  11992 S  9.7 13.2   0:14.58 java
    1 root      20   0  128128   6084   3480 S  0.0  0.6   0:01.61 systemd
    2 root      20   0       0      0      0 S  0.0  0.0   0:00.00 kthreadd
1
2
3
4

# 2. 查找问题线程

top -Hp [PID] 命令查看具体是哪个线程的问题

注意: 这里的 12647 是上第一步获取到的进程的 pid

top - 23:14:26 up  1:06,  4 users,  load average: 0.04, 0.05, 0.05
Threads:  60 total,   1 running,  59 sleeping,   0 stopped,   0 zombie
%Cpu(s):  2.9 us,  0.7 sy,  0.0 ni, 96.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1014972 total,    69604 free,   317508 used,   627860 buff/cache
KiB Swap:   839676 total,   839412 free,      264 used.   531876 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
12657 root      20   0 2244588 150752  11996 R  7.0 14.9   0:12.48 java
12661 root      20   0 2244588 150752  11996 S  0.3 14.9   0:00.26 java
12662 root      20   0 2244588 150752  11996 S  0.3 14.9   0:00.24 java
1
2
3
4
5
6
7
8
9
10

# 3. 具体定位

jps 查看系统中执行的 java 进程 (和系统的 ps 命令类似, 不同的是此命令只会列出 Java 的进程,)

jstack [PID] 查看进程中所有线程的执行信息,

通过 jstack 命令可以查看进程中所有线程的执行信息,

执行 jstack 12647 得到输出结果如下,

如果想把第二步中的 PID 和此处的 nid 对应起来, 需要把 PID 转成16进制

jstack 定位线程状况,重点关注:WAITING BLOCKED

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.271-b09 mixed mode):

"Attach Listener" #58 daemon prio=9 os_prio=0 tid=0x00007f7210003000 nid=0x3281 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"pool-1-thread-50" #57 prio=5 os_prio=0 tid=0x00007f7238164800 nid=0x3241 waiting on condition [0x00007f72078f7000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000f8be4578> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
...
...
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

# 4. 信息解读

从第三步中获取的信息需要关注的内容

如 L6 中waiting on condition [0x00007f72078f7000] (a java.lang.Object) 等待某把锁的释放.

假如有一个进程中100个线程,很多线程都在waiting on <xx>,一定要找到是哪个线程持有这把锁

# 怎么找

搜索 jstack dump 的信息,找 <xx> ,看哪个线程持有这把锁 RUNNABLE

如下面程序, 执行后只有线程 MyThread-01 会获取到锁, 其他的线程都会等待

private static Object lock1 = new Object();
public static void main(String[] args) throws InterruptedException {
    new Thread(() -> {
        synchronized (lock1) {
            System.out.println(Thread.currentThread().getName() + " get lock1");
            for(;;){}
        }
    }, "MyThread-01").start();

    Thread.sleep(10);

    for(int i = 0; i < 5; i++) {
        new Thread(() -> {
            synchronized (lock1) {
                System.out.println(Thread.currentThread().getName() + " get lock1");
            }
        }, "Other-Thread-" + i).start();
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

上面例子中就会出现

...
"Other-Thread-1" #10 prio=5 os_prio=0 tid=0x00007f33c40fa000 nid=0x5f0 waiting for monitor entry [0x00007f33c97af000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.mashibing.jvm.c5_gc.Deadlock.lambda$main$1(Deadlock.java:28)
	- waiting to lock <0x00000000f085fbb0> (a java.lang.Object)
	at com.mashibing.jvm.c5_gc.Deadlock$$Lambda$2/303563356.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

"Other-Thread-0" #9 prio=5 os_prio=0 tid=0x00007f33c40f8000 nid=0x5ef waiting for monitor entry [0x00007f33c98b0000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.mashibing.jvm.c5_gc.Deadlock.lambda$main$1(Deadlock.java:28)
	- waiting to lock <0x00000000f085fbb0> (a java.lang.Object)
	at com.mashibing.jvm.c5_gc.Deadlock$$Lambda$2/303563356.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

"MyThread-01" #8 prio=5 os_prio=0 tid=0x00007f33c40f6800 nid=0x5ee runnable [0x00007f33c99b1000]
   java.lang.Thread.State: RUNNABLE
	at com.mashibing.jvm.c5_gc.Deadlock.lambda$main$0(Deadlock.java:11)
	- locked <0x00000000f085fbb0> (a java.lang.Object)
	at com.mashibing.jvm.c5_gc.Deadlock$$Lambda$1/471910020.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21

通过上面日志我们可以发现, MyThread-01 拿到了锁(L19), 而其他的线程都在等待 (L5, L12),

所以我们就能定位 locked <0x00000000f085fbb0> 这把锁有问题.

为什么阿里规范里规定,线程的名称(尤其是线程池)都要写有意义的名称

怎么样自定义线程池里的线程名称?(自定义ThreadFactory)

# 常见问题

# 频繁GC问题

  1. jinfo [PID] 查看进程的相信信息

  2. 查看 GC 情况

    1. jstat -gc [PID] 动态观察gc情况

      jstat -gc 4655 500 : 每个500个毫秒打印GC的情况

    2. jvisualVM

    3. jconsole 桌面化的, 可远程

    4. Jprofiler (号称最好用)

    如果面试官问你是怎么定位OOM问题的?

    如果你回答用图形界面(错误)

    1. 已经上线的系统不用图形界面用什么?

      cmdline 或 arthas

    2. 图形界面到底用在什么地方?

      测试!测试的时候进行监控!(压测观察)

# OOM问题

  1. 通过 jmap -histo [PID] | head -20 查找有多少对象产生.

  2. 堆转储, 通过命令jmap -dump:format=b,file=[test.hprof] [pid]转存成文件再做分析

    线上系统,内存特别大,jmap执行期间会对进程产生很大影响,甚至卡顿(电商不适合)

    1. 设定了参数 HeapDump,OOM 的时候会自动产生堆转储文件
    2. 很多服务器备份(高可用),停掉这台服务器对其他服务器不影响
    3. 在线定位 - arthas (一般小点儿公司用不到)
  3. dump文件分析

    使用 MAT / jhat / jvisualvm 进行 https://www.cnblogs.com/baihuitestsoftware/articles/6406271.html

    • jvisualvm 解析

      打开后, 选择装入快照然后选择文件

    • jhat 解析

    jhat -J-mx512M xxx.dump

    分析完成后可以在 http://localhost:7000 查看结果

    拉到最后:找到对应链接 可以使用OQL查找特定问题对象

  4. 找到代码的问题

# 排查工具

# jconsole远程连接

开始连接前, 需要先开启 JMX

  1. 程序启动加入参数:

    java \
    -Djava.rmi.server.hostname=192.168.31.233 \
    -Dcom.sun.management.jmxremote \
    -Dcom.sun.management.jmxremote.port=11111 \
    -Dcom.sun.management.jmxremote.authenticate=false \
    -Dcom.sun.management.jmxremote.ssl=false \
    -Xms200M -Xmx200M -XX:+PrintGC \
    com/mashibing/jvm/c5_gc/T15_FullGC_Problem01
    
    1
    2
    3
    4
    5
    6
    7
    8
  2. 如果遭遇 Local host name unknown:XXX的错误,修改/etc/hosts文件,把XXX加入进去

    192.168.17.11 basic localhost localhost.localdomain localhost4 localhost4.localdomain4
    ::1         localhost localhost.localdomain localhost6 localhost6.localdomain6
    
    1
    2
  3. 打开 jconsole 选择远程连接

# jvisualvm远程连接

https://www.cnblogs.com/liugh/p/7620336.html (简单做法)

# jprofiler (收费)

# arthas在线排查工具

文档地址 简单使用可以看 快速入门

为什么需要在线排查? 在生产上我们经常会碰到一些不好排查的问题,例如线程安全问题,用最简单的threaddump或者heapdump不好查到问题原因。

为了排查这些问题,有时我们会临时加一些日志,比如在一些关键的函数里打印出入参,然后重新打包发布,如果打了日志还是没找到问题,继续加日志,重新打包发布。对于上线流程复杂而且审核比较严的公司,从改代码到上线需要层层的流转,会大大影响问题排查的进度。

# 常用命令

  • jvm 观察jvm信息

  • thread 定位线程问题

  • dashboard 观察系统情况

  • heapdump 导出 dump 文件(作用跟 jmap -dump:xxx 类似), 然后使用 jhat 分析

  • jad 反编译

    动态代理生成类的问题定位 第三方的类(观察代码) 版本问题(确定自己最新提交的版本是不是被使用)

  • redefine 热替换 目前有些限制条件:只能改方法实现(方法已经运行完成),不能改方法名, 不能改属性 m() -> mm()

  • sc - search class

  • watch - watch method

  • 没有包含的功能:jmap

上次更新时间: 2020/11/17 上午12:35:40