龙卷风+莫莫科。不断增长的响应时间

Question

当我们使用以下命令在tornado服务器上进行负载测试时：

ab -n 500 -c 100 http://<hostname>/api/stats/?events=691

在前400个请求之后(以200 rps的速度)-最后100个请求需要很长时间。

我们在log中得到了以下结果：

[I 140314 12:25:19 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 12.92ms
[I 140314 12:25:19 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 21.22ms
[I 140314 12:25:19 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 28.75ms
[I 140314 12:25:20 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 3021.00ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6403.66ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6411.02ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6417.97ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6420.90ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6426.83ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6439.17ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6442.40ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6445.59ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6449.05ms
[I 140314 12:25:24 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 6445.53ms
[I 140314 12:25:30 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 12985.94ms
[I 140314 12:25:30 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 12871.76ms
[I 140314 12:25:30 web:1462] 200 GET /api/stats/?events=691 (127.0.0.1) 12760.86ms

Momoko有以下连接设置：

db_min_con = 5
db_max_con = 70

我们将postgresql限制为300个连接，对pgpool也有同样的限制。

为什么在测试结束时响应时间会增长？去哪里挖？

Answer 1

您是否尝试使用普通同步psycopg2重新创建此问题？也许这个github issue会提供一个提示呢？