Changeset 2704

Timestamp:

01/17/25 15:18:37 (3 weeks ago)

Author:

hshepherd

Message:

Port across changes from the patching - Not yet tested

Location:

XIOS2/dev/hshepherd/reduce_output_log/src

Files:

• client.cpp (modified) (11 diffs)
• client.hpp (modified) (1 diff)
• cxios.cpp (modified) (2 diffs)
• cxios.hpp (modified) (1 diff)
• server.cpp (modified) (11 diffs)
• server.hpp (modified) (1 diff)

XIOS2/dev/hshepherd/reduce_output_log/src/client.cpp

@@ -13 +13 @@
 #include "buffer_client.hpp"
 #include "string_tools.hpp"
+#include "timestats.hpp"
 
 namespace xios
@@ -261 +262 @@
     }
 
+        std::vector<double> CClient::collate_timings(std::string timing_param)
+    {
+      int myrank, comm_size;
+      MPI_Comm_rank(intraComm, &myrank);
+      MPI_Comm_size(intraComm, &comm_size);
+
+      std::vector<double> collated_results;
+      MPI_Barrier(intraComm);
+      if (myrank == 0) {
+        double recv_val = 0.;
+        collated_results.push_back(CTimer::get(timing_param).getCumulatedTime());
+        for (int i = 1; i < comm_size; i++) {
+          MPI_Recv(&recv_val, 1, MPI_DOUBLE, i, 0, intraComm, MPI_STATUS_IGNORE);
+          collated_results.push_back(recv_val);
+        }
+      } else {
+        double snd_val = CTimer::get(timing_param).getCumulatedTime();
+        MPI_Send(&snd_val, 1, MPI_DOUBLE, 0, 0, intraComm);
+      }
+      MPI_Barrier(intraComm);
+      return collated_results;
+    }
+
+    void CClient::present_collated_timings(void)
+    {
+      std::vector<double> blocking_times = collate_timings("Blocking time");
+      // we need to suspend the XIOS init/finalize timer briefly to gather the measurements
+      CTimer::get("XIOS init/finalize").suspend();
+      std::vector<double> init_final_times = collate_timings("XIOS init/finalize");
+      CTimer::get("XIOS init/finalize").resume();
+      std::vector<double> ratio = percentage_ratio_vec_double(blocking_times, init_final_times);
+      if (rank_ == 0) {
+        int n_ranks;
+        MPI_Comm_size(intraComm, &n_ranks);
+        
+        report(0) << " Performance metrics across all client ranks" << endl;
+        report(0) << "     Collating from " << n_ranks << " ranks" << endl;
+        write_summary_timings(blocking_times, "Time spent waiting for free buffer");
+        write_summary_timings(ratio, "Waiting ratio (percentage)");
+      }
+    }
+
+    void CClient::write_summary_timings(std::vector<double>& collated_results,
+                                        std::string results_label)
+    {
+      report(0) << "  " << results_label << " average " << calc_mean_double(collated_results) << endl;
+      report(0) << "  " << results_label << " std dev " << calc_std_double(collated_results) << endl;
+      report(0) << "  " << results_label << " min " << calc_min_double(collated_results) << endl;
+      report(0) << "  " << results_label << " max " << calc_max_double(collated_results) << endl;
+    }
 
     void CClient::finalize(void)
@@ -266 +317 @@
       int rank ;
       int msg=0 ;
+
+      // Do our collated summary
+      present_collated_timings();
+      MPI_Barrier(intraComm);
 
       MPI_Comm_rank(intraComm,&rank) ;
@@ -294 +349 @@
       
       info(20) << "Client side context is finalized"<<endl ;
+
+      if (CXios::reduceLogFiles) report(0) << "Performance summary from the first rank in this intraComm." << endl;
+
       report(0) <<" Performance report : Whole time from XIOS init and finalize: "<< CTimer::get("XIOS init/finalize").getCumulatedTime()<<" s"<<endl ;
       report(0) <<" Performance report : total time spent for XIOS : "<< CTimer::get("XIOS").getCumulatedTime()<<" s"<<endl ;
@@ -354 +412 @@
 
     /*!
+    * \brief Check to see if we are on a rank for which we an output file
+    * If reduced output is selected we only write from a single client
+    * rank
+    */
+    bool CClient::writeLogFromRank()
+    {
+      bool do_write = false;
+      if (!CXios::reduceLogFiles)
+      {
+        return true;
+      }
+      if (rank_ == 0)
+      {
+        do_write = true;
+      }
+      return do_write;
+    }
+
+    /*!
     * \brief Open a file stream to write the info logs
     * Open a file stream with a specific file name suffix+rank
@@ -359 +436 @@
     * \param fileName [in] protype file name
     */
-    void CClient::openInfoStream(const StdString& fileName)
-    {
-      std::filebuf* fb = m_infoStream.rdbuf();
-      openStream(fileName, ".out", fb);
-
-      info.write2File(fb);
-      report.write2File(fb);
+        void CClient::openInfoStream(const StdString& fileName)
+    {
+      if (writeLogFromRank())
+      {
+        std::filebuf* fb = m_infoStream.rdbuf();
+        openStream(fileName, ".out", fb);
+
+        info.write2File(fb);
+        report.write2File(fb);
+      }
     }
 
@@ -371 +451 @@
     void CClient::openInfoStream()
     {
-      info.write2StdOut();
-      report.write2StdOut();
+      if (writeLogFromRank())
+      {
+        info.write2StdOut();
+        report.write2StdOut();
+      }
     }
 
@@ -378 +461 @@
     void CClient::closeInfoStream()
     {
-      if (m_infoStream.is_open()) m_infoStream.close();
-    }
+      if (writeLogFromRank())
+      {
+        if (m_infoStream.is_open()) m_infoStream.close();
+      }
+    }
+
 
     /*!
@@ -389 +476 @@
     void CClient::openErrorStream(const StdString& fileName)
     {
-      std::filebuf* fb = m_errorStream.rdbuf();
-      openStream(fileName, ".err", fb);
-
-      error.write2File(fb);
+      if (writeLogFromRank())
+      {
+        std::filebuf* fb = m_errorStream.rdbuf();
+        openStream(fileName, ".err", fb);
+
+        error.write2File(fb);
+      }
     }
 
@@ -398 +488 @@
     void CClient::openErrorStream()
     {
-      error.write2StdErr();
+      if (writeLogFromRank())
+      {
+        error.write2StdErr();
+      }
     }
 
@@ -404 +497 @@
     void CClient::closeErrorStream()
     {
-      if (m_errorStream.is_open()) m_errorStream.close();
+      if (writeLogFromRank())
+      {
+        if (m_errorStream.is_open()) m_errorStream.close();
+      }
     }
 }

XIOS2/dev/hshepherd/reduce_output_log/src/client.hpp

@@ -46 +46 @@
 
         static void openStream(const StdString& fileName, const StdString& ext, std::filebuf* fb);
+
+      private:
+        static bool writeLogFromRank();
+        static std::vector<double> collate_timings(std::string);
+        static void present_collated_timings();
+        static void write_summary_timings(std::vector<double>&, std::string);
     };
 }

XIOS2/dev/hshepherd/reduce_output_log/src/cxios.cpp

@@ -41 +41 @@
   StdSize CXios::maxBufferSize = std::numeric_limits<int>::max() ;
   bool CXios::printLogs2Files;
+  bool CXios::reduceLogFiles;
   bool CXios::isOptPerformance = true;
   CRegistry* CXios::globalRegistry = 0;
@@ -82 +83 @@
     report.setLevel(getin<int>("info_level",50));
     printLogs2Files=getin<bool>("print_file",false);
-
+    reduceLogFiles=getin<bool>("reduce_logging",false);
     xiosStack=getin<bool>("xios_stack",true) ;
     systemStack=getin<bool>("system_stack",false) ;

XIOS2/dev/hshepherd/reduce_output_log/src/cxios.hpp

@@ -43 +43 @@
 
      static bool printLogs2Files; //!< Printing out logs into files
+     static bool reduceLogFiles;  //!<Reduce the log files to lead client, lead server and lead level2 server
      static bool usingOasis ;     //!< Using Oasis
      static bool usingServer ;    //!< Using server (server mode)

XIOS2/dev/hshepherd/reduce_output_log/src/server.cpp

@@ -14 +14 @@
 #include "timer.hpp"
 #include "mem_checker.hpp"
+#include "timestats.hpp"
 #include "event_scheduler.hpp"
 #include "string_tools.hpp"
@@ -34 +35 @@
     bool CServer::finished=false ;
     bool CServer::is_MPI_Initialized ;
+    bool CServer::writeLogFromRank;
     CEventScheduler* CServer::eventScheduler = 0;
 
@@ -397 +399 @@
       if (rank==0) isRoot=true;
       else isRoot=false;
+
+      writeLogFromRank = determineWriteLogFromRank();
       
       eventScheduler = new CEventScheduler(intraComm) ;
     }
 
+    std::vector<double> CServer::collate_timings(std::string timing_param)
+    {
+      int myrank, comm_size;
+      MPI_Comm_rank(intraComm, &myrank);
+      MPI_Comm_size(intraComm, &comm_size);
+
+      std::vector<double> collated_results;
+      MPI_Barrier(intraComm);
+      if (myrank == 0) {
+        double recv_val = 0.;
+        collated_results.push_back(CTimer::get(timing_param).getCumulatedTime());
+        for (int i = 1; i < comm_size; i++) {
+          MPI_Recv(&recv_val, 1, MPI_DOUBLE, i, 0, intraComm, MPI_STATUS_IGNORE);
+          collated_results.push_back(recv_val);
+        }
+      } else {
+        double snd_val = CTimer::get(timing_param).getCumulatedTime();
+        MPI_Send(&snd_val, 1, MPI_DOUBLE, 0, 0, intraComm);
+      }
+      MPI_Barrier(intraComm);
+      return collated_results;
+    }
+
+    void CServer::present_collated_timings(void)
+    {
+      std::vector<double> processing_times = collate_timings("Process events");
+      std::vector<double> xios_server_times = collate_timings("XIOS server");
+      std::vector<double> ratio = percentage_ratio_vec_double(processing_times, xios_server_times);
+      // writeLogFromRank gives the lead rank for L1 servers and server pools
+      if (getRank() == 0) {
+        int n_ranks;
+        MPI_Comm_size(intraComm, &n_ranks);
+        report(0) << " Performance metrics across the intraComm communicator for this rank." << endl;
+        report(0) << "     There are " << n_ranks << " ranks in this intraComm" << endl;
+        write_summary_timings(processing_times, "Processing events");
+        write_summary_timings(ratio, "Ratio (Percentage)");
+      }
+    }
+      
+
+    void CServer::write_summary_timings(std::vector<double>& collated_results,
+                                        std::string results_label)
+    {
+      report(0) << "  " << results_label << " average " << calc_mean_double(collated_results) << endl;
+      report(0) << "  " << results_label << " std dev " << calc_std_double(collated_results) << endl;
+      report(0) << "  " << results_label << " min " << calc_min_double(collated_results) << endl;
+      report(0) << "  " << results_label << " max " << calc_max_double(collated_results) << endl;
+    }
+  
+
     void CServer::finalize(void)
     {
+      present_collated_timings();
+      MPI_Barrier(intraComm);
+
       CTimer::get("XIOS").suspend() ;
      
@@ -430 +487 @@
         else MPI_Finalize() ;
       }
+
+      if (CXios::reduceLogFiles) report(0) << "Performance summary from the first rank in this intraComm." << endl;
+
       report(0)<<"Performance report : Time spent for XIOS : "<<CTimer::get("XIOS server").getCumulatedTime()<<endl  ;
       report(0)<<"Performance report : Time spent in processing events : "<<CTimer::get("Process events").getCumulatedTime()<<endl  ;
@@ -907 +967 @@
     }
 
+    bool CServer::determineWriteLogFromRank()
+    {
+      // Write from rank zero of each intracomm, which will be the rank of
+      // the lead level one and two servers
+      if (!CXios::reduceLogFiles) return true;
+      if (getRank() == 0) return true;
+      return false;
+    }
+
     /*!
     * \brief Open a file stream to write the info logs
@@ -915 +984 @@
     void CServer::openInfoStream(const StdString& fileName)
     {
-      std::filebuf* fb = m_infoStream.rdbuf();
-      openStream(fileName, ".out", fb);
-
-      info.write2File(fb);
-      report.write2File(fb);
+      if (writeLogFromRank)
+      {
+        std::filebuf* fb = m_infoStream.rdbuf();
+        openStream(fileName, ".out", fb);
+
+        info.write2File(fb);
+        report.write2File(fb);
+      }
     }
 
@@ -925 +997 @@
     void CServer::openInfoStream()
     {
-      info.write2StdOut();
-      report.write2StdOut();
+      if (writeLogFromRank)
+      {
+        info.write2StdOut();
+        report.write2StdOut();
+      }
     }
 
@@ -932 +1007 @@
     void CServer::closeInfoStream()
     {
-      if (m_infoStream.is_open()) m_infoStream.close();
+      if (writeLogFromRank)
+      {
+        if (m_infoStream.is_open()) m_infoStream.close();
+      }
     }
 
@@ -943 +1021 @@
     void CServer::openErrorStream(const StdString& fileName)
     {
-      std::filebuf* fb = m_errorStream.rdbuf();
-      openStream(fileName, ".err", fb);
-
-      error.write2File(fb);
+      if (writeLogFromRank)
+      {
+        std::filebuf* fb = m_errorStream.rdbuf();
+        openStream(fileName, ".err", fb);
+
+        error.write2File(fb);
+      }
     }
 
@@ -952 +1033 @@
     void CServer::openErrorStream()
     {
-      error.write2StdErr();
+      if (writeLogFromRank)
+      {
+        error.write2StdErr();
+      }
     }
 
@@ -958 +1042 @@
     void CServer::closeErrorStream()
     {
-      if (m_errorStream.is_open()) m_errorStream.close();
+      if (writeLogFromRank)
+      {
+        if (m_errorStream.is_open()) m_errorStream.close();
+      }
     }
 }

XIOS2/dev/hshepherd/reduce_output_log/src/server.hpp

@@ -74 +74 @@
         static StdOFStream m_infoStream;
         static StdOFStream m_errorStream;
+        static bool writeLogFromRank;
         static void openStream(const StdString& fileName, const StdString& ext, std::filebuf* fb);
+        static std::vector<double> collate_timings(std::string);
+        static void present_collated_timings();
+        static void write_summary_timings(std::vector<double>&, std::string);
+        static bool determineWriteLogFromRank();
     };
 }