Request Time in Nginx Log as always 0.000 for HIT Request

[Maxim Dounin]

Hello!

On Mon, Aug 03, 2020 at 03:54:15PM -0400, anish10dec wrote:

> In our case response body is of size around 4MB to 8MB and its showing
> 0.000.
> 
> Since "request time" is for analyzing the time taken for delivering the
> content to client , we are not able to get the actual value or time taken .
> 
> Even on slow user connection its showing 0.000 . 
> Generally it should be much higher as it captures the total time taken for
> delivering last byte of the content to user.

The $request_time variable shows the time from reading the the 
first byte of the request from the client to sending the last byte 
of the response to the socket buffer.  Note the difference: not 
deliverying the last byte to the user, but sending the response to 
the socket buffer.  With large enough socket buffers and/or small 
enough responses $request_time can be 0, and usually this is 
expected result since all request processing happens within a 
single event loop iteration.

In some extreme cases $request_time can be seen to be 0 even if 
sending the response is slow and takes significant time: this 
might happen if reading from disk is very slow (slower than 
sending to the client), so nginx never blocks on sending.  Most 
often this happens when using sendfile, and the sendfile_max_chunk 
directive (http://nginx.org/r/sendfile_max_chunk) can be used to 
limit the amount of data sent within a single event loop 
iteration.  Given the response sizes this is unlikely your case 
though, as 4M to 8M looks quite comparable to modern sizes of 
socket buffers, especially when using auto-tuning.

-- 
Maxim Dounin
http://mdounin.ru/