java - jHiccup:直方图数据似乎不一致

Question

我正在用Azul的jHiccup运行一个应用程序。该应用程序是通过带有-javaagent选项的jsvc启动的。 jHiccup设置为默认设置（输出文件名除外）。

该应用程序运行约107分钟。但是，如果我将所得的hgrm文件中的所有值相加，则打total的总长度似乎太大。

我像这样计算打values值的总和：

Sum( (TotalCountIncludingThisValue[n] - TotalCountIncludingThisValue[n-1]) * Value[n] )

结果是1275万，或〜213分钟（假设值以毫秒为单位）。这大约是应用程序运行时间的两倍。

Total count * Mean（从直方图值的底部开始）也给出1200万，因此该公式很可能是正确的。

为了进行比较，我从GC日志中添加了“申请时间”和“停止时间”。结果接近我的预期：〜105分钟。应用时间和约2分钟。停止时间。



我不小心覆盖了原始文件，因此这些是来自不同运行的示例文件：
https://dl.dropboxusercontent.com/u/644287/jHiccup/hiccup.dat
https://dl.dropboxusercontent.com/u/644287/jHiccup/hiccup.dat.hgrm

运行耗时约79分钟（17：50-19：09），但是Mean * TotalCount为约2300万。 （即380分钟）。

Answer 1

更新：[在下面保留我原来的错误帖子]

好。因此，我们两个人的数学都错了（在您的问题和我的最初答案中）。表示（Total Count * Mean（应该大致等于运行时间）的健全性检查完全是伪数学。

下面的思想练习可以简单地证明这一点：

下面是一个非常简单的场景：衡量一个运行100秒（空闲，所有间隔显示0打h）的应用程序。然后，您对系统进行^ Z 100秒。然后，让它再次在前台运行，然后立即^ C。总运行时间为200秒。

关于这种系统，这里有一些恰当的“人类将如何用数字描述”的陈述：


99.99％'ile将非常接近100,000毫秒。
10％，20％，... 50％都将非常接近0毫秒。
在前100秒（以及前100,000个采样周期）内，平均值为0毫秒。
在第二个100秒（以及第二个100,000个采样周期）内，平均值为50,000毫秒。
总体平均值为25,000毫秒（在200秒的总运行时间内）。


但是，在直方图的TotalCount中将（适当地）报告200,000个结果（每1毫秒经过的时间一个）。

因此（平均*总数）= 200,000 * 25,000 == 5,000,000,000

这是挂钟时间的25,000倍。这没有错。乘法发生了〜N ^ 2件事（实际上是N *（N-1）/ 2），而这恰恰是它的正确行为...

此处的关键在于，对于每个百分位，直方图[正确地]报告会遇到打levels水平低于一定幅度的总体随机样本的百分比（不随时间进行协调）。当发生一次长时间冻结时（例如，在示例输出中的最大2654毫秒中看到），这不是受影响的1个时间点。冻结的毫秒数将与采样时间点一样多。如果正确测量并表示，一次冻结将每毫秒生成大约1个计数，其值在最大值和0（2654毫秒，2653毫秒，2652毫秒，... 3毫秒，2毫秒，1毫秒）之间线性变化。这是计算随机，不协调样本可能遇到的潜在延迟分布的正确方法。

我有些尴尬，因为我的原始答案重复了我在题为“如何不衡量延迟”（http://www.infoq.com/presentations/latency-pitfalls）的演讲中警告过的相同错误假设（幻灯片中的图形正好讨论了上述情况），这是在大约32分钟内的“协调遗漏问题”下）。我用正确的数学方法构建了jHiccup和HdrHistogram来避免此问题，这就是为什么您在数据中看到正确的结果的原因。

实际上，如果您的健全性检查显示“良好”的数字，且最大时间在1000毫秒以内，那将很好地表明测量系统显示出协调的遗漏...

-吉尔

--------原始答案，这是“错误” -----------

您可以发布显示此示例的.hgrm数据集吗？我刚刚看过的文件似乎显示了总的运行时间与.hgrm文件中的计数之间密切的关系。最简单的健全性测试是Total Count * Mean（均在文件底部报告）应该与运行时非常接近。这些数据来自产生百分比线的相同直方图。

注意，出于非常简单的原因，百分位线上的计数不是累加的。对于相同的精确值，可以报告两个百分位水平。对于噪音很小的长期运行，这是很常见的。但是，您上面的数学运算（仅计算增量计数）“应该”正确运行。

[请注意，您的数学运算偏离了1行：每一个百分位行都显示百分位和计数值，该值的值等于或低于该行的值。因此，值应乘以下一行（n + 1）处的计数与“此”行（n）处的计数之间的差值，但对您的测量没有太大的影响]。

下面是一个样本文件格式控制运行，耗时约1685秒，其中jHiccup在运行30秒后开始检测（约1655秒的检测时间）。在此数据集上使用excel，结果为：

总和（（TotalCountInIncludeThisValue [n + 1]-TotalCountInIncludeThisValue [n]）* Value [n]）

显示约16237秒，平均值*总计数显示约16591秒。

jHiccup直方图报告，CDT 2013年4月22日星期一15:28:07：

值，百分位数，包括此值在内的TotalCount

1.01 0.000000000000         47
1.06 0.100000000000     483774
1.06 0.200000000000     483774
1.06 0.300000000000     483774
1.10 0.400000000000     628589
1.11 0.500000000000     804685
1.12 0.550000000000    1024190
1.12 0.600000000000    1024190
1.12 0.650000000000    1024190
1.13 0.700000000000    1388741
1.13 0.750000000000    1388741
1.13 0.775000000000    1388741
1.13 0.800000000000    1388741
1.13 0.825000000000    1388741
1.13 0.850000000000    1388741
1.13 0.875000000000    1388741
1.13 0.887500000000    1388741
1.13 0.900000000000    1388741
1.13 0.912500000000    1388741
1.14 0.925000000000    1471124
1.14 0.937500000000    1471124
1.14 0.943750000000    1471124
1.14 0.950000000000    1471124
1.14 0.956250000000    1471124
1.14 0.962500000000    1471124
1.14 0.968750000000    1471124
1.14 0.971875000000    1471124
1.14 0.975000000000    1471124
1.14 0.978125000000    1492169
1.14 0.981250000000    1492169
1.14 0.984375000000    1492169
1.14 0.985937500000    1492169
1.14 0.987500000000    1492169
1.14 0.989062500000    1492169
1.15 0.990625000000    1500639
1.15 0.992187500000    1500639
1.15 0.992968750000    1500639
1.15 0.993750000000    1500639
1.15 0.994531250000    1500639
1.16 0.995312500000    1504895
1.16 0.996093750000    1504895
1.16 0.996484375000    1504895
1.16 0.996875000000    1504895
1.16 0.997265625000    1504895
1.16 0.997656250000    1504895
1.17 0.998046875000    1506535
1.17 0.998242187500    1506535
1.17 0.998437500000    1506535
1.17 0.998632812500    1506535
1.17 0.998828125000    1506535
1.18 0.999023437500    1507442
1.18 0.999121093750    1507442
1.18 0.999218750000    1507442
1.18 0.999316406250    1507442
1.18 0.999414062500    1507442
1.18 0.999511718750    1507836
1.18 0.999560546875    1507836
1.18 0.999609375000    1507836
1.18 0.999658203125    1507836
1.18 0.999707031250    1507836
1.19 0.999755859375    1508028
1.19 0.999780273438    1508028
1.19 0.999804687500    1508028
1.19 0.999829101563    1508028
1.20 0.999853515625    1508106
1.20 0.999877929688    1508106
1.21 0.999890136719    1508145
1.21 0.999902343750    1508145
1.22 0.999914550781    1508163
1.22 0.999926757813    1508174
1.25 0.999938964844    1508186
1.34 0.999945068359    1508195
1.82 0.999951171875    1508204
2.42 0.999957275391    1508213
3.54 0.999963378906    1508222
4.74 0.999969482422    1508231
5.09 0.999972534180    1508236
5.98 0.999975585938    1508241
6.24 0.999978637695    1508245
7.01 0.999981689453    1508251
7.97 0.999984741211    1508254
8.26 0.999986267090    1508257
8.96 0.999987792969    1508259
9.02 0.999989318848    1508261
9.98 0.999990844727    1508265
10.24 0.999992370605    1508266
11.01 0.999993133545    1508268
11.01 0.999993896484    1508268
11.97 0.999994659424    1508269
13.95 0.999995422363    1508271
14.98 0.999996185303    1508272
14.98 0.999996566772    1508272
16.00 0.999996948242    1508273
16.00 0.999997329712    1508273
17.02 0.999997711182    1508274
18.05 0.999998092651    1508275
18.05 0.999998283386    1508275
18.05 0.999998474121    1508275
18.05 0.999998664856    1508275
19.07 0.999998855591    1508276
19.07 0.999999046326    1508276
19.07 0.999999141693    1508276
19.07 0.999999237061    1508276
19.07 0.999999332428    1508276
19.97 0.999999427795    1508277
19.97 1.000000000000    1508277

#[Mean    =         1.10, StdDeviation   =         0.06]
#[Max     =        19.84, Total count    =      1508277]
#[Buckets =           25, SubBuckets     =          256]