[svn-r11894] Purpose:

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:

1 files changed, 46 insertions, 3 deletions

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"