mirror/hdf5
2
0
Fork 0
mirror of https://github.com/HDFGroup/hdf5.git synced 2024-11-27 02:10:55 +08:00
Code Issues Packages Projects Releases Wiki Activity

[svn-r11894] Purpose:

Browse Source 
Feature, address bug #426

Description:
The h5perf test now also keeps track of the time it takes to:

open a file: Time between start of open and start first read/write
close a file: Time between end of last read/write and end of close.

This information is only displayed if debug output printing is enabled (level 3 or higher)

Solution:
The test actually has all of the data necessary to compute the time it takes to open
and close a file; it just wasn't recording it.  Added 4 new timers:

HDF5_FILE_READ_OPEN
HDF5_FILE_READ_CLOSE
HDF5_FILE_WRITE_OPEN
HDF5_FILE_WRITE_CLOSE

that keep track of the time to open/close a file opened for reading/writing.

Platforms tested:
heping and mir

Misc. update:
This commit is contained in:
Leon Arber 2006-01-26 17:45:51 -05:00
parent 25f2ebda39
commit d61b687587
3 changed files with 137 additions and 12 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

96
perform/pio_perf.c
View File

@ -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;

49
perform/pio_timer.c
View File

@ -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"

4
perform/pio_timer.h
View File

@ -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,