Merge pull request #3124 from pnorbert/profiling_pretty_print

Added adios2_json_pp pretty print python script ...

source/adios2/engine/bp5/BP5Writer.cpp

@@ -77,6 +77,7 @@ StepStatus BP5Writer::BeginStep(StepMode mode, const float timeoutSeconds)
         TimePoint wait_start = Now();
         if (m_WriteFuture.valid())
         {
+            m_Profiler.Start("WaitOnAsync");
             m_WriteFuture.get();
             m_Comm.Barrier();
             AsyncWriteDataCleanup();
@@ -85,12 +86,17 @@ StepStatus BP5Writer::BeginStep(StepMode mode, const float timeoutSeconds)
             {
                 WriteMetadataFileIndex(m_LatestMetaDataPos,
                                        m_LatestMetaDataSize);
-                std::cout << "BeginStep, wait on async write was = "
-                          << wait.count() << " time since EndStep was = "
-                          << m_LastTimeBetweenSteps.count()
-                          << " expect next one to be = "
-                          << m_ExpectedTimeBetweenSteps.count() << std::endl;
+                if (m_Parameters.verbose > 0)
+                {
+                    std::cout << "BeginStep, wait on async write was = "
+                              << wait.count() << " time since EndStep was = "
+                              << m_LastTimeBetweenSteps.count()
+                              << " expect next one to be = "
+                              << m_ExpectedTimeBetweenSteps.count()
+                              << std::endl;
+                }
             }
+            m_Profiler.Stop("WaitOnAsync");
         }
     }
 
@@ -1452,11 +1458,13 @@ void BP5Writer::DoClose(const int transportIndex)
     Seconds wait(0.0);
     if (m_WriteFuture.valid())
     {
+        m_Profiler.Start("WaitOnAsync");
         m_AsyncWriteLock.lock();
         m_flagRush = true;
         m_AsyncWriteLock.unlock();
         m_WriteFuture.get();
         wait += Now() - wait_start;
+        m_Profiler.Stop("WaitOnAsync");
     }
 
     m_FileDataManager.CloseFiles(transportIndex);
@@ -1474,15 +1482,17 @@ void BP5Writer::DoClose(const int transportIndex)
     if (m_Parameters.AsyncWrite)
     {
         // wait until all process' writing thread completes
+        m_Profiler.Start("WaitOnAsync");
         wait_start = Now();
         m_Comm.Barrier();
         AsyncWriteDataCleanup();
         wait += Now() - wait_start;
-        if (m_Comm.Rank() == 0)
+        if (m_Comm.Rank() == 0 && m_Parameters.verbose > 0)
         {
             std::cout << "Close waited " << wait.count()
                       << " seconds on async threads" << std::endl;
         }
+        m_Profiler.Stop("WaitOnAsync");
     }
 
     if (m_Comm.Rank() == 0)

source/adios2/toolkit/format/bp/BPSerializer.cpp

@@ -47,12 +47,12 @@ std::string BPSerializer::GetRankProfilingJSON(
 {
     auto lf_WriterTimer = [](std::string &rankLog,
                              const profiling::Timer &timer) {
-        rankLog += "\"" + timer.m_Process + "_" + timer.GetShortUnits() +
-                   "\": " + std::to_string(timer.m_ProcessTime) + ", ";
+        rankLog += ", \"" + timer.m_Process + "_" + timer.GetShortUnits() +
+                   "\": " + std::to_string(timer.m_ProcessTime);
     };
 
     // prepare string dictionary per rank
-    std::string rankLog("{ \"rank\": " + std::to_string(m_RankMPI) + ", ");
+    std::string rankLog("{ \"rank\": " + std::to_string(m_RankMPI));
 
     auto &profiler = m_Profiler;
 
@@ -61,42 +61,30 @@ std::string BPSerializer::GetRankProfilingJSON(
     // avoid whitespace
     std::replace(timeDate.begin(), timeDate.end(), ' ', '_');
 
-    rankLog += "\"start\": \"" + timeDate + "\", ";
-    rankLog += "\"threads\": " + std::to_string(m_Parameters.Threads) + ", ";
+    rankLog += ", \"start\": \"" + timeDate + "\"";
+    rankLog += ", \"threads\": " + std::to_string(m_Parameters.Threads);
     rankLog +=
-        "\"bytes\": " + std::to_string(profiler.m_Bytes.at("buffering")) + ", ";
+        ", \"bytes\": " + std::to_string(profiler.m_Bytes.at("buffering"));
 
     for (const auto &timerPair : profiler.m_Timers)
     {
         const profiling::Timer &timer = timerPair.second;
-        rankLog += "\"" + timer.m_Process + "_" + timer.GetShortUnits() +
-                   "\": " + std::to_string(timer.m_ProcessTime) + ", ";
+        rankLog += ", \"" + timer.m_Process + "_" + timer.GetShortUnits() +
+                   "\": " + std::to_string(timer.m_ProcessTime);
     }
 
     const size_t transportsSize = transportsTypes.size();
 
     for (unsigned int t = 0; t < transportsSize; ++t)
     {
-        rankLog += "\"transport_" + std::to_string(t) + "\": { ";
-        rankLog += "\"type\": \"" + transportsTypes[t] + "\", ";
+        rankLog += ", \"transport_" + std::to_string(t) + "\": { ";
+        rankLog += "\"type\": \"" + transportsTypes[t] + "\"";
 
         for (const auto &transportTimerPair : transportsProfilers[t]->m_Timers)
         {
             lf_WriterTimer(rankLog, transportTimerPair.second);
         }
-        // replace last comma with space
-        rankLog.pop_back();
-        rankLog.pop_back();
-        rankLog += " ";
-
-        if (t == transportsSize - 1) // last element
-        {
-            rankLog += "}";
-        }
-        else
-        {
-            rankLog += "},";
-        }
+        rankLog += "}";
     }
     rankLog += " }"; // end rank entry
 

source/adios2/toolkit/profiling/iochrono/IOChrono.cpp

@@ -40,16 +40,11 @@ JSONProfiler::JSONProfiler(helper::Comm const &comm) : m_Comm(comm)
     m_Profiler.m_IsActive = true; // default is true
 
     AddTimerWatch("buffering");
-    // xAddTimerWatch("memcpy");
     AddTimerWatch("endstep");
     AddTimerWatch("PP");
-    // AddTimerWatch("meta_merge");
     AddTimerWatch("meta_gather");
-    // AddTimerWatch("meta_ds");
-    // AddTimerWatch("meta_s");
-    // AddTimerWatch("meta_sort_merge");
-
     AddTimerWatch("AWD");
+    AddTimerWatch("WaitOnAsync");
 
     m_Profiler.m_Bytes.emplace("buffering", 0);
 
@@ -74,7 +69,7 @@ std::string JSONProfiler::GetRankProfilingJSON(
     };
 
     // prepare string dictionary per rank
-    std::string rankLog("{ \"rank\": " + std::to_string(m_RankMPI) + ", ");
+    std::string rankLog("{ \"rank\":" + std::to_string(m_RankMPI));
 
     auto &profiler = m_Profiler;
 
@@ -83,10 +78,10 @@ std::string JSONProfiler::GetRankProfilingJSON(
     // avoid whitespace
     std::replace(timeDate.begin(), timeDate.end(), ' ', '_');
 
-    rankLog += "\"start\": \"" + timeDate + "\", ";
-    // rankLog += "\"threads\": " + std::to_string(m_Parameters.Threads) + ", ";
+    rankLog += ", \"start\":\"" + timeDate + "\"";
+    // rankLog += ", \"threads\":" + std::to_string(m_Parameters.Threads);
     rankLog +=
-        "\"bytes\": " + std::to_string(profiler.m_Bytes.at("buffering")) + ", ";
+        ", \"bytes\":" + std::to_string(profiler.m_Bytes.at("buffering"));
 
     for (const auto &timerPair : profiler.m_Timers)
     {
@@ -100,26 +95,14 @@ std::string JSONProfiler::GetRankProfilingJSON(
 
     for (unsigned int t = 0; t < transportsSize; ++t)
     {
-        rankLog += "\"transport_" + std::to_string(t) + "\": { ";
-        rankLog += "\"type\": \"" + transportsTypes[t] + "\", ";
+        rankLog += ", \"transport_" + std::to_string(t) + "\":{";
+        rankLog += "\"type\":\"" + transportsTypes[t] + "\"";
 
         for (const auto &transportTimerPair : transportsProfilers[t]->m_Timers)
         {
             lf_WriterTimer(rankLog, transportTimerPair.second);
         }
-        // replace last comma with space
-        rankLog.pop_back();
-        rankLog.pop_back();
-        rankLog += " ";
-
-        if (t == transportsSize - 1) // last element
-        {
-            rankLog += "}";
-        }
-        else
-        {
-            rankLog += "},";
-        }
+        rankLog += "}";
     }
     rankLog += " }"; // end rank entry
 

source/adios2/toolkit/profiling/iochrono/Timer.h

@@ -90,13 +90,17 @@ class Timer
         }
     }
 
-    void AddToJsonStr(std::string &rankLog) const
+    void AddToJsonStr(std::string &rankLog, const bool addComma = true) const
     {
         if (0 == m_nCalls)
             return;
 
+        if (addComma)
+        {
+            rankLog += ", ";
+        }
         rankLog +=
-            "\"" + m_Process + "\":{ \"mus\":" + std::to_string(m_ProcessTime);
+            "\"" + m_Process + "\":{\"mus\":" + std::to_string(m_ProcessTime);
         rankLog += ", \"nCalls\":" + std::to_string(m_nCalls);
 
         if (500 > m_nCalls)
@@ -106,7 +110,7 @@ class Timer
                 rankLog += ", \"trace\":[" + m_Details + "]";
             }
         }
-        rankLog += "}, ";
+        rankLog += "}";
     }
 
     std::string m_Details;

source/utils/CMakeLists.txt

@@ -72,6 +72,10 @@ endif()
 if(Python_Interpreter_FOUND)
   add_subdirectory(bp4dbg)
   add_subdirectory(bp5dbg)
+  install(PROGRAMS adios2_json_pp.py
+    RENAME adios2_json_pp
+    DESTINATION ${CMAKE_INSTALL_BINDIR}
+    COMPONENT adios2_scripts-runtime)
 endif()
 
 install(PROGRAMS adios2_deactivate_bp

source/utils/adios2_json_pp.py

@@ -0,0 +1,32 @@
+#!/usr/bin/env python3
+import json
+import argparse
+from os.path import exists
+
+
+def SetupArgs():
+    parser = argparse.ArgumentParser()
+    parser.add_argument("--indent", "-i", type=int, default=2,
+                        help="indent size, default=2")
+    parser.add_argument("FILE", help="Name of the JSON file")
+    args = parser.parse_args()
+
+    # print(args)
+    return args
+
+
+def CheckFileName(args):
+    if not exists(args.FILE):
+        print("ERROR: File " + args.FILE + " does not exist", flush=True)
+        exit(1)
+
+
+if __name__ == "__main__":
+
+    args = SetupArgs()
+    CheckFileName(args)
+
+    with open(args.FILE) as jsonfile:
+        parsed = json.load(jsonfile)
+
+    print(json.dumps(parsed, indent=args.indent, sort_keys=False))