Add comments, descriptions for the VFD log feature.

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 <max_code) {                                                                      \
+            H5F_POST_VFD_SWMR_LOG_ENTRY_INTERNAL(fp,entry_type_code,log_info);                                    \
+        } \
+    } while (0)
+
+/* Note: change H5F_POST_VFD_SWMR_LOG_ENTRY_RELEASE(f, c, 1, m) on the following lines to 
+ *       H5F_POST_VFD_SWMR_LOG_ENTRY_RELEASE(f, c, your_number_entry_production, m)
+ *       as necessary. 
+ */
+#ifndef NDEBUG
+#define H5F_POST_VFD_SWMR_LOG_ENTRY(f, c, m) H5F_POST_VFD_SWMR_LOG_ENTRY_INTERNAL(f, c, m)
+#else
+#define H5F_POST_VFD_SWMR_LOG_ENTRY(f, c, m) H5F_POST_VFD_SWMR_LOG_ENTRY_RELEASE(f, c, 1, m)
 #endif
-/* clang-format on */
 
 #endif /* H5Fpkg_H */
diff --git a/src/H5Fvfd_swmr.c b/src/H5Fvfd_swmr.c
index 5119b38..3f24352 100644
--- a/src/H5Fvfd_swmr.c
+++ b/src/H5Fvfd_swmr.c
@@ -54,17 +54,38 @@
 #define nanosecs_per_second    1000000000 /* nanoseconds per second */
 #define nanosecs_per_tenth_sec 100000000  /* nanoseconds per 0.1 second */
 
+/* Declare an array of string to identify the VFD SMWR Log tags. 
+ * Note this array is used to generate the entry tag by the log reporting macro
+ * H5F_POST_VFD_SWMR_LOG_ENTRY.
+ *
+ * The following is the first version. Developers can add/modify the tags as necessary.
+ *
+ * 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, 0, log_msg) will put the log_msg attached to
+ * the entry tag "EOT_PROCESSING_TIME".
+ * The entry code number is listed in the comment for convenience. 
+ * Currently for the production mode, only the "EOT_PROCESSING_TIME" is present.
+ */
+
 /* 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_PROCESSING_TIME",         /* 0 */
+                                             "FILE_OPEN",                   /* 1 */                        
+                                             "FILE_CLOSE",                  /* 2 */
+                                             "EOT_TRIGGER_TIME",            /* 3 */
                                              "EOT_META_FILE_INDEX"          /* 4 */
                                             };
 /* clang-format on */
 
+/* This string defines the format of the VFD SWMR log file. 
+ * The current maximum length of entry tag string is set to 26. 
+ * One can enlarge or reduce this number as necessary. 
+ * For example, to enlarge the maximum length of entry tag string to 30,
+ * Just change 26 to 30 in the following line, like 
+ * const char *log_fmt_str="%-30s: %.3lf s: %s\n"; 
+ */
+const char *log_fmt_str="%-26s: %.3lf s: %s\n";
+
 /********************/
 /* Local Prototypes */
 /********************/
@@ -329,14 +350,16 @@ H5F_vfd_swmr_close_or_flush(H5F_t *f, hbool_t closing)
         if (H5F__vfd_swmr_update_end_of_tick_and_tick_num(shared, TRUE) < 0)
             HDONE_ERROR(H5E_FILE, H5E_CANTSET, FAIL, "unable to update end of tick");
     }
-#if 1 /*Kent */
-    H5F_POST_VFD_SWMR_LOG_ENTRY(f, 1, "VFD SWMR File close or flush ends")
+#if 1 /*Kent  Save the end of close or flush info. to the log file, subject to comment out. */
+    H5F_POST_VFD_SWMR_LOG_ENTRY(f, 2, "VFD SWMR File close or flush ends");
 #endif
 done:
 
+    /* Kent: close the VFD SWMR log file if it is turned on */
     if (shared->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, &current_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, &current_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)