Merge pull request #136 from grnydawn/ykim/omega/logging

fixed bugs in Omega logging

Author: philipwjones

components/omega/OmegaBuild.cmake

@@ -27,7 +27,7 @@ set(CASEROOT                      "${OMEGA_BUILD_DIR}/e3smcase")
 macro(common)
 
   option(OMEGA_DEBUG "Turn on error message throwing (default OFF)." OFF)
-  option(OMEGA_LOG_UNBUFFERED "Turn on unbuffered logging (default OFF)." OFF)
+  option(OMEGA_LOG_FLUSH "Turn on unbuffered logging (default OFF)." OFF)
 
   if(NOT DEFINED OMEGA_CXX_FLAGS)
     set(OMEGA_CXX_FLAGS "")
@@ -521,6 +521,7 @@ macro(update_variables)
   endif()
 
   if(OMEGA_DEBUG)
+    set(OMEGA_LOG_FLUSH ON)
     add_definitions(-DOMEGA_DEBUG -DOMEGA_LOG_LEVEL=1)
   else()
     string(TOUPPER "${OMEGA_LOG_LEVEL}" _LOG_LEVEL)
@@ -543,8 +544,8 @@ macro(update_variables)
     endif()
   endif()
 
-  if(OMEGA_LOG_UNBUFFERED)
-    add_definitions(-DOMEGA_LOG_UNBUFFERED)
+  if(OMEGA_LOG_FLUSH)
+    add_definitions(-DOMEGA_LOG_FLUSH)
   endif()
 
   if(OMEGA_LOG_TASKS)

components/omega/doc/devGuide/CMakeBuild.md

@@ -66,7 +66,7 @@ OMEGA_HIP_FLAGS: HIP compiler flags
 OMEGA_MEMORY_LAYOUT: Kokkos memory layout ("LEFT" or "RIGHT"). "RIGHT" is a default value.
 OMEGA_TILE_LENGTH: a length of one "side" of a Kokkos tile. 64 is a default value.
 OMEGA_LOG_LEVEL: a default logging level. "OMEGA_LOG_INFO" is a default value.
-OMEGA_LOG_UNBUFFERED: turn on the unbuffered logging. "OFF" is a default value.
+OMEGA_LOG_FLUSH: turn on the unbuffered logging. "OFF" is a default value.
 OMEGA_LOG_TASKS: set the tasks that generate log file. "0" is a default value.
 ```
 

components/omega/src/infra/LogFormatters.h

@@ -12,47 +12,40 @@
 #include "DataTypes.h"
 #include <spdlog/spdlog.h>
 
-// TODO:
-// 1. Use template to create formatter for various array types
-// 2. Consider using some of the following for formatting
-// View.rank()
-// View.rank_dynamic()
-// View.stride_(0, 1,2,3...)()
-// View.span()
-// View.size()
-// View.span_is_contiguous()
-// View.use_count()
-// View.label()
-// View.is_allocated()
-// ExecSpace.name()
-// ExecSpace.print_configuration(ostr);
-// ExecSpace.print_configuration(ostr, detail);
-// MemSpace.name()
-
-template <>
-struct fmt::formatter<OMEGA::HostArray1DReal> : fmt::formatter<std::string> {
-   auto format(OMEGA::HostArray1DReal my,
-               format_context &ctx) -> decltype(ctx.out()) {
 #ifdef OMEGA_DEBUG
-      return fmt::format_to(
-          ctx.out(), "[data type of '{}' is HostArray1DReal.]", my.label());
+#define GENERATE_FORMATTER(D, T)                                               \
+   template <>                                                                 \
+   struct fmt::formatter<OMEGA::Array##D##T> : fmt::formatter<std::string> {   \
+      auto format(OMEGA::Array##D##T my,                                       \
+                  format_context &ctx) -> decltype(ctx.out()) {                \
+         return fmt::format_to(ctx.out(), "{}({}D:{})", my.label(), my.rank(), \
+                               my.size());                                     \
+      }                                                                        \
+   };
 #else
-      return fmt::format_to(ctx.out(), "[data type of '' is HostArray1DReal.]");
+#define GENERATE_FORMATTER(D, T)                                             \
+   template <>                                                               \
+   struct fmt::formatter<OMEGA::Array##D##T> : fmt::formatter<std::string> { \
+      auto format(OMEGA::Array##D##T my,                                     \
+                  format_context &ctx) -> decltype(ctx.out()) {              \
+         return fmt::format_to(ctx.out(), "{}", my.label());                 \
+      }                                                                      \
+   };
 #endif
-   }
-};
 
-template <>
-struct fmt::formatter<OMEGA::HostArray2DReal> : fmt::formatter<std::string> {
-   auto format(OMEGA::HostArray2DReal my,
-               format_context &ctx) -> decltype(ctx.out()) {
-#ifdef OMEGA_DEBUG
-      return fmt::format_to(
-          ctx.out(), "[data type of '{}' is HostArray2DReal.]", my.label());
-#else
-      return fmt::format_to(ctx.out(), "[data type of '' is HostArray2DReal.]");
-#endif
-   }
-};
+#define GENERATE_FORMATTER_DIM(D) \
+   GENERATE_FORMATTER(D, I4)      \
+   GENERATE_FORMATTER(D, I8)      \
+   GENERATE_FORMATTER(D, R4)      \
+   GENERATE_FORMATTER(D, R8)
+
+GENERATE_FORMATTER_DIM(1D)
+GENERATE_FORMATTER_DIM(2D)
+GENERATE_FORMATTER_DIM(3D)
+GENERATE_FORMATTER_DIM(4D)
+GENERATE_FORMATTER_DIM(5D)
+
+#undef GENERATE_FORMATTER_DIM
+#undef GENERATE_FORMATTER
 
 #endif // OMEGA_LOG_FORMATTERS_H

components/omega/src/infra/Logging.cpp

@@ -6,15 +6,14 @@
 /// This implements Omega logging initialization.
 //
 //===----------------------------------------------------------------------===//
-
-#define _OMEGA_STRINGIFY(x) #x
-#define _OMEGA_TOSTRING(x)  _OMEGA_STRINGIFY(x)
-
 #include "Logging.h"
 #include "MachEnv.h"
 #include <iostream>
 #include <spdlog/sinks/basic_file_sink.h>
 
+#define _OMEGA_STRINGIFY(x) #x
+#define _OMEGA_TOSTRING(x)  _OMEGA_STRINGIFY(x)
+
 namespace OMEGA {
 
 // Function to pack log message
@@ -30,15 +29,17 @@ std::string _PackLogMsg(const char *file, int line, const std::string &msg) {
    return "[" + path + ":" + std::to_string(line) + "] " + msg;
 }
 
-std::vector<int> splitTasks(const std::string &str) {
+std::vector<int> splitTasks(const std::string &str, const OMEGA::I4 NumTasks) {
    std::vector<int> Tasks;
    std::stringstream ss(str);
    std::string Task;
    int Start, Stop;
    char Dash;
 
    if (str == "ALL") {
-      Tasks.push_back(-1);
+      for (int i = 0; i < NumTasks; ++i) {
+         Tasks.push_back(i);
+      }
       return Tasks;
    }
 
@@ -59,25 +60,58 @@ std::vector<int> splitTasks(const std::string &str) {
       }
    }
 
+   if (std::find(Tasks.begin(), Tasks.end(), -1) != Tasks.end()) {
+      Tasks.clear();
+      for (int i = 0; i < NumTasks; ++i) {
+         Tasks.push_back(i);
+      }
+   }
+
    return Tasks;
 }
 
-int initLogging(std::shared_ptr<spdlog::logger> Logger) {
+// return code: 1->enabled, 0->disabled, negative values->errors
+int initLogging(const OMEGA::MachEnv *DefEnv,
+                std::shared_ptr<spdlog::logger> Logger) {
+
+   int RetVal = 0;
 
-   int RetVal = 1;
+   OMEGA::I4 TaskId   = DefEnv->getMyTask();
+   OMEGA::I4 NumTasks = DefEnv->getNumTasks();
 
-   spdlog::set_default_logger(Logger);
+   std::vector<int> Tasks =
+       splitTasks(_OMEGA_TOSTRING(OMEGA_LOG_TASKS), NumTasks);
+
+   if (Tasks.size() > 0 &&
+       (std::find(Tasks.begin(), Tasks.end(), TaskId) != Tasks.end())) {
+
+      spdlog::set_default_logger(Logger);
+
+      spdlog::set_pattern("[%n %l] %v");
+      spdlog::set_level(
+          static_cast<spdlog::level::level_enum>(SPDLOG_ACTIVE_LEVEL));
+      spdlog::flush_on(spdlog::level::warn);
+
+      RetVal = 1; // log enabled
+
+   } else {
+      spdlog::set_level(spdlog::level::off);
+      RetVal = 0; // log disabled
+   }
 
    return RetVal;
 }
 
+// return code: 1->enabled, 0->disabled, negative values->errors
 int initLogging(const OMEGA::MachEnv *DefEnv, std::string const &LogFilePath) {
 
-   int RetVal;
+   int RetVal = 0;
 
-   OMEGA::I4 TaskId = DefEnv->getMyTask();
+   OMEGA::I4 TaskId   = DefEnv->getMyTask();
+   OMEGA::I4 NumTasks = DefEnv->getNumTasks();
 
-   std::vector<int> Tasks = splitTasks(_OMEGA_TOSTRING(OMEGA_LOG_TASKS));
+   std::vector<int> Tasks =
+       splitTasks(_OMEGA_TOSTRING(OMEGA_LOG_TASKS), NumTasks);
 
    if (Tasks.size() > 0 &&
        (std::find(Tasks.begin(), Tasks.end(), TaskId) != Tasks.end())) {
@@ -89,27 +123,28 @@ int initLogging(const OMEGA::MachEnv *DefEnv, std::string const &LogFilePath) {
             auto NewLogFilePath = LogFilePath.substr(0, dotPos) + "_" +
                                   std::to_string(TaskId) +
                                   LogFilePath.substr(dotPos);
-            initLogging(spdlog::basic_logger_mt("*", NewLogFilePath));
-
+            spdlog::set_default_logger(
+                spdlog::basic_logger_mt("*", NewLogFilePath));
          } else {
-            initLogging(spdlog::basic_logger_mt("*", LogFilePath));
+            spdlog::set_default_logger(
+                spdlog::basic_logger_mt("*", LogFilePath));
          }
 
          spdlog::set_pattern("[%n %l] %v");
          spdlog::set_level(
              static_cast<spdlog::level::level_enum>(SPDLOG_ACTIVE_LEVEL));
          spdlog::flush_on(spdlog::level::warn);
 
-         RetVal = 1;
+         RetVal = 1; // log enalbed
 
       } catch (spdlog::spdlog_ex const &Ex) {
          std::cout << "Log init failed: " << Ex.what() << std::endl;
-         RetVal = -1;
+         RetVal = -1; // error occured
       }
 
    } else {
       spdlog::set_level(spdlog::level::off);
-      RetVal = 0;
+      RetVal = 0; // log disabled
    }
 
    return RetVal;

components/omega/src/infra/Logging.h

@@ -17,12 +17,15 @@
 #define SPDLOG_ACTIVE_LEVEL 2
 #endif
 
-#include "LogFormatters.h"
+#include "DataTypes.h"
 #include <spdlog/spdlog.h>
 #include <string>
 
-#if defined(OMEGA_LOG_UNBUFFERED)
-#define _LOG_FLUSH spdlog::logger::flush()
+#include "LogFormatters.h"
+
+#if defined(OMEGA_LOG_FLUSH)
+#define _LOG_FLUSH \
+   spdlog::apply_all([](std::shared_ptr<spdlog::logger> l) { l->flush(); })
 #else
 #define _LOG_FLUSH (void)0
 #endif
@@ -77,10 +80,14 @@ class MachEnv;
 
 const std::string OmegaDefaultLogfile = "omega.log";
 
-int initLogging(std::shared_ptr<spdlog::logger> Logger);
+int initLogging(const OMEGA::MachEnv *DefEnv,
+                std::shared_ptr<spdlog::logger> Logger);
+
 int initLogging(const OMEGA::MachEnv *DefEnv,
                 std::string const &LogFilePath = OmegaDefaultLogfile);
+
 std::string _PackLogMsg(const char *file, int line, const std::string &msg);
+
 } // namespace OMEGA
 
 #endif // OMEGA_LOG_H