Enhancement: APIs for Metadata events.

dftracer/logger.py

@@ -100,6 +100,11 @@ def log_event(self, name, cat, start_time, duration, string_args=None):
                 string_args = {}
             self.logger.log_event(name=name, cat=cat, start_time=start_time, duration=duration, string_args=string_args)
 
+    def log_metadata_event(self, key, value):
+        if DFTRACER_ENABLE and self.logger:
+            logging.debug(f"logger.log_metadata_event {key} {value}")
+            self.logger.log_metadata_event(key=key, value=value)
+
     def finalize(self):
         if DFTRACER_ENABLE and self.logger:
             logging.debug(f"logger.finalize")
@@ -221,6 +226,10 @@ def wrapper(*args, **kwargs):
 
         return wrapper
 
+    def log_metadata(self, key, value):
+        if DFTRACER_ENABLE and self._enable:
+            dftracer.get_instance().log_metadata_event(key=key, value=value)
+
     def iter(self, func, iter_name="step"):
         if DFTRACER_ENABLE and self._enable:
             iter_val = 1

dftracer_dbg/logger.py

@@ -99,6 +99,13 @@ def log_event(self, name, cat, start_time, duration, string_args=None):
             if string_args is None:
                 string_args = {}
             self.logger.log_event(name=name, cat=cat, start_time=start_time, duration=duration, string_args=string_args)
+
+    def log_metadata_event(self, key, value):
+        if DFTRACER_ENABLE and self.logger:
+            logging.debug(f"logger.log_metadata_event {key} {value}")
+            if string_args is None:
+                string_args = {}
+            self.logger.log_metadata_event(key=key, value=value)
 
     def finalize(self):
         if DFTRACER_ENABLE and self.logger:
@@ -171,7 +178,7 @@ def __exit__(self, exc_type, exc_val, exc_tb):
         if DFTRACER_ENABLE and self._enable:
             if not self._flush:
                 self.flush()
-
+    
     def log(self, func):
         if DFTRACER_ENABLE and self._enable:
             arg_names = inspect.getfullargspec(func)[0]
@@ -221,6 +228,10 @@ def wrapper(*args, **kwargs):
 
         return wrapper
 
+    def log_metadata(self, key, value):
+        if DFTRACER_ENABLE and self._enable:
+            dftracer.get_instance().log_metadata_event(key=key, value=value)
+
     def iter(self, func, iter_name="step"):
         if DFTRACER_ENABLE and self._enable:
             iter_val = 1

include/dftracer/dftracer.h

@@ -10,7 +10,8 @@
  */
 #include <dftracer/core/constants.h>
 #include <dftracer/core/typedef.h>
-
+#define DF_DATA_EVENT 0
+#define DF_METADATA_EVENT 1
 #ifdef __cplusplus
 extern "C" {
 #endif
@@ -37,14 +38,16 @@ void finalize();
 __attribute__((unused)) static ConstEventNameType CPP_LOG_CATEGORY = "CPP_APP";
 
 class DFTracer {
+  int event_type;  // 0->event  1->metadata
   bool initialized;
   ConstEventNameType name;
   ConstEventNameType cat;
   TimeResolution start_time;
   std::unordered_map<std::string, std::any> *metadata;
 
  public:
-  DFTracer(ConstEventNameType _name, ConstEventNameType _cat);
+  DFTracer(ConstEventNameType _name, ConstEventNameType _cat,
+           int event_type = DF_DATA_EVENT);
 
   void update(const char *key, int value);
 
@@ -61,13 +64,18 @@ class DFTracer {
   initialize_no_bind(log_file, data_dirs, process_id);
 #define DFTRACER_CPP_FINI() finalize()
 #define DFTRACER_CPP_FUNCTION() \
-  DFTracer profiler_dft_fn = DFTracer((char *)__FUNCTION__, CPP_LOG_CATEGORY);
+  DFTracer profiler_dft_fn =    \
+      DFTracer((char *)__FUNCTION__, CPP_LOG_CATEGORY, DF_DATA_EVENT);
+
+#define DFTRACER_CPP_METADATA(name, key, value) \
+  { DFTracer profiler_##name = DFTracer(key, value, DF_METADATA_EVENT); }
 
 #define DFTRACER_CPP_REGION(name) \
-  DFTracer profiler_##name = DFTracer(#name, CPP_LOG_CATEGORY);
+  DFTracer profiler_##name = DFTracer(#name, CPP_LOG_CATEGORY, DF_DATA_EVENT);
 
 #define DFTRACER_CPP_REGION_START(name) \
-  DFTracer *profiler_##name = new DFTracer(#name, CPP_LOG_CATEGORY);
+  DFTracer *profiler_##name =           \
+      new DFTracer(#name, CPP_LOG_CATEGORY, DF_DATA_EVENT);
 
 #define DFTRACER_CPP_REGION_END(name) delete profiler_##name
 
@@ -89,7 +97,7 @@ struct DFTracerData {
 
 __attribute__((unused)) static ConstEventNameType C_LOG_CATEGORY = "C_APP";
 struct DFTracerData *initialize_region(ConstEventNameType name,
-                                       ConstEventNameType cat);
+                                       ConstEventNameType cat, int event_type);
 void finalize_region(struct DFTracerData *data);
 void update_metadata_int(struct DFTracerData *data, const char *key, int value);
 void update_metadata_string(struct DFTracerData *data, const char *key,
@@ -102,15 +110,24 @@ void update_metadata_string(struct DFTracerData *data, const char *key,
 #define DFTRACER_C_FINI() finalize()
 
 #define DFTRACER_C_FUNCTION_START() \
-  struct DFTracerData *data_fn = initialize_region(__func__, C_LOG_CATEGORY);
+  struct DFTracerData *data_fn =    \
+      initialize_region(__func__, C_LOG_CATEGORY, DF_DATA_EVENT);
 
 #define DFTRACER_C_FUNCTION_END() finalize_region(data_fn);
 
 #define DFTRACER_C_REGION_START(name) \
-  struct DFTracerData *data_##name = initialize_region(#name, C_LOG_CATEGORY);
+  struct DFTracerData *data_##name =  \
+      initialize_region(#name, C_LOG_CATEGORY, DF_DATA_EVENT);
 
 #define DFTRACER_C_REGION_END(name) finalize_region(data_##name);
 
+#define DFTRACER_C_METADATA(name, key, val)             \
+  {                                                     \
+    struct DFTracerData *data_##name =                  \
+        initialize_region(key, val, DF_METADATA_EVENT); \
+    finalize_region(data_##name);                       \
+  }
+
 #define DFTRACER_C_FUNCTION_UPDATE_INT(key, val) \
   update_metadata_int(data_fn, key, val);
 

src/dftracer/core/dftracer_main.cpp

@@ -89,6 +89,16 @@ void dftracer::DFTracerCore::log(
   }
 }
 
+void dftracer::DFTracerCore::log_metadata(ConstEventNameType key, ConstEventNameType value) {
+  DFTRACER_LOG_DEBUG("DFTracerCore::log", "");
+  if (this->is_initialized && conf->enable) {
+    if (logger != nullptr) {
+      logger->log_metadata(key, value);
+    } else {
+      DFTRACER_LOG_ERROR("DFTracerCore::log logger not initialized", "");
+    }
+  }
+}
 bool dftracer::DFTracerCore::finalize() {
   DFTRACER_LOG_DEBUG("DFTracerCore::finalize", "");
   if (this->is_initialized && conf->enable) {

src/dftracer/core/dftracer_main.h

@@ -55,6 +55,8 @@ class DFTracerCore {
   void log(ConstEventNameType event_name, ConstEventNameType category,
            TimeResolution start_time, TimeResolution duration,
            std::unordered_map<std::string, std::any> *metadata);
+
+  void log_metadata(ConstEventNameType key, ConstEventNameType value);
 
   inline void enter_event() { logger->enter_event(); }
 

src/dftracer/core/enumeration.h

@@ -51,4 +51,5 @@ inline void convert(const std::string &s, cpplogger::LoggerType &type) {
 #define METADATA_NAME_FILE_HASH "FH"
 #define METADATA_NAME_HOSTNAME_HASH "HH"
 #define METADATA_NAME_STRING_HASH "SH"
+#define CUSTOM_METADATA "CM"
 #endif  // DFTRACER_ENUMERATION_H

src/dftracer/df_logger.h

@@ -238,23 +238,7 @@ class DFTLogger {
     return t;
   }
 
-  inline void log(ConstEventNameType event_name, ConstEventNameType category,
-                  TimeResolution start_time, TimeResolution duration,
-                  std::unordered_map<std::string, std::any> *metadata) {
-    DFTRACER_LOG_DEBUG("DFTLogger.log", "");
-    ThreadID tid = 0;
-    if (dftracer_tid) {
-      tid = df_gettid();
-    }
-    int local_index;
-    if (!include_metadata) {
-      local_index = index.load();
-    }
-    if (metadata != nullptr) {
-      metadata->insert_or_assign("level", level);
-      int parent_index_value = get_parent();
-      metadata->insert_or_assign("p_idx", parent_index_value);
-    }
+  inline void handle_mpi(ThreadID tid) {
 #ifdef DFTRACER_MPI_ENABLE
     if (!mpi_event) {
       int initialized;
@@ -281,7 +265,26 @@ class DFTLogger {
       }
     }
 #endif
+  }
 
+  inline void log(ConstEventNameType event_name, ConstEventNameType category,
+                  TimeResolution start_time, TimeResolution duration,
+                  std::unordered_map<std::string, std::any> *metadata) {
+    DFTRACER_LOG_DEBUG("DFTLogger.log", "");
+    ThreadID tid = 0;
+    if (dftracer_tid) {
+      tid = df_gettid();
+    }
+    int local_index;
+    if (!include_metadata) {
+      local_index = index.load();
+    }
+    if (metadata != nullptr) {
+      metadata->insert_or_assign("level", level);
+      int parent_index_value = get_parent();
+      metadata->insert_or_assign("p_idx", parent_index_value);
+    }
+    handle_mpi(tid);
     if (this->writer != nullptr) {
       if (include_metadata) {
         int current_index = get_current();
@@ -298,6 +301,26 @@ class DFTLogger {
     }
   }
 
+  inline void log_metadata(ConstEventNameType key, ConstEventNameType value) {
+    DFTRACER_LOG_DEBUG("DFTLogger.log_metadata", "");
+    ThreadID tid = 0;
+    if (dftracer_tid) {
+      tid = df_gettid();
+    }
+    int local_index;
+    if (!include_metadata) {
+      local_index = index.load();
+    }
+    handle_mpi(tid);
+    if (this->writer != nullptr) {
+      this->writer->log_metadata(index_stack[level - 1], key, value,
+                                 CUSTOM_METADATA, this->process_id, tid);
+      has_entry = true;
+    } else {
+      DFTRACER_LOG_ERROR("DFTLogger.log_metadata writer not initialized", "");
+    }
+  }
+
   inline uint16_t hash_and_store(char *filename, ConstEventNameType name) {
     if (filename == NULL) return 0;
     char file[PATH_MAX];

src/dftracer/dftracer.cpp

@@ -6,45 +6,61 @@
 #include <dftracer/core/enumeration.h>
 #include <dftracer/dftracer.h>
 
-DFTracer::DFTracer(ConstEventNameType _name, ConstEventNameType _cat)
-    : initialized(true), name(_name), cat(_cat), metadata(nullptr) {
+DFTracer::DFTracer(ConstEventNameType _name, ConstEventNameType _cat,
+                   int event_type)
+    : initialized(true),
+      name(_name),
+      cat(_cat),
+      metadata(nullptr),
+      event_type(event_type) {
   DFTRACER_LOG_DEBUG("DFTracer::DFTracer event %s cat %s ", _name, _cat);
   auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
                                                ProfileType::PROFILER_CPP_APP);
   if (dftracer_core != nullptr) {
-    if (dftracer_core->include_metadata)
-      metadata = new std::unordered_map<std::string, std::any>();
-    start_time = dftracer_core->get_time();
+    if (event_type == DF_DATA_EVENT) {
+      if (dftracer_core->include_metadata)
+        metadata = new std::unordered_map<std::string, std::any>();
+      start_time = dftracer_core->get_time();
+    }
   }
   dftracer_core->enter_event();
 }
 void DFTracer::update(const char *key, int value) {
   DFTRACER_LOG_DEBUG("DFTracer::update event %s cat %s  key %s value %d ", name,
                      cat, key, value);
-  auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
-                                               ProfileType::PROFILER_CPP_APP);
-  if (dftracer_core != nullptr && dftracer_core->is_active() &&
-      dftracer_core->include_metadata) {
-    metadata->insert_or_assign(key, value);
+  if (event_type == DF_DATA_EVENT) {
+    auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
+                                                 ProfileType::PROFILER_CPP_APP);
+    if (dftracer_core != nullptr && dftracer_core->is_active() &&
+        dftracer_core->include_metadata) {
+      metadata->insert_or_assign(key, value);
+    }
   }
 }
 void DFTracer::update(const char *key, const char *value) {
   DFTRACER_LOG_DEBUG("DFTracer::update event %s cat %s  key %s value %s ", name,
                      cat, key, value);
-  auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
-                                               ProfileType::PROFILER_CPP_APP);
-  if (dftracer_core != nullptr && dftracer_core->is_active() &&
-      dftracer_core->include_metadata) {
-    metadata->insert_or_assign(key, value);
+  if (event_type == DF_DATA_EVENT) {
+    auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
+                                                 ProfileType::PROFILER_CPP_APP);
+    if (dftracer_core != nullptr && dftracer_core->is_active() &&
+        dftracer_core->include_metadata) {
+      metadata->insert_or_assign(key, value);
+    }
   }
 }
 void DFTracer::finalize() {
   DFTRACER_LOG_DEBUG("DFTracer::finalize event %s cat %s", name, cat);
   auto dftracer_core = DFTRACER_MAIN_SINGLETON(ProfilerStage::PROFILER_OTHER,
                                                ProfileType::PROFILER_CPP_APP);
   if (dftracer_core != nullptr && dftracer_core->is_active()) {
-    TimeResolution end_time = dftracer_core->get_time();
-    dftracer_core->log(name, cat, start_time, end_time - start_time, metadata);
+    if (event_type == DF_DATA_EVENT) {
+      TimeResolution end_time = dftracer_core->get_time();
+      dftracer_core->log(name, cat, start_time, end_time - start_time,
+                         metadata);
+    } else if (event_type == DF_METADATA_EVENT) {
+      dftracer_core->log_metadata(name, cat);
+    }
 
     dftracer_core->exit_event();
     if (dftracer_core->include_metadata) delete (metadata);
@@ -73,10 +89,10 @@ void initialize_no_bind(const char *log_file, const char *data_dirs,
 }
 
 struct DFTracerData *initialize_region(ConstEventNameType name,
-                                       ConstEventNameType cat) {
+                                       ConstEventNameType cat, int event_type) {
   DFTRACER_LOG_DEBUG("dftracer.initialize_region event %s cat %s", name, cat);
   auto data = new DFTracerData();
-  data->profiler = new DFTracer(name, C_LOG_CATEGORY);
+  data->profiler = new DFTracer(name, cat, event_type);
   return data;
 }
 void finalize_region(struct DFTracerData *data) {

src/dftracer/pydftracer.cpp

@@ -31,5 +31,7 @@ PYBIND11_MODULE(pydftracer, m) {
         py::arg("int_args") = std::unordered_map<std::string, int>(),
         py::arg("string_args") = std::unordered_map<std::string, std::string>(),
         py::arg("float_args") = std::unordered_map<std::string, float>());
+  m.def("log_metadata_event", &dftracer::log_metadata_event,
+        "log metadata event", py::arg("key"), py::arg("value"));
   m.def("finalize", &dftracer::finalize, "finalize dftracer");
 }

src/dftracer/pydftracer.cpp.in

@@ -41,6 +41,17 @@ void log_event(std::string name, std::string cat, TimeResolution start_time,
     DFTRACER_LOG_DEBUG("py.log_event dftracer not initialized", "");
 }
 
+void log_metadata_event(std::string key, std::string value) {
+  DFTRACER_LOG_DEBUG("py.log_metadata_event", "");
+  auto dftracer_inst =
+      dftracer::Singleton<dftracer::DFTracerCore>::get_instance(
+          ProfilerStage::PROFILER_OTHER, ProfileType::PROFILER_PY_APP);
+  if (dftracer_inst != nullptr)
+    dftracer_inst->log_metadata(key.c_str(), value.c_str());
+  else
+    DFTRACER_LOG_DEBUG("py.log_metadata_event dftracer not initialized", "");
+}
+
 void enter_event() {
   DFTRACER_LOG_DEBUG("py.enter_event", "");
   auto dftracer_inst =

src/dftracer/pydftracer_dbg.cpp

@@ -31,5 +31,7 @@ PYBIND11_MODULE(pydftracer_dbg, m) {
         py::arg("int_args") = std::unordered_map<std::string, int>(),
         py::arg("string_args") = std::unordered_map<std::string, std::string>(),
         py::arg("float_args") = std::unordered_map<std::string, float>());
+  m.def("log_metadata_event", &dftracer::log_metadata_event,
+        "log metadata event", py::arg("key"), py::arg("value"));
   m.def("finalize", &dftracer::finalize, "finalize dftracer");
 }

test/c/test.c

@@ -35,6 +35,7 @@ int main(int argc, char *argv[]) {
       init = 1;
     }
   }
+  DFTRACER_C_METADATA(meta, "key", "value");
   char filename[1024];
   sprintf(filename, "%s/demofile_c.txt", argv[1]);
   foo();

test/cpp/test.cpp

@@ -39,6 +39,7 @@ int main(int argc, char *argv[]) {
       init = 1;
     }
   }
+  DFTRACER_CPP_METADATA(meta, "key", "value");
   char filename[1024];
   sprintf(filename, "%s/demofile.txt", argv[1]);
   char filename_link[1024];