Hello!
On Fri, Feb 15, 2019 at 12:54:37PM -0500, joao.pereira wrote:
> We are trying to measure times using the variables referred on the following
> article and on the emails above:
> https://www.nginx.com/blog/using-nginx-logging-for-application-performance-monitoring/#var_request_time
>
> But It came to our attention that those are not accurate, our log file:
> log_format main ‘“$request_time" - $upstream_response_time” -
> “$upstream_connect_time” - “$upstream_header_time”;
>
> STALE only show $request_time but no $upstream_*
> Hits are taking "0.000 to 0.001 which makes no sense because we are doing
> the request from EU to US, the MISS seems ok as they show both
> $request_time and $upstream_* , there is any way to measure these times
> properly ?
The "HIT" status means that a response was returned from cache.
Since there is no request to the upstream server, no upstream
times are expected to be available. The $request_time variable
counts time between reading the first byte of a request from the
socket and writing the last byte of the response to the socket.
As long as socket buffers are large enough, this can happen in one
event loop iteration, so times like "0.000" are pretty normal for
small responses.
The "STALE" status means that the response was returned from
cache, as per "proxy_cache_use_stale". And this implies that
there will be no upstream times, much like with "HIT".
Note well that if you are using "proxy_cache_background_update",
which uses subrequests to update cache, the main request will have
the "STALE" status, and there will be no upstream times as
explained above, but $request_time will still include subrequest
execution time. If you want to see subrequest details in log,
including upstream times, consider the "log_subrequest"
configuration directive (http://nginx.org/r/log_subrequest).
--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx mailing list
nginx@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx
