Can now register live print names and skip printing sections without …

…it refs idaholab#15444

framework/include/actions/SetupMeshAction.h

@@ -35,4 +35,9 @@ class SetupMeshAction : public MooseObjectAction
    * @return The new type of object that will be built.
    */
   std::string modifyParamsForUseSplit(InputParameters & moose_object_params) const;
+
+  /// Timers
+  PerfID _setup_mesh_timer;
+  PerfID _set_mesh_base_timer;
+  PerfID _init_mesh_timer;
 };

framework/include/interfaces/PerfGraphInterface.h

@@ -60,6 +60,17 @@ class PerfGraphInterface
    */
   PerfID registerTimedSection(const std::string & section_name, const unsigned int level);
 
+  /**
+   * Call to register a named section for timing.
+   *
+   * @param section_name The name of the code section to be timed
+   * @param level The importance of the timer - lower is more important (0 will always come out)
+   * @param live_message The message to be printed to the screen during execution
+   * @param print_dots Whether or not progress dots should be printed for this section
+   * @return The ID of the section - use when starting timing
+   */
+  PerfID registerTimedSection(const std::string & section_name, const unsigned int level, const std::string & live_message, const bool print_dots = true);
+
   /// Params
   const InputParameters * _pg_params;
 

framework/include/utils/PerfGraph.h

@@ -71,10 +71,25 @@ class PerfGraph : protected ConsoleStreamInterface
   /**
    * Registers a named section of code
    *
+   * Note: this will automatically set the section_name to what will print out
+   * during a live print.  It will only be printed out if live printing is forced.
+   * It will also dissallow the printing of progress dots.
+   *
    * @return The unique ID to use for that section
    */
   PerfID registerSection(const std::string & section_name, unsigned int level);
 
+  /**
+   * Registers a named section of code
+   *
+   * @param section_name The name of the section as it will be printed in the PerfGraph
+   * @param level The verbosity level
+   * @param live_message The message to be printed to the screen during execution
+   * @param print_dots Whether or not progress dots should be printed for this section
+   * @return The unique ID to use for that section
+   */
+  PerfID registerSection(const std::string & section_name, unsigned int level, const std::string & live_message, const bool print_dots);
+
   /**
    * Print the tree out
    *
@@ -210,6 +225,18 @@ class PerfGraph : protected ConsoleStreamInterface
 
   typedef VariadicTable<std::string, unsigned long int, Real, Real, Real, long int> HeaviestTable;
 
+  /**
+   * Used to hold metadata about the registered sections
+   */
+  struct SectionInfo
+  {
+    PerfID _id;
+    std::string _name;
+    unsigned int _level;
+    std::string _live_message;
+    bool _print_dots;
+  };
+
   /**
    * Use to hold the time for each section
    *
@@ -352,11 +379,8 @@ class PerfGraph : protected ConsoleStreamInterface
   /// Map of section names to IDs
   std::map<std::string, PerfID> _section_name_to_id;
 
-  /// Map of IDs to section names
-  std::map<PerfID, std::string> _id_to_section_name;
-
-  /// Map of IDs to level
-  std::map<PerfID, unsigned int> _id_to_level;
+  /// Map of IDs to section information
+  std::map<PerfID, SectionInfo> _id_to_section_info;
 
   /// The time for each section.  This is updated on updateTiming()
   /// Note that this is _total_ cumulative time across every place

framework/src/actions/SetupMeshAction.C

@@ -97,7 +97,12 @@ SetupMeshAction::validParams()
   return params;
 }
 
-SetupMeshAction::SetupMeshAction(InputParameters params) : MooseObjectAction(params) {}
+SetupMeshAction::SetupMeshAction(InputParameters params) : MooseObjectAction(params),
+                                                           _setup_mesh_timer(registerTimedSection("SetupMeshAction::act::setup_mesh", 1, "Setting Up Mesh", true)),
+                                                           _set_mesh_base_timer(registerTimedSection("SetupMeshAction::act::set_mesh_base", 1, "Setting Mesh", true)),
+                                                           _init_mesh_timer(registerTimedSection("SetupMeshAction::act::set_mesh_base", 1, "Initializing Mesh", true))
+
+                    {}
 
 void
 SetupMeshAction::setupMesh(MooseMesh * mesh)
@@ -226,6 +231,8 @@ SetupMeshAction::act()
   // Create the mesh object and tell it to build itself
   if (_current_task == "setup_mesh")
   {
+    TIME_SECTION(_setup_mesh_timer);
+
     if (_app.masterMesh())
       _mesh = _app.masterMesh()->safeClone();
     else
@@ -277,6 +284,8 @@ SetupMeshAction::act()
 
   else if (_current_task == "set_mesh_base")
   {
+    TIME_SECTION(_set_mesh_base_timer);
+
     if (!_app.masterMesh() && !_mesh->hasMeshBase())
     {
       // We want to set the MeshBase object to that coming from mesh generators when the following
@@ -294,6 +303,8 @@ SetupMeshAction::act()
 
   else if (_current_task == "init_mesh")
   {
+    TIME_SECTION(_init_mesh_timer);
+
     if (_app.masterMesh())
     {
       if (_app.masterDisplacedMesh())

framework/src/interfaces/PerfGraphInterface.C

@@ -55,3 +55,12 @@ PerfGraphInterface::registerTimedSection(const std::string & section_name, const
   else
     return _perf_graph.registerSection(section_name, level);
 }
+
+PerfID
+PerfGraphInterface::registerTimedSection(const std::string & section_name, const unsigned int level, const std::string & live_message, const bool print_dots)
+{
+  if (_prefix != "")
+    return _perf_graph.registerSection(_prefix + "::" + section_name, level, live_message, print_dots);
+  else
+    return _perf_graph.registerSection(section_name, level, live_message, print_dots);
+}

framework/src/mesh/MooseMesh.C

@@ -226,17 +226,17 @@ MooseMesh::MooseMesh(const InputParameters & parameters)
     _regular_orthogonal_mesh(false),
     _allow_recovery(true),
     _construct_node_list_from_side_list(getParam<bool>("construct_node_list_from_side_list")),
-    _prepare_timer(registerTimedSection("prepare", 2)),
-    _update_timer(registerTimedSection("update", 3)),
-    _mesh_changed_timer(registerTimedSection("meshChanged", 3)),
-    _cache_changed_lists_timer(registerTimedSection("cacheChangedLists", 5)),
+    _prepare_timer(registerTimedSection("prepare", 2, "Preparing Mesh", true)),
+    _update_timer(registerTimedSection("update", 3, "Updating Mesh", true)),
+    _mesh_changed_timer(registerTimedSection("meshChanged", 3, "Updating Because Mesh Changed", true)),
+    _cache_changed_lists_timer(registerTimedSection("cacheChangedLists", 5, "Caching Changed Lists", true)),
     _update_active_semi_local_node_range_timer(
-        registerTimedSection("updateActiveSemiLocalNodeRange", 5)),
-    _build_node_list_timer(registerTimedSection("buildNodeList", 5)),
-    _build_bnd_elem_list_timer(registerTimedSection("buildBndElemList", 5)),
-    _node_to_elem_map_timer(registerTimedSection("nodeToElemMap", 5)),
+      registerTimedSection("updateActiveSemiLocalNodeRange", 5, "Updating ActiveSemiLocalNode Range", true)),
+    _build_node_list_timer(registerTimedSection("buildNodeList", 5, "Building Node List", true)),
+    _build_bnd_elem_list_timer(registerTimedSection("buildBndElemList", 5, "Building Boundary Elements List", true)),
+    _node_to_elem_map_timer(registerTimedSection("nodeToElemMap", 5, "Building Node To Elem Map", true)),
     _node_to_active_semilocal_elem_map_timer(
-        registerTimedSection("nodeToActiveSemilocalElemMap", 5)),
+      registerTimedSection("nodeToActiveSemilocalElemMap", 5, "Building SemiLocalElemMap", true)),
     _get_active_local_element_range_timer(registerTimedSection("getActiveLocalElementRange", 5)),
     _get_active_node_range_timer(registerTimedSection("getActiveNodeRange", 5)),
     _get_local_node_range_timer(registerTimedSection("getLocalNodeRange", 5)),
@@ -406,15 +406,11 @@ MooseMesh::prepare(bool force)
     // setting
     if (force || _needs_prepare_for_use)
     {
-      CONSOLE_TIMED_PRINT("Preparing for use");
-
       getMesh().prepare_for_use(false, false);
     }
   }
   else
   {
-    CONSOLE_TIMED_PRINT("Preparing for use");
-
     // Call prepare_for_use() and DO NOT allow renumbering
     getMesh().allow_renumbering(false);
     if (force || _needs_prepare_for_use)
@@ -695,7 +691,6 @@ void
 MooseMesh::buildNodeList()
 {
   TIME_SECTION(_build_node_list_timer);
-  CONSOLE_TIMED_PRINT("Building node lists");
 
   freeBndNodes();
 
@@ -730,7 +725,6 @@ void
 MooseMesh::buildBndElemList()
 {
   TIME_SECTION(_build_bnd_elem_list_timer);
-  CONSOLE_TIMED_PRINT("Building element lists");
 
   freeBndElems();
 
@@ -760,7 +754,6 @@ MooseMesh::nodeToElemMap()
     if (!_node_to_elem_map_built)
     {
       TIME_SECTION(_node_to_elem_map_timer);
-      CONSOLE_TIMED_PRINT("Building node to element map");
 
       for (const auto & elem : getMesh().active_element_ptr_range())
         for (unsigned int n = 0; n < elem->n_nodes(); n++)
@@ -781,7 +774,6 @@ MooseMesh::nodeToActiveSemilocalElemMap()
     Threads::spin_mutex::scoped_lock lock(Threads::spin_mtx);
 
     TIME_SECTION(_node_to_active_semilocal_elem_map_timer);
-    CONSOLE_TIMED_PRINT("Building active semilocal element map");
 
     if (!_node_to_active_semilocal_elem_map_built)
     {
@@ -805,7 +797,6 @@ MooseMesh::getActiveLocalElementRange()
   if (!_active_local_elem_range)
   {
     TIME_SECTION(_get_active_local_element_range_timer);
-    CONSOLE_TIMED_PRINT("Caching active local element range");
 
     _active_local_elem_range = libmesh_make_unique<ConstElemRange>(
         getMesh().active_local_elements_begin(), getMesh().active_local_elements_end(), GRAIN_SIZE);
@@ -820,7 +811,6 @@ MooseMesh::getActiveNodeRange()
   if (!_active_node_range)
   {
     TIME_SECTION(_get_active_node_range_timer);
-    CONSOLE_TIMED_PRINT("Caching active node range");
 
     _active_node_range = libmesh_make_unique<NodeRange>(
         getMesh().active_nodes_begin(), getMesh().active_nodes_end(), GRAIN_SIZE);
@@ -844,7 +834,6 @@ MooseMesh::getLocalNodeRange()
   if (!_local_node_range)
   {
     TIME_SECTION(_get_local_node_range_timer);
-    CONSOLE_TIMED_PRINT("Caching local node range");
 
     _local_node_range = libmesh_make_unique<ConstNodeRange>(
         getMesh().local_nodes_begin(), getMesh().local_nodes_end(), GRAIN_SIZE);
@@ -859,7 +848,6 @@ MooseMesh::getBoundaryNodeRange()
   if (!_bnd_node_range)
   {
     TIME_SECTION(_get_boundary_node_range_timer);
-    CONSOLE_TIMED_PRINT("Caching boundary node range");
 
     _bnd_node_range =
         libmesh_make_unique<ConstBndNodeRange>(bndNodesBegin(), bndNodesEnd(), GRAIN_SIZE);
@@ -874,7 +862,6 @@ MooseMesh::getBoundaryElementRange()
   if (!_bnd_elem_range)
   {
     TIME_SECTION(_get_boundary_element_range_timer);
-    CONSOLE_TIMED_PRINT("Caching boundary element range");
 
     _bnd_elem_range =
         libmesh_make_unique<ConstBndElemRange>(bndElemsBegin(), bndElemsEnd(), GRAIN_SIZE);
@@ -893,7 +880,6 @@ void
 MooseMesh::cacheInfo()
 {
   TIME_SECTION(_cache_info_timer);
-  CONSOLE_TIMED_PRINT("Caching mesh information");
 
   _subdomain_boundary_ids.clear();
   _neighbor_subdomain_boundary_ids.clear();
@@ -2186,7 +2172,6 @@ MooseMesh::init()
     // sub-apps need to just build their mesh like normal
     {
       TIME_SECTION(_read_recovered_mesh_timer);
-      CONSOLE_TIMED_PRINT("Rcovering mesh");
       getMesh().read(_app.getRestartRecoverFileBase() + "_mesh." +
                      _app.getRestartRecoverFileSuffix());
     }
@@ -2196,7 +2181,6 @@ MooseMesh::init()
   }
   else // Normally just build the mesh
   {
-    CONSOLE_TIMED_PRINT("Building mesh");
     buildMesh();
   }
 }

framework/src/problems/FEProblemBase.C

@@ -286,26 +286,26 @@ FEProblemBase::FEProblemBase(const InputParameters & parameters)
     _fail_next_linear_convergence_check(false),
     _started_initial_setup(false),
     _has_internal_edge_residual_objects(false),
-    _initial_setup_timer(registerTimedSection("initialSetup", 2)),
-    _project_solution_timer(registerTimedSection("projectSolution", 2)),
-    _compute_indicators_timer(registerTimedSection("computeIndicators", 1)),
-    _compute_markers_timer(registerTimedSection("computeMarkers", 1)),
-    _compute_user_objects_timer(registerTimedSection("computeUserObjects", 1)),
-    _execute_controls_timer(registerTimedSection("executeControls", 1)),
-    _execute_samplers_timer(registerTimedSection("executeSamplers", 1)),
-    _update_active_objects_timer(registerTimedSection("updateActiveObjects", 5)),
+    _initial_setup_timer(registerTimedSection("initialSetup", 2, "Performing Initial Setup")),
+    _project_solution_timer(registerTimedSection("projectSolution", 2, "Projecting Initial Solutions")),
+    _compute_indicators_timer(registerTimedSection("computeIndicators", 1, "Computing Indicators")),
+    _compute_markers_timer(registerTimedSection("computeMarkers", 1, "Computing Markers")),
+    _compute_user_objects_timer(registerTimedSection("computeUserObjects", 1, "Computing User Objects")),
+    _execute_controls_timer(registerTimedSection("executeControls", 1, "Executing Controls")),
+    _execute_samplers_timer(registerTimedSection("executeSamplers", 1, "Executing Samplers")),
+    _update_active_objects_timer(registerTimedSection("updateActiveObjects", 5, "Updating Active Objects")),
     _reinit_because_of_ghosting_or_new_geom_objects_timer(
-        registerTimedSection("reinitBecauseOfGhostingOrNewGeomObjects", 3)),
-    _exec_multi_app_transfers_timer(registerTimedSection("execMultiAppTransfers", 1)),
-    _init_timer(registerTimedSection("init", 2)),
-    _eq_init_timer(registerTimedSection("EquationSystems::Init", 2)),
-    _solve_timer(registerTimedSection("solve", 1)),
+      registerTimedSection("reinitBecauseOfGhostingOrNewGeomObjects", 3, "Reinitializing Because of Geometric Search Objects")),
+    _exec_multi_app_transfers_timer(registerTimedSection("execMultiAppTransfers", 1, "Executing Transfers")),
+    _init_timer(registerTimedSection("init", 2, "Initializing")),
+    _eq_init_timer(registerTimedSection("EquationSystems::Init", 2, "Initializing Equation Systems")),
+    _solve_timer(registerTimedSection("solve", 1, "Solving", false)),
     _check_exception_and_stop_solve_timer(registerTimedSection("checkExceptionAndStopSolve", 5)),
     _advance_state_timer(registerTimedSection("advanceState", 5)),
     _restore_solutions_timer(registerTimedSection("restoreSolutions", 5)),
     _save_old_solutions_timer(registerTimedSection("saveOldSolutions", 5)),
     _restore_old_solutions_timer(registerTimedSection("restoreOldSolutions", 5)),
-    _output_step_timer(registerTimedSection("outputStep", 1)),
+    _output_step_timer(registerTimedSection("outputStep", 1, "Outputting", false)),
     _on_timestep_begin_timer(registerTimedSection("onTimestepBegin", 2)),
     _compute_residual_l2_norm_timer(registerTimedSection("computeResidualL2Norm", 2)),
     _compute_residual_sys_timer(registerTimedSection("computeResidualSys", 5)),
@@ -322,18 +322,18 @@ FEProblemBase::FEProblemBase(const InputParameters & parameters)
     _compute_damping_timer(registerTimedSection("computeDamping", 1)),
     _possibly_rebuild_geom_search_patches_timer(
         registerTimedSection("possiblyRebuildGeomSearchPatches", 5)),
-    _initial_adapt_mesh_timer(registerTimedSection("initialAdaptMesh", 2)),
-    _adapt_mesh_timer(registerTimedSection("adaptMesh", 3)),
-    _update_mesh_xfem_timer(registerTimedSection("updateMeshXFEM", 5)),
-    _mesh_changed_timer(registerTimedSection("meshChanged", 3)),
+    _initial_adapt_mesh_timer(registerTimedSection("initialAdaptMesh", 2, "Performing Initial Adaptivity")),
+    _adapt_mesh_timer(registerTimedSection("adaptMesh", 3, "Adapting Mesh")),
+    _update_mesh_xfem_timer(registerTimedSection("updateMeshXFEM", 5, "Updating XFEM")),
+    _mesh_changed_timer(registerTimedSection("meshChanged", 3, "Handling Mesh Changes")),
     _mesh_changed_helper_timer(registerTimedSection("meshChangedHelper", 5)),
     _check_problem_integrity_timer(registerTimedSection("notifyWhenMeshChanges", 5)),
-    _serialize_solution_timer(registerTimedSection("serializeSolution", 3)),
-    _check_nonlinear_convergence_timer(registerTimedSection("checkNonlinearConvergence", 5)),
-    _check_linear_convergence_timer(registerTimedSection("checkLinearConvergence", 5)),
-    _update_geometric_search_timer(registerTimedSection("updateGeometricSearch", 3)),
-    _exec_multi_apps_timer(registerTimedSection("execMultiApps", 1)),
-    _backup_multi_apps_timer(registerTimedSection("backupMultiApps", 5)),
+    _serialize_solution_timer(registerTimedSection("serializeSolution", 3, "Serializing Solution")),
+    _check_nonlinear_convergence_timer(registerTimedSection("checkNonlinearConvergence", 5, "Checking Nonlinear Convergence")),
+    _check_linear_convergence_timer(registerTimedSection("checkLinearConvergence", 5, "Checking Linear Convergence")),
+    _update_geometric_search_timer(registerTimedSection("updateGeometricSearch", 3, "Updating Geometric Search")),
+    _exec_multi_apps_timer(registerTimedSection("execMultiApps", 1, "Executing MultiApps", false)),
+    _backup_multi_apps_timer(registerTimedSection("backupMultiApps", 5, "Backing Up MultiApp")),
     _u_dot_requested(false),
     _u_dotdot_requested(false),
     _u_dot_old_requested(false),