Bug 65082 - Duration of request is calculated wrong when ap_process_async_request is involved
Summary: Duration of request is calculated wrong when ap_process_async_request is invo...
Status: NEW
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: Core (show other bugs)
Version: 2.5-HEAD
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-01-15 17:16 UTC by boyanfb
Modified: 2021-01-18 15:59 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
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;
        }