feat: IO timers

src/coreComponents/fileIO/Outputs/BlueprintOutput.cpp

@@ -129,53 +129,57 @@
 }
 
 ///////////////////////////////////////////////////////////////////////////////////////////////////
-bool BlueprintOutput::execute( real64 const time,
-                               real64 const,
-                               integer const cycle,
-                               integer const,
-                               real64 const,
+bool BlueprintOutput::execute( real64 const time_n,
+                               real64 const GEOS_UNUSED_PARAM( dt ),
+                               integer const cycleNumber,
+                               integer const GEOS_UNUSED_PARAM( eventCounter ),
+                               real64 const GEOS_UNUSED_PARAM( eventProgress ),
                                DomainPartition & domain )
 {
   GEOS_MARK_FUNCTION;
 
-  MeshLevel const & meshLevel = domain.getMeshBody( 0 ).getBaseDiscretization();
+  {
+    Timer timer( m_outputTimer );
 
-  conduit::Node meshRoot;
-  conduit::Node & mesh = meshRoot[ "mesh" ];
-  conduit::Node & coordset = mesh[ "coordsets/nodes" ];
-  conduit::Node & topologies = mesh[ "topologies" ];
+    MeshLevel const & meshLevel = domain.getMeshBody( 0 ).getBaseDiscretization();
 
-  mesh[ "state/time" ] = time;
-  mesh[ "state/cycle" ] = cycle;
+    conduit::Node meshRoot;
+    conduit::Node & mesh = meshRoot[ "mesh" ];
+    conduit::Node & coordset = mesh[ "coordsets/nodes" ];
+    conduit::Node & topologies = mesh[ "topologies" ];
 
-  addNodalData( meshLevel.getNodeManager(), coordset, topologies, mesh[ "fields" ] );
+    mesh[ "state/time" ] = time_n;
+    mesh[ "state/cycle" ] = cycleNumber;
 
-  dataRepository::Group averagedElementData( "averagedElementData", this );
-  addElementData( meshLevel.getElemManager(), coordset, topologies, mesh[ "fields" ], averagedElementData );
+    addNodalData( meshLevel.getNodeManager(), coordset, topologies, mesh[ "fields" ] );
 
-  /// The Blueprint will complain if the fields node is present but empty.
-  if( mesh[ "fields" ].number_of_children() == 0 )
-  {
-    mesh.remove( "fields" );
-  }
+    dataRepository::Group averagedElementData( "averagedElementData", this );
+    addElementData( meshLevel.getElemManager(), coordset, topologies, mesh[ "fields" ], averagedElementData );
+
+    /// The Blueprint will complain if the fields node is present but empty.
+    if( mesh[ "fields" ].number_of_children() == 0 )
+    {
+      mesh.remove( "fields" );
+    }
 
-  /// Verify that the mesh conforms to the Blueprint.
-  conduit::Node info;
-  GEOS_ASSERT_MSG( conduit::blueprint::verify( "mesh", meshRoot, info ), info.to_json() );
+    /// Verify that the mesh conforms to the Blueprint.
+    conduit::Node info;
+    GEOS_ASSERT_MSG( conduit::blueprint::verify( "mesh", meshRoot, info ), info.to_json() );
 
-  /// Generate the Blueprint index.
-  conduit::Node fileRoot;
-  conduit::Node & index = fileRoot[ "blueprint_index/mesh" ];
-  conduit::blueprint::mesh::generate_index( mesh, "mesh", MpiWrapper::commSize(), index );
+    /// Generate the Blueprint index.
+    conduit::Node fileRoot;
+    conduit::Node & index = fileRoot[ "blueprint_index/mesh" ];
+    conduit::blueprint::mesh::generate_index( mesh, "mesh", MpiWrapper::commSize(), index );
 
-  /// Verify that the index conforms to the Blueprint.
-  info.reset();
-  GEOS_ASSERT_MSG( conduit::blueprint::mesh::index::verify( index, info ), info.to_json() );
+    /// Verify that the index conforms to the Blueprint.
+    info.reset();
+    GEOS_ASSERT_MSG( conduit::blueprint::mesh::index::verify( index, info ), info.to_json() );
 
-  /// Write out the root index file, then write out the mesh.
-  string const completePath = GEOS_FMT( "{}/blueprintFiles/cycle_{:07}", OutputBase::getOutputDirectory(), cycle );
-  string const filePathForRank = dataRepository::writeRootFile( fileRoot, completePath );
-  conduit::relay::io::save( meshRoot, filePathForRank, "hdf5" );
+    /// Write out the root index file, then write out the mesh.
+    string const completePath = GEOS_FMT( "{}/blueprintFiles/cycle_{:07}", OutputBase::getOutputDirectory(), cycleNumber );
+    string const filePathForRank = dataRepository::writeRootFile( fileRoot, completePath );
+    conduit::relay::io::save( meshRoot, filePathForRank, "hdf5" );
+  }
 
   return false;
 }
@@ -307,7 +311,19 @@
   } );
 }
 
+namespace logInfo
+{
+struct BlueprintOutputTimer : public OutputTimerBase
+{
+  std::string_view getDescription() const override { return "Blueprint output timing"; }
+};
+}
 
+logInfo::OutputTimerBase const & BlueprintOutput::getTimerCategory() const
+{
+  static logInfo::BlueprintOutputTimer timer;
+  return timer;
+}
 
 REGISTER_CATALOG_ENTRY( OutputBase, BlueprintOutput, string const &, dataRepository::Group * const )
 

src/coreComponents/fileIO/Outputs/BlueprintOutput.hpp

@@ -36,6 +36,12 @@ class ElementRegionManager;
  */
 class BlueprintOutput : public OutputBase
 {
+protected:
+  /**
+   * @copydoc OutputBase::getTimerCategory
+   */
+  logInfo::OutputTimerBase const & getTimerCategory() const override;
+
 public:
 
   /**

src/coreComponents/fileIO/Outputs/ChomboIO.cpp

@@ -30,6 +30,20 @@
 
 using namespace dataRepository;
 
+namespace logInfo
+{
+struct ChomboOutputTimer : public OutputTimerBase
+{
+  std::string_view getDescription() const override { return "Chombo output timing"; }
+};
+}
+
+logInfo::OutputTimerBase const & ChomboIO::getTimerCategory() const
+{
+  static logInfo::ChomboOutputTimer timer;
+  return timer;
+}
+
 ChomboIO::ChomboIO( string const & name, Group * const parent ):
   OutputBase( name, parent ),
   m_coupler( nullptr ),

src/coreComponents/fileIO/Outputs/ChomboIO.hpp

@@ -89,6 +89,12 @@ class ChomboIO final : public OutputBase
   } viewKeys;
   /// @endcond
 
+protected:
+  /**
+   * @copydoc OutputBase::getTimerCategory
+   */
+  logInfo::OutputTimerBase const & getTimerCategory() const override;
+
 private:
   ChomboCoupler * m_coupler;
   string m_outputPath;

src/coreComponents/fileIO/Outputs/OutputBase.cpp

@@ -29,6 +29,7 @@
 OutputBase::OutputBase( string const & name,
                         Group * const parent ):
   ExecutableGroup( name, parent ),
+  m_outputTimer(),
   m_childDirectory(),
   m_parallelThreads( 1 )
 {
@@ -43,6 +44,8 @@
     setInputFlag( InputFlags::OPTIONAL ).
     setDescription( "Number of plot files." );
 
+  // Add the Timers log level
+  addLogLevel< logInfo::OutputTimers >();
 }
 
 OutputBase::~OutputBase()
@@ -106,5 +109,23 @@
   }
 }
 
+void OutputBase::cleanup( real64 const GEOS_UNUSED_PARAM( time_n ),
+                          integer const GEOS_UNUSED_PARAM( cycleNumber ),
+                          integer const GEOS_UNUSED_PARAM( eventCounter ),
+                          real64 const GEOS_UNUSED_PARAM( eventProgress ),
+                          DomainPartition & GEOS_UNUSED_PARAM( domain ) )
+{
+  // Report timing statistics
+  real64 const time = std::chrono::duration< double >( m_outputTimer ).count();
+  real64 const minTime = MpiWrapper::min( time );
+  real64 const maxTime = MpiWrapper::max( time );
+  if( maxTime > 0 )
+  {
+    GEOS_LOG_LEVEL_INFO_RANK_0( logInfo::OutputTimers,
+                                GEOS_FMT( "{}: file writing time = {} s (min), {} s (max)",
+                                          getName(), minTime, maxTime ) );
+  }
+}
+
 
 } /* namespace geos */

src/coreComponents/fileIO/Outputs/OutputBase.hpp

@@ -21,11 +21,50 @@
 
 #include "dataRepository/Group.hpp"
 #include "dataRepository/ExecutableGroup.hpp"
-
+#include "dataRepository/LogLevelsInfo.hpp"  // For logInfo namespace
+#include "common/Timer.hpp"
 
 namespace geos
 {
 
+namespace logInfo
+{
+/**
+ * @brief Base timer category for output operations
+ * @details Provides configuration for logging output operation timing information
+ */
+struct OutputTimers
+{
+  /**
+   * @brief Get the description of this timer
+   * @return String view containing the timer description
+   */
+  static std::string_view getDescription() { return "Output timing information"; }
+
+  /**
+   * @brief Get the minimum log level for this timer
+   * @return Integer representing the minimum log level
+   */
+  static constexpr int getMinLogLevel() { return 1; }
+};
+
+/**
+ * @brief Base interface for specific output type timers
+ * @details Each output type (VTK, Silo, etc.) implements this interface to provide
+ *          its own timing category. This is used in conjunction with OutputTimers:
+ *          - OutputTimerBase: For polymorphic behavior in derived output classes
+ *          - OutputTimers: For the general output timing logging infrastructure
+ */
+struct OutputTimerBase
+{
+  /**
+   * @brief Get the description of this timer
+   * @return String view containing the timer description
+   */
+  virtual std::string_view getDescription() const = 0;
+};
+}
+
 /**
  * @class OutputBase
  *
@@ -102,6 +141,22 @@ class OutputBase : public ExecutableGroup
    **/
   virtual void initializePreSubGroups() override;
 
+  /// Timer used to track duration of file writing operations for this specific output type
+  std::chrono::system_clock::duration m_outputTimer;
+
+  /**
+   * @brief Get the timer category for this output type
+   * @return Reference to the output timer base for timing statistics
+   */
+  virtual logInfo::OutputTimerBase const & getTimerCategory() const = 0;
+
+  /// @copydoc geos::ExecutableGroup::cleanup
+  virtual void cleanup( real64 const time_n,
+                        integer const cycleNumber,
+                        integer const eventCounter,
+                        real64 const eventProgress,
+                        DomainPartition & domain ) override;
+
 private:
   string m_childDirectory;
   integer m_parallelThreads;

src/coreComponents/fileIO/Outputs/PythonOutput.cpp

@@ -18,6 +18,20 @@
 namespace geos
 {
 
+namespace logInfo
+{
+struct PythonOutputTimer : public OutputTimerBase
+{
+  std::string_view getDescription() const override { return "Python output timing"; }
+};
+}
+
+logInfo::OutputTimerBase const & PythonOutput::getTimerCategory() const
+{
+  static logInfo::PythonOutputTimer timer;
+  return timer;
+}
+
 REGISTER_CATALOG_ENTRY( OutputBase, PythonOutput, string const &, dataRepository::Group * const )
 
 } // namespace geos

src/coreComponents/fileIO/Outputs/PythonOutput.hpp

@@ -75,6 +75,9 @@ class PythonOutput : public OutputBase
     GEOS_UNUSED_VAR( domain );
     return true;
   }
+
+protected:
+  logInfo::OutputTimerBase const & getTimerCategory() const override;
 };
 
 

src/coreComponents/fileIO/Outputs/RestartOutput.cpp

@@ -24,6 +24,14 @@
 
 using namespace dataRepository;
 
+namespace logInfo
+{
+struct RestartOutputTimer : public OutputTimerBase
+{
+  std::string_view getDescription() const override { return "Restart output timing"; }
+};
+}
+
 RestartOutput::RestartOutput( string const & name,
                               Group * const parent ):
   OutputBase( name, parent )
@@ -41,19 +49,24 @@
 {
   GEOS_MARK_FUNCTION;
 
-  Group & rootGroup = this->getGroupByPath( "/Problem" );
+  {
+    Timer timer( m_outputTimer );
 
-  // Ignoring the eventProgress indicator for now to be compliant with the integrated test repo
-  // integer const eventProgressPercent = static_cast<integer const>(eventProgress * 100.0);
-  string const fileName = GEOS_FMT( "{}_restart_{:09}", getFileNameRoot(), cycleNumber );
-
-  rootGroup.prepareToWrite();
-  writeTree( joinPath( OutputBase::getOutputDirectory(), fileName ), *(rootGroup.getConduitNode().parent()) );
-  rootGroup.finishWriting();
+    Group & rootGroup = this->getGroupByPath( "/Problem" );
+    string const fileName = GEOS_FMT( "{}_restart_{:09}", getFileNameRoot(), cycleNumber );
+    rootGroup.prepareToWrite();
+    writeTree( joinPath( OutputBase::getOutputDirectory(), fileName ), *(rootGroup.getConduitNode().parent()) );
+    rootGroup.finishWriting();
+  }
 
   return false;
 }
 
+logInfo::OutputTimerBase const & RestartOutput::getTimerCategory() const
+{
+  static logInfo::RestartOutputTimer timer;
+  return timer;
+}
 
 REGISTER_CATALOG_ENTRY( OutputBase, RestartOutput, string const &, Group * const )
 } /* namespace geos */

src/coreComponents/fileIO/Outputs/RestartOutput.hpp

@@ -78,6 +78,12 @@ class RestartOutput : public OutputBase
     dataRepository::ViewKey writeFEMFaces = { "writeFEMFaces" };
   } viewKeys;
   /// @endcond
+
+protected:
+  /**
+   * @copydoc OutputBase::getTimerCategory
+   */
+  logInfo::OutputTimerBase const & getTimerCategory() const override;
 };