in src/result_formatter.cc [17:252]
void ResultFormatterText::output_results(const Profile& profile) {
printf("\nCommand Line: %s\n\n", profile.cmd_line.c_str());
printf("System info:\n");
printf("\tprocessor count: %lu\n", profile.sys_info->online_cpus.size());
if (profile.sys_info->caching_options.size()) {
printf("\tcaching options: %s\n", profile.sys_info->caching_options.c_str());
}
printf("\n");
unsigned int jobnum = 1;
for (auto& job : profile.jobs) {
std::shared_ptr<JobOptions> options = job->get_options();
std::shared_ptr<JobResults> results = job->get_results();
printf ("Input parameters:\n\n");
printf ("\tjob: %u\n", jobnum);
printf ("\t________\n");
printf ("\tduration: %us\n", options->duration);
printf ("\twarm up time: %us\n", options->warmup_time);
if (options->measure_latency) {
printf("\tmeasuring latency\n");
}
if (options->measure_iops_std_dev) {
printf ("\tgathering IOPs at intervals of %ums\n", options->io_bucket_duration_ms);
}
if (options->use_time_seed) {
printf("\t using random_device for seed\n");
} else {
printf ("\trandom seed: %lu\n", options->rand_seed);
}
unsigned int all_threads = options->use_total_threads ? options->total_threads : 0;
if (!all_threads) {
for (auto& target : options->targets) all_threads += target->threads_per_target;
}
printf("\ttotal threads: %u\n", all_threads);
for (auto& target : options->targets) {
printf("\tpath: '%s'\n", target->path.c_str());
printf("\t\tsize: %luB\n", target->size);
if (target->open_flags & O_DIRECT) {
printf("\t\tusing O_DIRECT\n");
}
if (target->open_flags & O_SYNC) {
printf("\t\tusing O_SYNC\n");
}
printf("\t\tperforming mix test (read/write ratio: %u/%u)\n",
100-target->write_percentage, target->write_percentage);
printf("\t\tblock size: %lu\n", target->block_size);
if (target->use_random_alignment) {
printf("\t\tusing random I/O (alignment: %lu)\n", target->stride);
} else if (target->use_interlocked) {
printf("\t\tusing interlocked sequential I/O (stride: %lu)\n", target->stride);
} else {
printf("\t\tusing sequential I/O (stride: %lu)\n", target->stride);
}
printf("\t\tnumber of outstanding I/O operations: %u)\n", target->overlap);
if (target->base_offset) {
printf("\t\tbase file offset: %lu bytes\n", target->base_offset);
}
if (target->max_size != target->size) {
printf("\t\tmax file size: %lu bytes\n", target->max_size);
}
printf("\t\tthread stride size: %lu\n", target->thread_offset);
if (target->zero_buffers) {
printf("\t\tzeroing I/O buffers\n");
} else if (target->rand_buffers) {
printf("\t\tfilling I/O buffers with random data\n");
}
if (target->separate_buffers) {
printf("\t\tseparating read and write buffers\n");
}
if (!options->use_total_threads) {
printf("\t\tthreads per file: %u\n", target->threads_per_target);
}
printf("\t\tblock device: %s\n", target->device.c_str());
printf("\t\tdevice scheduler: %s\n", target->scheduler.c_str());
}
printf("\n");
printf("Results for job %u:\n", jobnum);
++jobnum;
printf("test time: %us\n", options->duration);
printf("*****************************************************\n\n");
// CPU stats
unsigned num_cpu_fields = results->cpu_usage_percentages.begin()->second.size();
double cpu_usage_totals[num_cpu_fields] = {0};
printf(" CPU | Usage | User | Kernel | IO Wait | Idle \n");
printf("-------------------------------------------------------\n");
for (auto& usage : results->cpu_usage_percentages) {
printf("%5u ", usage.first);
// add to the totals and print the usage for each column
for (int i = 0; i < num_cpu_fields; ++i) {
double u = usage.second[i]*100;
cpu_usage_totals[i] += u;
printf("| %6.2lf%% ", u);
}
printf("\n");
}
printf("-------------------------------------------------------\n");
printf(" avg: ");
// calculate averages from totals and print one at a time
for (int i = 0; i < num_cpu_fields; ++i) {
double u = cpu_usage_totals[i]/profile.sys_info->online_cpus.size();
printf("%6.2lf%%%s", u, (i == num_cpu_fields-1 ? "\n" : " | "));
}
printf("\n");
/* *************************** IOPs **************************** */
printf("Total IO\n");
print_iops(job, RW);
printf("Read IO\n");
print_iops(job, READ);
printf("Write IO\n");
print_iops(job, WRITE);
printf("\n");
/* *************************** Latency %-iles **************************** */
if (!options->measure_latency) return;
// create histograms accumulating all reads and write
Histogram<uint64_t> read_histogram;
Histogram<uint64_t> write_histogram;
Histogram<uint64_t> total_histogram;
for (auto& thread_result : results->thread_results) {
for (auto& t_result : thread_result->target_results) {
read_histogram.Merge(t_result->read_latency_histogram);
write_histogram.Merge(t_result->write_latency_histogram);
total_histogram.Merge(read_histogram);
total_histogram.Merge(write_histogram);
}
}
// make sure there are reads/writes to get
bool has_reads = read_histogram.GetSampleSize() > 0;
bool has_writes = write_histogram.GetSampleSize() > 0;
// buffers for snprintf
char readbuf[11] = {0};
char writebuf[11] = {0};
char * na = (char*)"N/A";
// pointers that either point to the buffer or na at any given time
char * readstr = na;
char * writestr = na;
printf(" %%-ile | Read (ms) | Write (ms) | Total (ms)\n");
printf("----------------------------------------------\n");
readstr = has_reads ?
snprintf(readbuf, 11, "%10.3lf", (double)read_histogram.GetMin()/1000), readbuf :
na;
writestr = has_writes ?
snprintf(writebuf, 11, "%10.3lf", (double)write_histogram.GetMin()/1000), writebuf :
na;
printf(" min | %10s | %10s | %10.3lf\n",
readstr,
writestr,
(double)total_histogram.GetMin()/1000
);
std::pair<double, std::string> percentiles[] = {
{ 0.25, "25th" },
{ 0.50, "50th" },
{ 0.75, "75th" },
{ 0.90, "90th" },
{ 0.95, "95th" },
{ 0.99, "99th" },
{ 0.999, "3-nines" },
{ 0.9999, "4-nines" },
{ 0.99999, "5-nines" },
{ 0.999999, "6-nines" },
{ 0.9999999, "7-nines" },
{ 0.99999999, "8-nines" },
{ 0.999999999, "9-nines"}
};
for (auto& p : percentiles)
{
readstr = has_reads ?
snprintf(
readbuf,
11,
"%10.3lf",
(double)read_histogram.GetPercentile(p.first)/1000
), readbuf :
na;
writestr = has_writes ?
snprintf(
writebuf,
11,
"%10.3lf",
(double)write_histogram.GetPercentile(p.first)/1000
), writebuf :
na;
printf("%7s | %10s | %10s | %10.3lf\n",
p.second.c_str(),
readstr,
writestr,
(double)total_histogram.GetPercentile(p.first)/1000
);
}
readstr = has_reads ?
snprintf(readbuf, 11, "%10.3lf", (double)read_histogram.GetMax()/1000), readbuf :
na;
writestr = has_writes ?
snprintf(writebuf, 11, "%10.3lf", (double)write_histogram.GetMax()/1000), writebuf :
na;
printf(" max | %10s | %10s | %10.3lf\n",
readstr,
writestr,
(double)total_histogram.GetMax()/1000
);
printf("\n");
}
}