为什么要介绍使用这个工具？ 我们在性能调优的过程中， 比如GC优化过程， 想观察进程卡顿情况，就可以使用jHiccup。ZGC号称卡顿控制在10ms以内， 怎么客观地看到这个数字呢，使用jHiccup就可以做到这一点。
1 jHiccup简介
jHiccup是一个开源工具，用于测量与应用程序底层Java运行时平台相关的暂停和停滞(或“hiccups”)。这个新工具捕获Java虚拟机(JVM)、操作系统、管理程序(如果使用的话)和硬件对应用程序停滞和响应时间的总体影响。
jHiccup允许开发人员、系统操作员和性能工程师轻松地创建和分析响应时间配置文件，并清楚地确定应用程序延迟的原因是驻留在应用程序代码还是底层运行时平台中。jHiccup对应用程序是完全透明和非侵入性的，在操作中没有任何性能开销，并且与使用任何JVM的所有Java应用程序兼容。 jHiccup允许开发人员、系统操作员和性能工程师轻松地创建和分析响应时间配置文件，并清楚地确定应用程序延迟的原因是驻留在应用程序代码还是底层运行时平台中。jHiccup对应用程序是完全透明和非侵入性的，在操作中没有任何性能开销，并且与使用任何JVM的所有Java应用程序兼容。
通过一段代码来分析下它的原理，它通过启动一个线程来记录自从上次休眠以来的时间间隔。这个线程会休眠一毫秒（默认，可配置），然后醒来，记录自从上次醒来的时间，并重复这个过程。这里的关键是理解“hiccup”是指那些超出正常或预期的停顿。如果所有的停顿都恰好是100毫秒，那么系统运行得很平稳，没有额外的停顿发生，因此没有“hiccup”需要记录。这种设计是为了捕捉那些比正常操作更慢的异常停顿，而不是记录性能改善或者正常波动的情况。
public void run() {
final long resolutionNsec = (long)(config.resolutionMs * 1000L * 1000L);
try {
long shortestObservedDeltaTimeNsec = Long.MAX_VALUE;
long timeBeforeMeasurement = Long.MAX_VALUE;
while (doRun) {
if (config.resolutionMs != 0) {
TimeUnit.NANOSECONDS.sleep(resolutionNsec);
if (allocateObjects) {
// Allocate an object to make sure potential allocation stalls are measured.
lastSleepTimeObj = new Long(timeBeforeMeasurement);
}
}
final long timeAfterMeasurement = System.nanoTime();
final long deltaTimeNsec = timeAfterMeasurement - timeBeforeMeasurement;
timeBeforeMeasurement = timeAfterMeasurement;
if (deltaTimeNsec < 0) {
// On the very first iteration (which will not time the loop in it's entirety)
// the delta will be negative, and we'll skip recording.
continue;
}
if (deltaTimeNsec < shortestObservedDeltaTimeNsec) {
shortestObservedDeltaTimeNsec = deltaTimeNsec;
}
long hiccupTimeNsec = deltaTimeNsec - shortestObservedDeltaTimeNsec;
recorder.recordValueWithExpectedInterval(hiccupTimeNsec, resolutionNsec);
}
} catch (InterruptedException e) {
if (config.verbose) {
log.println("# HiccupRecorder interrupted/terminating...");
}
}
}
2 使用指南
2.1 下载jHiccup
从Azul官网下载jHiccup。下载后，解压缩文件，你会找到 jHiccup.jar
2.2 使用 jHiccup 运行程序
java -javaagent:<path-to-jHiccup.jar> -jar your-app.jar
2.3 配置 jHiccup
- -d：开始记录前的延迟时间(毫秒)
- -i：报告间隔（默认为 5000 毫秒）
- -l：日志文件名称
- -c：启动一个控制进程(一个单独的java进程)，记录操作系统和硬件的影响，默认不启用
例如：
java -javaagent:path/to/jHiccup.jar="-c -l hiccuplog" -jar your-app.jar
2.4 生成日志文件
运行应用程序后，jHiccup 会生成日志文件，文件名由 -l 参数指定。不指定的话， 文件名称即是hiccuplog，如何有-c参数，还会生成一个hiccuplog.c
2.5 日志解析
2.5.1 方式1
从github上下载HistogramLogAnalyzer代码， 编译构建mvn clean package，运行即可。将生成的hiccuplog拖入其中，即可看到图形。
2.5.2 方式2
使用jHiccup自带的工具(在jHiccup解压包里)
% jHiccupLogProcessor -i hiccuplog -o mylog
生成可读的文件内容如下， 可与上述图形中的数据进行对比
#[Interval percentile log between 0.000 and <Infinite> seconds (relative to StartTime)]
#[StartTime: 1725875182.187 (seconds since epoch), Mon Sep 09 17:46:22 CST 2024]
Time: IntervalPercentiles:count ( 50% 90% Max ) TotalPercentiles:count ( 50% 90% 99% 99.9% 99.99% Max )
5.182: I:4408 ( 0.066 0.393 13.828 ) T:4408 ( 0.066 0.393 7.864 12.059 13.828 13.828 )
10.182: I:4460 ( 0.066 0.229 5.276 ) T:8868 ( 0.066 0.279 5.046 11.076 13.828 13.828 )
15.182: I:4501 ( 0.066 0.197 2.392 ) T:13369 ( 0.066 0.246 3.506 10.289 13.107 13.828 )
20.182: I:4404 ( 0.066 0.311 9.241 ) T:17773 ( 0.066 0.262 2.916 9.961 13.107 13.828 )
25.182: I:4397 ( 0.082 0.328 5.472 ) T:22170 ( 0.066 0.279 2.408 9.437 12.845 13.828 )
30.182: I:4489 ( 0.066 0.197 4.882 ) T:26659 ( 0.066 0.262 2.163 9.306 12.845 13.828 )
35.182: I:4494 ( 0.066 0.180 5.079 ) T:31153 ( 0.066 0.246 1.884 8.913 12.386 13.828 )
40.182: I:4465 ( 0.066 0.213 4.096 ) T:35618 ( 0.066 0.246 1.753 8.716 12.386 13.828 )
45.182: I:4482 ( 0.066 0.213 19.137 ) T:40100 ( 0.066 0.246 1.786 9.044 15.139 19.137 )
50.182: I:4477 ( 0.066 0.213 4.178 ) T:44577 ( 0.066 0.246 1.671 8.847 15.139 19.137 )
55.182: I:4474 ( 0.066 0.229 9.372 ) T:49051 ( 0.066 0.246 1.671 8.454 15.139 19.137 )
60.182: I:4476 ( 0.066 0.229 5.046 ) T:53527 ( 0.066 0.246 1.589 8.290 14.156 19.137 )
65.182: I:4474 ( 0.066 0.229 4.424 ) T:58001 ( 0.066 0.246 1.524 7.995 14.156 19.137 )
70.182: I:4396 ( 0.066 0.328 4.882 ) T:62397 ( 0.066 0.246 1.540 7.799 13.828 19.137 )
75.182: I:4377 ( 0.082 0.360 4.981 ) T:66774 ( 0.066 0.246 1.524 7.406 13.828 19.137 )
80.182: I:4475 ( 0.066 0.229 4.489 ) T:71249 ( 0.066 0.246 1.491 7.209 13.173 19.137 )
85.182: I:4488 ( 0.066 0.213 4.620 ) T:75737 ( 0.066 0.246 1.475 6.914 13.173 19.137 )
90.182: I:4476 ( 0.066 0.229 3.260 ) T:80213 ( 0.066 0.246 1.442 6.685 13.107 19.137 )
95.182: I:4515 ( 0.066 0.180 2.736 ) T:84728 ( 0.066 0.246 1.393 6.357 13.107 19.137 )
100.182: I:4476 ( 0.066 0.229 3.965 ) T:89204 ( 0.066 0.246 1.393 6.226 13.107 19.137 )
105.182: I:4476 ( 0.066 0.246 4.751 ) T:93680 ( 0.066 0.246 1.360 6.029 12.845 19.137 )
110.182: I:4490 ( 0.066 0.213 4.456 ) T:98170 ( 0.066 0.246 1.327 5.800 12.845 19.137 )
115.182: I:4496 ( 0.066 0.229 10.027 ) T:102666 ( 0.066 0.246 1.327 5.833 12.386 19.137 )
120.183: I:4415 ( 0.066 0.311 4.522 ) T:107081 ( 0.066 0.246 1.327 5.472 12.386 19.137 )
125.182: I:4357 ( 0.082 0.360 4.653 ) T:111438 ( 0.066 0.246 1.343 5.374 12.124 19.137 )
130.183: I:4484 ( 0.066 0.213 4.915 ) T:115922 ( 0.066 0.246 1.327 5.276 12.124 19.137 )
135.182: I:4508 ( 0.066 0.213 4.981 ) T:120430 ( 0.066 0.246 1.311 5.210 12.059 19.137 )
140.182: I:4477 ( 0.066 0.229 4.227 ) T:124907 ( 0.066 0.246 1.294 5.046 12.059 19.137 )
145.182: I:4512 ( 0.066 0.180 4.014 ) T:129419 ( 0.066 0.246 1.262 4.981 12.059 19.137 )
150.182: I:4501 ( 0.066 0.213 4.817 ) T:133920 ( 0.066 0.246 1.262 4.915 11.862 19.137 )
155.182: I:4532 ( 0.066 0.180 4.751 ) T:138452 ( 0.066 0.246 1.245 4.850 11.862 19.137 )
160.182: I:4487 ( 0.066 0.213 4.981 ) T:142939 ( 0.066 0.246 1.229 4.817 11.403 19.137 )
165.182: I:4506 ( 0.066 0.197 3.817 ) T:147445 ( 0.066 0.229 1.212 4.719 11.403 19.137 )
170.182: I:4426 ( 0.066 0.311 5.210 ) T:151871 ( 0.066 0.246 1.229 4.686 11.207 19.137 )
175.182: I:4390 ( 0.082 0.344 9.634 ) T:156261 ( 0.066 0.246 1.245 4.719 11.207 19.137 )
180.182: I:4492 ( 0.066 0.197 5.112 ) T:160753 ( 0.066 0.246 1.245 4.686 11.141 19.137 )
185.182: I:4506 ( 0.066 0.180 5.538 ) T:165259 ( 0.066 0.246 1.229 4.653 11.141 19.137 )
190.183: I:4498 ( 0.066 0.197 4.456 ) T:169757 ( 0.066 0.246 1.229 4.620 11.141 19.137 )
195.182: I:4517 ( 0.066 0.197 4.915 ) T:174274 ( 0.066 0.246 1.212 4.588 11.076 19.137 )
200.182: I:4461 ( 0.066 0.246 4.817 ) T:178735 ( 0.066 0.246 1.212 4.555 11.076 19.137 )
205.183: I:4499 ( 0.066 0.213 5.046 ) T:183234 ( 0.066 0.246 1.196 4.522 10.879 19.137 )
210.182: I:4472 ( 0.066 0.246 5.243 ) T:187706 ( 0.066 0.246 1.212 4.489 10.879 19.137 )
215.182: I:4511 ( 0.066 0.197 3.703 ) T:192217 ( 0.066 0.229 1.180 4.424 10.813 19.137 )
220.183: I:4405 ( 0.082 0.328 5.276 ) T:196622 ( 0.066 0.246 1.212 4.424 10.813 19.137 )
225.183: I:4349 ( 0.082 0.393 5.833 ) T:200971 ( 0.066 0.246 1.229 4.424 10.420 19.137 )
230.183: I:4461 ( 0.066 0.246 4.522 ) T:205432 ( 0.066 0.246 1.229 4.424 10.420 19.137 )
235.183: I:4513 ( 0.066 0.197 6.488 ) T:209945 ( 0.066 0.246 1.212 4.424 10.420 19.137 )
240.182: I:4464 ( 0.066 0.246 4.522 ) T:214409 ( 0.066 0.246 1.212 4.391 10.355 19.137 )
245.182: I:4494 ( 0.066 0.213 5.112 ) T:218903 ( 0.066 0.246 1.212 4.391 10.355 19.137 )
250.182: I:4468 ( 0.066 0.262 4.129 ) T:223371 ( 0.066 0.246 1.196 4.358 10.289 19.137 )
255.183: I:4511 ( 0.066 0.213 4.817 ) T:227882 ( 0.066 0.246 1.196 4.358 10.289 19.137 )
260.183: I:4500 ( 0.066 0.213 5.308 ) T:232382 ( 0.066 0.246 1.180 4.293 10.224 19.137 )
265.183: I:4452 ( 0.066 0.279 4.456 ) T:236834 ( 0.066 0.246 1.180 4.293 10.224 19.137 )
270.183: I:4314 ( 0.082 0.426 5.112 ) T:241148 ( 0.066 0.246 1.196 4.260 10.158 19.137 )
275.182: I:4383 ( 0.082 0.344 4.751 ) T:245531 ( 0.066 0.246 1.196 4.260 10.158 19.137 )
280.182: I:4484 ( 0.066 0.213 4.063 ) T:250015 ( 0.066 0.246 1.196 4.227 10.093 19.137 )
285.182: I:4500 ( 0.066 0.197 4.227 ) T:254515 ( 0.066 0.246 1.196 4.227 10.093 19.137 )
290.182: I:4490 ( 0.066 0.229 4.817 ) T:259005 ( 0.066 0.246 1.180 4.194 10.093 19.137 )
295.183: I:4485 ( 0.066 0.213 4.489 ) T:263490 ( 0.066 0.246 1.180 4.194 10.027 19.137 )
300.183: I:4472 ( 0.066 0.229 5.210 ) T:267962 ( 0.066 0.246 1.180 4.194 10.027 19.137 )
305.183: I:4368 ( 0.066 0.410 13.304 ) T:272330 ( 0.066 0.246 1.229 4.293 10.224 19.137 )
310.182: I:4493 ( 0.066 0.197 5.407 ) T:276823 ( 0.066 0.246 1.229 4.293 10.224 19.137 )
315.182: I:4521 ( 0.066 0.180 4.588 ) T:281344 ( 0.066 0.246 1.212 4.260 10.158 19.137 )
320.182: I:4431 ( 0.066 0.295 5.112 ) T:285775 ( 0.066 0.246 1.212 4.260 10.158 19.137 )
325.182: I:4397 ( 0.082 0.344 4.653 ) T:290172 ( 0.066 0.246 1.212 4.227 10.093 19.137 )
330.182: I:4493 ( 0.066 0.213 4.260 ) T:294665 ( 0.066 0.246 1.212 4.227 10.093 19.137 )
335.182: I:4516 ( 0.066 0.197 2.195 ) T:299181 ( 0.066 0.246 1.212 4.227 10.093 19.137 )
340.183: I:4496 ( 0.066 0.213 5.079 ) T:303677 ( 0.066 0.246 1.196 4.194 10.027 19.137 )
345.182: I:4481 ( 0.066 0.229 4.325 ) T:308158 ( 0.066 0.246 1.196 4.194 10.027 19.137 )
350.182: I:4475 ( 0.066 0.229 3.785 ) T:312633 ( 0.066 0.246 1.196 4.178 10.027 19.137 )
355.182: I:4510 ( 0.066 0.197 10.027 ) T:317143 ( 0.066 0.246 1.180 4.194 10.027 19.137 )
360.182: I:4486 ( 0.066 0.229 4.915 ) T:321629 ( 0.066 0.246 1.180 4.194 10.027 19.137 )
365.182: I:4492 ( 0.066 0.213 4.719 ) T:326121 ( 0.066 0.246 1.180 4.194 10.027 19.137 )
370.182: I:4430 ( 0.066 0.295 4.014 ) T:330551 ( 0.066 0.246 1.180 4.178 9.961 19.137 )
375.182: I:4388 ( 0.082 0.344 4.227 ) T:334939 ( 0.066 0.246 1.180 4.178 9.961 19.137 )
380.183: I:4506 ( 0.066 0.197 4.555 ) T:339445 ( 0.066 0.246 1.180 4.162 9.961 19.137 )
385.182: I:4519 ( 0.066 0.180 4.751 ) T:343964 ( 0.066 0.246 1.163 4.145 9.896 19.137 )
390.182: I:4478 ( 0.066 0.229 4.358 ) T:348442 ( 0.066 0.246 1.163 4.129 9.896 19.137 )
395.182: I:4515 ( 0.066 0.197 3.785 ) T:352957 ( 0.066 0.246 1.163 4.129 9.830 19.137 )
400.182: I:4468 ( 0.066 0.246 5.669 ) T:357425 ( 0.066 0.246 1.163 4.129 9.830 19.137 )
405.182: I:4484 ( 0.066 0.229 10.617 ) T:361909 ( 0.066 0.246 1.163 4.145 9.830 19.137 )
410.183: I:4486 ( 0.066 0.213 3.850 ) T:366395 ( 0.066 0.246 1.163 4.129 9.830 19.137 )
415.182: I:4508 ( 0.066 0.213 9.896 ) T:370903 ( 0.066 0.246 1.163 4.145 9.830 19.137 )
420.183: I:4437 ( 0.066 0.279 6.029 ) T:375340 ( 0.066 0.246 1.163 4.129 9.830 19.137 )
425.182: I:4348 ( 0.082 0.393 10.945 ) T:379688 ( 0.066 0.246 1.180 4.162 9.896 19.137 )
430.182: I:4504 ( 0.066 0.197 3.326 ) T:384192 ( 0.066 0.246 1.163 4.145 9.896 19.137 )
435.182: I:4503 ( 0.066 0.213 3.998 ) T:388695 ( 0.066 0.246 1.163 4.145 9.896 19.137 )
440.182: I:4489 ( 0.066 0.213 3.097 ) T:393184 ( 0.066 0.246 1.163 4.129 9.830 19.137 )
445.182: I:4529 ( 0.066 0.180 5.014 ) T:397713 ( 0.066 0.246 1.147 4.112 9.830 19.137 )
450.182: I:4470 ( 0.066 0.246 3.965 ) T:402183 ( 0.066 0.246 1.147 4.096 9.830 19.137 )
455.182: I:4511 ( 0.066 0.197 4.030 ) T:406694 ( 0.066 0.246 1.147 4.080 9.830 19.137 )
460.182: I:4491 ( 0.066 0.213 4.784 ) T:411185 ( 0.066 0.246 1.130 4.063 9.765 19.137 )
465.182: I:4490 ( 0.066 0.213 6.193 ) T:415675 ( 0.066 0.246 1.130 4.063 9.765 19.137 )
470.183: I:4437 ( 0.066 0.279 4.850 ) T:420112 ( 0.066 0.246 1.130 4.063 9.699 19.137 )
475.182: I:4363 ( 0.082 0.393 10.813 ) T:424475 ( 0.066 0.246 1.147 4.112 9.830 19.137 )
480.182: I:4496 ( 0.066 0.197 4.456 ) T:428971 ( 0.066 0.246 1.147 4.112 9.830 19.137 )
485.182: I:4496 ( 0.066 0.213 6.128 ) T:433467 ( 0.066 0.246 1.130 4.112 9.830 19.137 )
490.182: I:4488 ( 0.066 0.229 5.177 ) T:437955 ( 0.066 0.246 1.130 4.112 9.830 19.137 )
495.182: I:4505 ( 0.066 0.213 3.654 ) T:442460 ( 0.066 0.246 1.130 4.096 9.765 19.137 )
500.183: I:4484 ( 0.066 0.213 4.030 ) T:446944 ( 0.066 0.246 1.130 4.063 9.765 19.137 )
505.182: I:4510 ( 0.066 0.197 3.932 ) T:451454 ( 0.066 0.246 1.130 4.063 9.699 19.137 )
510.182: I:4484 ( 0.066 0.229 9.175 ) T:455938 ( 0.066 0.246 1.130 4.063 9.699 19.137 )
515.182: I:4516 ( 0.066 0.197 4.850 ) T:460454 ( 0.066 0.246 1.114 4.063 9.634 19.137 )
520.183: I:4438 ( 0.066 0.262 4.686 ) T:464892 ( 0.066 0.246 1.130 4.047 9.634 19.137 )
525.182: I:4361 ( 0.082 0.377 6.226 ) T:469253 ( 0.066 0.246 1.130 4.063 9.634 19.137 )
530.182: I:4492 ( 0.066 0.229 4.325 ) T:473745 ( 0.066 0.246 1.130 4.063 9.634 19.137 )
535.183: I:4502 ( 0.066 0.229 9.437 ) T:478247 ( 0.066 0.246 1.130 4.080 9.634 19.137 )
