Re: $request_time vs. $upstream_response_time

[Igor Sysoev <is@xxxxxxxxxxxxx>]

On Mon, Apr 28, 2008 at 01:32:15PM +0400, umask wrote:

> Добрый день,
> 
> 
> 
> Пишу лог так:
> 
>         # logging upstream request processing time
> 
>         log_format  main  '$remote_addr - $remote_user [$time_local] 
> "$request" '
> 
>                           '"$status" $body_bytes_sent "$http_referer" '
> 
>                           '"$http_user_agent" "$http_x_forwarded_for" '
> 
>                           '$request_time "$upstream_addr" 
> [$upstream_response_time]';
> 
> 
> 
> Вот кусок лога:
> 
> 
> 
> 
> 
> 217.118.66.30 - - [28/Apr/2008:05:15:39 +0400] "GET /... HTTP/1.1" "200" 363 
> "-" "Nokia6151/2.0 (03.56) Profile/MIDP-2.0 Configuration/CLDC-1.1" "-" 0.223 
> "127.0.0.1:8180" [0.223]
> 
> 87.225.69.128 - - [28/Apr/2008:05:17:14 +0400] "GET /... HTTP/1.1" "200" 357 
> "http://prik.us/indexh.php"; "MOT-V80/0E.03.26R MIB/2.2.1 Profile/MIDP-2.0 
> Configuration/CLDC-1.0" "213.145.144.252" 0.256 "127.0.0.1:8180" [0.256]
> 
> 87.225.69.128 - - [28/Apr/2008:05:17:39 +0400] "GET /... HTTP/1.1" "200" 355 
> "http://prik.us/indexh.php"; "Nokia8310/1.0 (05.11)" "80.67.210.155" 0.209 
> "127.0.0.1:8180" [0.209]
> 
> 200.35.64.68 - - [28/Apr/2008:06:42:28 +0400] "GET /... HTTP/1.0" "200" 355 
> "-" "Nokia5610 XpressMusic/2.0 (04.88) Profile/MIDP-2.1 
> Configuration/CLDC-1.1" "10.16.71.6" 0.852 "127.0.0.1:8180" [0.852]
> 
> 217.148.51.144 - - [28/Apr/2008:12:45:56 +0400] "GET /... HTTP/1.1" "200" 415 
> "-" "Philips292 / Obigo Browser 2.0" "-" 0.273 "127.0.0.1:8180" [0.273]
> 
> 80.93.48.119 - - [28/Apr/2008:13:04:59 +0400] "GET /... HTTP/1.0" "200" 262 
> "-" "-" "-" 0.251 "127.0.0.1:8180" [0.237]
> 
> 
> 
> Вопрос.
> 
> Входит ли $request_time в $upstream_response_time?
> 
> 
> 
> По логике так.
> 
> $request_time - это время, сколько nginx получал от клиента все данные 
> запроса в буфер. Потом эти данные из буфера передались на бэкенд. К бэкенду 
> это время никакого отношения не имеет.
> 
> $upstream_response_time - это время, которое прошло с того момента, как nginx 
> отправил бэкенду запрос и до того момента, когда бэкенд ему полностью ответил.
> 
> 
> 
> Но по вырезке из лога складывается впечатление, что $upstream_response_time 
> включает в себя $request_time. Поясните, пожалуйста.

Да. $request_time - это время обработки запроса. Считается от получения первых
данных от клиента до оправления последних данных для клиента в ядро.


-- 
Игорь Сысоев
http://sysoev.ru