湖南营销网站建设联系方式,2018年靖边建设项目招投标网站,只做男生穿搭的网站,head first wordpress 中文版一、使用 JDK 自带工具查看 JVM 情况 在我的机器上运行 ls 命令#xff0c;可以看到 JDK 8 提供了非常多的工具或程序#xff1a; 接下来#xff0c;我会与你介绍些常用的监控工具。你也可以先通过下面这张图了解下各种工具的基本作用#xff1a;
为了测试这些工具#x…一、使用 JDK 自带工具查看 JVM 情况 在我的机器上运行 ls 命令可以看到 JDK 8 提供了非常多的工具或程序 接下来我会与你介绍些常用的监控工具。你也可以先通过下面这张图了解下各种工具的基本作用
为了测试这些工具我们先来写一段代码启动 10 个死循环的线程每个线程分配一个 10MB 左右的字符串然后休眠 10 秒。可以想象到这个程序会对 GC 造成压力。
//启动10个线程
IntStream.rangeClosed(1, 10).mapToObj(i - new Thread(() - {while (true) {//每一个线程都是一个死循环休眠10秒打印10M数据String payload IntStream.rangeClosed(1, 10000000).mapToObj(__ - a).collect(Collectors.joining()) UUID.randomUUID().toString();try {TimeUnit.SECONDS.sleep(10);} catch (InterruptedException e) {e.printStackTrace();}System.out.println(payload.length());}
})).forEach(Thread::start);TimeUnit.HOURS.sleep(1); 修改 pom.xml配置 spring-boot-maven-plugin 插件打包的 Java 程序的 main 方法类
plugingroupIdorg.springframework.boot/groupIdartifactIdspring-boot-maven-plugin/artifactIdconfigurationmainClassorg.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication/mainClass/configuration
/plugin 然后使用 java -jar 启动进程设置 JVM 参数让堆最小最大都是 1GB
java -jar common-mistakes-0.0.1-SNAPSHOT.jar -Xms1g -Xmx1g
1、jps
首先使用 jps 得到 Java 进程列表这会比使用 ps 来的方便 ➜ ~ jps
12707
22261 Launcher
23864 common-mistakes-0.0.1-SNAPSHOT.jar
15608 RemoteMavenServer36
23243 Main
23868 Jps
22893 KotlinCompileDaemon
2、jinfo
然后可以使用 jinfo 打印 JVM 的各种参数
➜ ~ jinfo 23864
Java System Properties:
#Wed Jan 29 12:49:47 CST 2020
...
user.namezhuye
path.separator\:
os.version10.15.2
java.runtime.nameJava(TM) SE Runtime Environment
file.encodingUTF-8
java.vm.nameJava HotSpot(TM) 64-Bit Server VM
...VM Flags:
-XX:CICompilerCount4 -XX:ConcGCThreads2 -XX:G1ConcRefinementThreads8 -XX:G1HeapRegionSize1048576 -XX:GCDrainStackTargetSize64 -XX:InitialHeapSize268435456 -XX:MarkStackSize4194304 -XX:MaxHeapSize4294967296 -XX:MaxNewSize2576351232 -XX:MinHeapDeltaBytes1048576 -XX:NonNMethodCodeHeapSize5835340 -XX:NonProfiledCodeHeapSize122911450 -XX:ProfiledCodeHeapSize122911450 -XX:ReservedCodeCacheSize251658240 -XX:SegmentedCodeCache -XX:UseCompressedClassPointers -XX:UseCompressedOops -XX:UseG1GCVM Arguments:
java_command: common-mistakes-0.0.1-SNAPSHOT.jar -Xms1g -Xmx1g
java_class_path (initial): common-mistakes-0.0.1-SNAPSHOT.jar
Launcher Type: SUN_STANDARD 查看第 15 行和 19 行可以发现我们设置 JVM 参数的方式不对-Xms1g 和 -Xmx1g 这两个参数被当成了 Java 程序的启动参数整个 JVM 目前最大内存是 4GB 左右而不是 1GB。 当我们怀疑 JVM 的配置很不正常的时候要第一时间使用工具来确认参数。除了使用工具确认 JVM 参数外你也可以打印 VM 参数和程序参数
System.out.println(VM options);
System.out.println(ManagementFactory.getRuntimeMXBean().getInputArguments().stream().collect(Collectors.joining(System.lineSeparator())));
System.out.println(Program arguments);
System.out.println(Arrays.stream(args).collect(Collectors.joining(System.lineSeparator()))); 把 JVM 参数放到 -jar 之前重新启动程序可以看到如下输出从输出也可以确认这次 JVM 参数的配置正确了
➜ target git:(master) ✗ java -Xms1g -Xmx1g -jar common-mistakes-0.0.1-SNAPSHOT.jar test
VM options
-Xms1g
-Xmx1g
Program arguments
test
3、jvisualvm 启动另一个重量级工具 jvisualvm 观察一下程序可以在概述面板再次确认 JVM 参数设置成功了 继续观察监视面板可以看到JVM 的 GC 活动基本是 10 秒发生一次堆内存在 250MB 到 900MB 之间波动活动线程数是 22。我们可以在监视面板看到 JVM 的基本情况也可以直接在这里进行手动 GC 和堆 Dump 操作 4、jconsole 如果希望看到各个内存区的 GC 曲线图可以使用 jconsole 观察。jconsole 也是一个综合性图形界面监控工具比 jvisualvm 更方便的一点是可以用曲线的形式监控各种数据包括 MBean 中的属性值 5、jstat 同样如果没有条件使用图形界面毕竟在 Linux 服务器上我们主要使用命令行工具又希望看到 GC 趋势的话我们可以使用 jstat 工具。 jstat 工具允许以固定的监控频次输出 JVM 的各种监控指标比如使用 -gcutil 输出 GC 和内存占用汇总信息每隔 5 秒输出一次输出 100 次可以看到 Young GC 比较频繁而 Full GC 基本 10 秒一次
➜ ~ jstat -gcutil 23940 5000 100S0 S1 E O M CCS YGC YGCT FGC FGCT CGC CGCT GCT0.00 100.00 0.36 87.63 94.30 81.06 539 14.021 33 3.972 837 0.976 18.9680.00 100.00 0.60 69.51 94.30 81.06 540 14.029 33 3.972 839 0.978 18.9790.00 0.00 0.50 99.81 94.27 81.03 548 14.143 34 4.002 840 0.981 19.1260.00 100.00 0.59 70.47 94.27 81.03 549 14.177 34 4.002 844 0.985 19.1640.00 100.00 0.57 99.85 94.32 81.09 550 14.204 34 4.002 845 0.990 19.1960.00 100.00 0.65 77.69 94.32 81.09 559 14.469 36 4.198 847 0.993 19.6590.00 100.00 0.65 77.69 94.32 81.09 559 14.469 36 4.198 847 0.993 19.6590.00 100.00 0.70 35.54 94.32 81.09 567 14.763 37 4.378 853 1.001 20.1420.00 100.00 0.70 41.22 94.32 81.09 567 14.763 37 4.378 853 1.001 20.1420.00 100.00 1.89 96.76 94.32 81.09 574 14.943 38 4.487 859 1.007 20.4380.00 100.00 1.39 39.20 94.32 81.09 575 14.946 38 4.487 861 1.010 20.442 其中S0 表示 Survivor0 区占用百分比S1 表示 Survivor1 区占用百分比E 表示 Eden 区占用百分比O 表示老年代占用百分比M 表示元数据区占用百分比YGC 表示年轻代回收次数YGCT 表示年轻代回收耗时FGC 表示老年代回收次数FGCT 表示老年代回收耗时。 继续来到线程面板可以看到大量以 Thread 开头的线程基本都是有节奏的 10 秒运行一下其他时间都在休眠和我们的代码逻辑匹配 点击面板的线程 Dump 按钮可以查看线程瞬时的线程栈 6、jstack 通过命令行工具 jstack也可以实现抓取线程栈的操作
➜ ~ jstack 23940
2020-01-29 13:08:15
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.312-LTS mixed mode):...main #1 prio5 os_prio31 cpu440.66ms elapsed574.86s tid0x00007ffdd9800000 nid0x2803 waiting on condition [0x0000700003849000]java.lang.Thread.State: TIMED_WAITING (sleeping)at java.lang.Thread.sleep(java.base11.0.3/Native Method)at java.lang.Thread.sleep(java.base11.0.3/Thread.java:339)at java.util.concurrent.TimeUnit.sleep(java.base11.0.3/TimeUnit.java:446)at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.main(CommonMistakesApplication.java:41)at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base11.0.3/Native Method)at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base11.0.3/NativeMethodAccessorImpl.java:62)at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base11.0.3/DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(java.base11.0.3/Method.java:566)at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)at org.springframework.boot.loader.Launcher.launch(Launcher.java:51)at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:52)Thread-1 #13 prio5 os_prio31 cpu17851.77ms elapsed574.41s tid0x00007ffdda029000 nid0x9803 waiting on condition [0x000070000539d000]java.lang.Thread.State: TIMED_WAITING (sleeping)at java.lang.Thread.sleep(java.base11.0.3/Native Method)at java.lang.Thread.sleep(java.base11.0.3/Thread.java:339)at java.util.concurrent.TimeUnit.sleep(java.base11.0.3/TimeUnit.java:446)at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.lambda$null$1(CommonMistakesApplication.java:33)at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication$$Lambda$41/0x00000008000a8c40.run(Unknown Source)at java.lang.Thread.run(java.base11.0.3/Thread.java:834)... 抓取后可以使用类似fastthread这样的在线分析工具来分析线程栈。
7、jcmd 我们来看一下 Java HotSpot 虚拟机的 NMT 功能。 通过 NMT我们可以观察细粒度内存使用情况设置 -XX:NativeMemoryTrackingsummary/detail 可以开启 NMT 功能开启后可以使用 jcmd 工具查看 NMT 数据。 我们重新启动一次程序这次加上 JVM 参数以 detail 方式开启 NMT
-Xms1g -Xmx1g -XX:ThreadStackSize256k -XX:NativeMemoryTrackingdetail 在这里我们还增加了 -XX:ThreadStackSize 参数并将其值设置为 256k也就是期望把线程栈设置为 256KB。我们通过 NMT 观察一下设置是否成功。 启动程序后执行如下 jcmd 命令以概要形式输出 NMT 结果。可以看到当前有 32 个线程线程栈总共保留了差不多 4GB 左右的内存。我们明明配置线程栈最大 256KB 啊为什么会出现 4GB 这么夸张的数字呢到底哪里出了问题呢
➜ ~ jcmd 24404 VM.native_memory summary
24404:Native Memory Tracking:Total: reserved6635310KB, committed5337110KB
- Java Heap (reserved1048576KB, committed1048576KB)(mmap: reserved1048576KB, committed1048576KB)- Class (reserved1066233KB, committed15097KB)(classes #902)(malloc9465KB #908)(mmap: reserved1056768KB, committed5632KB)- Thread (reserved4209797KB, committed4209797KB)(thread #32)(stack: reserved4209664KB, committed4209664KB)(malloc96KB #165)(arena37KB #59)- Code (reserved249823KB, committed2759KB)(malloc223KB #730)(mmap: reserved249600KB, committed2536KB)- GC (reserved48700KB, committed48700KB)(malloc10384KB #135)(mmap: reserved38316KB, committed38316KB)- Compiler (reserved186KB, committed186KB)(malloc56KB #105)(arena131KB #7)- Internal (reserved9693KB, committed9693KB)(malloc9661KB #2585)(mmap: reserved32KB, committed32KB)- Symbol (reserved2021KB, committed2021KB)(malloc1182KB #334)(arena839KB #1)- Native Memory Tracking (reserved85KB, committed85KB)(malloc5KB #53)(tracking overhead80KB)- Arena Chunk (reserved196KB, committed196KB)(malloc196KB) 重新以 VM.native_memory detail 参数运行 jcmd
jcmd 24404 VM.native_memory detail 有 16 个可疑线程每一个线程保留了 262144KB 内存也就是 256MB通过下图红框可以看到使用关键字 262144KB for Thread Stack from 搜索到了 16 个结果 ThreadStackSize 参数的单位是 KB所以我们如果要设置线程栈 256KB那么应该设置 256 而不是 256k。重新设置正确的参数后使用 jcmd 再次验证下 除了用于查看 NMT 外jcmd 还有许多功能。我们可以通过 help看到它的所有功能
jcmd 24781 help 对于其中每一种功能我们都可以进一步使用 help 来查看介绍。比如使用 GC.heap_info 命令可以打印 Java 堆的一些信息
jcmd 24781 help GC.heap_info
二、使用 Wireshark 分析 SQL 批量插入慢的问题 首先我们可以在这里下载 Wireshark启动后选择某个需要捕获的网卡。由于我们连接的是本地的 MySQL因此选择 loopback 回环网卡 然后Wireshark 捕捉这个网卡的所有网络流量。我们可以在上方的显示过滤栏输入 tcp.port 6657来过滤出所有 6657 端口的 TCP 请求因为我们是通过 6657 端口连接 MySQL 的。 可以看到程序运行期间和 MySQL 有大量交互。因为 Wireshark 直接把 TCP 数据包解析为了 MySQL 协议所以下方窗口可以直接显示 MySQL 请求的 SQL 查询语句。我们看到testuser 表的每次 insert 操作插入的都是一行记录 如果列表中的 Protocol 没有显示 MySQL 的话你可以手动点击 Analyze 菜单的 Decode As 菜单然后加一条规则把 6657 端口设置为 MySQL 协议 这就说明我们的程序并不是在做批量插入操作和普通的单条循环插入没有区别。调试程序进入 ClientPreparedStatement 类可以看到执行批量操作的是 executeBatchInternal 方法。 优化方式: 如果有条件的话优先把 insert 语句优化为一条语句也就是 executeBatchedInserts 方法 如果不行的话再尝试把 insert 语句优化为多条语句一起提交也就是 executePreparedBatchAsMultiStatement 方法。
三、使用 MAT 分析 OOM 问题 对于排查 OOM 问题、分析程序堆内存使用情况最好的方式就是分析堆转储。 Java 的 OutOfMemoryError 是比较严重的问题需要分析出根因所以对生产应用一般都会这样设置 JVM 参数方便发生 OOM 时进行堆转储
-XX:HeapDumpOnOutOfMemoryError -XX:HeapDumpPath.
1、使用 MAT 分析 OOM 问题一般可以按照以下思路进行 ① 通过支配树功能或直方图功能查看消耗内存最大的类型来分析内存泄露的大概原因 ② 查看那些消耗内存最大的类型、详细的对象明细列表以及它们的引用链来定位内存泄露的具体点 ③ 配合查看对象属性的功能可以脱离源码看到对象的各种属性的值和依赖关系帮助我们理清程序逻辑和参数 ④ 辅助使用查看线程栈来看 OOM 问题是否和过多线程有关甚至可以在线程栈看到 OOM 最后一刻出现异常的线程。
三、使用 Arthas 分析高 CPU 问题 1、首先通过 dashboard thread 命令基本可以在几秒钟内一键定位问题找出消耗 CPU 最多的线程和方法栈 2、然后直接 jad 反编译相关代码来确认根因 3、此外如果调用入参不明确的话可以使用 watch 观察方法入参并根据方法执行时间来过滤慢请求的入参。
