七层网络性能基准测试中的协调遗漏问题--Coordinated Omission

前言

在讲述这个问题之前首先我们先要搞清楚七层网络测试协议的几个关键性性能测试指标和通用的关系模型。其次搞清楚四层协议，七层协议中性能测试给出的时延讲述的是个什么东西。最后讲述为什么大部分的性能测试工具所测得给出的时延结果或多或少的包含了协调遗漏（Coordinated Omission）问题。

衡量一个web系统的网络性能指标

要对一个网站或者是其他的网络应用做性能测试，首先我们应该搞明白要测什么。给出一个测试方法的三要素包含了：测试指标，测试工具和测试模型。对于七层网络测试，测试工具千千万（其实也就那么几个好用的，不要太较真），测试模型五花八门。但是影响一个七层网络应用或者说一个七层的网络服务的指标除开软件自身代码设计带来的限制之外还有哪些外在因素会影响着这个系统。那么首先先来搞清楚影响着一个web系统的性能指标到底有哪些。

因为大多数的七层网络应用无外乎C/S或者B/S架构。客户端通过请求来访问后端服务。服务能处理的请求越多，处理的请求越快，为越多的用户提供服务就成为了衡量服务的一个标准。所以单位时间内请求的多少（Query Per Second），单位时间内能建立的连接数量（Concurrent Connections）和每个请求的响应时间（Response Time）就成为了衡量一个服务器处理业务能力的关键网络性能指标。

但是每个request对CPU的性能消耗，系统BUS总线上的I/O消耗，物理服务器外围接口的消耗会让不同的服务针对这三个参数有着自己的特性表现。通常一个服务的性能由QPS和CC两个因素来决定，每一套系统这两个值都有一个相对极限的极值存在。在进行一个网络系统的基准测试时，你可能会在一定量（有可能不是最高）的QPS情况下找到最大并发连接数。这种时候多半是看系统在额定并发下有多少QPS。也可以在一定量（有可能不是最高）的并发连接数情况下找到最大的QPS。这种时候一般是看系统能够处理最大的QPS。这里可能就会有同学问了，为什么不能鱼和熊掌不可兼得。按照我个人的理解来解释一下“为什么一个网络应用系统很难看到或者说我们最希望但是又很难看到：网络系统达到所能承载最大的并发连接数下同时达到系统负载最高的QPS。似乎并发链接开的多了接收的请求也就多了，自然而然QPS也就上来了。”

再解释这个之前，我们先要引入之前提到的一个指标：请求响应时间（RT）。每个请求在发出之后网络总是需要时间将请求收发，系统总是需要时间来处理这个这个请求的。我们可以记客户端发出请求的时间为t0。请求通过网络送达到应用系统，系统接收到请求。我们将请求从客户端通过网络发送到服务器的这段时间记为t1。从系统接收到请求到系统将请求处理完所消耗的时间记为t2。处理完的请求从服务器端通过网络发送会客户端的这段时间记为记t3。客户端接收到服务器处理完的请求的时间记为t4。（请注意t0和t4为两个时间点）

对客户端而言对于一个请求来说它的响应时间就是△t=t0-t4=t1+t2+t3。假设你现在的QPS很高，就意味着你每秒发送的请求很多，姑且不论网络堵塞对t1和t3时间的影响（假设客户端高QPS和低QPS下，客户端到服务器的整个网络链路是非常通畅的）。QPS越高就意味着服务器每秒要处理的请求数越多，这就意味着服务器系统CPU要频繁的上下文切换来处理这些请求，这无意间增加了系统的消耗，同样的也会增加系统处理这些请求的时间。相比于新建并发连接数而言，QPS会首先成为服务器的性能瓶颈。如果此时的QPS是服务器所能处理的最高的QPS，那么此时这个服务的系统还要开启高的并发链接，就意味着系统需要消耗更多的资源来建立新建链接。

对于网络服务系统，每个系统在QPS和并发链接数这两个方面都有一个相对极限值。在应用场景访问压力下，只要某一项达到了系统的最高值，则另外一项就很难再有提高。这就是整体系统吞吐量最大值。我们可以用一个图来表述并发连接数，QPS，平均响应时间三者的关系。

该图的横坐标表示服务器所承载的负载。在一些测试软件中会模拟Vuser来对服务器发起请求压力，而在另一些测试软件中则会模拟开启多少并发连接数来对服务器发起请求压力。对服务器而言这些都是负载压力。该图的纵坐标表述为响应时间，吞吐量和系统资源利用率的一个数量级（虽然这三者的单位不一样但为了表述变化曲线做了简化）。

黄色区域表述为系统的一个轻量负载情况。随着请求压力的增加，系统开启更多的线程来处理请求，并发连接数增大。系统的负载增大，每个请求的响应时间增长并且系统资源的利用率在逐步增加。

绿色区域表述为系统在一个适当高压力负载的情况。随着请求压力的增加，系统资源负载到达了系统所能承受的临界值，系统无法分配更多的资源来处理请求。每个请求的平均响应时间增长。在黄色和绿色的区域内，虽然系统的负载在逐步增大，但是好在系统资源还够用，网络服务能够正常运转并且客户也有有一个较为良好的服务时间体验。

随着客户的增大，单位时间内请求压力的持续增大，系统到达了红色区域内。该区域表示系统已经没有多余的资源来处理新来的请求了。这个时候你可以想象随着QPS的增加，系统处理每个请求的时间会呈指数级增长，系统实际QPS就开始降低了（显然这个时候的并发链接数会是当前系统最大值）。在系统高负载和无法响应的超高负载下会有一个临界值，我们称之为失速点。在坐标轴左侧逼近该点QPS会逐渐达到一个最高点。一但QPS超过该点则系统实际能够处理的QPS会立马降低，QPS就会失速。

在基准测试中，失速点的探索是必要的。而不同于性能测试，性能测试更加侧重于某个场景下系统的表现。这个场景可能处于系统轻量负载阶段，重度负载阶段或者在系统失速无法响应阶段。经过上述讨论后你会发现抛开并发谈QPS或者抛开QPS谈并发就是极度耍流氓的做法。并发，QPS和响应时间三者相互影响。

协调遗漏（Corrdinate Omission）

接下来进入正题，什么是协调遗漏。协调遗漏尝试想描述问题的是：“当系统处于高压力的情况，大部分性能测试工具，所测得的请求时延（请求的响应时间）大多数只表述为系统服务的时延值。而不是当前测试计划中请求的时延值”。

想要解释这个问题，我们还需要再补充一个概念：测试计划任务。在大部分基准测试工具中有着相似的测试流程可以表述如下：

1. 测试工具开启测试线程。（不同的测试工具可能会使用虚拟用户来描述这个概念，但是本质上还是开线程）
2. 每个线程中按照测试计划的时间开始发送请求，并等待发送的请求响应。然后继续重复发送和响应的过程。
3. 记录每个请求的延迟response time - request time。即请求返回的时间减去请求发送时的时间。

我们以wrk为例：当你准备使用wrk来进行测试时，你首先需要指定请求总量，开启的并发连接数，测试执行的时间。然后wrk按照你的要求来进行测试。wrk会按照你的要求与服务器建立你指定的并发连接数，然后开始发送请求，然后记录请求返回的时间。这一切看似合乎常理，你能收到一份有关当前测试的请求时延报告，并且评估你的系统在当前测试场景下是否合理。但是在基准测试时wrk所反馈的时延报告是存在问题。这个问题就在于报告中显示的时延只是服务器处理请求并通过网络往返客户端之间的时间。它并没有反映出当前请求在客户端等待了多少时间才发送出去。

试想一下：你在找寻一个系统的失速点，你给测试工具设定了你认为的稍微高一点的负载。而这个负载正好处于失速点往后的某个点。这就意味着系统无法全部处理你的请求。随着测试时间的增加，你规定的测试时间内请求的成功率会随之减小。其原因就在，随着测试的进行测试工具需要等一个请求响应时间会越来越长并最终超过你设定的测试时间。当你使用wrk设定好了请求总数，所要开启的并发连接数和测试运行总时间时。wrk就做了一个测试计划，每个时间段内需要发出去多少请求。但是实际上呢，在系统失速情况下，可能当前时间段连上个时间段的请求都没发送完。很多请求在测试端等待了。而最后的报告上有体现请求在测试端发送等待的结果么？实际上并没有。测试工具只对发出去的包打上了一个时间标签并在该包返回测试发送端的时候检测该时间标签。从中计算出服务器的响应时间。

打个比方就好像：我去排队打饭，打饭的阿姨每一分钟可以给一个人打好一份饭菜。我先在在队伍的最后一个等待阿姨给我的饭菜。我前面有三个人，前两个人花了一分钟打完饭走了，到了第三个人他站在那发呆很久左挑右挑花了5分钟才打完饭。最后轮到我了，我就花了一分钟把饭菜打好了。所以对我来说，我从阿姨那拿到饭菜所花掉的时间是1+1+5+1=8分钟，而不是仅仅1分钟就拿到了饭菜。阿姨就好比服务器，而我则是压力发送端发出去的一个包。

由于测试工具统计上的原因，最后显示在测试报告中时延分布直方图中越往后的请求其所测试的偏差就会越大。

上图展现了校正后的时延分布直方图和未校正的时延分布直方图。蓝线表示校正过后的，黄线表示未校正的。百分比越大其所测试的时延误差越大。好了现在我们知道时延误差的根本原因之后，怎么在最后测试报告的时延直方图中表示出来呢。

HDR直方分布图

首先我们要理解在普通直方图上为什么越接近100%其时延误差越大。

打个比方：
想象一个很理想的系统，每个请求只需要1毫秒即可处理100个请求。当这个系统正常运行了100秒以后，这个系统忽然中邪了100秒，这100秒期间只能处理2个请求了。我现在使用性能测试工具对这个系统进行100QPS的压测，执行200秒。那么它的时延分布直方图会是什么样子呢？

前100秒的平均值为1毫秒。
接下来100秒的平均值是50秒。
200秒的平均值是25秒。
第50百分位数为1毫秒。
第75百分位是50秒。
99.99百分位数是100秒。

现在能看出来上图所讲未经过矫正后的时延直方图为什么会有一个陡增的过程了吧。其主要原因是直方分布图在50%-99.99%范围内只有一个请求作为样本采样，而在前100秒内有100000个请求作为样本采样。如果我们想要表示前100秒和后100秒采样的随机公平性。那么在后一百秒中我们需要补充99998个样本。

HDR直方图（High Dynamic Range Histogram）支持在可配置的整数值范围内记录和分析采样数据值，并在该范围内具有可配置的值精度。值精度表示为值记录中的有效位数，并提供对值范围内的值量化行为的控制以及任何给定级别的后续值分辨率。

HDR在时延统计上可以干嘛呢？

作用一：提高时延精度
当然是提高我们直方分布图的精度。假设HDR配置为跟踪0到3,600,000,000,000之间观察到的整数值的计数，同时保持该范围内3个有效数字的值精度。因此，该范围内的值量化将不大于任何值的1/1000（或0.1％）。这样HDR直方图可用于跟踪和分析观察到的响应时间计数，范围在1纳秒到1小时之间，同时保持如果取微秒为单位其精度可以控制在1纳秒，1毫秒为单位其精度控制在1微妙，以1秒为单位其精度可以控制在1毫秒，如果要取1小时为单位其精度也可控制在3.6秒。在当前CPU的时钟计算ns为单位下，HDR直方图明显是可以满足计算的。

作用二：在样本缺少情况下补充样本
这个是最重要的一点。为例理解HDR直方图比普通直方图的好处。我们先回到原来的测试模型以wrk发送请求为例，当确定好请求总数，并发连接数和运行时间时，其实每秒发多少个请求就已经确定了。测试工具一边等待请求返回统计响应时间，一边绘制直方图。理论上直方图采样的时间间隔要小于响应时间，这样才能够将全部的请求统计在直方图中。如果出现某些请求响应时间过长，且错过了采样的时间间隔点。则这个请求的响应时延值就没有被直方图统计到。

在HRD直方图库中有个方法就是recordvalueWithExpectedInterval()。该方法的作用是记录在直方图预计的时间间隔点采到的样本。那么请求如果响应时间过长必然会导致在直方图中记录的样本时间间隔过长。当样本统计的时间间隔超过了expectedIntervalBetweenValueSamples，那么就会以expectedIntervalBetweenValueSamples为步长来填充数据。直至样本采样的数据间隔时间低于expectedIntervalBetweenValueSamples的最高值。

总的来说使用HDR直方图来进行时延统计的流程如下：

1. 使用HRD histogram统计响应时间分布，测试会根据压测运行时间有计划的采样。
2. 当recordvalue()采样时间>请求响应时间时，请求被记录。
3. 当请求响应时间>recordvalue()采样时间时，只是用recordvalue()会导致有些请求没有被直方图采样统计。
4. 此时使用expectedIntervalBetweenValueSamples会填充一系列的数据到直方图中，最后填充的速率会线性减少。
5. 样本缺少是会自动填补缺失的样本。

因为针对高负载压力网络系统的压测所以当测试工具发起压测请求，随着时间的推移其请求的响应请求会越来越长。那么在指定的测试时间中请求的成功率和请求的响应时间直方分布图中的MAX值结果会越来越大。这种失速情况下基准测试如何衡量当前系统的状态，就显得尤为重要。单看请求在网络系统中处理的时间已经无法真实反映实际情况。文中虽然只是以wrk为例，但在Jmeter，Loadrunner，vegeta，YCSB等测试工具中或多或少也会有这种协调遗漏问题的存在。

YCSB引入了预期时间概念，用于表述请求在离开压测发送端所需要等待的时间。在throttle方法中，YCSB引入了一个本地线程变量来记录请求开始等待的时间。针对每一次操作，YCSB使用预期的时间来计算请求等待的时间。但是YCSB在默认情况下是同步的发起请求，客户端必须等待上一个请求的响应然后发送下一个请求。在高负载的情况下如果使用异步的方式去发起请求，其统计的结果也不具有参考价值。这个时候引入HDR直方图来显示其结果就会是比较行之有效的方法。事实上YCSB也是这么来做的。

wrk2实战

刚刚说了那么多，肯定有人会问了。既然测试工具有这种统计误差，那么有什么测试工具能够很好的消除掉这种统计误差呢。就笔者实际测试经验中，在开源工具中wrk2和vegeta在基准测试时可以比较好的做到消除这种时延显示误差。当然YCSB也是一种工具，不过你如果要测试一个http或者https服务器那显然不是首选。我比较推荐wrk2来观看这种统计误差结果。wrk2的参数中给出了可以打印出经过校准之后的时延直方分布图和未经过校准的时延直方分布图结果。

wrk2的Git链接在这里给出，感兴趣的观众可以去看看https://github.com/giltene/wrk2。这里笔者稍微提一个题外话。wrk2的作者Gil Tene，是最开始在公众平台上提出协调遗漏（Coordinated Omisson）问题的人。并且在他努力下对wrk进行了改进，引入了HDR直方图统计并且可以使wrk有可控制的计划速率。在Gil Tene的游说下，使得vegeta的作者Tomás Senart采用了他提倡的请求算法来控制QPS访问请求速率，并且使用HDR直方分布图来统计时延。

下面简要说下wrk2的用法，wrk2的帮助说明如下：

    Usage: wrk <options> <url>                            
      Options:                                            
        -c, --connections <N>  Connections to keep open   
        -d, --duration    <T>  Duration of test           
        -t, --threads     <N>  Number of threads to use   
                                                          
        -s, --script      <S>  Load Lua script file       
        -H, --header      <H>  Add header to request      
        -L  --latency          Print latency statistics   
        -U  --u_latency        Print uncorrected latency statistics
            --timeout     <T>  Socket/request timeout     
        -B, --batch_latency    Measure latency of whole   
                               batches of pipelined ops   
                               (as opposed to each op)    
        -v, --version          Print version details      
        -R, --rate        <T>  work rate (throughput)     
                               in requests/sec (total)    
                               [Required Parameter]       
                                                          
                                                          
      Numeric arguments may include a SI unit (1k, 1M, 1G)
      Time arguments may include a time unit (2s, 2m, 2h)

一般发起一个压测时需要指定压测机用指定线程来发起指定数量的并发链接，并且指定访问请求速率。通过-L打印矫正的时延统计时间，通过-U来打印未矫正的时延统计时间。

下面我们对实验室一台nginx服务器静态页面发起压测，测试输入的命令如下：

wrk2 -c 60000 -d 60s -t 32 -R 60000 -U http://10.130.1.10

指定通过32线程发起6W的并发连接数，压测时间为60s，请求的访问速率指定为6W。这意味着60s的时间内服务器按照计划要响应3600000000个请求。（注意在压力机和nginx服务器均做过系统优化，nginx做过软件层面优化，关于如何优化这一章，找个时间再写。说实话我在优化方面并不是大佬，所以写出来怕读者见笑）

经过时延校验过后的报告如下：

Running 1m test @ http://10.130.1.10
  32 threads and 60000 connections
  Thread calibration: mean lat.: 2263.597ms, rate sampling interval: 13541ms
  Thread calibration: mean lat.: 2280.954ms, rate sampling interval: 13328ms
  Thread calibration: mean lat.: 2282.731ms, rate sampling interval: 13787ms
  Thread calibration: mean lat.: 2256.999ms, rate sampling interval: 13082ms
  Thread calibration: mean lat.: 2348.102ms, rate sampling interval: 13615ms
  Thread calibration: mean lat.: 2269.768ms, rate sampling interval: 13230ms
  Thread calibration: mean lat.: 2375.317ms, rate sampling interval: 13533ms
  Thread calibration: mean lat.: 2377.771ms, rate sampling interval: 13754ms
  Thread calibration: mean lat.: 2234.929ms, rate sampling interval: 13303ms
  Thread calibration: mean lat.: 2423.598ms, rate sampling interval: 13598ms
  Thread calibration: mean lat.: 2398.815ms, rate sampling interval: 13688ms
  Thread calibration: mean lat.: 2401.973ms, rate sampling interval: 13631ms
  Thread calibration: mean lat.: 2368.699ms, rate sampling interval: 13606ms
  Thread calibration: mean lat.: 2387.026ms, rate sampling interval: 13860ms
  Thread calibration: mean lat.: 2412.950ms, rate sampling interval: 13893ms
  Thread calibration: mean lat.: 2346.627ms, rate sampling interval: 13672ms
  Thread calibration: mean lat.: 2459.439ms, rate sampling interval: 13811ms
  Thread calibration: mean lat.: 2422.094ms, rate sampling interval: 13819ms
  Thread calibration: mean lat.: 2453.822ms, rate sampling interval: 13844ms
  Thread calibration: mean lat.: 2380.262ms, rate sampling interval: 13631ms
  Thread calibration: mean lat.: 2381.460ms, rate sampling interval: 13770ms
  Thread calibration: mean lat.: 2497.586ms, rate sampling interval: 13918ms
  Thread calibration: mean lat.: 2507.002ms, rate sampling interval: 13901ms
  Thread calibration: mean lat.: 2476.060ms, rate sampling interval: 13959ms
  Thread calibration: mean lat.: 2478.912ms, rate sampling interval: 13975ms
  Thread calibration: mean lat.: 2447.736ms, rate sampling interval: 13877ms
  Thread calibration: mean lat.: 2534.116ms, rate sampling interval: 13926ms
  Thread calibration: mean lat.: 2592.255ms, rate sampling interval: 14155ms
  Thread calibration: mean lat.: 2581.342ms, rate sampling interval: 14049ms
  Thread calibration: mean lat.: 2431.668ms, rate sampling interval: 13680ms
  Thread calibration: mean lat.: 2485.046ms, rate sampling interval: 13959ms
  Thread calibration: mean lat.: 2401.554ms, rate sampling interval: 13844ms
Thread- 0: requests=13847,compllete=49149, hdr.total_count=49148, uhdr.tc=49148
Thread- 1: requests=669,compllete=48496, hdr.total_count=48495, uhdr.tc=48495
Thread- 2: requests=12722,compllete=48671, hdr.total_count=48663, uhdr.tc=48663
Thread- 3: requests=1468,compllete=48711, hdr.total_count=48703, uhdr.tc=48703
Thread- 4: requests=13196,compllete=49068, hdr.total_count=49067, uhdr.tc=49067
Thread- 5: requests=856,compllete=46995, hdr.total_count=46993, uhdr.tc=46993
Thread- 6: requests=12872,compllete=48260, hdr.total_count=48259, uhdr.tc=48259
Thread- 7: requests=12631,compllete=48159, hdr.total_count=48158, uhdr.tc=48158
Thread- 8: requests=674,compllete=49215, hdr.total_count=49214, uhdr.tc=49214
Thread- 9: requests=12864,compllete=48425, hdr.total_count=48424, uhdr.tc=48424
Thread-10: requests=12857,compllete=47541, hdr.total_count=47540, uhdr.tc=47540
Thread-11: requests=13156,compllete=48595, hdr.total_count=48594, uhdr.tc=48594
Thread-12: requests=13229,compllete=48263, hdr.total_count=48261, uhdr.tc=48261
Thread-13: requests=12025,compllete=48027, hdr.total_count=48026, uhdr.tc=48026
Thread-14: requests=12284,compllete=49022, hdr.total_count=49021, uhdr.tc=49021
Thread-15: requests=12500,compllete=48807, hdr.total_count=48798, uhdr.tc=48798
Thread-16: requests=12368,compllete=48123, hdr.total_count=48108, uhdr.tc=48108
Thread-17: requests=12503,compllete=48190, hdr.total_count=48176, uhdr.tc=48176
Thread-18: requests=12345,compllete=47892, hdr.total_count=47891, uhdr.tc=47891
Thread-19: requests=12423,compllete=47419, hdr.total_count=47418, uhdr.tc=47418
Thread-20: requests=12024,compllete=48162, hdr.total_count=48161, uhdr.tc=48161
Thread-21: requests=12304,compllete=47952, hdr.total_count=47951, uhdr.tc=47951
Thread-22: requests=12481,compllete=48571, hdr.total_count=48559, uhdr.tc=48559
Thread-23: requests=12609,compllete=49207, hdr.total_count=49206, uhdr.tc=49206
Thread-24: requests=12102,compllete=47840, hdr.total_count=47839, uhdr.tc=47839
Thread-25: requests=12058,compllete=47131, hdr.total_count=47130, uhdr.tc=47130
Thread-26: requests=12327,compllete=48566, hdr.total_count=48551, uhdr.tc=48551
Thread-27: requests=12649,compllete=48548, hdr.total_count=48537, uhdr.tc=48537
Thread-28: requests=11788,compllete=47859, hdr.total_count=47854, uhdr.tc=47854
Thread-29: requests=12256,compllete=47373, hdr.total_count=47372, uhdr.tc=47372
Thread-30: requests=11772,compllete=47780, hdr.total_count=47779, uhdr.tc=47779
Thread-31: requests=12173,compllete=48425, hdr.total_count=48424, uhdr.tc=48424
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    10.97s    10.68s    0.93m    69.73%
    Req/Sec     0.88k    26.17     0.99k    79.41%
  Latency Distribution (HdrHistogram - Recorded Latency)
 50.000%    7.75s 
 75.000%   16.63s 
 90.000%   28.05s 
 99.000%   41.22s 
 99.900%   47.19s 
 99.990%   50.86s 
 99.999%    0.89m 
100.000%    0.93m 

  Detailed Percentile spectrum:
       Value   Percentile   TotalCount 1/(1-Percentile)

       0.505     0.000000            1         1.00
     222.335     0.100000       154441         1.11
    1011.199     0.200000       308887         1.25
    2959.359     0.300000       463333         1.43
    5275.647     0.400000       617737         1.67
    7749.631     0.500000       772189         2.00
    9347.071     0.550000       849782         2.22
   11124.735     0.600000       926842         2.50
   12951.551     0.650000      1003876         2.86
   14630.911     0.700000      1081182         3.33
   16629.759     0.750000      1158431         4.00
   17956.863     0.775000      1197046         4.44
   19513.343     0.800000      1235635         5.00
   21315.583     0.825000      1274410         5.71
   23445.503     0.850000      1312841         6.67
   25788.415     0.875000      1351307         8.00
   26935.295     0.887500      1370714         8.89
   28049.407     0.900000      1389934        10.00
   29163.519     0.912500      1409292        11.43
   30294.015     0.925000      1428766        13.33
   31375.359     0.937500      1447954        16.00
   32014.335     0.943750      1457455        17.78
   32751.615     0.950000      1467162        20.00
   33587.199     0.956250      1477087        22.86
   34471.935     0.962500      1486455        26.67
   35487.743     0.968750      1496103        32.00
   36077.567     0.971875      1501104        35.56
   36700.159     0.975000      1505933        40.00
   37388.287     0.978125      1510684        45.71
   38207.487     0.981250      1515537        53.33
   39124.991     0.984375      1520236        64.00
   39682.047     0.985938      1522741        71.11
   40239.103     0.987500      1525091        80.00
   40828.927     0.989062      1527460        91.43
   41484.287     0.990625      1529878       106.67
   42205.183     0.992188      1532270       128.00
   42598.399     0.992969      1533542       142.22
   42991.615     0.993750      1534725       160.00
   43384.831     0.994531      1535890       182.86
   43843.583     0.995313      1537161       213.33
   44335.103     0.996094      1538343       256.00
   44564.479     0.996484      1538933       284.44
   44826.623     0.996875      1539500       320.00
   45154.303     0.997266      1540101       365.71
   45481.983     0.997656      1540704       426.67
   45875.199     0.998047      1541310       512.00
   46104.575     0.998242      1541636       568.89
   46333.951     0.998437      1541934       640.00
   46596.095     0.998633      1542239       731.43
   46891.007     0.998828      1542538       853.33
   47218.687     0.999023      1542822      1024.00
   47382.527     0.999121      1542970      1137.78
   47611.903     0.999219      1543128      1280.00
   47841.279     0.999316      1543266      1462.86
   48136.191     0.999414      1543422      1706.67
   48496.639     0.999512      1543572      2048.00
   48660.479     0.999561      1543642      2275.56
   48889.855     0.999609      1543726      2560.00
   49086.463     0.999658      1543796      2925.71
   49381.375     0.999707      1543874      3413.33
   49610.751     0.999756      1543947      4096.00
   49807.359     0.999780      1543991      4551.11
   49938.431     0.999805      1544021      5120.00
   50135.039     0.999829      1544061      5851.43
   50364.415     0.999854      1544094      6826.67
   50593.791     0.999878      1544134      8192.00
   50757.631     0.999890      1544151      9102.22
   50888.703     0.999902      1544172     10240.00
   51052.543     0.999915      1544192     11702.86
   51249.151     0.999927      1544207     13653.33
   51478.527     0.999939      1544226     16384.00
   51576.831     0.999945      1544237     18204.44
   51675.135     0.999951      1544245     20480.00
   51871.743     0.999957      1544258     23405.71
   52002.815     0.999963      1544265     27306.67
   52461.567     0.999969      1544273     32768.00
   52658.175     0.999973      1544278     36408.89
   52822.015     0.999976      1544285     40960.00
   52854.783     0.999979      1544288     46811.43
   52920.319     0.999982      1544292     54613.33
   53379.071     0.999985      1544297     65536.00
   53510.143     0.999986      1544299     72817.78
   53608.447     0.999988      1544302     81920.00
   53673.983     0.999989      1544306     93622.86
   53673.983     0.999991      1544306    109226.67
   53903.359     0.999992      1544309    131072.00
   53936.127     0.999993      1544310    145635.56
   53968.895     0.999994      1544313    163840.00
   53968.895     0.999995      1544313    187245.71
   53968.895     0.999995      1544313    218453.33
   54165.503     0.999996      1544315    262144.00
   54165.503     0.999997      1544315    291271.11
   54919.167     0.999997      1544316    327680.00
   54919.167     0.999997      1544316    374491.43
   54951.935     0.999998      1544318    436906.67
   54951.935     0.999998      1544318    524288.00
   54951.935     0.999998      1544318    582542.22
   54951.935     0.999998      1544318    655360.00
   54951.935     0.999999      1544318    748982.86
   55672.831     0.999999      1544320    873813.33
   55672.831     1.000000      1544320          inf
#[Mean    =    10970.250, StdDeviation   =    10679.981]
#[Max     =    55640.064, Total count    =      1544320]
#[Buckets =           27, SubBuckets     =         2048]
----------------------------------------------------------
  1544442 requests in 1.00m, 350.55MB read
  Socket errors: connect 0, read 20330, write 0, timeout 969519
Requests/sec:  25807.56
Transfer/sec:      5.86MB

未经过时延校验过后的报告如下：

----------------------------------------------------------

  Latency Distribution (HdrHistogram - Uncorrected Latency (measured without taking delayed starts into account))
 50.000%  259.07ms
 75.000%  938.49ms
 90.000%    3.42s 
 99.000%   15.04s 
 99.900%   37.58s 
 99.990%   46.01s 
 99.999%    0.85m 
100.000%    0.92m 

  Detailed Percentile spectrum:
       Value   Percentile   TotalCount 1/(1-Percentile)

       0.195     0.000000            1         1.00
      23.887     0.100000       155524         1.11
      25.999     0.200000       309662         1.25
      31.711     0.300000       463335         1.43
     250.495     0.400000       618503         1.67
     259.071     0.500000       773079         2.00
     471.551     0.550000       849754         2.22
     480.511     0.600000       927119         2.50
     493.567     0.650000      1003936         2.86
     721.919     0.700000      1081314         3.33
     938.495     0.750000      1159197         4.00
     954.879     0.775000      1197273         4.44
    1154.047     0.800000      1235933         5.00
    1819.647     0.825000      1274356         5.71
    1852.415     0.850000      1313571         6.67
    1911.807     0.875000      1351320         8.00
    2069.503     0.887500      1370841         8.89
    3416.063     0.900000      1389934        10.00
    3661.823     0.912500      1409421        11.43
    3704.831     0.925000      1428633        13.33
    3831.807     0.937500      1447870        16.00
    3913.727     0.943750      1457510        17.78
    6701.055     0.950000      1467120        20.00
    7274.495     0.956250      1477145        22.86
    7364.607     0.962500      1486690        26.67
    7471.103     0.968750      1496252        32.00
    7561.215     0.971875      1501223        35.56
    7696.383     0.975000      1505739        40.00
   13631.487     0.978125      1510543        45.71
   14483.455     0.981250      1515393        53.33
   14655.487     0.984375      1520512        64.00
   14745.599     0.985938      1522725        71.11
   14843.903     0.987500      1525359        80.00
   14966.783     0.989062      1527643        91.43
   15138.815     0.990625      1529863       106.67
   15663.103     0.992188      1532255       128.00
   26968.063     0.992969      1533463       142.22
   28491.775     0.993750      1534680       160.00
   29278.207     0.994531      1535915       182.86
   29851.647     0.995313      1537084       213.33
   30670.847     0.996094      1538298       256.00
   31227.903     0.996484      1538896       284.44
   32014.335     0.996875      1539496       320.00
   32767.999     0.997266      1540098       365.71
   33587.199     0.997656      1540704       426.67
   34996.223     0.998047      1541310       512.00
   35586.047     0.998242      1541617       568.89
   36110.335     0.998437      1541912       640.00
   36601.855     0.998633      1542228       731.43
   37060.607     0.998828      1542520       853.33
   37715.967     0.999023      1542813      1024.00
   38731.775     0.999121      1542963      1137.78
   41680.895     0.999219      1543114      1280.00
   42991.615     0.999316      1543266      1462.86
   43581.439     0.999414      1543428      1706.67
   43941.887     0.999512      1543568      2048.00
   44171.263     0.999561      1543643      2275.56
   44400.639     0.999609      1543721      2560.00
   44630.015     0.999658      1543804      2925.71
   44859.391     0.999707      1543882      3413.33
   45088.767     0.999756      1543949      4096.00
   45187.071     0.999780      1543982      4551.11
   45318.143     0.999805      1544019      5120.00
   45449.215     0.999829      1544069      5851.43
   45514.751     0.999854      1544100      6826.67
   45744.127     0.999878      1544134      8192.00
   45875.199     0.999890      1544153      9102.22
   46071.807     0.999902      1544170     10240.00
   46202.879     0.999915      1544190     11702.86
   46333.951     0.999927      1544207     13653.33
   46563.327     0.999939      1544227     16384.00
   46759.935     0.999945      1544237     18204.44
   46989.311     0.999951      1544245     20480.00
   47284.223     0.999957      1544256     23405.71
   47677.439     0.999963      1544267     27306.67
   47906.815     0.999969      1544273     32768.00
   48463.871     0.999973      1544278     36408.89
   48594.943     0.999976      1544283     40960.00
   49086.463     0.999979      1544288     46811.43
   49676.287     0.999982      1544292     54613.33
   50298.879     0.999985      1544297     65536.00
   50495.487     0.999986      1544299     72817.78
   50921.471     0.999988      1544302     81920.00
   51118.079     0.999989      1544304     93622.86
   51216.383     0.999991      1544306    109226.67
   51904.511     0.999992      1544309    131072.00
   52002.815     0.999993      1544310    145635.56
   52101.119     0.999994      1544312    163840.00
   52101.119     0.999995      1544312    187245.71
   52658.175     0.999995      1544314    218453.33
   52789.247     0.999996      1544315    262144.00
   52789.247     0.999997      1544315    291271.11
   52822.015     0.999997      1544317    327680.00
   52822.015     0.999997      1544317    374491.43
   52822.015     0.999998      1544317    436906.67
   53313.535     0.999998      1544318    524288.00
   53313.535     0.999998      1544318    582542.22
   53313.535     0.999998      1544318    655360.00
   53313.535     0.999999      1544318    748982.86
   54165.503     0.999999      1544319    873813.33
   54165.503     0.999999      1544319   1048576.00
   54165.503     0.999999      1544319   1165084.44
   54165.503     0.999999      1544319   1310720.00
   54165.503     0.999999      1544319   1497965.71
   54919.167     0.999999      1544320   1747626.67
   54919.167     1.000000      1544320          inf
#[Mean    =     1273.260, StdDeviation   =     3529.400]
#[Max     =    54886.400, Total count    =      1544320]
#[Buckets =           27, SubBuckets     =         2048]
----------------------------------------------------------
  1544442 requests in 1.00m, 350.55MB read
  Socket errors: connect 0, read 20330, write 0, timeout 969519
Requests/sec:  25807.56
Transfer/sec:      5.86MB

可以看到两者在50%-99%之间的分布直方图时延差异。

  Latency Distribution (HdrHistogram - Recorded Latency)
 50.000%    7.75s 
 75.000%   16.63s 
 90.000%   28.05s 
 99.000%   41.22s 
 99.900%   47.19s 
 99.990%   50.86s 
 99.999%    0.89m 
100.000%    0.93m 
  Latency Distribution (HdrHistogram - Uncorrected Latency (measured without taking delayed starts into account))
 50.000%  259.07ms
 75.000%  938.49ms
 90.000%    3.42s 
 99.000%   15.04s 
 99.900%   37.58s 
 99.990%   46.01s 
 99.999%    0.85m 
100.000%    0.92m 

应为测试所给出的参数是会让nginx服务器失速的一个参数。所以在失速情况下未经过校准的时延报告如果只看平均值的话看起来时延会很低。但是实际上很多请求还没发出去呢。

本博客是博主查阅了国外文献之后按照自己对协调遗漏的理解写下来的。如有理解错误欢迎及时指正。另外附上Gil Tene这哥们针对时延的两次公开演讲，感兴趣的朋友可以不妨去听听。

了解延迟 https://www.youtube.com/watch?v=9MKY4KypBzg

如何不测量潜伏期 https://www.infoq.com/presentations/latency-pitfalls/