Bug 65082

Summary: Duration of request is calculated wrong when ap_process_async_request is involved
Product: Apache httpd-2 Reporter: boyanfb
Component: CoreAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: NEW ---    
Severity: normal CC: boyanfb
Priority: P2    
Version: 2.5-HEAD   
Target Milestone: ---   
Hardware: PC   
OS: Linux   

Description boyanfb 2021-01-15 17:16:00 UTC
During ap_process_request(), ap_process_async_request() is called which at start sets the request start time using:

            ap_time_process_request(r->connection->sbh, START_PREQUEST);

At the end it increases the worker duration with the difference between the time set using START_PREQUEST and STOP_PREQUEST

            ap_time_process_request(c->sbh, STOP_PREQUEST);
Now back to ap_process_request() which also increases the duration, using the the same START_PREQUEST

            ap_time_process_request(c->sbh, STOP_PREQUEST);

thus the time spent inside ap_process_async_request() is doubled(in.

The code that sets the duration is this(scoreboard.c):

    if (status == START_PREQUEST) {
        ws->start_time = ws->last_used = apr_time_now();
    else if (status == STOP_PREQUEST) {
        ws->stop_time = ws->last_used = apr_time_now();
        if (ap_extended_status) {
            ws->duration += ws->stop_time - ws->start_time;