From f3bca0e22f1ae6dded606e170bfb5699fe8f42a2 Mon Sep 17 00:00:00 2001 From: myang6 Date: Wed, 27 Oct 2021 12:30:40 -0500 Subject: Add comments, descriptions for the VFD log feature. --- src/H5FDvfd_swmr_private.h | 28 +----------- src/H5Fint.c | 4 +- src/H5Fpkg.h | 69 ++++++++++++++++++++---------- src/H5Fvfd_swmr.c | 103 ++++++++++++++++++++++++++++++++++----------- test/vfd_swmr_common.c | 1 + test/vfd_swmr_log_writer.c | 85 ++++++++----------------------------- 6 files changed, 145 insertions(+), 145 deletions(-) diff --git a/src/H5FDvfd_swmr_private.h b/src/H5FDvfd_swmr_private.h index 9e56d00..a2c29cd 100644 --- a/src/H5FDvfd_swmr_private.h +++ b/src/H5FDvfd_swmr_private.h @@ -89,34 +89,8 @@ H5_DLL herr_t H5F_dump_eot_queue(void); /***************************************/ /* VFD SWMR Helper macros to calcuate the elapsed time */ -/* The total time in seconds */ +/* The total time is in seconds */ #define TOTAL_TIME_PASSED(X, Y) \ ((double)((Y.tv_sec - X.tv_sec) * 1000000000 + (Y.tv_nsec - X.tv_nsec))) / 1000000000.0 -/* -#define TIME_PASSED_MIN(X) (unsigned int)(X / 60000) -#define TIME_PASSED_SEC(X, Y) (unsigned int)((X - Y * 60000) / 1000) -#define TIME_PASSED_MSEC(X, Y, Z) (unsigned int)(X - Y * 60000 - Z * 1000) -*/ - -/* Add more tags */ -/* The VFD SMWR Log tags. Note this array of string is used to generate the - * entry tag by the log reporting function H5F_POST_VFD_SWMR_LOG_ENTRY. - * If the entry code is 0, H5Fvfd_swmr_log_tags[0] is used to report the entry tag. - * H5F_POST_VFD_SWMR_LOG_ENTRY(f, 3, log_msg) will put the log_msg attached to - * the entry tag "EOT_PROCESSING_TIME". - */ -#if 0 -/* clang-format off */ -/* The entry code number is listed in the comment for convenience. */ -static const char *H5Fvfd_swmr_log_tags[] = { - "FILE_OPEN", /* 0 */ - "FILE_CLOSE", /* 1 */ - "EOT_TRIGGER_TIME", /* 2 */ - "EOT_PROCESSING_TIME", /* 3 */ - "EOT_META_FILE_INDEX" /* 4 */ - }; -/* clang-format on */ -#endif - #endif /* H5FDvfd_swmr_private_H */ diff --git a/src/H5Fint.c b/src/H5Fint.c index f7a988b..6827158 100644 --- a/src/H5Fint.c +++ b/src/H5Fint.c @@ -2226,8 +2226,8 @@ H5F_open(const char *name, unsigned flags, hid_t fcpl_id, hid_t fapl_id) /* Success */ ret_value = file; -#if 1 /*Kent: write to the log file when H5F_open ends. Tested, now comment out.*/ - H5F_POST_VFD_SWMR_LOG_ENTRY(file, 0, "File open ends") +#if 1 /*Kent: write to the log file when H5F_open ends. Tested, can be commented out if necessary.*/ + H5F_POST_VFD_SWMR_LOG_ENTRY(file, 1, "File open ends"); #endif done: if ((NULL == ret_value) && file) { diff --git a/src/H5Fpkg.h b/src/H5Fpkg.h index 41c4b6b..2fc896a 100644 --- a/src/H5Fpkg.h +++ b/src/H5Fpkg.h @@ -612,29 +612,52 @@ H5_DLL htri_t H5F__same_file_test(hid_t file_id1, hid_t file_id2); H5_DLL herr_t H5F__reparse_file_lock_variable_test(void); #endif /* H5F_TESTING */ -/* VFD SMWR log reporting macros */ -/* The first argument is the HDF5 file pointer(H5F_t *). Its value needs to be checked - * to avoid a failure caused by "Low-Level File I/O " in the testhdf5 which involves - * the test of a non-existing HDF5 file. */ -#define H5F_POST_VFD_SWMR_LOG_ENTRY(fp, entry_type_code, body) \ - if (fp != NULL) \ - if (fp->shared != NULL) \ - if (fp->shared->vfd_swmr_log_on == TRUE) \ - H5F_post_vfd_swmr_log_entry(fp, entry_type_code, body); - -H5_DLL herr_t H5F_post_vfd_swmr_log_entry(H5F_t *f, int entry_type_code, char *body); -/* clang-format off */ -/* The entry code number is listed in the comment for convenience. */ - -#if 0 -static const char *H5Fvfd_swmr_log_tags[] = { - "FILE_OPEN", /* 0 */ - "FILE_CLOSE", /* 1 */ - "EOT_TRIGGER_TIME", /* 2 */ - "EOT_PROCESSING_TIME", /* 3 */ - "EOT_META_FILE_INDEX" /* 4 */ - }; +/* VFD SMWR LOG REPORTING MACROS */ + +/* H5F_POST_VFD_SWMR_LOG_ENTRY is the macro that needs to be used by the developers. + * It calls an internal reporting function H5F_post_vfd_swmr_log_entry() that receives + * the log entry_type_code, which generates the log tag, and the message log_info, which + * the library developer wants to save into the log file. + * + * The macro H5F_POST_VFD_SWMR_LOG_ENTRY_RELEASE(f, c, number_entry_production, m) is + * called by H5F_POST_VFD_SWMR_LOG_ENTRY when the HDF5 library is built with the + * production mode. Number_entry_production will control the number of entry tags that + * applications can receive. Currently this number is set to 1 and is subject to change + * when more tags are useful to be present to applications. + * + * The first argument of the macro is the HDF5 file pointer(H5F_t *). + * Its value needs to be checked to avoid a failure caused by "Low-Level File I/O " + * in the testhdf5 program, which involves the test of a non-existing HDF5 file. + */ + +H5_DLL void H5F_post_vfd_swmr_log_entry(H5F_t *f, int entry_type_code, char *log_info); + +#define H5F_POST_VFD_SWMR_LOG_ENTRY_INTERNAL(fp, entry_type_code, log_info) \ + do { \ + if (fp != NULL) { \ + if (fp->shared != NULL) { \ + if (fp->shared->vfd_swmr_log_on == TRUE) { \ + H5F_post_vfd_swmr_log_entry(fp, entry_type_code, log_info); \ + } \ + } \ + } \ + } while (0) + +#define H5F_POST_VFD_SWMR_LOG_ENTRY_RELEASE(fp, entry_type_code, max_code, log_info) \ + do { \ + if (entry_type_code vfd_swmr_log_on) { HDfclose(shared->vfd_swmr_log_file_ptr); } + /* Kent */ FUNC_LEAVE_NOAPI(ret_value) } @@ -782,10 +805,14 @@ H5F_vfd_swmr_writer_end_of_tick(H5F_t *f, hbool_t wait_for_reader) HDassert(shared->page_buf); HDassert(shared->vfd_swmr_writer); - if (f->shared->vfd_swmr_log_on == true) { + /* Kent */ + /* Obtain the starting time for the logging info: the processing time of this function. */ + if (shared->vfd_swmr_log_on == true) { if (HDclock_gettime(CLOCK_MONOTONIC, &start_time) < 0) HGOTO_ERROR(H5E_FILE, H5E_CANTGET, FAIL, "can't get time via clock_gettime"); } + /* Kent */ + if (!vfd_swmr_writer_may_increase_tick_to(shared->tick_num + 1, wait_for_reader)) goto update_eot; @@ -908,15 +935,17 @@ update_eot: HGOTO_ERROR(H5E_FILE, H5E_CANTSET, FAIL, "unable to insert entry into the EOT queue") done: - if (f->shared->vfd_swmr_log_on == true) { + /* Kent: Calcuate the processing time and write the time info to the log file */ + if (shared->vfd_swmr_log_on == true) { if (HDclock_gettime(CLOCK_MONOTONIC, &end_time) < 0) HGOTO_ERROR(H5E_FILE, H5E_CANTGET, FAIL, "can't get time via clock_gettime"); log_msg = HDmalloc(48); temp_time = (unsigned int)(TOTAL_TIME_PASSED(start_time, end_time) * 1000); HDsprintf(log_msg, "Writer time is %u milliseconds", temp_time); - H5F_POST_VFD_SWMR_LOG_ENTRY(f, 3, log_msg) + H5F_POST_VFD_SWMR_LOG_ENTRY(f, 0, log_msg); HDfree(log_msg); } + /* Kent */ FUNC_LEAVE_NOAPI(ret_value) } @@ -1921,22 +1950,46 @@ done: FUNC_LEAVE_NOAPI(ret_value) } -/* Log reporting function, called by macro H5F_POST_VFD_SWMR_LOG_ENTRY */ -herr_t -H5F_post_vfd_swmr_log_entry(H5F_t *f, int entry_type_code, char *body) +/*------------------------------------------------------------------------- + * + * Function: H5F_post_vfd_swmr_log_entry + * + * Purpose: Write the log information to the log file. + * + * Parameters: + * H5F_t *f IN: HDF5 file pointer + * int entry_type_code IN: The entry type code to identify the + * log entry tag. + * char *log_info IN: The information to be stored in the + * log file. + * Return: None + * + *------------------------------------------------------------------------- + */ + +void +H5F_post_vfd_swmr_log_entry(H5F_t *f, int entry_type_code, char *log_info) { - herr_t ret_value = SUCCEED; double temp_time; struct timespec current_time; - FUNC_ENTER_NOAPI(FAIL) - if (HDclock_gettime(CLOCK_MONOTONIC, ¤t_time) < 0) - HGOTO_ERROR(H5E_FILE, H5E_CANTGET, FAIL, "can't get time via clock_gettime"); - temp_time = TOTAL_TIME_PASSED(f->shared->vfd_swmr_log_start_time, current_time); - - /* TODO: add a check for the range of entry_type_code to separate debug mode from the production mode.*/ - HDfprintf(f->shared->vfd_swmr_log_file_ptr, "%-25s: %.3lf s: %s\n", H5Fvfd_swmr_log_tags[entry_type_code], - temp_time, body); - -done: - FUNC_LEAVE_NOAPI(ret_value) + char *gettime_error; + + /* Obtain the current time. + If failed, write an error message to the log file. + else calcluate the elapsed time in seconds since the log file + was created and wirte the time to the log file. */ + if (HDclock_gettime(CLOCK_MONOTONIC, ¤t_time) < 0) { + gettime_error = HDmalloc(14); + HDsprintf(gettime_error, "gettime_error"); + HDfprintf(f->shared->vfd_swmr_log_file_ptr, + "%-26s: %s\n", H5Fvfd_swmr_log_tags[entry_type_code], + gettime_error); + HDfree(gettime_error); + } + else { + temp_time = TOTAL_TIME_PASSED(f->shared->vfd_swmr_log_start_time, current_time); + HDfprintf(f->shared->vfd_swmr_log_file_ptr,log_fmt_str, + H5Fvfd_swmr_log_tags[entry_type_code], temp_time, log_info); + } + return; } diff --git a/test/vfd_swmr_common.c b/test/vfd_swmr_common.c index 2cae0be..cfe93aa 100644 --- a/test/vfd_swmr_common.c +++ b/test/vfd_swmr_common.c @@ -369,6 +369,7 @@ init_vfd_swmr_config(H5F_vfd_swmr_config_t *config, uint32_t tick_len, uint32_t } /* init_vfd_swmr_config() */ +/* Initialize the log file path in config, this function should be called after init_vfd_swmr_config. */ void init_vfd_swmr_log(H5F_vfd_swmr_config_t *config, const char *log_file_fmtstr, ...) diff --git a/test/vfd_swmr_log_writer.c b/test/vfd_swmr_log_writer.c index 9ab50bd..62d8318 100644 --- a/test/vfd_swmr_log_writer.c +++ b/test/vfd_swmr_log_writer.c @@ -11,24 +11,23 @@ * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */ /* Description of this program: - * This program checks the performance of group creations for VFD SWMR. + * This program shows an example on how a VFD log file can be written. + * It is adapted from the group performence test. Most options of the + * group performance test are still kept. + * To turn on the log feature, one just needs to provide the log file path as + * indicated by the line init_vfd_swmr_log(&config, "./log-test") in the main + * function. The init_vfd_swmr_log is defined inside the vfd_swmr_common.c. + * For the demo of the log feature, + * one just needs to do te following: + * After compiling the program, just run the following line + * ./vfd_swmr_log_writer -n 1000 -P -q + * A VFD SWMR log file log-test is generated. + * The log-test should include something like: + * 'EOT_PROCESSING_TIME : 0.040 s: Writer time is 1 milliseconds' + * This program also checks the performance of group creations for VFD SWMR. * Currently the group creation time, H5Fopen and H5Fclose time are measured. - * After compiling the program, - * ./vfd_swmr_gperf_writer -n 1000 -P -N 5 -q - * will generate 1000 groups, each group has 5 attributes. - * ./vfd_swmr_gperf_writer -n 1000 -P -N 0 -q - * will generate 1000 empty groups. - * ./vfd_swmr_gperf_writer -n 1000 -P -l 1 -q - * will generate 1000 groups with 1 level of nested groups,(like /g1/g2) - * each group has one attribute. - * ./vfd_swmr_gperf_writer -n 1000 -P -S -G -V -N 5 -l 1 -m 8 -t 4 -B 16384 -s 8192 - * will generate 1000 groups with 1 level of nested groups,(like /g1/g2) - * each group has 5 attributes and the attribute type is variable length string. - * The groups is created without using VFD SWMR; - * The groups are created with the earliest file format(old-styled) - * The program is run with max_lag = 8, tick_len = 4; - * The page buffer size is 16384 bytes. The page size is 8192 bytes. - * + * The output can help check the contents in the log-test. + * */ #define H5F_FRIEND /*suppress error about including H5Fpkg */ @@ -118,58 +117,7 @@ usage(const char *progname) "-b: write data in big-endian byte order\n" " (For the performance test, -V overwrites -b)\n" "-A at_pattern: `at_pattern' for different attribute tests\n" - " The value of `at_pattern` is one of the following:\n" - " `compact` - Attributes added in compact storage\n" - " `dense` - An attribute added in dense storage\n" - " `compact-del` - Attributes added and then one\n" - " attribute deleted, in compact \n" - " `dense-del` - Attributes added until the storage\n" - " is dense then an attribute deleted\n" - " the storge still in dense\n" - " `compact-add-to-dense` - Attributes added first in compact\n" - " then in dense storage\n" - " `dense-del-to-compact` - Attributes added until the storage\n" - " is dense, then several attributes \n" - " deleted, the storage changed to\n" - " compact\n" - " `modify` - An attribute added then modified\n" - " `add-vstr` - A VL string attribute added\n" - " `remove-vstr` - A VL string attribute added then\n" - " deleted\n" - " `modify-vstr` - A VL string attribute added then \n" - " modified \n" - " `add-ohr-block` - An attribute is added and this forces\n" - " the creation of object header\n" - " continuation block \n" - " `del-ohr-block` - An attribute is added and this forces\n" - " the creation of object header\n" - " continuation block and then this \n" - " attribute is deleted so the \n" - " object header continuation block is \n" - " removed. \n" "-O grp_op_pattern: `grp_op_pattern' for different group operation tests\n" - " The value of `grp_op_pattern` is one of the following:\n" - " `grp-creation` - A group is created.\n" - " `grp-deletion` - An existing group is deleted.\n" - " `grp-move` - A group is moved to become \n" - " another group. \n" - " `grp-ins-links` - Links are inserted, including\n" - " both hard and soft links. \n" - " `grp-del-links` - Links are deleted, including\n" - " both hard ans soft links. \n" - " `grp-compact-t-dense` - Links are inserted to the group.\n" - " The link storage of this group \n" - " changed from compact to dense. \n" - " The links include both hard and\n" - " soft links. \n" - " `grp-dense-t-compact` - Links are inserted to the group\n" - " The link storage of this group \n" - " changed from compact to dense. \n" - " Then several links are deleted.\n" - " The link storage changed from \n" - " dense to compact again. \n" - " The links include both hard and\n" - " soft links. \n" "-a steps: `steps` between adding attributes\n" " (Don't recommend to use this option for performance test.)\n" "-q: silence printouts, few messages\n" @@ -2763,6 +2711,7 @@ main(int argc, char **argv) /* config, tick_len, max_lag, writer, flush_raw_data, md_pages_reserved, md_file_path */ init_vfd_swmr_config(&config, s.tick_len, s.max_lag, writer, FALSE, 128, "./group-shadow"); + /* Create the log file log-test under the current directory. */ init_vfd_swmr_log(&config, "./log-test"); /* If old-style option is chosen, use the earliest file format(H5F_LIBVER_EARLIEST) -- cgit v0.12