Nginx-ru mailing list archive (nginx-ru@sysoev.ru)
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: $upstream_response_time != времени о твета бэкэнда
Hello!
On Fri, Oct 22, 2010 at 07:43:13PM +0400, cronfy wrote:
> День добрый.
>
> Решил поэкспериментировать с 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'ы, до закрытия соединения с бэкэнда.
>
> Вопросы: это баг или фича и можно ли каким-либо образом все-таки
> получить чистое время, за которое данные были получены от бэкэнда?
Тот факт, что perl'овый sleep() оказывается включён в
$upstream_response_time - следствие того, что время в nginx'е
обновляется только при получении очередной партии событий из ядра.
Предполагается, что код не блокируется и соответственно обработка
событий происходит быстро.
Выглядит всё как-то так:
<получили событие из ядра>
обновили время
...
сделали sleep()
...
запомнили время перед тем как делать connect()
сделали connect()
В результате запомненное время - было получено из ядра до вызова
sleep(), и соответственно время sleep() будет включено в
$upstream_response_time.
Maxim Dounin
_______________________________________________
nginx-ru mailing list
nginx-ru@xxxxxxxxx
http://nginx.org/mailman/listinfo/nginx-ru
|