From: Alan D. Brunelle Date: Tue, 27 May 2008 14:39:14 +0000 (-0400) Subject: Put message notes from kernel into a separate file for easy tracking X-Git-Tag: blktrace-1.0.0~21 X-Git-Url: https://git.kernel.dk/?a=commitdiff_plain;h=84a26fcd9adebd1537bf2c4eee69d1ca23ccbc5f;p=blktrace.git Put message notes from kernel into a separate file for easy tracking Also made made_dev_hdr standard for all usages. --- diff --git a/btt/args.c b/btt/args.c index 2d0dfdf..9c5c4d5 100644 --- a/btt/args.c +++ b/btt/args.c @@ -335,7 +335,7 @@ void handle_args(int argc, char *argv[]) setup_ifile(input_name); if (output_name == NULL) { - ranges_ofp = avgs_ofp = stdout; + ranges_ofp = avgs_ofp = msgs_ofp = stdout; easy_parse_avgs = 0; } else { @@ -359,6 +359,15 @@ void handle_args(int argc, char *argv[]) if (verbose) printf("Sending stats data to %s\n", fname); + sprintf(fname, "%s.msg", output_name); + msgs_ofp = fopen(fname, "w"); + if (msgs_ofp == NULL) { + perror(fname); + exit(1); + } + if (verbose) + printf("Sending K messages to %s\n", fname); + if (easy_parse_avgs) { sprintf(fname, "%s.xvg", output_name); xavgs_ofp = fopen(fname, "w"); diff --git a/btt/bt_timeline.c b/btt/bt_timeline.c index bb32e44..2eed087 100644 --- a/btt/bt_timeline.c +++ b/btt/bt_timeline.c @@ -30,7 +30,7 @@ char bt_timeline_version[] = "2.05"; char *devices, *exes, *input_name, *output_name, *seek_name, *bno_dump_name; char *d2c_name, *q2c_name, *per_io_name, *unplug_hist_name; char *sps_name; -FILE *ranges_ofp, *avgs_ofp, *xavgs_ofp, *per_io_ofp; +FILE *ranges_ofp, *avgs_ofp, *xavgs_ofp, *per_io_ofp, *msgs_ofp; int verbose, done, time_bounded, output_all_data, seek_absolute; int easy_parse_avgs; double t_astart, t_aend; @@ -69,6 +69,8 @@ int main(int argc, char *argv[]) iostat_dump_stats(iostat_last_stamp, 1); } + if (msgs_ofp != stdout) + fclose(msgs_ofp); if (ranges_ofp != stdout) fclose(ranges_ofp); if (avgs_ofp != stdout) diff --git a/btt/globals.h b/btt/globals.h index 299a02e..c4b7674 100644 --- a/btt/globals.h +++ b/btt/globals.h @@ -183,6 +183,7 @@ extern char *seek_name, *iostat_name, *d2c_name, *q2c_name, *per_io_name; extern char *bno_dump_name, *unplug_hist_name, *sps_name; extern double range_delta; extern FILE *ranges_ofp, *avgs_ofp, *xavgs_ofp, *iostat_ofp, *per_io_ofp; +extern FILE *msgs_ofp; extern int verbose, done, time_bounded, output_all_data, seek_absolute; extern int easy_parse_avgs; extern unsigned int n_devs; @@ -250,6 +251,7 @@ void add_file(struct file_info **fipp, FILE *fp, char *oname); void clean_files(struct file_info **fipp); void add_buf(void *buf); void clean_bufs(void); +char *make_dev_hdr(char *pad, size_t len, struct d_info *dip, int add_parens); void dbg_ping(void); /* mmap.c */ @@ -260,7 +262,6 @@ int next_trace(struct blk_io_trace *t, void **pdu); /* output.c */ int output_avgs(FILE *ofp); int output_ranges(FILE *ofp); -char *make_dev_hdr(char *pad, size_t len, struct d_info *dip); /* proc.c */ void add_process(__u32 pid, char *name); diff --git a/btt/iostat.c b/btt/iostat.c index c4ddcb4..d701e2f 100644 --- a/btt/iostat.c +++ b/btt/iostat.c @@ -124,7 +124,7 @@ void __dump_stats(__u64 stamp, int all, struct d_info *dip, struct stats_t *asp) * 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)); + 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); diff --git a/btt/misc.c b/btt/misc.c index 4e721fc..0ddd260 100644 --- a/btt/misc.c +++ b/btt/misc.c @@ -100,4 +100,20 @@ void clean_bufs(void) } } +char *make_dev_hdr(char *pad, size_t len, struct d_info *dip, int add_parens) +{ + if (dip->map == NULL) { + if (add_parens) + snprintf(pad, len, "(%3d,%3d)", + MAJOR(dip->device), MINOR(dip->device)); + else + snprintf(pad, len, "%d,%d", + MAJOR(dip->device), MINOR(dip->device)); + } + else + snprintf(pad, len, "%s", dip->map->device); + + return pad; +} + void dbg_ping(void) {} diff --git a/btt/output.c b/btt/output.c index ab1566b..3076412 100644 --- a/btt/output.c +++ b/btt/output.c @@ -90,28 +90,6 @@ static inline char *avg2string(struct avg_info *ap, char *string) return string; } -char *make_dev_hdr(char *pad, size_t len, struct d_info *dip) -{ - if (dip->map == NULL) - snprintf(pad, len, "(%3d,%3d)", - MAJOR(dip->device), MINOR(dip->device)); - else - snprintf(pad, len, "%s", dip->map->device); - - return pad; -} - -char *make_dev_hdrX(char *pad, size_t len, struct d_info *dip) -{ - if (dip->map == NULL) - snprintf(pad, len, "%d,%d", - MAJOR(dip->device), MINOR(dip->device)); - else - snprintf(pad, len, "%s", dip->map->device); - - return pad; -} - struct __oda { FILE *ofp; ai_dip_t (*func)(struct d_info *); @@ -123,7 +101,8 @@ void __output_dip_avg(struct d_info *dip, void *arg) if (ap->n > 0) { char dev_info[15]; ap->avg = BIT_TIME(ap->total) / (double)ap->n; - __output_avg(odap->ofp, make_dev_hdr(dev_info, 15, dip), ap, 0); + __output_avg(odap->ofp, make_dev_hdr(dev_info, 15, dip, 1), + ap, 0); } } @@ -148,7 +127,8 @@ void __output_q2d_histo(struct d_info *dip, void *arg) char dev_info[15]; FILE *ofp = q2dp->ofp; - fprintf(q2dp->ofp, "%10s | ", make_dev_hdr(dev_info, 15, dip)); + fprintf(q2dp->ofp, "%10s | ", + make_dev_hdr(dev_info, 15, dip, 1)); q2d_display(ofp, dip->q2d_priv); q2d_acc(q2dp->q2d_all, dip->q2d_priv); q2dp->n++; @@ -203,7 +183,7 @@ void __output_dip_merge_ratio(struct d_info *dip, void *arg) blks_avg = (double)dip->avgs.blks.total / d2c_n; fprintf((FILE *)arg, "%10s | %8llu %8llu %7.1lf | %8llu %8llu %8llu %8llu\n", - make_dev_hdr(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 1), (unsigned long long)dip->n_qs, (unsigned long long)dip->n_ds, ratio, @@ -215,7 +195,7 @@ void __output_dip_merge_ratio(struct d_info *dip, void *arg) if (easy_parse_avgs) { fprintf(xavgs_ofp, "DMI %s %llu %llu %.9lf %llu %llu %llu %llu\n", - make_dev_hdrX(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 0), (unsigned long long)dip->n_qs, (unsigned long long)dip->n_ds, ratio, @@ -284,7 +264,7 @@ void __output_dip_prep_ohead(struct d_info *dip, void *arg) fprintf(odp->ofp, "%10s | %8.4lf%% %8.4lf%% %8.4lf%% %8.4lf%% %8.4lf%%\n", - make_dev_hdr(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 1), 100.0 * (double)(dip->avgs.q2g.total) / q2c_total, 100.0 * (double)(dip->avgs.g2i.total) / q2c_total, 100.0 * (double)(dip->avgs.q2m.total) / q2c_total, @@ -419,8 +399,8 @@ static void do_output_dip_seek_info(struct d_info *dip, FILE *ofp, int is_q2q) nmodes = seeki_mode(handle, &m); fprintf(ofp, "%10s | %15lld %15.1lf %15lld | %lld(%d)", - make_dev_hdr(dev_info, 15, dip), nseeks, mean, median, - nmodes > 0 ? m.modes[0] : 0, m.most_seeks); + make_dev_hdr(dev_info, 15, dip, 1), nseeks, mean, + median, nmodes > 0 ? m.modes[0] : 0, m.most_seeks); for (i = 1; i < nmodes; i++) fprintf(ofp, " %lld", m.modes[i]); fprintf(ofp, "\n"); @@ -429,7 +409,7 @@ static void do_output_dip_seek_info(struct d_info *dip, FILE *ofp, int is_q2q) char *rec = is_q2q ? "QSK" : "DSK"; fprintf(xavgs_ofp, "%s %s %lld %.9lf %lld %lld %d", - rec, make_dev_hdrX(dev_info, 15, dip), + rec, make_dev_hdr(dev_info, 15, dip, 0), nseeks, mean, median, nmodes > 0 ? m.modes[0] : 0, m.most_seeks); for (i = 1; i < nmodes; i++) @@ -539,13 +519,13 @@ void __dip_output_plug(struct d_info *dip, void *arg) pct = 100.0 * ((dip->plugged_time / delta) / delta); fprintf(ofp, "%10s | %10d(%10d) | %13.9lf%%\n", - make_dev_hdr(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 1), dip->nplugs, dip->n_timer_unplugs, pct); if (easy_parse_avgs) { fprintf(xavgs_ofp, "PLG %s %d %d %.9lf\n", - make_dev_hdrX(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 0), dip->nplugs, dip->n_timer_unplugs, pct); } @@ -590,13 +570,13 @@ void __dip_output_plug_nios(struct d_info *dip, void *arg) } fprintf(ofp, "%10s | %10.1lf %10.1lf\n", - make_dev_hdr(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 1), a_nios_uplug, a_nios_uplug_t); if (easy_parse_avgs) { fprintf(xavgs_ofp, "UPG %s %.9lf %.9lf\n", - make_dev_hdrX(dev_info, 15, dip), + make_dev_hdr(dev_info, 15, dip, 0), a_nios_uplug, a_nios_uplug_t); } } @@ -649,12 +629,12 @@ void __dip_output_actQ(struct d_info *dip, void *arg) double a_actQs = (double)dip->t_act_q / (double)dip->n_qs; fprintf((FILE *)arg, "%10s | %13.1lf\n", - make_dev_hdr(dev_info, 15, dip), a_actQs); + make_dev_hdr(dev_info, 15, dip, 1), a_actQs); if (easy_parse_avgs) { fprintf(xavgs_ofp, "ARQ %s %.9lf\n", - make_dev_hdrX(dev_info, 15, dip), a_actQs); + make_dev_hdr(dev_info, 15, dip, 0), a_actQs); } n_actQs++; diff --git a/btt/trace.c b/btt/trace.c index 1d9a1c0..efb9996 100644 --- a/btt/trace.c +++ b/btt/trace.c @@ -54,6 +54,23 @@ static void __add_trace(struct io *iop) } } +static void trace_message(struct io *iop) +{ + char scratch[15]; + char msg[iop->t.pdu_len + 1]; + + if (!io_setup(iop, IOP_M)) + return; + + memcpy(msg, iop->pdu, iop->t.pdu_len); + msg[iop->t.pdu_len] = '\0'; + + fprintf(msgs_ofp, "%s %5d.%09lu %s\n", + make_dev_hdr(scratch, 15, iop->dip, 1), + (int)SECONDS(iop->t.time), + (unsigned long)NANO_SECONDS(iop->t.time), msg); +} + void add_trace(struct io *iop) { if (iop->t.action & BLK_TC_ACT(BLK_TC_NOTIFY)) { @@ -68,6 +85,8 @@ void add_trace(struct io *iop) add_process(iop->t.pid, iop->pdu); } } + else if (iop->t.action == BLK_TN_MESSAGE) + trace_message(iop); io_release(iop); } else if (iop->t.action & BLK_TC_ACT(BLK_TC_PC))