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

pcman.zhang · 2012-11-28T15:15:15+00:00

Hello! 2012/12/2 tiger yang: > 内存泄漏的问题解决了，出在cloudwu的pbc...

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

pcman.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

fengmo.q

Hi,

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

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

http://tengine.taobao.org/

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

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

Jinglong
Software Engineer
Server Platforms Team at Taobao

pcman.zhang

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

fengmo.q

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

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

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

Jinglong
Software Engineer
Server Platforms Team at Taobao

pcman.zhang

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

On Wednesday, November 28, 2012 3:47:19 PM UTC+8, jinglong wrote:

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

在 2012年11月28日下午3:36，Freeman Zhang <pcman...@gmail.com>写道：
我想问的是，可否使用$request_time来衡量用户端的感受？

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

fengmo.q

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收到此事件。

On Wednesday, November 28, 2012 3:47:19 PM UTC+8, jinglong wrote:

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

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

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

Jinglong
Software Engineer
Server Platforms Team at Taobao

defage

$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

在 2012年11月28日下午4:50，pengqi <fen...@gmail.com>写道：

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收到此事件。

On Wednesday, November 28, 2012 3:47:19 PM UTC+8, jinglong wrote:

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

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

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--
刘太华

fengmo.q

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

在 2012年11月30日下午3:25，刘太华 <de...@gmail.com>写道：

$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

在 2012年11月28日下午4:50，pengqi <fen...@gmail.com>写道：

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收到此事件。

On Wednesday, November 28, 2012 3:47:19 PM UTC+8, jinglong wrote:

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

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

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--
刘太华

Jinglong
Software Engineer
Server Platforms Team at Taobao

backingwu

Hi，

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

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

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

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

On Friday, November 30, 2012 3:33:27 PM UTC+8, jinglong wrote:

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

在 2012年11月30日下午3:25，刘太华 <def...@gmail.com>写道：

$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

在 2012年11月28日下午4:50，pengqi <feng...@gmail.com>写道：

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收到此事件。

On Wednesday, November 28, 2012 3:47:19 PM UTC+8, jinglong wrote:

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

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

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

On Wednesday, November 28, 2012 3:24:58 PM UTC+8, jinglong wrote:

Hi,

$request_time最小精度为ms，很可能请求的处理时间就是很短。
另外淘宝开源的nginx fork，tengine中支持精度为微秒的变量$request_time_usec，有需要可以试试：）

http://tengine.taobao.org/

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

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

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--
刘太华

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

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

txldroid

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

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

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

On Thursday, September 18, 2014 at 4:09:47 AM UTC+8, agentzh wrote:

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

liujingjun001

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

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

我现在用 openresty ，然后写了一个耗时的 for 循环，但是 request_time 还是 0.000.
我把请求都用 lua 处理了，就没有把请求再 upstream ，所以 upstream_response_time 是 “-” 是正常的。要是说 upstream 是 php 的 cgi 的话 upstream_response_time 是有值的。
现在的疑问就是 request_time 为什么是 0.000，再者怎么得出我访问该耗时地址所消耗的时间呢？

On Thursday, September 18, 2014 at 4:09:47 AM UTC+8, agentzh wrote:
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

spacewanderlzx

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

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

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

在 2016年12月16日星期五 UTC+8上午11:57:56，xl_tan写道：
我现在用 openresty ，然后写了一个耗时的 for 循环，但是 request_time 还是 0.000.
我把请求都用 lua 处理了，就没有把请求再 upstream ，所以 upstream_response_time 是 “-” 是正常的。要是说 upstream 是 php 的 cgi 的话 upstream_response_time 是有值的。
现在的疑问就是 request_time 为什么是 0.000，再者怎么得出我访问该耗时地址所消耗的时间呢？

On Thursday, September 18, 2014 at 4:09:47 AM UTC+8, agentzh wrote:
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