nginxのリクエストを制限することができるngx_http_limit_req_moduleでハマった

nginxのリクエスト数を制限する、ngx_http_limit_req_moduleの動作を勝手に勘違いして勝手にハマったというお話です。大したことではないのですがdockerでその動作を再現した例はこちらです。

何にハマったのかというと、”5r/sが5req per secではない”のです。
”2r/sも2req per secではない”のです。でも”1r/sは1req per secです”。なぞなぞでしょうか。

...dockerのコンテナを動かしてshellを実行すると次のようなエラーログとアクセスログが出力されます。

nginx_1 | 2016/06/13 15:35:35 [error] 8#8: *18 limiting requests, excess: 0.995 by zone "five", client: 192.168.99.1, server: localhost, request: "GET / HTTP/1.1", host: "192.168.99.100"
nginx_1 | 192.168.99.1 - - [13/Jun/2016:15:35:35 +0000] "GET / HTTP/1.1" 429 0 "-" "curl/7.43.0" "-"

これは0.995秒過剰であるためリクエストが制限されたということですね。statusも429を返しています。え、shellでは合計3リクエスト投げているだけなのに！！！1秒間に5リクエスト以上も投げていないのに何故なのでしょうか！！！例のように5ならまだしも、大抵rateは数十数百とかに設定することが多いと思われるので、しっかりと検証していないとこの不可解な挙動に気づきにくいと思います。何故5r/sが5req per secではないのか、理解に苦しみます。KU☆SO☆GA！

さて、ngx_http_limit_req_module のコードを読んでみましょう。まずエラーログを出力していた箇所を探して読み解いていくのが楽でしょうか。

https://github.com/nginx/nginx/blob/c3aed0a23392a509f64b740064f5f6633e8c89d8/src/http/modules/ngx_http_limit_req_module.c#L231-L236

if (rc == NGX_BUSY) {
     ngx_log_error(lrcf->limit_log_level, r->connection->log, 0,
                   "limiting requests, excess: %ui.%03ui by zone \"%V\"",
                   excess / 1000, excess % 1000,
                   &limit->shm_zone->shm.name);
}

rc == NGX_BUSY の条件が成り立つ時にリクエストが制限されていると予想できます。 rcには ngx_http_limit_req_lookup という関数の結果が代入されているので、この関数がメインディッシュのようです。
次の式が一番重要になりそうです。

https://github.com/nginx/nginx/blob/c3aed0a23392a509f64b740064f5f6633e8c89d8/src/http/modules/ngx_http_limit_req_module.c#L404

excess = lr->excess - ctx->rate * ngx_abs(ms) / 1000 + 1000;

https://github.com/nginx/nginx/blob/c3aed0a23392a509f64b740064f5f6633e8c89d8/src/http/modules/ngx_http_limit_req_module.c#L412-L414

if ((ngx_uint_t) excess > limit->burst) {
    return NGX_BUSY;
}

lr->excess - ctx->rate * ngx_abs(ms) / 1000 + 1000 の結果が limit->burst より大きい場合にリクエストが制限されるようです。
先ほどのshell実行のようにrateを5r/s, burstをデフォルト値の0に設定した状態で、同時に2リクエストを受け付けた場合を考えてみましょう。
ngx_abs(ms) は前回リクエストから今までの経過時間なのでこれが0となり、excessは0以上なので
lr->excess - 0 + 1000 は必ず > 1000 になります。そしてburstは0に設定したので、必ず NGX_BUSY になります。
rateの値に関係なく、必ず NGX_BUSY になるので、1秒間に5リクエストを受け付ける前にすでに制限されていたわけですね。

続いてrateを5r/s, burstを0に設定した状態で、初回リクエストの0.2秒後に第2リクエストを受け付けた場合を考えてみましょう。 lr->excess は0とし、 ngx_abs(ms) は200（ミリ秒）、 ctx->rate は5000なので 0 - 5000 * 200 / 1000 + 1000 を計算すると0になります。burstは0に設定したので、 NGX_BUSY にはなりませんね。 rateが5r/sなので、1/5秒つまり200ミリ秒経過しているのでburstが0でも次のリクエストが受け付けられるということです。結論として、5r/sというのは厳密には1r/0.2sを超えるリクエストは制限されると言えます。

では1秒間でだいたい50リクエストを受け付ける設定したいのにどうしたらよいのでしょうか。
答えはburstを設定することです。というかburstは必ず設定しましょう。でないと並列性のあるリクエストが429になってしまいます。ついでにnodelayも設定すると良いと思います。個人的にはrate=50r/s, burst=50 nodelay の設定が妥当かと思います。この設定だとたしかに1秒間に最大100リクエストを受け付けてしまう可能性がありますが、少なくとも”並列性のある50リクエスト”を誤って429で返してしまう可能性はなくなります。むしろ他に良い設定があったら教えてくださいませ。つらい。

何やらややこしい話をして投げっぱなし感は少し残りますが、お口直しにクスリとした話を載せておきます。 nginxのメーリングリストより。

https://forum.nginx.org/read.php?2,244602,244623#msg-244623

You said "As long as rate is set to 4r/s, it's enough to do two requests with less than 250ms between them to trigger "delaying request message". I'm confused, why would 4r/s not allow 4 requests per second at full speed?? Isn't that the entire point.

https://forum.nginx.org/read.php?2,244602,244625#msg-244625

Note that specifying rate of 4 r/s doesn't imply 1-second measurement granularity. Much like 60 km/h speed limit doesn't imply that you have to drive for an hour before you'll reach a limit.

載せたのは一部ですが一連のやり取りを見つけた時はこの質問者さんと同じ気持ちだったのでなんでやねんって感じでしたが、車の制限速度の話が出た時には納得して少しニヤけてしまいましたｗめでたしめでたし。