http2 request log in accurate $request_time ?

xt3627216 nginx-forum at forum.nginx.org
Wed Jan 22 15:38:42 UTC 2020


nginx version: nginx-1.9.5 


hi,nginx compute $request_time   in log phase, which is in    

ngx_http_free_request (r) ->  ngx_http_log_request(r) -> log_handler(r)


but in http2 world, I see  every request closed through
ngx_http_v2_close_stream(stream, rc)

in ngx_http_v2_close_stream    have code below:


```
void
ngx_http_v2_close_stream(ngx_http_v2_stream_t *stream, ngx_int_t rc)
{
    ngx_event_t               *ev;
    ngx_connection_t          *fc;
    ngx_http_v2_node_t        *node;
    ngx_http_v2_connection_t  *h2c;

    h2c = stream->connection;
    node = stream->node;

    ngx_log_debug3(NGX_LOG_DEBUG_HTTP, h2c->connection->log, 0,
                   "http2 close stream %ui, queued %ui, processing %ui",
                   node->id, stream->queued, h2c->processing);
    
    fc = stream->request->connection;
    
    if (stream->queued) {
        fc->write->handler = ngx_http_v2_close_stream_handler;              
   
        return;
    }

    if (!stream->out_closed) {
        if (ngx_http_v2_send_rst_stream(h2c, node->id,
                                        NGX_HTTP_V2_INTERNAL_ERROR)
            != NGX_OK)
        {
            h2c->connection->error = 1;
        }
    }
    
    node->stream = NULL;
            
    ngx_queue_insert_tail(&h2c->closed, &node->reuse);
    h2c->closed_nodes++;
        
    ngx_http_free_request(stream->request, rc);
    xxx
}
```
if  stream->queued  is true,   then ngx_http_free_request will not be called
immediately, which will result $request_time larger then real request time?



any body can affirm this ?

Posted at Nginx Forum: https://forum.nginx.org/read.php?2,286797,286797#msg-286797



More information about the nginx mailing list