Merge branch 'feature/exec-stats' into 'develop'

Print execution statistics at the end of execution

See merge request !175

cmake/PugsDoc.cmake

@@ -97,7 +97,19 @@ if (EMACS AND GNUPLOT_FOUND AND GMSH)
       COMMENT "Building user documentation in doc/userdoc.pdf"
       VERBATIM)
 
-    add_custom_target(userdoc-pdf DEPENDS pugsdoc-dir "${PUGS_BINARY_DIR}/doc/userdoc.pdf" )
+    configure_file("${PUGS_SOURCE_DIR}/doc/build-userdoc-pdf.sh.in"
+      "${PUGS_BINARY_DIR}/doc/build-userdoc-pdf.sh"
+      FILE_PERMISSIONS OWNER_READ OWNER_WRITE OWNER_EXECUTE
+      @ONLY)
+
+    set_source_files_properties(
+      ${PUGS_BINARY_DIR}/build-pdf.sh2
+      PROPERTIES
+      GENERATED TRUE
+      HEADER_FILE_ONLY TRUE
+    )
+
+    add_custom_target(userdoc-pdf DEPENDS pugsdoc-dir "${PUGS_BINARY_DIR}/doc/userdoc.pdf" "${PUGS_BINARY_DIR}/doc/build-userdoc-pdf.sh")
 
     add_dependencies(userdoc userdoc-pdf)
 

doc/build-userdoc-pdf.sh.in

+#! /usr/bin/env bash
+
+@PDFLATEX_COMPILER@ -shell-escape -interaction nonstopmode userdoc
+@PDFLATEX_COMPILER@ -shell-escape -interaction nonstopmode userdoc
+@PDFLATEX_COMPILER@ -shell-escape -interaction nonstopmode userdoc

doc/lisp/build-doc-config.el

@@ -64,9 +64,7 @@
 (setq org-latex-listings 'minted
       org-latex-packages-alist '(("" "minted"))
       org-latex-pdf-process
-      '("cd ${PUGS_BINARY_DIR}/doc; pdflatex -shell-escape -interaction nonstopmode -output-directory %o %f"
-        "cd ${PUGS_BINARY_DIR}/doc; pdflatex -shell-escape -interaction nonstopmode -output-directory %o %f"
-        "cd ${PUGS_BINARY_DIR}/doc; pdflatex -shell-escape -interaction nonstopmode -output-directory %o %f"))
+      '("cd ${PUGS_BINARY_DIR}/doc; ./build-userdoc-pdf.sh"))
 
 (setq python-indent-guess-indent-offset-verbose nil)
 

doc/lisp/share/ob-pugs-error.el

@@ -131,7 +131,7 @@
     (with-temp-file in-file
       (insert body))
     (org-babel-eval
-		(format "${PUGS} --no-preamble --no-color %s 2>&1 | sed 's@/.*\.pgs:@test.pgs:@'"
+		(format "${PUGS} --no-exec-stat --no-preamble --no-color --threads=1 %s 2>&1 | sed 's@/.*\.pgs:@test.pgs:@'"
 			(org-babel-process-file-name in-file))
 		"")))
 

doc/lisp/share/ob-pugs.el

@@ -130,7 +130,7 @@
     (with-temp-file in-file
       (insert body))
     (org-babel-eval
-		(format "${PUGS} --no-preamble --no-color %s"
+		(format "${PUGS} --no-exec-stat --no-preamble --no-color --threads=1 %s"
 			(org-babel-process-file-name in-file))
 		"")))
 

doc/userdoc.org

@@ -391,8 +391,8 @@ answer a specific need. It must not be done /because it is possible to
 do it/!
 
 #+begin_verse
-When designing a language, the difficulty is not to offer new functionalities,\\
-it is generally to decide not to offer them.\\
+When designing a language, the difficulty is not to offer new functionalities,
+it is generally to decide not to offer them.
 --- Bjarne Stroustrup, C++ conference 2021.
 #+end_verse
 
@@ -1406,7 +1406,7 @@ they follow a few rules.
       \right.
     \end{equation*}
   #+end_src
-\\
+
   This is also the case for ~string~ values: only allowed operators are
   ~==~ and ~!=~.
   #+begin_src latex :results drawer :exports results
@@ -3136,7 +3136,6 @@ available in parallel
 
 ***** Item types
 
-\\
 The following functions are used to designate a specific ~item_type~
 - ~cell: void -> item_type~
 - ~face: void -> item_type~

src/main.cpp

@@ -4,12 +4,15 @@
 #include <mesh/DualMeshManager.hpp>
 #include <mesh/MeshDataManager.hpp>
 #include <mesh/SynchronizerManager.hpp>
+#include <utils/ExecutionStatManager.hpp>
 #include <utils/PugsUtils.hpp>
 #include <utils/RandomEngine.hpp>
 
 int
 main(int argc, char* argv[])
 {
+  ExecutionStatManager::create();
+
   std::string filename = initialize(argc, argv);
 
   SynchronizerManager::create();
@@ -20,15 +23,18 @@ main(int argc, char* argv[])
   DualMeshManager::create();
 
   parser(filename);
+  ExecutionStatManager::printInfo();
 
   DualMeshManager::destroy();
   DualConnectivityManager::destroy();
   MeshDataManager::destroy();
-  RandomEngine::destroy();
   QuadratureManager::destroy();
+  RandomEngine::destroy();
   SynchronizerManager::destroy();
 
   finalize();
 
+  ExecutionStatManager::destroy();
+
   return 0;
 }

src/utils/CMakeLists.txt

@@ -8,6 +8,7 @@ add_library(
   ConsoleManager.cpp
   Demangle.cpp
   Exceptions.cpp
+  ExecutionStatManager.cpp
   FPEManager.cpp
   Messenger.cpp
   Partitioner.cpp

src/utils/ExecutionStatManager.cpp

+#include <utils/ExecutionStatManager.hpp>
+
+#include <utils/Exceptions.hpp>
+#include <utils/Messenger.hpp>
+
+#include <cmath>
+#include <iomanip>
+#include <rang.hpp>
+#include <sys/resource.h>
+
+ExecutionStatManager* ExecutionStatManager::m_instance = nullptr;
+
+void
+ExecutionStatManager::_printMaxResidentMemory() const
+{
+  class Memory
+  {
+   private:
+    double m_value;
+
+   public:
+    PUGS_INLINE const double&
+    value() const
+    {
+      return m_value;
+    }
+
+    std::string
+    prettyPrint() const
+    {
+      const std::vector<std::string> units = {"B", "KB", "MB", "GB", "TB", "PB", "EB"};
+
+      double local_memory = m_value;
+      size_t i_unit       = 0;
+      while ((local_memory >= 1024) and (i_unit < units.size())) {
+        ++i_unit;
+        local_memory /= 1024;
+      }
+      std::ostringstream os;
+      os << local_memory << units[i_unit];
+      return os.str();
+    }
+
+    Memory()
+    {
+      rusage u;
+      getrusage(RUSAGE_SELF, &u);
+      m_value = u.ru_maxrss * 1024;
+    }
+
+    Memory(double value) : m_value{value} {}
+  };
+
+  Memory memory;
+  std::cout << "Memory: " << rang::style::bold << Memory{parallel::allReduceSum(memory.value())}.prettyPrint()
+            << rang::style::reset;
+  if (parallel::size() > 1) {
+    std::cout << " (over " << parallel::size() << " processes)";
+    std::cout << " Avg: " << rang::style::bold
+              << Memory{parallel::allReduceSum(memory.value()) / parallel::size()}.prettyPrint() << rang::style::reset;
+    std::cout << " Min: " << rang::style::bold << Memory{parallel::allReduceMin(memory.value())}.prettyPrint()
+              << rang::style::reset;
+    std::cout << " Max: " << rang::style::bold << Memory{parallel::allReduceMax(memory.value())}.prettyPrint()
+              << rang::style::reset;
+  }
+  std::cout << '\n';
+}
+
+void
+ExecutionStatManager::_printElapseTime() const
+{
+  std::cout << "Execution: " << rang::style::bold << m_instance->m_elapse_time.seconds() << 's' << rang::style::reset
+            << '\n';
+}
+
+void
+ExecutionStatManager::_printTotalCPUTime() const
+{
+  rusage u;
+  getrusage(RUSAGE_SELF, &u);
+
+  const double total_cpu_time =
+    u.ru_utime.tv_sec + u.ru_stime.tv_sec + (u.ru_utime.tv_usec + u.ru_stime.tv_usec) * 1E-6;
+
+  std::cout << "Total CPU: " << rang::style::bold << parallel::allReduceSum(total_cpu_time) << 's'
+            << rang::style::reset;
+  std::cout << " (" << parallel::allReduceSum(Kokkos::DefaultHostExecutionSpace::concurrency()) << " threads over "
+            << parallel::size() << " processes)";
+  if (total_cpu_time > 60) {
+    size_t seconds    = std::floor(total_cpu_time);
+    const size_t days = seconds / (24 * 3600);
+    seconds -= days * (24 * 3600);
+    const size_t hours = seconds / 3600;
+    seconds -= hours * 3600;
+    const size_t minutes = seconds / 60;
+    seconds -= minutes * 60;
+    std::cout << " " << rang::style::bold;
+    bool print = false;
+    if (days > 0) {
+      print = true;
+      std::cout << days << "d" << ' ';
+    }
+    if (print or (hours > 0)) {
+      print = true;
+      std::cout << std::setw(2) << std::setfill('0') << hours << "h";
+    }
+    if (print or (minutes > 0)) {
+      print = true;
+      std::cout << std::setw(2) << std::setfill('0') << minutes << "mn";
+    }
+    if (print) {
+      std::cout << rang::style::bold << std::setw(2) << std::setfill('0') << seconds << "s";
+    }
+    std::cout << rang::style::reset;
+  }
+  std::cout << '\n';
+}
+
+void
+ExecutionStatManager::printInfo()
+{
+  if (ExecutionStatManager::getInstance().doPrint()) {
+    std::cout << "----------------- " << rang::fg::green << "pugs exec stats" << rang::fg::reset
+              << " ---------------------\n";
+
+    ExecutionStatManager::getInstance()._printElapseTime();
+    ExecutionStatManager::getInstance()._printTotalCPUTime();
+    ExecutionStatManager::getInstance()._printMaxResidentMemory();
+  }
+}
+
+void
+ExecutionStatManager::create()
+{
+  if (ExecutionStatManager::m_instance == nullptr) {
+    ExecutionStatManager::m_instance = new ExecutionStatManager;
+  } else {
+    throw UnexpectedError("ExecutionStatManager already created");
+  }
+}
+
+void
+ExecutionStatManager::destroy()
+{
+  // One allows multiple destruction to handle unexpected code exit
+  if (ExecutionStatManager::m_instance != nullptr) {
+    delete ExecutionStatManager::m_instance;
+    ExecutionStatManager::m_instance = nullptr;
+  }
+}

src/utils/ExecutionStatManager.hpp

+#ifndef EXECUTION_STAT_MANAGER_HPP
+#define EXECUTION_STAT_MANAGER_HPP
+
+#include <utils/PugsAssert.hpp>
+#include <utils/Timer.hpp>
+
+class ExecutionStatManager
+{
+ private:
+  static ExecutionStatManager* m_instance;
+
+  Timer m_elapse_time;
+  bool m_do_print = true;
+
+  void _printMaxResidentMemory() const;
+  void _printElapseTime() const;
+  void _printTotalCPUTime() const;
+
+  explicit ExecutionStatManager()                   = default;
+  ExecutionStatManager(ExecutionStatManager&&)      = delete;
+  ExecutionStatManager(const ExecutionStatManager&) = delete;
+  ~ExecutionStatManager()                           = default;
+
+ public:
+  PUGS_INLINE
+  bool
+  doPrint() const
+  {
+    return m_do_print;
+  }
+
+  PUGS_INLINE
+  void
+  setPrint(bool do_print)
+  {
+    m_do_print = do_print;
+  }
+
+  PUGS_INLINE
+  static ExecutionStatManager&
+  getInstance()
+  {
+    Assert(m_instance != nullptr);   // LCOV_EXCL_LINE
+    return *m_instance;
+  }
+
+  static void printInfo();
+  static void create();
+  static void destroy();
+};
+
+#endif   // EXECUTION_STAT_MANAGER_HPP

src/utils/PugsUtils.cpp

@@ -4,6 +4,7 @@
 #include <utils/BuildInfo.hpp>
 #include <utils/CommunicatorManager.hpp>
 #include <utils/ConsoleManager.hpp>
+#include <utils/ExecutionStatManager.hpp>
 #include <utils/FPEManager.hpp>
 #include <utils/Messenger.hpp>
 #include <utils/PETScWrapper.hpp>
@@ -110,6 +111,10 @@ initialize(int& argc, char* argv[])
     bool show_preamble = true;
     app.add_flag("--preamble,!--no-preamble", show_preamble, "Show execution info preamble [default: true]");
 
+    bool print_exec_stat = true;
+    app.add_flag("--exec-stat,!--no-exec-stat", print_exec_stat,
+                 "Display memory and CPU usage after execution [default: true]");
+
     bool show_backtrace = true;
     app.add_flag("-b,--backtrace,!--no-backtrace", show_backtrace, "Show backtrace on failure [default: true]");
 
@@ -141,6 +146,7 @@ initialize(int& argc, char* argv[])
       CommunicatorManager::setSplitColor(mpi_split_color);
     }
 
+    ExecutionStatManager::getInstance().setPrint(print_exec_stat);
     BacktraceManager::setShow(show_backtrace);
     ConsoleManager::setShowPreamble(show_preamble);
     ConsoleManager::init(enable_color);