☰

nginx $request_time 中是否包含速率限制延迟？

tag-icon • tag-icon nginx http
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值不断攀升（从末尾开始的第三个值），因为请求越来越延迟以达到配置的限制：

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

相关内容