M. Edward (Ed) Borasky wrote:
> I'm experimenting with "btt" and I have a case where the "iostat"
> emulation is generating negative queue lengths. They seem to be steadily
> increasing in magnitude. The utilizations don't look right, either -- I
> don't think this device was 100 percent busy for the entire run.
>
> I've attached a sample -- the input files are huge, but I'll post them
> if you need them.
>
>
Hi Ed -
If you get a chance, could you try the attached patch - I have not
committed it, although it looks solid enough. I'm going to keep plugging
on this. [Note the stuff about await & svctm in the patch description.]
Thanks,
Alan
>From c66b8b2a18b467e5f3205f7187c37f5d7d58fc52 Mon Sep 17 00:00:00 2001
From: Alan D. Brunelle <alan.brunelle@xxxxxx>
Date: Fri, 30 May 2008 11:25:11 -0400
Subject: [PATCH] Massive re-write of iostat capability
rrqm/s, wrqm/s, r/s, w/s, rkB/s, wkB/s, avgrq-sz, avgqu-sz, and %util
all look good -- match up well w/ iostat. await & svctm do /not/ match
up well w/ iostat, but "look" right when looking at the raw data.
For the record:
await == Average time between GETRQ and COMPLETION for all I/O requests
completed in that sample.
svctm == Averate time between ISSUE and COMPLETION for all I/O requests
completed in that sample
Signed-off-by: Alan D. Brunelle <alan.brunelle@xxxxxx>
---
btt/bt_timeline.c | 6 +-
btt/devs.c | 3 +
btt/globals.h | 50 +++---
btt/iostat.c | 467 ++++++++++++++++++++++++++++----------------------
btt/trace_complete.c | 16 ++-
btt/trace_im.c | 5 +-
btt/trace_issue.c | 2 +-
7 files changed, 310 insertions(+), 239 deletions(-)
diff --git a/btt/bt_timeline.c b/btt/bt_timeline.c
index 2eed087..8c5739e 100644
--- a/btt/bt_timeline.c
+++ b/btt/bt_timeline.c
@@ -60,14 +60,10 @@ int main(int argc, char *argv[])
handle_args(argc, argv);
init_dev_heads();
- iostat_init();
if (process() || output_avgs(avgs_ofp) || output_ranges(ranges_ofp))
return 1;
- if (iostat_ofp) {
- fprintf(iostat_ofp, "\n");
- iostat_dump_stats(iostat_last_stamp, 1);
- }
+ iostat_dump_stats();
if (msgs_ofp != stdout)
fclose(msgs_ofp);
diff --git a/btt/devs.c b/btt/devs.c
index 3cf7a6c..4e2ca4c 100644
--- a/btt/devs.c
+++ b/btt/devs.c
@@ -89,6 +89,7 @@ void dip_exit(void)
unplug_hist_exit(dip->unplug_hist_handle);
if (output_all_data)
q2d_release(dip->q2d_priv);
+ iostat_free(dip->stats);
free(dip);
}
}
@@ -127,6 +128,8 @@ struct d_info *dip_add(__u32 device, struct io *iop)
dip->pre_culling = 1;
if (output_all_data)
dip->q2d_priv = q2d_init();
+ make_dev_hdr(str, 256, dip, 1);
+ dip->stats = iostat_alloc(str);
n_devs++;
}
diff --git a/btt/globals.h b/btt/globals.h
index c4b7674..fc358b6 100644
--- a/btt/globals.h
+++ b/btt/globals.h
@@ -41,7 +41,7 @@
#define BIT_START(iop) ((iop)->t.sector)
#define BIT_END(iop) ((iop)->t.sector + ((iop)->t.bytes >> 9))
#define IOP_READ(iop) ((iop)->t.action & BLK_TC_ACT(BLK_TC_READ))
-#define IOP_RW(iop) (IOP_READ(iop) ? 1 : 0)
+#define IOP_RW(iop) (IOP_READ(iop) ? 0 : 1)
#define TO_SEC(nanosec) ((double)(nanosec) / 1.0e9)
#define TO_MSEC(nanosec) (1000.0 * TO_SEC(nanosec))
@@ -128,18 +128,6 @@ struct devmap {
char device[32], node[32], pci[32], devno[32];
};
-struct stats {
- __u64 rqm[2], ios[2], sec[2], wait, svctm;
- double last_qu_change, last_dev_change, tot_qusz, idle_time;
- int cur_qusz, cur_dev;
-};
-
-struct stats_t {
- double n;
- double rqm_s[2], ios_s[2], sec_s[2];
- double avgrq_sz, avgqu_sz, await, svctm, p_util;
-};
-
struct d_info {
struct list_head all_head, hash_head;
void *heads;
@@ -149,7 +137,7 @@ struct d_info {
void *q2d_priv;
FILE *d2c_ofp, *q2c_ofp;
struct avgs_info avgs;
- struct stats stats, all_stats;
+ void *stats;
__u64 last_q, n_qs, n_ds;
__u64 n_act_q, t_act_q; /* # currently active when Q comes in */
__u32 device;
@@ -193,7 +181,7 @@ extern struct avgs_info all_avgs;
extern __u64 last_q;
extern struct region_info all_regions;
extern struct list_head all_ios, free_ios;
-extern __u64 iostat_interval, iostat_last_stamp;
+extern __u64 iostat_interval;
extern time_t genesis, last_vtrace;
extern double t_astart, t_aend;
extern __u64 q_histo[N_HIST_BKTS], d_histo[N_HIST_BKTS];
@@ -221,6 +209,10 @@ void dip_plug(__u32 dev, double cur_time);
void dip_unplug(__u32 dev, double cur_time, __u64 nio_ups);
void dip_unplug_tm(__u32 dev, __u64 nio_ups);
void dip_exit(void);
+static inline void *dip_get_stats(struct d_info *dip)
+{
+ return dip->stats;
+}
/* dip_rb.c */
int rb_insert(struct rb_root *root, struct io *iop);
@@ -230,14 +222,26 @@ void rb_foreach(struct rb_node *n, struct io *iop,
struct list_head *head);
/* iostat.c */
-void iostat_init(void);
-void iostat_getrq(struct io *iop);
-void iostat_merge(struct io *iop);
-void iostat_issue(struct io *iop);
-void iostat_unissue(struct io *iop);
-void iostat_complete(struct io *d_iop, struct io *c_iop);
-void iostat_check_time(__u64 stamp);
-void iostat_dump_stats(__u64 stamp, int all);
+void *iostat_alloc(char *hdr);
+void iostat_free(void *dsp);
+void iostat_insert(void *arg, struct io *i_iop);
+void iostat_issue(void *arg, struct io *d_iop);
+void iostat_merge(void *arg, struct io *iop);
+void iostat_complete(void *arg, struct io *c_iop, __u64 d2c, __u64 g2c,
+ unsigned int nqs);
+void __iostat_check_time(__u64 now);
+void __iostat_dump_stats(void);
+
+static inline void iostat_check_time(__u64 now)
+{
+ if (iostat_ofp)
+ __iostat_check_time(now);
+}
+static inline void iostat_dump_stats(void)
+{
+ if (iostat_ofp)
+ __iostat_dump_stats();
+}
/* latency.c */
void latency_init(struct d_info *dip);
diff --git a/btt/iostat.c b/btt/iostat.c
index d701e2f..88373be 100644
--- a/btt/iostat.c
+++ b/btt/iostat.c
@@ -1,7 +1,7 @@
/*
* blktrace output analysis: generate a timeline & gather statistics
*
- * Copyright (C) 2006 Alan D. Brunelle <Alan.Brunelle@xxxxxx>
+ * Copyright (C) 2006-2008 Alan D. Brunelle <Alan.Brunelle@xxxxxx>
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
@@ -18,194 +18,244 @@
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
*/
-#include <stdio.h>
-#include <unistd.h>
+
+#include <float.h>
#include "globals.h"
-#define INC_STAT(dip, fld) \
- do { \
- (dip)->stats. fld ++; \
- (dip)->all_stats. fld ++; \
- } while (0)
-
-#define DEC_STAT(dip, fld) \
- do { \
- (dip)->stats. fld --; \
- (dip)->all_stats. fld --; \
- } while (0)
-
-#define ADD_STAT(dip, fld, val) \
- do { \
- __u64 __v = (val); \
- (dip)->stats. fld += __v; \
- (dip)->all_stats. fld += __v; \
- } while (0)
-
-#define SUB_STAT(dip, fld, val) \
- do { \
- __u64 __v = (val); \
- (dip)->stats. fld -= __v; \
- (dip)->all_stats. fld -= __v; \
- } while (0)
-
-__u64 last_start, iostat_last_stamp;
+struct __stats {
+ __u64 sectors[2], ios[2], merges[2]; // READ & WRITE
+};
+
+struct disk_stats {
+ struct list_head head;
+ char *hdr;
+ __u64 stamp;
+ __u64 last_q, last_idle, busy_ticks;
+ __u64 rq_ticks, nqs, io_ticks;
+ long long in_flight, qusz;
+ double avgqsz;
+ struct __stats stats[2]; /* 0 == last values */
+
+ double sum_merges[2], sum_ios[2], sum_secs[2];
+ double sum_avgqsz, sum_await, sum_svctm, sum_util;
+};
+
+static __u64 last_seen = (__u64)-1;
+static __u64 last_start = (__u64)-1;
+static int ndumps = 0;
+
__u64 iostat_interval = 1000000000;
char *iostat_name = NULL;
FILE *iostat_ofp = NULL;
-void dump_hdr(void)
+#define delta_fld(dsp, fld) ((dsp)->stats[1]. fld - (dsp)->stats[0]. fld)
+
+static void clear_stats(struct __stats *sp)
{
- fprintf(iostat_ofp, "Device: rrqm/s wrqm/s r/s w/s "
- "rsec/s wsec/s rkB/s wkB/s "
- "avgrq-sz avgqu-sz await svctm %%util Stamp\n");
+ memset(sp, 0, sizeof(*sp));
}
-void iostat_init(void)
+void *iostat_alloc(char *hdr)
{
- last_start = (__u64)-1;
- if (iostat_ofp)
- dump_hdr();
+ struct disk_stats *dsp = malloc(sizeof(*dsp));
+
+ memset(dsp, 0, sizeof(*dsp));
+ dsp->hdr = strdup(hdr);
+
+ return dsp;
}
-void update_tot_qusz(struct d_info *dip, double now)
+void iostat_free(void *arg)
{
- dip->stats.tot_qusz += ((now - dip->stats.last_qu_change) *
- dip->stats.cur_qusz);
- dip->all_stats.tot_qusz += ((now - dip->all_stats.last_qu_change) *
- dip->all_stats.cur_qusz);
+ struct disk_stats *dsp = arg;
- dip->stats.last_qu_change = dip->all_stats.last_qu_change = now;
+ free(dsp->hdr);
+ free(dsp);
}
-void update_idle_time(struct d_info *dip, double now, int force)
+void iostat_insert(void *arg, struct io *i_iop)
{
- if (dip->stats.cur_dev == 0 || force) {
- dip->stats.idle_time += (now - dip->stats.last_dev_change);
- dip->all_stats.idle_time +=
- (now - dip->all_stats.last_dev_change);
+ struct disk_stats *dsp = arg;
+
+ if (dsp->qusz > 0) {
+ double dt = TO_SEC(i_iop->t.time - dsp->last_q);
+ dsp->avgqsz += ((double)(dsp->qusz) * dt);
}
- dip->stats.last_dev_change = dip->all_stats.last_dev_change = now;
+
+ dsp->qusz++;
+ dsp->last_q = i_iop->t.time;
}
-void __dump_stats(__u64 stamp, int all, struct d_info *dip, struct stats_t *asp)
+void iostat_issue(void *arg, struct io *d_iop)
{
- char hdr[16];
- struct stats *sp;
- double dt, nios, avgrq_sz, p_util, nrqm, await, svctm;
- double now = TO_SEC(stamp);
-
- if (all) {
- dt = (double)stamp / 1.0e9;
- sp = &dip->all_stats;
- }
- else {
- dt = (double)(stamp-last_start) / 1.0e9;
- sp = &dip->stats;
- }
+ struct disk_stats *dsp = arg;
+
+ if (dsp->in_flight == 0)
+ dsp->last_idle = d_iop->t.time;
+
+ dsp->in_flight++;
+}
+
+void iostat_merge(void *arg, struct io *iop)
+{
+ struct disk_stats *dsp = arg;
+ dsp->stats[1].merges[IOP_RW(iop)]++;
+}
+
+void iostat_complete(void *arg, struct io *c_iop, __u64 d2c, __u64 g2c,
+ unsigned int nqs)
+{
+ struct disk_stats *dsp = arg;
+ int rw = IOP_RW(c_iop);
+
+ dsp->stats[1].sectors[rw] += (c_iop->t.bytes >> 9);
+ dsp->stats[1].ios[rw]++;
- nios = (double)(sp->ios[0] + sp->ios[1]);
- nrqm = (double)(sp->rqm[0] + sp->rqm[1]);
- update_idle_time(dip, now, 1);
- update_tot_qusz(dip, now);
+ dsp->nqs += nqs;
+ if (g2c != (__u64)-1)
+ dsp->rq_ticks += g2c;
+ if (d2c != (__u64)-1)
+ dsp->io_ticks += d2c;
- if (nios > 0.0) {
- avgrq_sz = (double)(sp->sec[0] + sp->sec[1]) / nios;
- svctm = TO_MSEC(sp->svctm) / nios;
+ if (dsp->in_flight == 1)
+ dsp->busy_ticks += (c_iop->t.time - dsp->last_idle);
+ dsp->in_flight--;
+
+ if (dsp->qusz > 0) {
+ double dt = TO_SEC(c_iop->t.time - dsp->last_q);
+ dsp->avgqsz += ((double)(dsp->qusz) * dt);
}
- else
- avgrq_sz = svctm = 0.0;
- await = ((nios + nrqm) > 0.0) ? TO_MSEC(sp->wait) / (nios+nrqm) : 0.0;
- p_util = (sp->idle_time <= dt) ? 100.0 * (1.0 - (sp->idle_time / dt)) :
- 0.0;
+ dsp->qusz--;
+ dsp->last_q = c_iop->t.time;
+}
- /*
- * For AWAIT: nios should be the same as number of inserts
- * and we add in nrqm (number of merges), which should give
- * us the total number of IOs sent to the block IO layer.
- */
- fprintf(iostat_ofp, "%-11s ", make_dev_hdr(hdr, 11, dip, 1));
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->rqm[1] / dt);
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->rqm[0] / dt);
- fprintf(iostat_ofp, "%7.2lf ", (double)sp->ios[1] / dt);
- fprintf(iostat_ofp, "%7.2lf ", (double)sp->ios[0] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)sp->sec[1] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)sp->sec[0] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)(sp->sec[1] / 2) / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)(sp->sec[0] / 2) / dt);
- fprintf(iostat_ofp, "%8.2lf ", avgrq_sz);
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->tot_qusz / dt);
- fprintf(iostat_ofp, "%7.2lf ", await);
- fprintf(iostat_ofp, "%7.2lf ", svctm);
- fprintf(iostat_ofp, "%6.2lf", p_util);
- if (all)
- fprintf(iostat_ofp, "%8s\n", "TOTAL");
- else {
- fprintf(iostat_ofp, "%8.2lf\n", TO_SEC(stamp));
- sp->rqm[0] = sp->rqm[1] = 0;
- sp->ios[0] = sp->ios[1] = 0;
- sp->sec[0] = sp->sec[1] = 0;
- sp->wait = sp->svctm = 0;
+void sum_results(struct disk_stats *dsp, double *merges, double *ios,
+ double *secs, double avgqsz, double await,
+ double svctm, double util)
+{
+ int i;
- sp->tot_qusz = sp->idle_time = 0.0;
+ for (i = 0; i < 2; i++) {
+ dsp->sum_merges[i] += merges[i];
+ dsp->sum_ios[i] += ios[i];
+ dsp->sum_secs[i] += secs[i];
}
- if (asp) {
- int i;
+ dsp->sum_avgqsz += avgqsz;
+ dsp->sum_await += await;
+ dsp->sum_svctm += svctm;
+ dsp->sum_util += util;
+}
- asp->n += 1.0;
- for (i = 0; i < 2; i++) {
- asp->rqm_s[i] += ((double)sp->rqm[i] / dt);
- asp->ios_s[i] += ((double)sp->ios[i] / dt);
- asp->sec_s[i] += ((double)sp->sec[i] / dt);
- }
- asp->avgrq_sz += avgrq_sz;
- asp->avgqu_sz += (double)sp->tot_qusz / dt;
- asp->await += await;
- asp->svctm += svctm;
- asp->p_util += p_util;
+void dump_hdr(FILE *ofp)
+{
+ fprintf(ofp,
+ "%13s %8s %8s %8s %8s %8s %8s %8s %8s %8s %8s %6s %s\n",
+ "Device", "rrqm/s", "wrqm/s", "r/s", "w/s",
+ "rkB/s", "wkB/s", "avgrq-sz", "avgqu-sz", "await",
+ "svctm", "%util", "Stamp");
+}
+
+void dump(struct disk_stats *dsp, struct disk_stats *adsp, __u64 now,
+ double dt, char *tail)
+{
+ FILE *ofp = iostat_ofp;
+ double await, arqsz, busy_ticks, util, svctm;
+ double merges[2] = {
+ (double)delta_fld(dsp, merges[0]),
+ (double)delta_fld(dsp, merges[1])
+ };
+ double secs[2] = {
+ (double)delta_fld(dsp, sectors[0]),
+ (double)delta_fld(dsp, sectors[1])
+ };
+ double ios[2] = {
+ (double)delta_fld(dsp, ios[0]),
+ (double)delta_fld(dsp, ios[1])
+ };
+ double nios = ios[0] + ios[1];
+ double avgqsz = dsp->avgqsz / dt;
+
+ busy_ticks = TO_SEC(dsp->busy_ticks);
+ util = 100.0 * (busy_ticks / dt);
+
+ if (ios[0] || ios[1]) {
+ arqsz = (secs[0] + secs[1]) / nios;
+ await = 1000.0 * (TO_SEC(dsp->rq_ticks) / dsp->nqs);
+ svctm = 1000.0 * (TO_SEC(dsp->io_ticks) / nios);
}
+ else
+ await = arqsz = svctm = 0.0;
+
+ fprintf(ofp, "%13s ", dsp->hdr);
+ fprintf(ofp, "%8.2f %8.2f ", merges[0] / dt, merges[1] / dt);
+ fprintf(ofp, "%8.2f %8.2f ", ios[0] / dt, ios[1] / dt);
+ fprintf(ofp, "%8.1f %8.1f ", secs[0] / (2 * dt), secs[1] / (2 * dt));
+ fprintf(ofp, "%8.2f ", arqsz);
+ fprintf(ofp, "%8.2f ", avgqsz);
+ fprintf(ofp, "%8.2f ", await);
+ fprintf(ofp, "%8.2f ", svctm);
+ fprintf(ofp, "%6.2f ", util);
+ fprintf(ofp, "%6s\n", tail);
+
+ /*
+ * Accumulate results
+ */
+ sum_results(dsp, merges, ios, secs, avgqsz, await, svctm, util);
+ sum_results(adsp, merges, ios, secs, avgqsz, await, svctm, util);
+
+ /*
+ * Clear out counters, save current stats as previous.
+ */
+ dsp->busy_ticks = 0;
+ dsp->last_idle = now;
+ dsp->rq_ticks = dsp->io_ticks = 0;
+ dsp->nqs = 0;
+ dsp->last_q = now;
+ dsp->avgqsz = 0.0;
+
+ memcpy(&dsp->stats[0], &dsp->stats[1], sizeof(dsp->stats[1]));
}
-void __dump_stats_t(__u64 stamp, struct stats_t *asp, int all)
+void dump_a(struct disk_stats *dsp, double dt, int ndevs, int ndumps,
+ char *pre, char *pst)
{
- if (asp->n < 2.0) return; // What's the point?
-
- fprintf(iostat_ofp, "%-11s ", "TOTAL");
- fprintf(iostat_ofp, "%8.2lf ", asp->rqm_s[0]);
- fprintf(iostat_ofp, "%8.2lf ", asp->rqm_s[1]);
- fprintf(iostat_ofp, "%7.2lf ", asp->ios_s[0]);
- fprintf(iostat_ofp, "%7.2lf ", asp->ios_s[1]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[0]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[1]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[0] / 2.0);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[1] / 2.0);
- fprintf(iostat_ofp, "%8.2lf ", asp->avgrq_sz / asp->n);
- fprintf(iostat_ofp, "%8.2lf ", asp->avgqu_sz / asp->n);
- fprintf(iostat_ofp, "%7.2lf ", asp->await / asp->n);
- fprintf(iostat_ofp, "%7.2lf ", asp->svctm / asp->n);
- fprintf(iostat_ofp, "%6.2lf", asp->p_util / asp->n);
- if (all)
- fprintf(iostat_ofp, "%8s\n", "TOTAL");
- else
- fprintf(iostat_ofp, "%8.2lf\n", TO_SEC(stamp));
+ FILE *ofp = iostat_ofp;
+ double rd_merges = dsp->sum_merges[0];
+ double wr_merges = dsp->sum_merges[1];
+ double rd_ios = dsp->sum_ios[0];
+ double wr_ios = dsp->sum_ios[1];
+ double nios = rd_ios + wr_ios;
+ double rd_sec = dsp->sum_secs[0];
+ double wr_sec = dsp->sum_secs[1];
+ double arqsz = (rd_ios || wr_ios) ? (rd_sec + wr_sec) / nios : 0.0;
+
+ fprintf(ofp, "%13s ", pre);
+ fprintf(ofp, "%8.2f %8.2f ", rd_merges / dt, wr_merges / dt);
+ fprintf(ofp, "%8.2f %8.2f ", rd_ios / dt, wr_ios / dt);
+ fprintf(ofp, "%8.1f %8.1f ", rd_sec / (2 * dt), wr_sec / (2 * dt));
+ fprintf(ofp, "%8.2f ", arqsz);
+ fprintf(ofp, "%8.2f ", dsp->sum_avgqsz / (double)(ndevs * ndumps));
+ fprintf(ofp, "%8.2f ", dsp->sum_await / (double)(ndevs * ndumps));
+ fprintf(ofp, "%8.2f ", dsp->sum_svctm / (double)(ndevs * ndumps));
+ fprintf(ofp, "%6.2f ", dsp->sum_util / (double)(ndevs * ndumps));
+ fprintf(ofp, "%6s\n", pst);
}
-void iostat_dump_stats(__u64 stamp, int all)
+void collect_dsps(struct list_head *head)
{
struct d_info *dip;
- struct stats_t as;
-
- memset(&as, 0, sizeof(struct stats_t));
- if (all)
- dump_hdr();
+ struct disk_stats *dsp;
if (devices == NULL) {
struct list_head *p;
__list_for_each(p, &all_devs) {
dip = list_entry(p, struct d_info, all_head);
- __dump_stats(stamp, all, dip, &as);
+ dsp = dip_get_stats(dip);
+
+ list_add_tail(&dsp->head, head);
}
}
else {
@@ -215,82 +265,91 @@ void iostat_dump_stats(__u64 stamp, int all)
while (p && ((i = sscanf(p, "%u,%u", &mjr, &mnr)) == 2)) {
dip = __dip_find((__u32)((mjr << MINORBITS) | mnr));
- __dump_stats(stamp, all, dip, &as);
+ dsp = dip_get_stats(dip);
+
+ list_add_tail(&dsp->head, head);
p = strchr(p, ';');
if (p) p++;
}
}
-
- __dump_stats_t(stamp, &as, all);
-
- if (!all && iostat_ofp)
- fprintf(iostat_ofp, "\n");
}
-void iostat_check_time(__u64 stamp)
+void dump_stats(__u64 now, int clear0)
{
- if (iostat_ofp) {
- if (last_start == (__u64)-1)
- last_start = stamp;
- else if ((stamp - last_start) >= iostat_interval) {
- iostat_dump_stats(stamp, 0);
- last_start = stamp;
- }
-
- iostat_last_stamp = stamp;
+ double dt = TO_SEC(now - last_start);
+ int ndevs = 0;
+ char buf[128];
+ struct disk_stats adsp, *dsp;
+ struct list_head *p, *q;
+ LIST_HEAD(dsps);
+
+ memset(&adsp, 0, sizeof(adsp));
+ adsp.hdr = "TOTAL";
+
+ sprintf(buf, "%6.1lf", TO_SEC(now));
+ collect_dsps(&dsps);
+
+ list_for_each_safe(p, q, &dsps) {
+ dsp = list_entry(p, struct disk_stats, head);
+ list_del(&dsp->head);
+
+ if (dsp->in_flight)
+ dsp->busy_ticks += (now - dsp->last_idle);
+ if (clear0)
+ clear_stats(&dsp->stats[0]);
+ dump(dsp, &adsp, now, dt, buf);
+ ndevs++;
}
-}
-
-void iostat_getrq(struct io *iop)
-{
- update_tot_qusz(iop->dip, TO_SEC(iop->t.time));
- INC_STAT(iop->dip, cur_qusz);
-}
-
-void iostat_merge(struct io *iop)
-{
- INC_STAT(iop->dip, rqm[IOP_RW(iop)]);
-}
-
-void iostat_issue(struct io *iop)
-{
- int rw = IOP_RW(iop);
- struct d_info *dip = iop->dip;
- double now = TO_SEC(iop->t.time);
- INC_STAT(dip, ios[rw]);
- ADD_STAT(dip, sec[rw], iop->t.bytes >> 9);
+ if (ndevs > 1) {
+ dump_a(&adsp, dt, ndevs, 1, "ITER", "AVG");
+ fprintf(iostat_ofp, "\n");
+ }
- update_idle_time(dip, now, 0);
- INC_STAT(dip, cur_dev);
+ ndumps++;
}
-void iostat_unissue(struct io *iop)
+void __iostat_check_time(__u64 now)
{
- int rw = IOP_RW(iop);
- struct d_info *dip = iop->dip;
+ if (!iostat_ofp)
+ return;
+ if (last_start == (__u64)-1) {
+ dump_hdr(iostat_ofp);
+ last_start = now;
+ }
+ else if ((now - last_start) >= iostat_interval) {
+ dump_stats(now, 0);
+ last_start = now;
+ }
- DEC_STAT(dip, ios[rw]);
- SUB_STAT(dip, sec[rw], iop->t.bytes >> 9);
- DEC_STAT(dip, cur_dev);
+ last_seen = now;
}
-void iostat_complete(struct io *q_iop, struct io *c_iop)
+void __iostat_dump_stats(void)
{
- double now = TO_SEC(c_iop->t.time);
- struct d_info *dip = q_iop->dip;
-
- if (q_iop->i_time != (__u64)-1)
- ADD_STAT(c_iop->dip, wait, tdelta(q_iop->i_time,c_iop->t.time));
- else if (q_iop->m_time != (__u64)-1)
- ADD_STAT(c_iop->dip, wait, tdelta(q_iop->m_time,c_iop->t.time));
-
- update_tot_qusz(dip, now);
- DEC_STAT(dip, cur_qusz);
-
- update_idle_time(dip, now, 0);
- DEC_STAT(dip, cur_dev);
+ int ndevs = 0;
+ LIST_HEAD(dsps);
+ struct list_head *p, *q;
+ struct disk_stats adsp, *dsp;
+
+ dump_stats(last_seen, 0);
+ fprintf(iostat_ofp, "\n");
+
+ memset(&adsp, 0, sizeof(adsp));
+ adsp.hdr = "TOTAL";
+
+ collect_dsps(&dsps);
+ list_for_each_safe(p, q, &dsps) {
+ dsp = list_entry(p, struct disk_stats, head);
+ list_del(&dsp->head);
+ ndevs++;
+
+ sum_results(&adsp, dsp->sum_merges, dsp->sum_ios,
+ dsp->sum_secs, dsp->sum_avgqsz,
+ dsp->sum_await, dsp->sum_svctm, dsp->sum_util);
+ }
- ADD_STAT(dip, svctm, tdelta(q_iop->t.time, c_iop->t.time));
+ dump_hdr(iostat_ofp);
+ dump_a(&adsp, TO_SEC(last_seen), ndevs, ndumps, "TOTAL", "AVG");
}
diff --git a/btt/trace_complete.c b/btt/trace_complete.c
index 41bcb7d..2afda15 100644
--- a/btt/trace_complete.c
+++ b/btt/trace_complete.c
@@ -51,8 +51,11 @@ static void display_io_track(FILE *ofp, struct io *iop)
static void handle_complete(struct io *c_iop)
{
+ unsigned int nqs = 0;
LIST_HEAD(head);
struct list_head *p, *q;
+ __u64 g2c = (__u64)-1;
+ __u64 d2c = (__u64)-1;
update_blks(c_iop);
update_cregion(&all_regions, c_iop->t.time);
@@ -71,11 +74,10 @@ static void handle_complete(struct io *c_iop)
latency_q2c(q_iop->dip, q_iop->t.time, q2c);
if (q_iop->d_time != (__u64)-1) {
- __u64 d2c = tdelta(q_iop->d_time, c_iop->t.time);
-
+ if (d2c == (__u64)-1)
+ d2c = tdelta(q_iop->d_time, c_iop->t.time);
update_d2c(q_iop, d2c);
latency_d2c(q_iop->dip, c_iop->t.time, d2c);
- iostat_complete(q_iop, c_iop);
}
if (per_io_ofp) {
@@ -85,9 +87,17 @@ static void handle_complete(struct io *c_iop)
display_io_track(per_io_ofp, q_iop);
}
+ if (q_iop->g_time != (__u64)-1) {
+ if (g2c == (__u64)-1)
+ g2c = tdelta(q_iop->g_time, c_iop->t.time);
+ nqs++;
+ }
+
list_del(&q_iop->f_head);
io_release(q_iop);
}
+
+ iostat_complete(dip_get_stats(c_iop->dip), c_iop, d2c, g2c, nqs);
}
void trace_complete(struct io *c_iop)
diff --git a/btt/trace_im.c b/btt/trace_im.c
index 49c876c..0cb6690 100644
--- a/btt/trace_im.c
+++ b/btt/trace_im.c
@@ -24,8 +24,6 @@ static void handle_g(struct io *g_iop)
{
struct io *q_iop;
- iostat_getrq(g_iop);
-
q_iop = dip_find_sec(g_iop->dip, IOP_Q, g_iop->t.sector);
if (q_iop) {
q_iop->g_time = g_iop->t.time;
@@ -52,13 +50,14 @@ static void handle_i(struct io *i_iop)
if (q_iop->g_time != (__u64)-1)
update_g2i(q_iop, tdelta(q_iop->g_time, i_iop->t.time));
}
+ iostat_insert(dip_get_stats(i_iop->dip), i_iop);
}
static void handle_m(struct io *m_iop)
{
struct io *q_iop;
- iostat_merge(m_iop);
+ iostat_merge(dip_get_stats(m_iop->dip), m_iop);
q_iop = dip_find_sec(m_iop->dip, IOP_Q, m_iop->t.sector);
if (q_iop) {
diff --git a/btt/trace_issue.c b/btt/trace_issue.c
index a18d44d..1a4a203 100644
--- a/btt/trace_issue.c
+++ b/btt/trace_issue.c
@@ -30,8 +30,8 @@ static void handle_issue(struct io *d_iop)
seeki_add(d_iop->dip->seek_handle, d_iop);
bno_dump_add(d_iop->dip->bno_dump_handle, d_iop);
- iostat_issue(d_iop);
d_iop->dip->n_ds++;
+ iostat_issue(dip_get_stats(d_iop->dip), d_iop);
if (!remapper_dev(d_iop->t.device))
update_d_histo(d_iop->t.bytes);
--
1.5.4.3
