Esempio n. 1
0
/*!
 * @brief Displays rate info about the timer.
 *
 * This function prints a load of information about the rate of a timer's start times 
 * to the console.
 *
 * @param     timer     The timer for which info should be shown.
 * @param     show_all  After the average, etc. show all periods, 1 per line. Set false if
 *                      only a summary of the times is needed.
 *
 * @return 0 if successful
 */
void timing_print_rate_info(TIMING_TIMER_T * timer, bool show_all)
{
    int i;
    struct timeval lowest_elapsed_time = {100000000, 0};
    int lowest_elapsed_time_index = 0;
    struct timeval highest_elapsed_time = {0, 0};
    int highest_elapsed_time_index = 0;
    int rate;
    unsigned long std_dev = 0;
    int elapsed_usec;
    int average_usec;
    
    struct timeval elapsed_time = {0, 0};
    struct timeval total_elapsed_time = {0, 0};
    struct timeval average_elapsed_time = {0, 0};
    struct timeval delta;
    
    /* Since we are looking at the start times for rate information, we need two times stored
     * for one period, three times for two periods, etc. */
    int num_periods = timer->num_times_recorded - 1;
    
    /* There's no point in continuing if there is insufficient information available
     * to show period information. */
    if(num_periods <= 0)
    {
        tracemsg(_a("Rate info: %d timer start/stops is insufficient for rate analysis."), 
                    timer->num_times_recorded);
        return;
    }
    
    tracemsg(_a("Rate info: number of periods captured: %d"), num_periods);
    
    /* Go figure out some info about the timers captured. */
    for(i = 0; i < num_periods; i++)
    {
        /* Get elapsed_time between the two start times. */
        subtract(&(timer->times[i].start_time), &(timer->times[i+1].start_time), &elapsed_time);
                                   
        /* Check elapsed time against highest. */
        if(greater_than(&elapsed_time, &highest_elapsed_time))
        {
            highest_elapsed_time.tv_sec = elapsed_time.tv_sec;
            highest_elapsed_time.tv_usec = elapsed_time.tv_usec;
            highest_elapsed_time_index = i;
        }
            
        /* Check elapsed time against lowest. */
        if(less_than(&elapsed_time, &lowest_elapsed_time))
        {
            lowest_elapsed_time.tv_sec = elapsed_time.tv_sec;
            lowest_elapsed_time.tv_usec = elapsed_time.tv_usec;
            lowest_elapsed_time_index = i;
        }
            
        /* Add this elapsed time to total. */
        add(&elapsed_time, &total_elapsed_time, &total_elapsed_time);
            
        if(false)
        {
            tracemsg(_a("      result %4d: elapsed time %2lds, %6ld usec"), 
                         i, elapsed_time.tv_sec, elapsed_time.tv_usec);
        }
    }
            
    /* Figure out the average elapsed time. */
    average(&total_elapsed_time, timer->num_times_recorded, &average_elapsed_time);
    rate = rate_per_sec(&average_elapsed_time);
            
    tracemsg(_a(" Average period %2lds, %6ld usec (%d/sec)"), 
                average_elapsed_time.tv_sec, average_elapsed_time.tv_usec, rate);
                
    /* Figure out standard deviation for the set of periods. */
    average_usec = USECS(average_elapsed_time);
    for(i = 0; i < num_periods; i++)
    {
        /* Get elapsed_time between the two start times. */
        subtract(&(timer->times[i].start_time), &(timer->times[i+1].start_time), &elapsed_time);
        elapsed_usec = USECS(elapsed_time);
        std_dev += ((elapsed_usec - average_usec) * (elapsed_usec - average_usec));
    }
    
    std_dev = std_dev / i; /* Rounding error shouldn't matter too much.*/
    std_dev = square_root(std_dev);
    tracemsg(_a(" Approx std dev      %6ld usec"), std_dev);
                       
    /* For highest time recorded, figure out delta between this and average. */
    subtract(&average_elapsed_time, &highest_elapsed_time, &delta);
    rate = rate_per_sec(&highest_elapsed_time);
    tracemsg(_a(" Highest period %2lds, %6ld usec (%3d/sec, delta from avg %lds, %6ld us, result %d)"), 
                highest_elapsed_time.tv_sec, highest_elapsed_time.tv_usec, 
                rate, delta.tv_sec, delta.tv_usec, 
                highest_elapsed_time_index);
                       
    /* Same for lowest. */
    subtract(&lowest_elapsed_time, &average_elapsed_time, &delta);
    rate = rate_per_sec(&lowest_elapsed_time);          
    tracemsg(_a("  Lowest period %2lds, %6ld usec (%3d/sec, delta from avg %lds, %6ld us, result %d)"), 
                lowest_elapsed_time.tv_sec, lowest_elapsed_time.tv_usec, 
                rate, delta.tv_sec, delta.tv_usec, 
                lowest_elapsed_time_index);
    
               
    /* If told to show everything, dump all of the values to text in units of microseconds. 
     * Put commas before and after each value to make this easier to import into excel or
     * whatever as CSV as there's some sort of timestamp prepended to every printk these days... */ 
    if(show_all)
    {
        tracemsg(_a(""));
        tracemsg(_a(" All periods recorded (usecs):")); 
        for(i = 0; i < num_periods; i++)
        {
            subtract(&(timer->times[i].start_time), &(timer->times[i+1].start_time), &elapsed_time);
            tracemsg(",%ld,\n", USECS(elapsed_time));
        }
    }
        
} /* End of rate info. */
Esempio n. 2
0
void periodic_work() {
  fprintf(stderr,"i/o summary\n");
  fprintf(stderr," spool read rate:  %f msgs/sec\n", rate_per_sec(CF.spr_msgs_ts));
  fprintf(stderr," xmitr#1 intake rate:  %f msgs/sec\n", rate_per_sec(CF.kaf_msgs_ts));
  fprintf(stderr," xmitr#1 output rate: %f bytes/sec\n", rate_per_sec(CF.kaf_bytes_ts));
}