diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/H5FDlog.c | 118 | ||||
| -rw-r--r-- | src/H5FDlog.h | 47 |
2 files changed, 137 insertions, 28 deletions
diff --git a/src/H5FDlog.c b/src/H5FDlog.c index d0c4647..dae0e4a 100644 --- a/src/H5FDlog.c +++ b/src/H5FDlog.c @@ -132,6 +132,7 @@ typedef struct H5FD_log_t { double total_read_time; /* Total time spent in read operations */ double total_write_time; /* Total time spent in write operations */ double total_seek_time; /* Total time spent in seek operations */ + double total_truncate_time; /* Total time spent in truncate operations */ size_t iosize; /* Size of I/O information buffers */ FILE *logfp; /* Log file pointer */ H5FD_log_fapl_t fa; /* Driver-specific file access properties */ @@ -170,6 +171,8 @@ static herr_t H5FD_log_close(H5FD_t *_file); static int H5FD_log_cmp(const H5FD_t *_f1, const H5FD_t *_f2); static herr_t H5FD_log_query(const H5FD_t *_f1, unsigned long *flags); static haddr_t H5FD_log_alloc(H5FD_t *_file, H5FD_mem_t type, hid_t dxpl_id, hsize_t size); +static herr_t H5FD__log_free(H5FD_t *_file, H5FD_mem_t type, hid_t dxpl_id, haddr_t addr, + hsize_t size); static haddr_t H5FD_log_get_eoa(const H5FD_t *_file, H5FD_mem_t type); static herr_t H5FD_log_set_eoa(H5FD_t *_file, H5FD_mem_t type, haddr_t addr); static haddr_t H5FD_log_get_eof(const H5FD_t *_file, H5FD_mem_t type); @@ -203,7 +206,7 @@ static const H5FD_class_t H5FD_log_g = { H5FD_log_query, /*query */ NULL, /*get_type_map */ H5FD_log_alloc, /*alloc */ - NULL, /*free */ + H5FD__log_free, /*free */ H5FD_log_get_eoa, /*get_eoa */ H5FD_log_set_eoa, /*set_eoa */ H5FD_log_get_eof, /*get_eof */ @@ -735,6 +738,8 @@ H5FD_log_close(H5FD_t *_file) HDfprintf(file->logfp, "Total time in write operations: %f s\n", file->total_write_time); if(file->fa.flags & H5FD_LOG_TIME_SEEK) HDfprintf(file->logfp, "Total time in seek operations: %f s\n", file->total_seek_time); + if(file->fa.flags & H5FD_LOG_TIME_TRUNCATE) + HDfprintf(file->logfp, "Total time in truncate operations: %f s\n", file->total_truncate_time); /* Dump the write I/O information */ if(file->fa.flags & H5FD_LOG_FILE_WRITE) { @@ -957,6 +962,43 @@ H5FD_log_alloc(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, hsi /*------------------------------------------------------------------------- + * Function: H5FD__log_free + * + * Purpose: Release file memory. + * + * Return: SUCCEED/FAIL + * + * Programmer: Quincey Koziol + * Wednesday, September 28, 2016 + * + *------------------------------------------------------------------------- + */ +static herr_t +H5FD__log_free(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, + haddr_t addr, hsize_t size) +{ + H5FD_log_t *file = (H5FD_log_t *)_file; + + FUNC_ENTER_STATIC_NOERR + + if(file->fa.flags != 0) { + /* Reset the flavor of the information in the file */ + if(file->fa.flags & H5FD_LOG_FLAVOR) { + HDassert(addr < file->iosize); + H5_CHECK_OVERFLOW(size, hsize_t, size_t); + HDmemset(&file->flavor[addr], H5FD_MEM_DEFAULT, (size_t)size); + } /* end if */ + + /* Log the file memory freed */ + if(file->fa.flags & H5FD_LOG_FREE) + HDfprintf(file->logfp, "%10a-%10a (%10Hu bytes) (%s) Freed\n", addr, (addr + size) - 1, size, flavors[type]); + } /* end if */ + + FUNC_LEAVE_NOAPI(SUCCEED) +} /* end H5FD__log_free() */ + + +/*------------------------------------------------------------------------- * Function: H5FD_log_get_eoa * * Purpose: Gets the end-of-address marker for the file. The EOA marker @@ -1004,6 +1046,7 @@ H5FD_log_set_eoa(H5FD_t *_file, H5FD_mem_t type, haddr_t addr) FUNC_ENTER_NOAPI_NOINIT_NOERR if(file->fa.flags != 0) { + /* Check for increasing file size */ if(H5F_addr_gt(addr, file->eoa) && H5F_addr_gt(addr, 0)) { hsize_t size = addr - file->eoa; @@ -1018,6 +1061,22 @@ H5FD_log_set_eoa(H5FD_t *_file, H5FD_mem_t type, haddr_t addr) if(file->fa.flags & H5FD_LOG_ALLOC) HDfprintf(file->logfp, "%10a-%10a (%10Hu bytes) (%s) Allocated\n", file->eoa, addr, size, flavors[type]); } /* end if */ + + /* Check for decreasing file size */ + if(H5F_addr_lt(addr, file->eoa) && H5F_addr_gt(addr, 0)) { + hsize_t size = file->eoa - addr; + + /* Reset the flavor of the space freed by the shrink */ + if(file->fa.flags & H5FD_LOG_FLAVOR) { + HDassert((addr + size) < file->iosize); + H5_CHECK_OVERFLOW(size, hsize_t, size_t); + HDmemset(&file->flavor[addr], H5FD_MEM_DEFAULT, (size_t)size); + } /* end if */ + + /* Log the shrink like a free */ + if(file->fa.flags & H5FD_LOG_FREE) + HDfprintf(file->logfp, "%10a-%10a (%10Hu bytes) (%s) Freed\n", file->eoa, addr, size, flavors[type]); + } /* end if */ } /* end if */ file->eoa = addr; @@ -1167,7 +1226,7 @@ H5FD_log_read(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, hadd timeval_diff.tv_sec--; } /* end if */ time_diff = (double)timeval_diff.tv_sec + ((double)timeval_diff.tv_usec / (double)1000000.0f); - HDfprintf(file->logfp, " (%f s)\n", time_diff); + HDfprintf(file->logfp, " (%fs @ %.6lu.%.6llu)\n", time_diff, (unsigned long long)timeval_start.tv_sec, (unsigned long long)timeval_start.tv_usec); /* Add to total seek time */ file->total_seek_time += time_diff; @@ -1241,7 +1300,12 @@ H5FD_log_read(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, hadd if(file->fa.flags & H5FD_LOG_LOC_READ) { HDfprintf(file->logfp, "%10a-%10a (%10Zu bytes) (%s) Read", orig_addr, (orig_addr + orig_size) - 1, orig_size, flavors[type]); - /* XXX: Verify the flavor information, if we have it? */ + /* Verify that we are reading in the type of data we allocated in this location */ + if(file->flavor) { + HDassert(type == H5FD_MEM_DEFAULT || type == (H5FD_mem_t)file->flavor[orig_addr] || (H5FD_mem_t)file->flavor[orig_addr] == H5FD_MEM_DEFAULT); + HDassert(type == H5FD_MEM_DEFAULT || type == (H5FD_mem_t)file->flavor[(orig_addr + orig_size) - 1] || (H5FD_mem_t)file->flavor[(orig_addr + orig_size) - 1] == H5FD_MEM_DEFAULT); + } /* end if */ + #ifdef H5_HAVE_GETTIMEOFDAY if(file->fa.flags & H5FD_LOG_TIME_READ) { @@ -1256,7 +1320,7 @@ H5FD_log_read(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, hadd timeval_diff.tv_sec--; } /* end if */ time_diff = (double)timeval_diff.tv_sec + ((double)timeval_diff.tv_usec / (double)1000000.0f); - HDfprintf(file->logfp, " (%f s)\n", time_diff); + HDfprintf(file->logfp, " (%fs @ %.6lu.%.6llu)\n", time_diff, (unsigned long long)timeval_start.tv_sec, (unsigned long long)timeval_start.tv_usec); /* Add to total read time */ file->total_read_time += time_diff; @@ -1369,7 +1433,7 @@ H5FD_log_write(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, had timeval_diff.tv_sec--; } /* end if */ time_diff = (double)timeval_diff.tv_sec + ((double)timeval_diff.tv_usec / (double)1000000.0f); - HDfprintf(file->logfp, " (%f s)\n", time_diff); + HDfprintf(file->logfp, " (%fs @ %.6lu.%.6llu)\n", time_diff, (unsigned long long)timeval_start.tv_sec, (unsigned long long)timeval_start.tv_usec); /* Add to total seek time */ file->total_seek_time += time_diff; @@ -1438,8 +1502,10 @@ H5FD_log_write(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, had /* Check if this is the first write into a "default" section, grabbed by the metadata agregation algorithm */ if(file->fa.flags & H5FD_LOG_FLAVOR) { - if((H5FD_mem_t)file->flavor[orig_addr] == H5FD_MEM_DEFAULT) + if((H5FD_mem_t)file->flavor[orig_addr] == H5FD_MEM_DEFAULT) { HDmemset(&file->flavor[orig_addr], (int)type, orig_size); + HDfprintf(file->logfp, " (fresh)"); + } /* end if */ } /* end if */ #ifdef H5_HAVE_GETTIMEOFDAY @@ -1455,7 +1521,7 @@ H5FD_log_write(H5FD_t *_file, H5FD_mem_t type, hid_t H5_ATTR_UNUSED dxpl_id, had timeval_diff.tv_sec--; } /* end if */ time_diff = (double)timeval_diff.tv_sec + ((double)timeval_diff.tv_usec / (double)1000000.0f); - HDfprintf(file->logfp, " (%f s)\n", time_diff); + HDfprintf(file->logfp, " (%fs @ %.6lu.%.6llu)\n", time_diff, (unsigned long long)timeval_start.tv_sec, (unsigned long long)timeval_start.tv_usec); /* Add to total write time */ file->total_write_time += time_diff; @@ -1509,6 +1575,14 @@ H5FD_log_truncate(H5FD_t *_file, hid_t H5_ATTR_UNUSED dxpl_id, hbool_t H5_ATTR_U /* Extend the file to make sure it's large enough */ if(!H5F_addr_eq(file->eoa, file->eof)) { +#ifdef H5_HAVE_GETTIMEOFDAY + struct timeval timeval_start, timeval_stop; +#endif /* H5_HAVE_GETTIMEOFDAY */ + +#ifdef H5_HAVE_GETTIMEOFDAY + if(file->fa.flags & H5FD_LOG_TIME_TRUNCATE) + HDgettimeofday(&timeval_start, NULL); +#endif /* H5_HAVE_GETTIMEOFDAY */ #ifdef H5_HAVE_WIN32_API LARGE_INTEGER li; /* 64-bit (union) integer for SetFilePointer() call */ DWORD dwPtrLow; /* Low-order pointer bits from SetFilePointer() @@ -1539,10 +1613,40 @@ H5FD_log_truncate(H5FD_t *_file, hid_t H5_ATTR_UNUSED dxpl_id, hbool_t H5_ATTR_U if(-1 == HDftruncate(file->fd, (HDoff_t)file->eoa)) HSYS_GOTO_ERROR(H5E_IO, H5E_SEEKERROR, FAIL, "unable to extend file properly") #endif /* H5_HAVE_WIN32_API */ +#ifdef H5_HAVE_GETTIMEOFDAY + if(file->fa.flags & H5FD_LOG_TIME_TRUNCATE) + HDgettimeofday(&timeval_stop, NULL); +#endif /* H5_HAVE_GETTIMEOFDAY */ /* Log information about the truncate */ if(file->fa.flags & H5FD_LOG_NUM_TRUNCATE) file->total_truncate_ops++; + if(file->fa.flags & H5FD_LOG_TRUNCATE) { + HDfprintf(file->logfp, "Truncate: To %10a", file->eoa); +#ifdef H5_HAVE_GETTIMEOFDAY + if(file->fa.flags & H5FD_LOG_TIME_TRUNCATE) { + struct timeval timeval_diff; + double time_diff; + + /* Calculate the elapsed gettimeofday time */ + timeval_diff.tv_usec = timeval_stop.tv_usec - timeval_start.tv_usec; + timeval_diff.tv_sec = timeval_stop.tv_sec - timeval_start.tv_sec; + if(timeval_diff.tv_usec < 0) { + timeval_diff.tv_usec += 1000000; + timeval_diff.tv_sec--; + } /* end if */ + time_diff = (double)timeval_diff.tv_sec + ((double)timeval_diff.tv_usec / (double)1000000.0f); + HDfprintf(file->logfp, " (%fs @ %.6lu.%.6llu)\n", time_diff, (unsigned long long)timeval_start.tv_sec, (unsigned long long)timeval_start.tv_usec); + + /* Add to total truncate time */ + file->total_truncate_time += time_diff; + } /* end if */ + else + HDfprintf(file->logfp, "\n"); +#else /* H5_HAVE_GETTIMEOFDAY */ + HDfprintf(file->logfp, "\n"); +#endif /* H5_HAVE_GETTIMEOFDAY */ + } /* end if */ /* Update the eof value */ file->eof = file->eoa; diff --git a/src/H5FDlog.h b/src/H5FDlog.h index 2f1544e..11044e2 100644 --- a/src/H5FDlog.h +++ b/src/H5FDlog.h @@ -25,34 +25,39 @@ #define H5FD_LOG (H5FD_log_init()) /* Flags for H5Pset_fapl_log() */ +/* Flags for tracking 'meta' operations (truncate) */ +#define H5FD_LOG_TRUNCATE 0x00000001 +#define H5FD_LOG_META_IO (H5FD_LOG_TRUNCATE) /* Flags for tracking where reads/writes/seeks occur */ -#define H5FD_LOG_LOC_READ 0x00000001 -#define H5FD_LOG_LOC_WRITE 0x00000002 -#define H5FD_LOG_LOC_SEEK 0x00000004 +#define H5FD_LOG_LOC_READ 0x00000002 +#define H5FD_LOG_LOC_WRITE 0x00000004 +#define H5FD_LOG_LOC_SEEK 0x00000008 #define H5FD_LOG_LOC_IO (H5FD_LOG_LOC_READ|H5FD_LOG_LOC_WRITE|H5FD_LOG_LOC_SEEK) /* Flags for tracking number of times each byte is read/written */ -#define H5FD_LOG_FILE_READ 0x00000008 -#define H5FD_LOG_FILE_WRITE 0x00000010 +#define H5FD_LOG_FILE_READ 0x00000010 +#define H5FD_LOG_FILE_WRITE 0x00000020 #define H5FD_LOG_FILE_IO (H5FD_LOG_FILE_READ|H5FD_LOG_FILE_WRITE) /* Flag for tracking "flavor" (type) of information stored at each byte */ -#define H5FD_LOG_FLAVOR 0x00000020 +#define H5FD_LOG_FLAVOR 0x00000040 /* Flags for tracking total number of reads/writes/seeks/truncates */ -#define H5FD_LOG_NUM_READ 0x00000040 -#define H5FD_LOG_NUM_WRITE 0x00000080 -#define H5FD_LOG_NUM_SEEK 0x00000100 -#define H5FD_LOG_NUM_TRUNCATE 0x00000200 +#define H5FD_LOG_NUM_READ 0x00000080 +#define H5FD_LOG_NUM_WRITE 0x00000100 +#define H5FD_LOG_NUM_SEEK 0x00000200 +#define H5FD_LOG_NUM_TRUNCATE 0x00000400 #define H5FD_LOG_NUM_IO (H5FD_LOG_NUM_READ|H5FD_LOG_NUM_WRITE|H5FD_LOG_NUM_SEEK|H5FD_LOG_NUM_TRUNCATE) -/* Flags for tracking time spent in open/stat/read/write/seek/close */ -#define H5FD_LOG_TIME_OPEN 0x00000400 -#define H5FD_LOG_TIME_STAT 0x00000800 -#define H5FD_LOG_TIME_READ 0x00001000 -#define H5FD_LOG_TIME_WRITE 0x00002000 -#define H5FD_LOG_TIME_SEEK 0x00004000 -#define H5FD_LOG_TIME_CLOSE 0x00008000 -#define H5FD_LOG_TIME_IO (H5FD_LOG_TIME_OPEN|H5FD_LOG_TIME_STAT|H5FD_LOG_TIME_READ|H5FD_LOG_TIME_WRITE|H5FD_LOG_TIME_SEEK|H5FD_LOG_TIME_CLOSE) -/* Flag for tracking allocation of space in file */ -#define H5FD_LOG_ALLOC 0x00010000 -#define H5FD_LOG_ALL (H5FD_LOG_ALLOC|H5FD_LOG_TIME_IO|H5FD_LOG_NUM_IO|H5FD_LOG_FLAVOR|H5FD_LOG_FILE_IO|H5FD_LOG_LOC_IO) +/* Flags for tracking time spent in open/stat/read/write/seek/truncate/close */ +#define H5FD_LOG_TIME_OPEN 0x00000800 +#define H5FD_LOG_TIME_STAT 0x00001000 +#define H5FD_LOG_TIME_READ 0x00002000 +#define H5FD_LOG_TIME_WRITE 0x00004000 +#define H5FD_LOG_TIME_SEEK 0x00008000 +#define H5FD_LOG_TIME_TRUNCATE 0x00010000 +#define H5FD_LOG_TIME_CLOSE 0x00020000 +#define H5FD_LOG_TIME_IO (H5FD_LOG_TIME_OPEN|H5FD_LOG_TIME_STAT|H5FD_LOG_TIME_READ|H5FD_LOG_TIME_WRITE|H5FD_LOG_TIME_SEEK|H5FD_LOG_TIME_TRUNCATE|H5FD_LOG_TIME_CLOSE) +/* Flags for tracking allocation/release of space in file */ +#define H5FD_LOG_ALLOC 0x00040000 +#define H5FD_LOG_FREE 0x00080000 +#define H5FD_LOG_ALL (H5FD_LOG_FREE|H5FD_LOG_ALLOC|H5FD_LOG_TIME_IO|H5FD_LOG_NUM_IO|H5FD_LOG_FLAVOR|H5FD_LOG_FILE_IO|H5FD_LOG_LOC_IO|H5FD_LOG_META_IO) #ifdef __cplusplus extern "C" { |