$upstream_response_time != времени ответа бэкэнда
cronfy
cronfy на gmail.com
Пт Окт 22 19:43:13 MSD 2010
День добрый.
Решил поэкспериментировать с upstream_response_time - посмотреть, за
сколько времени бэкэнд отдает ответ. Когда-то давно Игорь писал:
>> т.е. время, за которое реально бэкенд генерил ответ равно
>> $upstream_response_time минус $request_time?
IS> Нет, это время как раз $upstream_response_time.
IS> $upstream_response_time - это время от вызова connect() и до закрытия
IS> соединения с бэкендом.
Простой тест: добавляем в server {} вызов перловой ф-ии, которая
делает sleep(1).
perl_set $slp NGX_PERL::sleepAWhile;
log_format TIME '[$time_local] $upstream_response_time $request_time' ;
server {
...
set $s $slp;
location / {
...
proxy_pass ...
}
}
В итоге в логе время $upstream_response_time и $request_time почти
всегда равны друг другу и составляют чуть более секунды:
[22/Oct/2010:19:23:44 +0400] 1.077 1.141
[22/Oct/2010:19:24:24 +0400] 1.078 1.078
[22/Oct/2010:19:24:25 +0400] 1.050 1.050
[22/Oct/2010:19:24:36 +0400] 1.161 1.161
[22/Oct/2010:19:24:45 +0400] 1.048 1.048
[22/Oct/2010:19:24:47 +0400] 1.052 1.052
[22/Oct/2010:19:24:58 +0400] 1.130 1.130
Видимо, в nginx connect() делается несколько раньше, чем выполняется
set $s. Фактически получается, что upstream_response_time - это не
время обработки запроса бэкэндом, а время с момента начала исполнения
location, включая все rewrite'ы, до закрытия соединения с бэкэнда.
Вопросы: это баг или фича и можно ли каким-либо образом все-таки
получить чистое время, за которое данные были получены от бэкэнда?
Спасибо.
--
// cronfy
Подробная информация о списке рассылки nginx-ru