レート制限の遅延は nginx $request_time に含まれていますか?

レート制限の遅延は nginx $request_time に含まれていますか?

リクエストが nginx のレート制限によって遅延された場合 (レート制限を超えたが、バースト レート内)、この遅延は nginx の$request_time合計に含まれますか?

nginxのドキュメントには次$request_timeのように書かれています「クライアントから最初のバイトが読み取られてから経過した時間」

リクエストが遅れる場合、それはクライアントからリクエストバイトが読み込まれる前ですか、それとも後ですか?レート制限はリクエスト ヘッダーなどに基づいて設定できるためです。

合計リクエスト時間と、クライアントとのネットワーク通信の送受信に特に費やされた時間を分離する方法はありますか?

注記: 私は を認識しており$upstream_response_time、それをログに記録しています。特に、nginx 内の特定の操作 (キャッシュ、レート制限など) とクライアント側のネットワーク通信を区別することに関心があります。

答え1

私のテストでは、nginxの$request_timeログ記録するレート制限による遅延を反映します。

クライアント:

wrk --timeout 20s -d 20 -t 79 -c 80 https://zapazoid.vistashare.net/Static/jquery.jnotify-1.1.min.js

設定:

nodelay静的レート制限から削除され、レート制限は1r/s、バーストは に設定されました80r/s

試験結果:

❯ wrk --timeout 20s -d 20 -t 79 -c 80 https://zapazoid.vistashare.net/Static/jquery.jnotify-1.1.min.js
Running 20s test @ https://zapazoid.vistashare.net/Static/jquery.jnotify-1.1.min.js
  79 threads and 80 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     9.97s     5.97s   19.93s    56.10%
    Req/Sec     0.27      1.57    10.00     97.56%
  41 requests in 20.10s, 140.14KB read
Requests/sec:      2.04
Transfer/sec:      6.97KB

Nginx ログにはリクエストが遅延していることが示されていました:

2021/11/29 15:40:23 [warn] 2608#2608: *355 delaying request, excess: 78.992, by zone "static-corp", client: 10.100.2.130, server: zapazoid.vistashare.net, request: "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1", host: "zapazoid.vistashare.net"

アクセス ログは次のように構成されました。

    log_format apm '$remote_addr - $remote_user [$time_local] '             
                   '"$request" $status $body_bytes_sent '                   
                   '"$http_referer" "$http_user_agent" '                    
                   '$request_time $upstream_response_time '                 
                   '$upstream_cache_status';

アクセス ログでは、$request_timeリクエストが設定された制限内に収まるように遅延が進むにつれて、値が上昇していることが示されました (最後から 3 番目の値)。

10.100.2.130 - - [29/Nov/2021:15:46:51 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 0.001 0.004 MISS
10.100.2.130 - - [29/Nov/2021:15:46:51 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 0.496 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:46:52 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 0.995 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:46:52 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 1.495 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:46:53 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 1.999 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:46:53 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 2.495 0.004 MISS
...
10.100.2.130 - - [29/Nov/2021:15:47:02 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 11.467 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:03 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 11.964 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:03 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 12.466 0.004 MISS
10.100.2.130 - - [29/Nov/2021:15:47:04 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 12.963 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:04 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 13.460 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:05 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 13.961 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:05 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 14.452 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:06 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 14.946 0.000 MISS
10.100.2.130 - - [29/Nov/2021:15:47:06 -0500] "GET /Static/jquery.jnotify-1.1.min.js HTTP/1.1" 200 3098 "-" "-" 15.446 0.000 MISS

関連情報