为何统计$request_time但是，内容是0.000

[Freeman Zhang]

HI All,

最近我们使用access log中的$request_time来分析对客户服务的质量
这台机器上配置有nginx cache
于是得到的$request_time常常有0.000的统计。。。。大概50%的访问是这样，每个请求发送3k上下

例：我去掉了其中的<host>信息和url信息。其中粗体的就是$request_time结果，我可否通过衡量$request_time来确定服务质量？

<host>         <host>    113.71.127.172  28/Nov/2012:14:30:05 +0800       93551   0.137   200     -       HIT     -               GET     -       MiTalk 565 (GT-I9100;10;zh) 2.3.6

<host>         <host>    120.41.114.14   28/Nov/2012:14:30:06 +0800        193     5313    0.000   200     -       HIT     -               GET     -       MiTalk 565 (SAMSUNG-SGH-I997;10;zh) 2.3.6

<host>         <host>    120.41.114.14   28/Nov/2012:14:30:06 +0800        193     7089    0.000   200     -       HIT     -               GET     -       MiTalk 565 (SAMSUNG-SGH-I997;10;zh) 2.3.6

<host>        <host>      120.41.114.14   28/Nov/2012:14:30:07 +0800        193     6223    0.000   200     -       HIT     -               GET     -       MiTalk 565 (SAMSUNG-SGH-I997;10;zh) 2.3.6

<host>        <host>      120.41.114.14   28/Nov/2012:14:30:07 +0800          6243    0.000   200     -       HIT     -               GET     -       MiTalk 565 (SAMSUNG-SGH-I997;10;zh) 2.3.6

10.9.2.33       121.11.79.75    120.41.114.14   28/Nov/2012:14:30:07 +0800      /mfsv2/avatar/s008/p01ztnKbce6l/xTPvAiZc3Nud8_150.jpeg  193     4781    0.000   200     -       HIT     -               GET     -       MiTalk 565 (SAMSUNG-SGH-I997;10;zh) 2.3.6

10.9.2.33       121.11.79.75    106.111.226.240 28/Nov/2012:14:30:07 +0800      /mfsv2/avatar/s008/p01EFT93exoo/H1hqSCkH2xGfIR.jpg      182     1415    0.000   200     -       HIT     -               GET     -       MiTalk 180 (MI-ONE C1;10;zh) 2.3.5

[pengqi]

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。

另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

--
邮件自: 列表“openresty”,专用于技术讨论!
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+...@googlegroups.com
详情: http://groups.google.com/group/openresty
官网: http://openresty.org/
仓库: https://github.com/agentzh/ngx_openresty
建议: 提问的智慧 http://wiki.woodpecker.org.cn/moin/AskForHelp
教程: http://agentzh.org/misc/nginx/agentzh-nginx-tutorials-zhcn.html

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

[Freeman Zhang]

我想问的是，可否使用$request_time来衡量用户端的感受？

[pengqi]

一般来说这个$request_time只是nginx处理请求的时间，并不包括网络发送数据到客户端的传输时间，如果网络状况很差，即使$request_time很小，用户端的感受时间仍然很长。一个可选的做法是，关闭掉keepalive，然后打开lingering_close，此时$request_time将包括客户端接收数据的时间。

[Freeman Zhang]

意思是客户端链接、收到并且关闭了connection之后的整个时间？
看了源代码，request_time是在log_module中做的
log_module是否是整个requet结束的时间？即包括event module处理完成的时候，整个时候是否可以认为client tcp层已经收到并发送了ack，然后os接收了ack的时间？

[pengqi]

Hi,

在 2012年11月28日 下午4:30，Freeman Zhang <pcman...@gmail.com>写道：

意思是客户端链接、收到并且关闭了connection之后的整个时间？

对。

 

看了源代码，request_time是在log_module中做的
log_module是否是整个requet结束的时间？即包括event module处理完成的时候，整个时候是否可以认为client tcp层已经收到并发送了ack，然后os接收了ack的时间？

之前说了这里根据配置有两种情况，keepalive打开或lingering_close关闭的情况下，请求rt的结束点为nginx将响应数据写入到发送缓冲区；keepalive关闭且lingering_close打开的情况下，请求的结束点为客户端接收完数据关闭连接，nginx收到此事件。

[刘太华]

$request_time is always time since start of the request (when
first bytes are read from client) till end of the request (when
last bytes are sent to client and logging happens).

Maxim Dounin

from:  http://forum.nginx.org/read.php?2,218716,218717#msg-218717

刘太华

[pengqi]

起始点是第1个数据包过来开始算，结束点具体看你是怎么配置，就是分我上面说的那2种情况。

[吴俊伟]

Hi，

看了解答，明白了是怎么回事。

但是也有一个问题：关闭keepalive之后，用户的体验会变差，有没有别的办法不需要关闭keepalive也能衡量服务质量？

我是这么想的，每次数据发送结束之后，都会有一个ack，每次发送的数据的最后的一个ack的时间减去接收到请求的时间应该就包括数据的传输时间，可以反应服务质量

不知道想的对不对，如果想法是正确的，如何去配置这个时间呢？

[Yichun Zhang (agentzh)]

Hello!

2014-09-16 20:05 GMT-07:00 吴俊伟:
> 但是也有一个问题：关闭keepalive之后，用户的体验会变差，有没有别的办法不需要关闭keepalive也能衡量服务质量？
>

或许你需要的是 $upstream_response_time 这个变量？

http://nginx.org/en/docs/http/ngx_http_upstream_module.html#var_upstream_response_time

Regards,
-agentzh

[XL T]

我现在用 openresty ，然后写了一个耗时的 for 循环，但是 request_time 还是 0.000.

我把请求都用 lua 处理了，就没有把请求再 upstream ，所以 upstream_response_time 是 “-” 是正常的。要是说 upstream 是 php 的 cgi 的话 upstream_response_time 是有值的。

现在的疑问就是 request_time 为什么是 0.000， 再者怎么得出我访问该耗时地址所消耗的时间呢？

[liujin...@gmail.com]

我也遇到同样的问题，我也是用openresty这样测试，request_time是0.000，请问你这边解决了吗？

在 2016年12月16日星期五 UTC+8上午11:57:56，xl_tan写道：

[Zexuan Luo]

你可能需要在获取 ngx.var.request_time 之前调用 ngx.update_time()
nginx 会缓存时间，通常只在有新的事件时才会更新。正常 HTTP 服务下，一般都能及时更新时间；不过如果只是用单个请求测试就不一定了。


在 2017年2月8日星期三 UTC+8上午11:00:42，liujin...@gmail.com写道：