void print_progress()

in wb/wb.c [918:1075]


void print_progress(int forced_print )
{
    if (!forced_print && !g_interval_print) 
        return;
    
    static apr_time_t prev_heartbeat_time = 0;
    static int heartbeats_num = 0, prev_done = 0;
    static apr_time_t time_now, delta_t;
    static int prev_bad, prev_err_conn, prev_err_recv, prev_err_length, prev_err_except;
    static int prev_epipe, prev_err_response;
    static apr_int64_t prev_totalbread, prev_totalposted, prev_totalread;
    static int sample_start = 0;
    

    time_now = apr_time_now();
    if (forced_print || (time_now - prev_heartbeat_time >= g_interval_print)) {
        if (!prev_heartbeat_time) 
                fprintf(stderr, "\n"); // first time, print the seperator
        else if (g_extended_progress && (heartbeats_num % 50 == 0)){
                fprintf(stderr,"________________________________________________________________________________\n");
                fprintf(stderr, "Time Req(#/sec) Recv(kBps) ");
                if (send_body)
                    fprintf(stderr, "Sent(kBps) ");
                fprintf(stderr, "Latency(min/max/mean[+/-sd] Failed(C/R/L/E/W/Non-2xx)");
                fprintf(stderr,"\n");
        }
        delta_t = time_now - prev_heartbeat_time;
        if (forced_print || prev_heartbeat_time) {
            if (!g_extended_progress) // print out simple info
            fprintf(stderr, "%2d: Completed %6d requests, rate is %lld #/sec.\n", 
                ++heartbeats_num, done, (long long int)(APR_USEC_PER_SEC * (done - prev_done)/delta_t));
            else {     // print out additional info
                apr_time_t totalcon = 0, total = 0, totald = 0, totalwait = 0;
                apr_time_t meancon, meantot, meand, meanwait;
                apr_interval_time_t mincon = AB_MAX, mintot = AB_MAX, mind = AB_MAX,
                                    minwait = AB_MAX;
                apr_interval_time_t maxcon = 0, maxtot = 0, maxd = 0, maxwait = 0;
                apr_interval_time_t mediancon = 0, mediantot = 0, mediand = 0, medianwait = 0;
                double sdtot = 0, sdcon = 0, sdd = 0, sdwait = 0;
                int req_num = done - prev_done;    
                
                if (req_num > 0){
                    /* work out connection times */
                    int i;

                    for (i = 0; i < req_num; i++) {
                        struct data *s = &stats[(i+sample_start)%g_stats_window];
                        mincon = ap_min(mincon, s->ctime);
                        mintot = ap_min(mintot, s->time);
                        mind = ap_min(mind, s->time - s->ctime);
                        minwait = ap_min(minwait, s->waittime);

                        maxcon = ap_max(maxcon, s->ctime);
                        maxtot = ap_max(maxtot, s->time);
                        maxd = ap_max(maxd, s->time - s->ctime);
                        maxwait = ap_max(maxwait, s->waittime);

                        totalcon += s->ctime;
                        total += s->time;
                        totald += s->time - s->ctime;
                        totalwait += s->waittime;
                    }
                    meancon = totalcon / req_num;
                    meantot = total / req_num;
                    meand = totald / req_num;
                    meanwait = totalwait / req_num;

                    /* calculating the sample variance: the sum of the squared deviations, divided by n-1 */
                    for (i = 0; i < req_num; i++) {
                        struct data *s = &stats[(i+sample_start)%g_stats_window];
                        double a;
                        a = ((double)s->time - meantot);
                        sdtot += a * a;
                        a = ((double)s->ctime - meancon);
                        sdcon += a * a;
                        a = ((double)s->time - (double)s->ctime - meand);
                        sdd += a * a;
                        a = ((double)s->waittime - meanwait);
                        sdwait += a * a;
                    }

                    sdtot = (req_num > 1) ? sqrt(sdtot / (req_num - 1)) : 0;
                    sdcon = (req_num > 1) ? sqrt(sdcon / (req_num - 1)) : 0;
                    sdd = (req_num > 1) ? sqrt(sdd / (req_num - 1)) : 0;
                    sdwait = (req_num > 1) ? sqrt(sdwait / (req_num - 1)) : 0;

                    if (!g_us_granularity) {
                        /*
                         * Reduce stats from apr time to milliseconds
                         */
                        mincon     = ap_round_ms(mincon);
                        mind       = ap_round_ms(mind);
                        minwait    = ap_round_ms(minwait);
                        mintot     = ap_round_ms(mintot);
                        meancon    = ap_round_ms(meancon);
                        meand      = ap_round_ms(meand);
                        meanwait   = ap_round_ms(meanwait);
                        meantot    = ap_round_ms(meantot);
                        mediancon  = ap_round_ms(mediancon);
                        mediand    = ap_round_ms(mediand);
                        medianwait = ap_round_ms(medianwait);
                        mediantot  = ap_round_ms(mediantot);
                        maxcon     = ap_round_ms(maxcon);
                        maxd       = ap_round_ms(maxd);
                        maxwait    = ap_round_ms(maxwait);
                        maxtot     = ap_round_ms(maxtot);
                        sdcon      = ap_double_ms(sdcon);
                        sdd        = ap_double_ms(sdd);
                        sdwait     = ap_double_ms(sdwait);
                        sdtot      = ap_double_ms(sdtot);
                   }
                }            
                sample_start = (sample_start + req_num)%g_stats_window;
                
                //fprintf(stderr, "\nTime Req(#/sec) Recv(kBps) Failed(C/R/L/E/W/Non-2xx)");
                fprintf(stderr, "%-5d%-11lld%-11lld", 
                        ++heartbeats_num,  
                        (long long int)(APR_USEC_PER_SEC * (done - prev_done)/delta_t),
                        (long long int)(APR_USEC_PER_SEC * (totalread - prev_totalread)/delta_t/1000));
                if (send_body)
                    //fprintf(stderr, "Sent(kBps) ");
                    fprintf(stderr, "%-11lld", (long long int)(APR_USEC_PER_SEC*(totalposted - prev_totalposted)/delta_t/1000));

                //fprintf(stderr, "Latency(min/max/avg/+-sd) Failed(C/R/L/E/W/Non-2xx)");
                fprintf(stderr, "%-6lld/%-8lld/%-6lld/%-8.1f/",(long long int)mintot,(long long int)maxtot,(long long int)meantot,sdtot);
                fprintf(stderr, "%d", bad - prev_bad);
                if (bad) {
                    fprintf(stderr, "(%d/%d/%d/%d/%d/%d)",
                        err_conn - prev_err_conn,
                        err_recv - prev_err_recv,
                        err_length - prev_err_length,
                        err_except - prev_err_except,
                        epipe - prev_epipe,
                        err_response - prev_err_response);
                }
                fprintf(stderr,"\n");
                prev_totalread = totalread;
                prev_totalposted = totalposted;
                prev_bad = bad;
                if (bad) {
                    prev_err_conn=err_conn;
                    prev_err_recv=err_recv;
                    prev_err_length=err_length;
                    prev_err_except=err_except;
                    prev_epipe=epipe;
                    prev_err_response=err_response;        
                }            

                
            }

            fflush(stderr);
            prev_done = done;
        }
        prev_heartbeat_time = time_now;

    }
} // end of print_progress