X-Git-Url: https://git.kernel.dk/?p=fio.git;a=blobdiff_plain;f=stat.c;h=a8a96c85a4120b0d70dee939c9102fe340565aae;hp=23657cee6a7702c3aacd81783acb1516b3960a1b;hb=beb4a5b43197e579bf91db007539c999fb04fe13;hpb=5c0abd5e21df3b0ca7ee0833eb0ddf3f87ad4374 diff --git a/stat.c b/stat.c index 23657cee..a8a96c85 100644 --- a/stat.c +++ b/stat.c @@ -282,6 +282,46 @@ bool calc_lat(struct io_stat *is, unsigned long long *min, return true; } +void show_mixed_group_stats(struct group_run_stats *rs, struct buf_output *out) +{ + char *io, *agg, *min, *max; + char *ioalt, *aggalt, *minalt, *maxalt; + uint64_t io_mix = 0, agg_mix = 0, min_mix = -1, max_mix = 0, min_run = -1, max_run = 0; + int i; + const int i2p = is_power_of_2(rs->kb_base); + + for (i = 0; i < DDIR_RWDIR_CNT; i++) { + if (!rs->max_run[i]) + continue; + io_mix += rs->iobytes[i]; + agg_mix += rs->agg[i]; + min_mix = min_mix < rs->min_bw[i] ? min_mix : rs->min_bw[i]; + max_mix = max_mix > rs->max_bw[i] ? max_mix : rs->max_bw[i]; + min_run = min_run < rs->min_run[i] ? min_run : rs->min_run[i]; + max_run = max_run > rs->max_run[i] ? max_run : rs->max_run[i]; + } + io = num2str(io_mix, rs->sig_figs, 1, i2p, N2S_BYTE); + ioalt = num2str(io_mix, rs->sig_figs, 1, !i2p, N2S_BYTE); + agg = num2str(agg_mix, rs->sig_figs, 1, i2p, rs->unit_base); + aggalt = num2str(agg_mix, rs->sig_figs, 1, !i2p, rs->unit_base); + min = num2str(min_mix, rs->sig_figs, 1, i2p, rs->unit_base); + minalt = num2str(min_mix, rs->sig_figs, 1, !i2p, rs->unit_base); + max = num2str(max_mix, rs->sig_figs, 1, i2p, rs->unit_base); + maxalt = num2str(max_mix, rs->sig_figs, 1, !i2p, rs->unit_base); + log_buf(out, " MIXED: bw=%s (%s), %s-%s (%s-%s), io=%s (%s), run=%llu-%llumsec\n", + agg, aggalt, min, max, minalt, maxalt, io, ioalt, + (unsigned long long) min_run, + (unsigned long long) max_run); + free(io); + free(agg); + free(min); + free(max); + free(ioalt); + free(aggalt); + free(minalt); + free(maxalt); +} + void show_group_stats(struct group_run_stats *rs, struct buf_output *out) { char *io, *agg, *min, *max; @@ -306,7 +346,7 @@ void show_group_stats(struct group_run_stats *rs, struct buf_output *out) max = num2str(rs->max_bw[i], rs->sig_figs, 1, i2p, rs->unit_base); maxalt = num2str(rs->max_bw[i], rs->sig_figs, 1, !i2p, rs->unit_base); log_buf(out, "%s: bw=%s (%s), %s-%s (%s-%s), io=%s (%s), run=%llu-%llumsec\n", - rs->unified_rw_rep ? " MIXED" : str[i], + (rs->unified_rw_rep == UNIFIED_MIXED) ? " MIXED" : str[i], agg, aggalt, min, max, minalt, maxalt, io, ioalt, (unsigned long long) rs->min_run[i], (unsigned long long) rs->max_run[i]); @@ -320,6 +360,10 @@ void show_group_stats(struct group_run_stats *rs, struct buf_output *out) free(minalt); free(maxalt); } + + /* Need to aggregate statisitics to show mixed values */ + if (rs->unified_rw_rep == UNIFIED_BOTH) + show_mixed_group_stats(rs, out); } void stat_calc_dist(uint64_t *map, unsigned long total, double *io_u_dist) @@ -418,7 +462,7 @@ static double convert_agg_kbytes_percent(struct group_run_stats *rs, int ddir, i { double p_of_agg = 100.0; if (rs && rs->agg[ddir] > 1024) { - p_of_agg = mean * 100 / (double) (rs->agg[ddir] / 1024.0); + p_of_agg = mean * 100.0 / (double) (rs->agg[ddir] / 1024.0); if (p_of_agg > 100.0) p_of_agg = 100.0; @@ -426,6 +470,168 @@ static double convert_agg_kbytes_percent(struct group_run_stats *rs, int ddir, i return p_of_agg; } +static void show_mixed_ddir_status(struct group_run_stats *rs, struct thread_stat *ts, + struct buf_output *out) +{ + unsigned long runt; + unsigned long long min, max, bw, iops; + double mean, dev; + char *io_p, *bw_p, *bw_p_alt, *iops_p, *post_st = NULL; + struct thread_stat *ts_lcl; + + int i2p; + int ddir = 0, i; + + /* Handle aggregation of Reads (ddir = 0), Writes (ddir = 1), and Trims (ddir = 2) */ + ts_lcl = malloc(sizeof(struct thread_stat)); + memset((void *)ts_lcl, 0, sizeof(struct thread_stat)); + ts_lcl->unified_rw_rep = UNIFIED_MIXED; /* calculate mixed stats */ + for (i = 0; i < DDIR_RWDIR_CNT; i++) { + ts_lcl->clat_stat[i].min_val = ULONG_MAX; + ts_lcl->slat_stat[i].min_val = ULONG_MAX; + ts_lcl->lat_stat[i].min_val = ULONG_MAX; + ts_lcl->bw_stat[i].min_val = ULONG_MAX; + ts_lcl->iops_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_high_prio_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_low_prio_stat[i].min_val = ULONG_MAX; + } + ts_lcl->sync_stat.min_val = ULONG_MAX; + + sum_thread_stats(ts_lcl, ts, 1); + + assert(ddir_rw(ddir)); + + if (!ts_lcl->runtime[ddir]) + return; + + i2p = is_power_of_2(rs->kb_base); + runt = ts_lcl->runtime[ddir]; + + bw = (1000 * ts_lcl->io_bytes[ddir]) / runt; + io_p = num2str(ts_lcl->io_bytes[ddir], ts->sig_figs, 1, i2p, N2S_BYTE); + bw_p = num2str(bw, ts->sig_figs, 1, i2p, ts->unit_base); + bw_p_alt = num2str(bw, ts->sig_figs, 1, !i2p, ts->unit_base); + + iops = (1000 * ts_lcl->total_io_u[ddir]) / runt; + iops_p = num2str(iops, ts->sig_figs, 1, 0, N2S_NONE); + + log_buf(out, " mixed: IOPS=%s, BW=%s (%s)(%s/%llumsec)%s\n", + iops_p, bw_p, bw_p_alt, io_p, + (unsigned long long) ts_lcl->runtime[ddir], + post_st ? : ""); + + free(post_st); + free(io_p); + free(bw_p); + free(bw_p_alt); + free(iops_p); + + if (calc_lat(&ts_lcl->slat_stat[ddir], &min, &max, &mean, &dev)) + display_lat("slat", min, max, mean, dev, out); + if (calc_lat(&ts_lcl->clat_stat[ddir], &min, &max, &mean, &dev)) + display_lat("clat", min, max, mean, dev, out); + if (calc_lat(&ts_lcl->lat_stat[ddir], &min, &max, &mean, &dev)) + display_lat(" lat", min, max, mean, dev, out); + if (calc_lat(&ts_lcl->clat_high_prio_stat[ddir], &min, &max, &mean, &dev)) { + display_lat(ts_lcl->lat_percentiles ? "high prio_lat" : "high prio_clat", + min, max, mean, dev, out); + if (calc_lat(&ts_lcl->clat_low_prio_stat[ddir], &min, &max, &mean, &dev)) + display_lat(ts_lcl->lat_percentiles ? "low prio_lat" : "low prio_clat", + min, max, mean, dev, out); + } + + if (ts->slat_percentiles && ts_lcl->slat_stat[ddir].samples > 0) + show_clat_percentiles(ts_lcl->io_u_plat[FIO_SLAT][ddir], + ts_lcl->slat_stat[ddir].samples, + ts->percentile_list, + ts->percentile_precision, "slat", out); + if (ts->clat_percentiles && ts_lcl->clat_stat[ddir].samples > 0) + show_clat_percentiles(ts_lcl->io_u_plat[FIO_CLAT][ddir], + ts_lcl->clat_stat[ddir].samples, + ts->percentile_list, + ts->percentile_precision, "clat", out); + if (ts->lat_percentiles && ts_lcl->lat_stat[ddir].samples > 0) + show_clat_percentiles(ts_lcl->io_u_plat[FIO_LAT][ddir], + ts_lcl->lat_stat[ddir].samples, + ts->percentile_list, + ts->percentile_precision, "lat", out); + + if (ts->clat_percentiles || ts->lat_percentiles) { + const char *name = ts->lat_percentiles ? "lat" : "clat"; + char prio_name[32]; + uint64_t samples; + + if (ts->lat_percentiles) + samples = ts_lcl->lat_stat[ddir].samples; + else + samples = ts_lcl->clat_stat[ddir].samples; + + /* Only print this if some high and low priority stats were collected */ + if (ts_lcl->clat_high_prio_stat[ddir].samples > 0 && + ts_lcl->clat_low_prio_stat[ddir].samples > 0) + { + sprintf(prio_name, "high prio (%.2f%%) %s", + 100. * (double) ts_lcl->clat_high_prio_stat[ddir].samples / (double) samples, + name); + show_clat_percentiles(ts_lcl->io_u_plat_high_prio[ddir], + ts_lcl->clat_high_prio_stat[ddir].samples, + ts->percentile_list, + ts->percentile_precision, prio_name, out); + + sprintf(prio_name, "low prio (%.2f%%) %s", + 100. * (double) ts_lcl->clat_low_prio_stat[ddir].samples / (double) samples, + name); + show_clat_percentiles(ts_lcl->io_u_plat_low_prio[ddir], + ts_lcl->clat_low_prio_stat[ddir].samples, + ts->percentile_list, + ts->percentile_precision, prio_name, out); + } + } + + if (calc_lat(&ts_lcl->bw_stat[ddir], &min, &max, &mean, &dev)) { + double p_of_agg = 100.0, fkb_base = (double)rs->kb_base; + const char *bw_str; + + if ((rs->unit_base == 1) && i2p) + bw_str = "Kibit"; + else if (rs->unit_base == 1) + bw_str = "kbit"; + else if (i2p) + bw_str = "KiB"; + else + bw_str = "kB"; + + p_of_agg = convert_agg_kbytes_percent(rs, ddir, mean); + + if (rs->unit_base == 1) { + min *= 8.0; + max *= 8.0; + mean *= 8.0; + dev *= 8.0; + } + + if (mean > fkb_base * fkb_base) { + min /= fkb_base; + max /= fkb_base; + mean /= fkb_base; + dev /= fkb_base; + bw_str = (rs->unit_base == 1 ? "Mibit" : "MiB"); + } + + log_buf(out, " bw (%5s/s): min=%5llu, max=%5llu, per=%3.2f%%, " + "avg=%5.02f, stdev=%5.02f, samples=%" PRIu64 "\n", + bw_str, min, max, p_of_agg, mean, dev, + (&ts_lcl->bw_stat[ddir])->samples); + } + if (calc_lat(&ts_lcl->iops_stat[ddir], &min, &max, &mean, &dev)) { + log_buf(out, " iops : min=%5llu, max=%5llu, " + "avg=%5.02f, stdev=%5.02f, samples=%" PRIu64 "\n", + min, max, mean, dev, (&ts_lcl->iops_stat[ddir])->samples); + } + + free(ts_lcl); +} + static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts, int ddir, struct buf_output *out) { @@ -477,7 +683,7 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts, } log_buf(out, " %s: IOPS=%s, BW=%s (%s)(%s/%llumsec)%s\n", - rs->unified_rw_rep ? "mixed" : io_ddir_name(ddir), + (ts->unified_rw_rep == UNIFIED_MIXED) ? "mixed" : io_ddir_name(ddir), iops_p, bw_p, bw_p_alt, io_p, (unsigned long long) ts->runtime[ddir], post_st ? : ""); @@ -1078,12 +1284,13 @@ static void show_thread_status_normal(struct thread_stat *ts, if (strlen(ts->description)) log_buf(out, " Description : [%s]\n", ts->description); - if (ts->io_bytes[DDIR_READ]) - show_ddir_status(rs, ts, DDIR_READ, out); - if (ts->io_bytes[DDIR_WRITE]) - show_ddir_status(rs, ts, DDIR_WRITE, out); - if (ts->io_bytes[DDIR_TRIM]) - show_ddir_status(rs, ts, DDIR_TRIM, out); + for_each_rw_ddir(ddir) { + if (ts->io_bytes[ddir]) + show_ddir_status(rs, ts, ddir, out); + } + + if (ts->unified_rw_rep == UNIFIED_BOTH) + show_mixed_ddir_status(rs, ts, out); show_latencies(ts, out); @@ -1207,7 +1414,7 @@ static void show_ddir_status_terse(struct thread_stat *ts, &minv); else len = 0; - + for (i = 0; i < FIO_IO_U_LIST_MAX_LEN; i++) { if (i >= len) { log_buf(out, ";0%%=0"); @@ -1251,6 +1458,40 @@ static void show_ddir_status_terse(struct thread_stat *ts, } } +static void show_mixed_ddir_status_terse(struct thread_stat *ts, + struct group_run_stats *rs, + int ver, struct buf_output *out) +{ + struct thread_stat *ts_lcl; + int i; + + /* Handle aggregation of Reads (ddir = 0), Writes (ddir = 1), and Trims (ddir = 2) */ + ts_lcl = malloc(sizeof(struct thread_stat)); + memset((void *)ts_lcl, 0, sizeof(struct thread_stat)); + ts_lcl->unified_rw_rep = UNIFIED_MIXED; /* calculate mixed stats */ + for (i = 0; i < DDIR_RWDIR_CNT; i++) { + ts_lcl->clat_stat[i].min_val = ULONG_MAX; + ts_lcl->slat_stat[i].min_val = ULONG_MAX; + ts_lcl->lat_stat[i].min_val = ULONG_MAX; + ts_lcl->bw_stat[i].min_val = ULONG_MAX; + ts_lcl->iops_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_high_prio_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_low_prio_stat[i].min_val = ULONG_MAX; + } + ts_lcl->sync_stat.min_val = ULONG_MAX; + ts_lcl->lat_percentiles = ts->lat_percentiles; + ts_lcl->clat_percentiles = ts->clat_percentiles; + ts_lcl->slat_percentiles = ts->slat_percentiles; + ts_lcl->percentile_precision = ts->percentile_precision; + memcpy(ts_lcl->percentile_list, ts->percentile_list, sizeof(ts->percentile_list)); + + sum_thread_stats(ts_lcl, ts, 1); + + /* add the aggregated stats to json parent */ + show_ddir_status_terse(ts_lcl, rs, DDIR_READ, ver, out); + free(ts_lcl); +} + static struct json_object *add_ddir_lat_json(struct thread_stat *ts, uint32_t percentiles, struct io_stat *lat_stat, uint64_t *io_u_plat) { @@ -1312,12 +1553,12 @@ static void add_ddir_status_json(struct thread_stat *ts, assert(ddir_rw(ddir) || ddir_sync(ddir)); - if (ts->unified_rw_rep && ddir != DDIR_READ) + if ((ts->unified_rw_rep == UNIFIED_MIXED) && ddir != DDIR_READ) return; dir_object = json_create_object(); json_object_add_value_object(parent, - ts->unified_rw_rep ? "mixed" : io_ddir_name(ddir), dir_object); + (ts->unified_rw_rep == UNIFIED_MIXED) ? "mixed" : io_ddir_name(ddir), dir_object); if (ddir_rw(ddir)) { bw_bytes = 0; @@ -1420,6 +1661,39 @@ static void add_ddir_status_json(struct thread_stat *ts, } } +static void add_mixed_ddir_status_json(struct thread_stat *ts, + struct group_run_stats *rs, struct json_object *parent) +{ + struct thread_stat *ts_lcl; + int i; + + /* Handle aggregation of Reads (ddir = 0), Writes (ddir = 1), and Trims (ddir = 2) */ + ts_lcl = malloc(sizeof(struct thread_stat)); + memset((void *)ts_lcl, 0, sizeof(struct thread_stat)); + ts_lcl->unified_rw_rep = UNIFIED_MIXED; /* calculate mixed stats */ + for (i = 0; i < DDIR_RWDIR_CNT; i++) { + ts_lcl->clat_stat[i].min_val = ULONG_MAX; + ts_lcl->slat_stat[i].min_val = ULONG_MAX; + ts_lcl->lat_stat[i].min_val = ULONG_MAX; + ts_lcl->bw_stat[i].min_val = ULONG_MAX; + ts_lcl->iops_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_high_prio_stat[i].min_val = ULONG_MAX; + ts_lcl->clat_low_prio_stat[i].min_val = ULONG_MAX; + } + ts_lcl->sync_stat.min_val = ULONG_MAX; + ts_lcl->lat_percentiles = ts->lat_percentiles; + ts_lcl->clat_percentiles = ts->clat_percentiles; + ts_lcl->slat_percentiles = ts->slat_percentiles; + ts_lcl->percentile_precision = ts->percentile_precision; + memcpy(ts_lcl->percentile_list, ts->percentile_list, sizeof(ts->percentile_list)); + + sum_thread_stats(ts_lcl, ts, 1); + + /* add the aggregated stats to json parent */ + add_ddir_status_json(ts_lcl, rs, DDIR_READ, parent); + free(ts_lcl); +} + static void show_thread_status_terse_all(struct thread_stat *ts, struct group_run_stats *rs, int ver, struct buf_output *out) @@ -1437,14 +1711,17 @@ static void show_thread_status_terse_all(struct thread_stat *ts, log_buf(out, "%d;%s;%s;%d;%d", ver, fio_version_string, ts->name, ts->groupid, ts->error); - /* Log Read Status */ + /* Log Read Status, or mixed if unified_rw_rep = 1 */ show_ddir_status_terse(ts, rs, DDIR_READ, ver, out); - /* Log Write Status */ - show_ddir_status_terse(ts, rs, DDIR_WRITE, ver, out); - /* Log Trim Status */ - if (ver == 2 || ver == 4 || ver == 5) - show_ddir_status_terse(ts, rs, DDIR_TRIM, ver, out); - + if (ts->unified_rw_rep != UNIFIED_MIXED) { + /* Log Write Status */ + show_ddir_status_terse(ts, rs, DDIR_WRITE, ver, out); + /* Log Trim Status */ + if (ver == 2 || ver == 4 || ver == 5) + show_ddir_status_terse(ts, rs, DDIR_TRIM, ver, out); + } + if (ts->unified_rw_rep == UNIFIED_BOTH) + show_mixed_ddir_status_terse(ts, rs, ver, out); /* CPU Usage */ if (ts->total_run_time) { double runt = (double) ts->total_run_time; @@ -1549,6 +1826,9 @@ static struct json_object *show_thread_status_json(struct thread_stat *ts, add_ddir_status_json(ts, rs, DDIR_TRIM, root); add_ddir_status_json(ts, rs, DDIR_SYNC, root); + if (ts->unified_rw_rep == UNIFIED_BOTH) + add_mixed_ddir_status_json(ts, rs, root); + /* CPU Usage */ if (ts->total_run_time) { double runt = (double) ts->total_run_time; @@ -1877,7 +2157,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src, int k, l, m; for (l = 0; l < DDIR_RWDIR_CNT; l++) { - if (!dst->unified_rw_rep) { + if (!(dst->unified_rw_rep == UNIFIED_MIXED)) { sum_stat(&dst->clat_stat[l], &src->clat_stat[l], first, false); sum_stat(&dst->clat_high_prio_stat[l], &src->clat_high_prio_stat[l], first, false); sum_stat(&dst->clat_low_prio_stat[l], &src->clat_low_prio_stat[l], first, false); @@ -1933,7 +2213,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src, dst->io_u_lat_m[k] += src->io_u_lat_m[k]; for (k = 0; k < DDIR_RWDIR_CNT; k++) { - if (!dst->unified_rw_rep) { + if (!(dst->unified_rw_rep == UNIFIED_MIXED)) { dst->total_io_u[k] += src->total_io_u[k]; dst->short_io_u[k] += src->short_io_u[k]; dst->drop_io_u[k] += src->drop_io_u[k]; @@ -1949,7 +2229,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src, for (k = 0; k < FIO_LAT_CNT; k++) for (l = 0; l < DDIR_RWDIR_CNT; l++) for (m = 0; m < FIO_IO_U_PLAT_NR; m++) - if (!dst->unified_rw_rep) + if (!(dst->unified_rw_rep == UNIFIED_MIXED)) dst->io_u_plat[k][l][m] += src->io_u_plat[k][l][m]; else dst->io_u_plat[k][0][m] += src->io_u_plat[k][l][m]; @@ -1959,7 +2239,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src, for (k = 0; k < DDIR_RWDIR_CNT; k++) { for (m = 0; m < FIO_IO_U_PLAT_NR; m++) { - if (!dst->unified_rw_rep) { + if (!(dst->unified_rw_rep == UNIFIED_MIXED)) { dst->io_u_plat_high_prio[k][m] += src->io_u_plat_high_prio[k][m]; dst->io_u_plat_low_prio[k][m] += src->io_u_plat_low_prio[k][m]; } else { @@ -2168,7 +2448,7 @@ void __show_run_stats(void) rs->kb_base = ts->kb_base; rs->unit_base = ts->unit_base; rs->sig_figs = ts->sig_figs; - rs->unified_rw_rep += ts->unified_rw_rep; + rs->unified_rw_rep |= ts->unified_rw_rep; for (j = 0; j < DDIR_RWDIR_CNT; j++) { if (!ts->runtime[j]) @@ -2301,7 +2581,7 @@ void __show_run_stats(void) free(opt_lists); } -void __show_running_run_stats(void) +int __show_running_run_stats(void) { struct thread_data *td; unsigned long long *rt; @@ -2315,9 +2595,9 @@ void __show_running_run_stats(void) for_each_td(td, i) { td->update_rusage = 1; - td->ts.io_bytes[DDIR_READ] = td->io_bytes[DDIR_READ]; - td->ts.io_bytes[DDIR_WRITE] = td->io_bytes[DDIR_WRITE]; - td->ts.io_bytes[DDIR_TRIM] = td->io_bytes[DDIR_TRIM]; + for_each_rw_ddir(ddir) { + td->ts.io_bytes[ddir] = td->io_bytes[ddir]; + } td->ts.total_run_time = mtime_since(&td->epoch, &ts); rt[i] = mtime_since(&td->start, &ts); @@ -2352,6 +2632,8 @@ void __show_running_run_stats(void) free(rt); fio_sem_up(stat_sem); + + return 0; } static bool status_file_disabled; @@ -2536,6 +2818,14 @@ void regrow_logs(struct thread_data *td) td->flags &= ~TD_F_REGROW_LOGS; } +void regrow_agg_logs(void) +{ + enum fio_ddir ddir; + + for (ddir = 0; ddir < DDIR_RWDIR_CNT; ddir++) + regrow_log(agg_io_log[ddir]); +} + static struct io_logs *get_cur_log(struct io_log *iolog) { struct io_logs *cur_log; @@ -2739,7 +3029,8 @@ static unsigned long add_log_sample(struct thread_data *td, __add_stat_to_log(iolog, ddir, elapsed, td->o.log_max != 0, priority_bit); - iolog->avg_last[ddir] = elapsed - (this_window - iolog->avg_msec); + iolog->avg_last[ddir] = elapsed - (elapsed % iolog->avg_msec); + return iolog->avg_msec; } @@ -2977,7 +3268,7 @@ static int __add_samples(struct thread_data *td, struct timespec *parent_tv, next_log = avg_time; spent = mtime_since(parent_tv, t); - if (spent < avg_time && avg_time - spent >= LOG_MSEC_SLACK) + if (spent < avg_time && avg_time - spent > LOG_MSEC_SLACK) return avg_time - spent; if (needs_lock) @@ -3070,13 +3361,16 @@ static int add_iops_samples(struct thread_data *td, struct timespec *t) int calc_log_samples(void) { struct thread_data *td; - unsigned int next = ~0U, tmp; + unsigned int next = ~0U, tmp = 0, next_mod = 0, log_avg_msec_min = -1U; struct timespec now; int i; + long elapsed_time = 0; fio_gettime(&now, NULL); for_each_td(td, i) { + elapsed_time = mtime_since_now(&td->epoch); + if (!td->o.stats) continue; if (in_ramp_time(td) || @@ -3087,17 +3381,34 @@ int calc_log_samples(void) if (!td->bw_log || (td->bw_log && !per_unit_log(td->bw_log))) { tmp = add_bw_samples(td, &now); - if (tmp < next) - next = tmp; + + if (td->bw_log) + log_avg_msec_min = min(log_avg_msec_min, (unsigned int)td->bw_log->avg_msec); } if (!td->iops_log || (td->iops_log && !per_unit_log(td->iops_log))) { tmp = add_iops_samples(td, &now); - if (tmp < next) - next = tmp; + + if (td->iops_log) + log_avg_msec_min = min(log_avg_msec_min, (unsigned int)td->iops_log->avg_msec); } + + if (tmp < next) + next = tmp; } + /* if log_avg_msec_min has not been changed, set it to 0 */ + if (log_avg_msec_min == -1U) + log_avg_msec_min = 0; + + if (log_avg_msec_min == 0) + next_mod = elapsed_time; + else + next_mod = elapsed_time % log_avg_msec_min; + + /* correction to keep the time on the log avg msec boundary */ + next = min(next, (log_avg_msec_min - next_mod)); + return next == ~0U ? 0 : next; }