diff options
Diffstat (limited to 'perform')
| -rw-r--r-- | perform/pio_perf.c | 96 | ||||
| -rw-r--r-- | perform/pio_timer.c | 49 | ||||
| -rw-r--r-- | perform/pio_timer.h | 4 |
3 files changed, 137 insertions, 12 deletions
diff --git a/perform/pio_perf.c b/perform/pio_perf.c index d436e5c..f19afa7 100644 --- a/perform/pio_perf.c +++ b/perform/pio_perf.c @@ -532,6 +532,10 @@ run_test(iotype iot, parameters parms, struct options *opts) minmax *read_mm_table=NULL; minmax *read_gross_mm_table=NULL; minmax *read_raw_mm_table=NULL; + minmax *read_open_mm_table=NULL; + minmax *read_close_mm_table=NULL; + minmax *write_open_mm_table=NULL; + minmax *write_close_mm_table=NULL; minmax write_mpi_mm = {0.0, 0.0, 0.0, 0}; minmax write_mm = {0.0, 0.0, 0.0, 0}; minmax write_gross_mm = {0.0, 0.0, 0.0, 0}; @@ -540,6 +544,10 @@ run_test(iotype iot, parameters parms, struct options *opts) minmax read_mm = {0.0, 0.0, 0.0, 0}; minmax read_gross_mm = {0.0, 0.0, 0.0, 0}; minmax read_raw_mm = {0.0, 0.0, 0.0, 0}; + minmax read_open_mm = {0.0, 0.0, 0.0, 0}; + minmax read_close_mm = {0.0, 0.0, 0.0, 0}; + minmax write_open_mm = {0.0, 0.0, 0.0, 0}; + minmax write_close_mm = {0.0, 0.0, 0.0, 0}; raw_size = (off_t)parms.num_dsets * (off_t)parms.num_bytes; parms.io_type = iot; @@ -569,13 +577,18 @@ run_test(iotype iot, parameters parms, struct options *opts) write_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); write_gross_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); write_raw_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + write_open_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + write_close_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); if (!parms.h5_write_only) { - read_mpi_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); - read_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); - read_gross_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); - read_raw_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); - } + read_mpi_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + read_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + read_gross_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + read_raw_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + read_open_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + read_close_mm_table = calloc((size_t)parms.num_iters , sizeof(minmax)); + + } /* Do IO iteration times, collecting statistics each time */ for (i = 0; i < parms.num_iters; ++i) { @@ -603,10 +616,22 @@ run_test(iotype iot, parameters parms, struct options *opts) write_gross_mm_table[i] = write_gross_mm; /* gather all of the raw "write" times */ - t = get_time(res.timers, HDF5_RAW_WRITE_FIXED_DIMS); + t = get_time(res.timers, HDF5_RAW_WRITE_FIXED_DIMS); get_minmax(&write_raw_mm, t); - write_raw_mm_table[i] = write_raw_mm; + write_raw_mm_table[i] = write_raw_mm; + + /* gather all of the file open times (time from open to first write) */ + t = get_time(res.timers, HDF5_FILE_WRITE_OPEN); + get_minmax(&write_open_mm, t); + + write_open_mm_table[i] = write_open_mm; + + /* gather all of the file close times (time from last write to close) */ + t = get_time(res.timers, HDF5_FILE_WRITE_CLOSE); + get_minmax(&write_close_mm, t); + + write_close_mm_table[i] = write_close_mm; if (!parms.h5_write_only) { /* gather all of the "mpi read" times */ @@ -632,6 +657,19 @@ run_test(iotype iot, parameters parms, struct options *opts) get_minmax(&read_raw_mm, t); read_raw_mm_table[i] = read_raw_mm; + + /* gather all of the file open times (time from open to first read) */ + t = get_time(res.timers, HDF5_FILE_READ_OPEN); + get_minmax(&read_open_mm, t); + + read_open_mm_table[i] = read_open_mm; + + /* gather all of the file close times (time from last read to close) */ + t = get_time(res.timers, HDF5_FILE_READ_CLOSE); + get_minmax(&read_close_mm, t); + + read_close_mm_table[i] = read_close_mm; + } pio_time_destroy(res.timers); @@ -684,6 +722,24 @@ run_test(iotype iot, parameters parms, struct options *opts) output_results(opts,"Write Open-Close",write_gross_mm_table,parms.num_iters,raw_size); + /* Print out time from open to first write */ + if (pio_debug_level >= 3) { + /* output all of the times for all iterations */ + print_indent(3); + output_report("Write file open details:\n"); + output_all_info(write_open_mm_table, parms.num_iters, 4); + } + + /* Print out time from last write to close */ + if (pio_debug_level >= 3) { + /* output all of the times for all iterations */ + print_indent(3); + output_report("Write file close details:\n"); + output_all_info(write_close_mm_table, parms.num_iters, 4); + } + + + if (!parms.h5_write_only) { /* Read statistics */ /* Print the raw data throughput if desired */ @@ -728,8 +784,26 @@ run_test(iotype iot, parameters parms, struct options *opts) output_all_info(read_gross_mm_table, parms.num_iters, 4); } - output_results(opts, "Read Open-Close", read_gross_mm_table, - parms.num_iters, raw_size); + output_results(opts, "Read Open-Close", read_gross_mm_table, + parms.num_iters, raw_size); + + + /* Print out time from open to first read */ + if (pio_debug_level >= 3) { + /* output all of the times for all iterations */ + print_indent(3); + output_report("Read file open details:\n"); + output_all_info(read_open_mm_table, parms.num_iters, 4); + } + + /* Print out time from last read to close */ + if (pio_debug_level >= 3) { + /* output all of the times for all iterations */ + print_indent(3); + output_report("Read file close details:\n"); + output_all_info(read_close_mm_table, parms.num_iters, 4); + } + } /* clean up our mess */ @@ -737,12 +811,16 @@ run_test(iotype iot, parameters parms, struct options *opts) free(write_mm_table); free(write_gross_mm_table); free(write_raw_mm_table); + free(write_open_mm_table); + free(write_close_mm_table); if (!parms.h5_write_only) { free(read_mpi_mm_table); free(read_mm_table); free(read_gross_mm_table); free(read_raw_mm_table); + free(read_open_mm_table); + free(read_close_mm_table); } return ret_value; diff --git a/perform/pio_timer.c b/perform/pio_timer.c index 10e0ff4..027b536 100644 --- a/perform/pio_timer.c +++ b/perform/pio_timer.c @@ -119,21 +119,55 @@ set_time(pio_time *pt, timer_type t, int start_stop) if (pt->type == MPI_TIMER) { if (start_stop == START) { pt->mpi_timer[t] = MPI_Wtime(); + + /* When we start the timer for HDF5_FINE_WRITE_FIXED_DIMS or HDF5_FINE_READ_FIXED_DIMS + * we compute the time it took to only open the file */ + if(t == HDF5_FINE_WRITE_FIXED_DIMS) + pt->total_time[HDF5_FILE_WRITE_OPEN] += pt->mpi_timer[t] - pt->mpi_timer[HDF5_GROSS_WRITE_FIXED_DIMS]; + else if(t == HDF5_FINE_READ_FIXED_DIMS) + pt->total_time[HDF5_FILE_READ_OPEN] += pt->mpi_timer[t] - pt->mpi_timer[HDF5_GROSS_READ_FIXED_DIMS]; + } else { pt->total_time[t] += MPI_Wtime() - pt->mpi_timer[t]; + pt->mpi_timer[t] = MPI_Wtime(); + + /* When we stop the timer for HDF5_GROSS_WRITE_FIXED_DIMS or HDF5_GROSS_READ_FIXED_DIMS + * we compute the time it took to close the file after the last read/write finished */ + if(t == HDF5_GROSS_WRITE_FIXED_DIMS) + pt->total_time[HDF5_FILE_WRITE_CLOSE] += pt->mpi_timer[t] - pt->mpi_timer[HDF5_FINE_WRITE_FIXED_DIMS]; + else if(t == HDF5_GROSS_READ_FIXED_DIMS) + pt->total_time[HDF5_FILE_READ_CLOSE] += pt->mpi_timer[t] - pt->mpi_timer[HDF5_FINE_READ_FIXED_DIMS]; } } else { if (start_stop == START) { gettimeofday(&pt->sys_timer[t], NULL); + + /* When we start the timer for HDF5_FINE_WRITE_FIXED_DIMS or HDF5_FINE_READ_FIXED_DIMS + * we compute the time it took to only open the file */ + if(t == HDF5_FINE_WRITE_FIXED_DIMS) + pt->total_time[HDF5_FILE_WRITE_OPEN] += sub_time(&(pt->sys_timer[t]), &(pt->sys_timer[HDF5_GROSS_WRITE_FIXED_DIMS])); + else if(t == HDF5_FINE_READ_FIXED_DIMS) + pt->total_time[HDF5_FILE_READ_OPEN] += sub_time(&(pt->sys_timer[t]), &(pt->sys_timer[HDF5_GROSS_READ_FIXED_DIMS])); + + } else { struct timeval sys_t; gettimeofday(&sys_t, NULL); - pt->total_time[t] += - ((double)sys_t.tv_sec + + pt->total_time[t] += sub_time(&sys_t, &(pt->sys_timer[t])); + +/* ((double)sys_t.tv_sec + ((double)sys_t.tv_usec) / MICROSECOND) - ((double)pt->sys_timer[t].tv_sec + - ((double)pt->sys_timer[t].tv_usec) / MICROSECOND); + ((double)pt->sys_timer[t].tv_usec) / MICROSECOND);*/ + + /* When we stop the timer for HDF5_GROSS_WRITE_FIXED_DIMS or HDF5_GROSS_READ_FIXED_DIMS + * we compute the time it took to close the file after the last read/write finished */ + if(t == HDF5_GROSS_WRITE_FIXED_DIMS) + pt->total_time[HDF5_FILE_WRITE_CLOSE] += sub_time(&(pt->sys_timer[t]), &(pt->sys_timer[HDF5_FINE_WRITE_FIXED_DIMS])); + else if(t == HDF5_GROSS_READ_FIXED_DIMS) + pt->total_time[HDF5_FILE_READ_CLOSE] += sub_time(&(pt->sys_timer[t]), &(pt->sys_timer[HDF5_FINE_READ_FIXED_DIMS])); + } } @@ -201,6 +235,15 @@ get_time(pio_time *pt, timer_type t) return pt->total_time[t]; } +/* Assumes that a > b */ +static inline double sub_time(struct timeval* a, struct timeval* b) +{ + ((double)a->tv_sec + + ((double)a->tv_usec) / MICROSECOND) - + ((double)b->tv_sec + + ((double)b->tv_usec) / MICROSECOND); +} + #endif /* H5_HAVE_PARALLEL */ #ifdef STANDALONE #include "pio_standalone.c" diff --git a/perform/pio_timer.h b/perform/pio_timer.h index 3094997..ca942a3 100644 --- a/perform/pio_timer.h +++ b/perform/pio_timer.h @@ -32,6 +32,10 @@ typedef enum timer_type_ { HDF5_DATASET_CREATE, HDF5_MPI_WRITE, HDF5_MPI_READ, + HDF5_FILE_READ_OPEN, + HDF5_FILE_READ_CLOSE, + HDF5_FILE_WRITE_OPEN, + HDF5_FILE_WRITE_CLOSE, HDF5_FINE_WRITE_FIXED_DIMS, HDF5_FINE_READ_FIXED_DIMS, HDF5_GROSS_WRITE_FIXED_DIMS, |