fix rpc_press can't send request equably

[bumingchun]

项目中利用rpc_press进行压测，出现服务衰减问题，即压测过程中服务性能越变越差。后来通过分析发现rpc_press压测工具的实现存在问题，网络或者CPU抖动造成的发送请求不均匀会一直保存在窗口中，并影响后续请求，随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀。具体分析如下：

举例说明：假设 QPS: 100，异步发送请求平均耗时 1ms，为方便画图，假设队列最大长度为10。

图(1) 中发送编号为4的请求时CPU或者网络抖动，造成本应在t+31发出的请求滞后了15ms，按照代码逻辑，编号为5/6的请求分别在t + 47 和 t + 51发出

图(2) 我们假设队列最大长度为10，按照图上的计算过程可以得到，发送完请求14后会sleep 24ms，这样就导致发送请求4时的抖动，对请求15发送时间造成了影响，抖动会在队列中一直存在。QPS越高，请求间隔越短，这个问题越容易出现。

本pull request利用一种更简单的方式来计算请求间隔，来解决上述问题。

[wwbmmm]

非常感谢，这个PR解答了我多年的困惑！

[wwbmmm]

如果req_rate > 100000 (虽然实际上极少出现），会导致interval变成0
而原来的代码还能处理这种情况

[bumingchun]

如果req_rate > 100000，确实有你说的这个问题。但是考虑到单线程发送1百万qps是几乎不可能的，我在新代码中设置了单线程发送qps的上限为1百万，这也是一个合理的限制。同时使用nanosecond来计算interval，这样可以使高qps情况下interval计算更为准确。

[guodongxiaren]

rpc_replay是不是也有类似问题

[bumingchun]

rpc_replay是不是也有类似问题

是的，rpc_replay也有一样的问题。本次只修改了rpc_press是想让大家帮忙review一下目前这样改的思路是否可行，然后再修改rpc_replay

[guodongxiaren]

把时间分辨率从us变成ns有什么特殊的考虑吗？是不是和要解决的问题无关？

[bumingchun]

把时间分辨率从us变成ns有什么特殊的考虑吗？是不是和要解决的问题无关？

将时间分辨率从us变成ns是为了解决高qps情况下，因为取整interval精度不够的问题，导致压测qps不准问题。举例说明，例如我们设置req_rate为510000，要是使用us，计算出来的interval = 1 us，要是忽略发送请求的时间(理想情况)，则最终的qps是1000000。要是使用ns，计算出来的interval是1960ns，忽略发送请求时间，则最终qps为510204，更为准确。

[wwbmmm]

这里用usleep((expected_time - end_time)/1000)就可以，不用引入std的依赖

[bumingchun]

是的，使用usleep((expected_time - end_time)/1000)也可以。但为什么要避免引入std的依赖呢？这样的好处是什么呢？

[wwbmmm]

保持代码风格一致吧，brpc其它地方sleep的时候都是用的usleep

[bumingchun]

好的，代码已更新

[jamesge]

新老代码的主要差异在计算“实际的延时”这点上：老代码大约是用前1秒的平均延时，新代码是只用上一次访问的延时。这个差异可能难以得出“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”这个结论。需要要进一步看看深层次的原因，可能和高qps场景下一些计算的精度不够关联更大。这个随机抖动场景是否能人为构造一下？ @bumingchun 这样其他人也可以复现debug看看。

[jamesge]

把时间分辨率从us变成ns有什么特殊的考虑吗？是不是和要解决的问题无关？

将时间分辨率从us变成ns是为了解决高qps情况下，因为取整interval精度不够的问题，导致压测qps不准问题。举例说明，例如我们设置req_rate为510000，要是使用us，计算出来的interval = 1 us，要是忽略发送请求的时间(理想情况)，则最终的qps是1000000。要是使用ns，计算出来的interval是1960ns，忽略发送请求时间，则最终qps为510204，更为准确。

基于通知机制的(condition)的唤醒精度是60us，sleep的精度一般远大于60us，小于2ms。只是把参数计算地很精确的话，传给sleep后的实际效果其实得不到保证。一般要追求精确的时间控制，是不能使用sleep机制的，这里用sleep的潜台词就是这个场景下代码简单比时间精准更重要，用us肯定是够了。

[guodongxiaren]

这个PR还是有必要重点关注一下，虽然代码diff有待商榷。但是提到的问题是真实存在的，我之前也遇到过rpc_replay发稳定流量给预发布环境，每隔几天服务端就恶化的问题。还有就是压测的时候，流量持续一段较长时间服务性能恶化。重启服务不能恢复，但是重启rpc_replay能恢复。当时我也观察到每次恶化的时候rpc_replay输出的日志中qps不均衡的问题。

[wwbmmm]

这个问题可以复用，启动echo_server，然后用rpc_press压，当传-thread_num=12 -qps=0（同步发送）时，qps大概是100000，且cpu使用稳定在2左右。
当传-thread_num=12 -qps=100000（异步发送）时，可以看到，虽然rpc_press显示的qps一直在100000左右，但是server的cpu使用率会一路下降到1以下。如果重启rpc_press，cpu使用率会再次升到2（图中时间粒度太粗，被平均了），然后又逐步下降到1以下。

我推测的原因是这样的：

1. 如 @jamesge 指出的，sleep的精度一般远大于60us，那么在qps较大的时候，每次计算出来要sleep的时间间隔是比较短的，比如本来只需sleep 10us，每隔10us发一个请求，结果sleep实际花了100us，接着会立即发出10个请求，这就造成了抖动
2. 如 @bumingchun 指出的，抖动会在队列中一直存在，那么过了一个完整的窗口之后，会计算出应该sleep 100us，这时调用sleep，可能实际的sleep时间变成了200us，如此反复抖动会不断积累变大
3. 最终导致的结果是，server端收到的瞬时qps是不均匀的（以毫秒为尺度来看），可能某段时间一个请求都没有，某段时间收到大量请求，但是以秒的尺度来看，qps的数值是均匀的
4. 由于单连接会合并同一时间的IO，瞬时qps越高，合并效果越好，cpu使用率越低。在echo_server的例子中，随着瞬时qps越来越不均衡，cpu使用率也越来越低。但对于其它的业务场景，比如在业务代码中使用到很多锁的话，有可能会出现瞬时qps越高、cpu使用越高的情况，那么就会出现压测过程中服务性能越变越差的现象。

[wwbmmm]

补充一些信息：
我加了一个bvar Maxer，统计两次请求之前的间隔的最大值：

bvar::Maxer<int> g_request_interval;
bvar::Window<bvar::Maxer<int> > g_request_interval_window("max_request_interval", &g_request_interval, 1);

发送请求那里：

g_request_interval << (end_time - timeq.back());

然后用异步rpc_press，可以看到这个值是不断在增长的：

对应的，latency也在不断增长

而cpu（无论是rpc press还是server端）则呈现先下降后增长的状态：

[bumingchun]

新老代码的主要差异在计算“实际的延时”这点上：老代码大约是用前1秒的平均延时，新代码是只用上一次访问的延时。这个差异可能难以得出“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”这个结论。需要要进一步看看深层次的原因，可能和高qps场景下一些计算的精度不够关联更大。这个随机抖动场景是否能人为构造一下？ @bumingchun 这样其他人也可以复现debug看看。

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

按照你的提示@jamesge，我在发送代码中引入一个人为抖动，可以稳定复现该问题，具体代码在 reproduce_rpc_press_issue 这里，大家可以参考一下。

利用修改后rpc_press压测echo_server(为了让接口延时变大，在代码中增加了一段for循环)，压测4000qps，可以看到接口延时在持续上涨，并且concurrency波动很大。

同时我又修改了rpc_press中info_thread.cpp的代码，让其以10ms为间隔打印发送的请求数，可以看到压测一段时间后，每10ms发送的请求数很不均匀

压测命令为: ./rpc_press -proto=../../example/echo_c++/echo.proto -method=example.EchoService.Echo -server=xxx:8000 -input=./test_echo.json -qps=4000

[jamesge]

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

新方法中一旦某段时间发送特别慢（如线程不被调度了），恢复后实际时间就会远大于预期时间，之后会不做任何sleep以最大速率连续发送，直到预期时间追上？这个其实timeq针对的问题，只受之前一段请求的影响。

[bumingchun]

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

新方法中一旦某段时间发送特别慢（如线程不被调度了），恢复后实际时间就会远大于预期时间，之后会不做任何sleep以最大速率连续发送，直到预期时间追上？这个其实timeq针对的问题，只受之前一段请求的影响。

我理解新方法和原有实现都有这个问题，且原有实现抖动会被累计，影响之后的窗口，这才是最大的问题。
以4000qps举例，分析两种情况
情况一：假设end_time - expected_time = 0.5s时，两种方式都会已最大速率连续发送约2000个请求，但原有实现连续发送2000个请求的时间都记录在窗口中，会导致下一个窗口中2000个请求还是连续发送。新的方式中只要expected_time追上end_time后，对后续请求没有影响。
情况二：假设end_time - expected_time = 2s时，新的方式会连续发送8000个请求，旧方式会连续发送2000个请求，这个情况下原有实现是可以减少连续发送请求数，但是原有实现之后的所有请求都是以2000一组连续发送的，以后发送请求都是不均匀的。

我刚刚研究了一下jmeter的实现方式，代码如下，它的实现是用上一次发送请求的延时来计算sleep时间，这个方式可以避免你提到的连续发送问题，但弊端是因为抖动qps会小于预设值。我提交的新实现方式则是会在抖动后连续发送请求来尽量保证qps准确。大家可以看看我们采用哪种方式更合适。

[bumingchun]

又想了一下，可能采用jmeter的这种实现方式更好，出现抖动、线程不被调度等情况，很有可能是发压力的机器的问题(负载，网络等)，这个时候在qps指标上体现出这些问题，也有利于问题排查。如果通过连续发送的方式补上因为抖动造成的影响，有2个弊端，1、造成一定程度请求不均匀，2、没有暴露压力机的问题，不利于问题排查。所以倾向采用jmeter的实现方式。

[jamesge]

我理解新方法和原有实现都有这个问题，且原有实现抖动会被累计，影响之后的窗口，这才是最大的问题。 以4000qps举例，分析两种情况 情况一：假设end_time - expected_time = 0.5s时，两种方式都会已最大速率连续发送约2000个请求，但原有实现连续发送2000个请求的时间都记录在窗口中，会导致下一个窗口中2000个请求还是连续发送。新的方式中只要expected_time追上end_time后，对后续请求没有影响。 情况二：假设end_time - expected_time = 2s时，新的方式会连续发送8000个请求，旧方式会连续发送2000个请求，这个情况下原有实现是可以减少连续发送请求数，但是原有实现之后的所有请求都是以2000一组连续发送的，以后发送请求都是不均匀的。

”原有实现连续发送2000个请求的时间都记录在窗口中“，发送2000个请求后导致缓慢的那个请求已经出队列了吧，并不会导致后面连续发送，这个判断是有问题的。新方法相当于老方法中的timeq无限大，jmeter的方法类似于timeq容量为1。jmeter的方法就如你说的，在很多情况下会导致实际qps低于指定qps，相当于压力总是打了个折扣。老方法就是注意到这一点做了折中。

我本地观察了一些cases，”抖动“问题的主要原因我认为是：1. 高qps导致usleep精度不足； 2. 线程不够。这两个问题会交织在一起：现在代码中默认一个线程可以承担10000qps，可以达到，但会导致usleep精度不足，现象就是qps明显低于预期。把单个线程承担的qps调低，以及对timeq容量上限、usleep逻辑做些调整，应该可以解决问题。

[bumingchun]

我理解新方法和原有实现都有这个问题，且原有实现抖动会被累计，影响之后的窗口，这才是最大的问题。 以4000qps举例，分析两种情况 情况一：假设end_time - expected_time = 0.5s时，两种方式都会已最大速率连续发送约2000个请求，但原有实现连续发送2000个请求的时间都记录在窗口中，会导致下一个窗口中2000个请求还是连续发送。新的方式中只要expected_time追上end_time后，对后续请求没有影响。 情况二：假设end_time - expected_time = 2s时，新的方式会连续发送8000个请求，旧方式会连续发送2000个请求，这个情况下原有实现是可以减少连续发送请求数，但是原有实现之后的所有请求都是以2000一组连续发送的，以后发送请求都是不均匀的。

”原有实现连续发送2000个请求的时间都记录在窗口中“，发送2000个请求后导致缓慢的那个请求已经出队列了吧，并不会导致后面连续发送，这个判断是有问题的。新方法相当于老方法中的timeq无限大，jmeter的方法类似于timeq容量为1。jmeter的方法就如你说的，在很多情况下会导致实际qps低于指定qps，相当于压力总是打了个折扣。老方法就是注意到这一点做了折中。

我本地观察了一些cases，”抖动“问题的主要原因我认为是：1. 高qps导致usleep精度不足； 2. 线程不够。这两个问题会交织在一起：现在代码中默认一个线程可以承担10000qps，可以达到，但会导致usleep精度不足，现象就是qps明显低于预期。把单个线程承担的qps调低，以及对timeq容量上限、usleep逻辑做些调整，应该可以解决问题。

"发送2000个请求后导致缓慢的那个请求已经出队列了吧，并不会导致后面连续发送"，我理解是会影响后面请求发送的，我把这个过程画了个图，你看我的图有问题吗？是不是可以说明这个问题。

[wwbmmm]

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

新方法中一旦某段时间发送特别慢（如线程不被调度了），恢复后实际时间就会远大于预期时间，之后会不做任何sleep以最大速率连续发送，直到预期时间追上？这个其实timeq针对的问题，只受之前一段请求的影响。

有个改进的方法，每隔n个请求，重置expected_time = end_time + interval
或者限制expected_time不能落后当前时间太多(X)

if (expected_time < end_time - X) {
    expected_time = end_time - X;
}

[bumingchun]

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

新方法中一旦某段时间发送特别慢（如线程不被调度了），恢复后实际时间就会远大于预期时间，之后会不做任何sleep以最大速率连续发送，直到预期时间追上？这个其实timeq针对的问题，只受之前一段请求的影响。

有个改进的方法，每隔n个请求，重置expected_time = end_time + interval 或者限制expected_time不能落后当前时间太多(X)

if (expected_time < end_time - X) {
    expected_time = end_time - X;
}

这个思路可以，相当于是我的实现方式和jmeter实现方式的折中。即可以尽量保证qps等于预设值，也可以避免大量请求以最高速率发送。

[bumingchun]

新代码计算expected_time的方式为(start_time + n * interval)，其中start_time是发第一个请求的时间，n是请求个数，并不是依赖上一次的访问时延，程序启动的时间就决定了每个请求发送的expected_time，这种实现方式中expected_time不受抖动影响。旧的实现方式中抖动是会累计的，本次抖动会影响一个窗口过后请求的发送时间，并一直传递，所以我才有“随程序运行时间变长，抖动出现的次数越来越多，发送地请求会越来越不均匀”的结论。

新方法中一旦某段时间发送特别慢（如线程不被调度了），恢复后实际时间就会远大于预期时间，之后会不做任何sleep以最大速率连续发送，直到预期时间追上？这个其实timeq针对的问题，只受之前一段请求的影响。

有个改进的方法，每隔n个请求，重置expected_time = end_time + interval 或者限制expected_time不能落后当前时间太多(X)

if (expected_time < end_time - X) {
    expected_time = end_time - X;
}

这个思路可以，相当于是我的实现方式和jmeter实现方式的折中。即可以尽量保证qps等于预设值，也可以避免大量请求以最高速率发送。

我参照 @wwbmmm 的建议，对之前的实现进行了改进，避免end_time和expected_time相差很大时，导致连续发送的问题。当end_time - expected_time > max_tolerant_delay时，设置expected_time为end_time。大家帮忙看一下，目前的实现是否可行。 @wwbmmm @guodongxiaren @jamesge

[wwbmmm]

LGTM

[bumingchun]

请问这个代码什么时候可以merge呢？ @wwbmmm

[guodongxiaren]

rpc_replay是不是也有类似问题

是的，rpc_replay也有一样的问题。本次只修改了rpc_press是想让大家帮忙review一下目前这样改的思路是否可行，然后再修改rpc_replay

@bumingchun rpc_replay的修改提了吗？

[bumingchun]

不好意思，pr提的时间有点长，后面把rpc_replay给忘了，我最近提交一下