/*!
* @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. */
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));
}
