Adding actions for opening, flushing, and closing the logs (#1442)

* Adding actions for opening, flushing, and closing the logs

* Adding a contents check for the log file

* Adding actions for adjusting the logging and echo thresholds

* Log threshold should have been echo threshold

* Adding some basic documentation of the new logging actions

* Adding the ability to set the log threshold when the open log action is called

* Adding handling for ascent logging actions for MPI and testing

* Setting default threshold level based on MPI rank

* Removing extra lines

CHANGELOG.md

@@ -16,6 +16,7 @@ and this project aspires to adhere to [Semantic Versioning](https://semver.org/s
 - [email protected]
 
 ### Added
+- Added action options relating to logging functionality including `open_log`, `flush_log`, and `close_log` to toggle logging as well as `set_log_threshold` and `set_echo_threshold` to control logging and standard output levels.
 - Added a new unified logging infrastructure.
 - Added support for unstructured topologies with mixed elements types (for example, hexs and tets).
 - Added support for `pyramid` and `wedge` elements.

src/docs/sphinx/Actions/Actions.rst

@@ -19,6 +19,11 @@ The currently supported actions are:
 - ``add_triggers`` : adds a list of triggers that executes a set of actions based on a condition
 - ``save_info`` : saves ascent info result at the end of execution
 - ``save_session`` : saves expression session info at the end of execution (see :ref:`ExpressionsSaveSession`)
+- ``open_log`` : opens an assent logging stream and starts logging
+- ``flush_log`` : flushes the current logging stream to the output file
+- ``close_log`` : closes the current logging stream which stops logging
+- ``set_log_threshold`` : changes the threshold of messages recorded in the log file
+- ``set_echo_threshold`` : changes the threshold of messages displayed in standard output
 
 
 Ascent actions can be specified within the integration using Conduit Nodes and can be read in through a file.

src/docs/sphinx/Actions/Logging.rst

@@ -0,0 +1,86 @@
+.. ############################################################################
+.. # Copyright (c) Lawrence Livermore National Security, LLC and other Ascent
+.. # Project developers. See top-level LICENSE AND COPYRIGHT files for dates and
+.. # other details. No copyright assignment is required to contribute to Ascent.
+.. ############################################################################
+
+.. _Logging:
+
+Logging Overview
+================
+
+Ascent's logging options allow for control over the types of messages and information that are
+recorded and displayed. These functionalities are provided to allow for additional information to
+be recorded while the tool is being run in order to identify and diagnose any erroneous behavior. 
+
+The ``log`` options refer to the messages that are collected in a designated log stream and output
+to a designated log file. The ``echo`` options control the messages and types of information output
+to the standard output stream.
+
+Log Levels:
+- ``all`` : all messages will be recorded
+- ``debug`` : extra verbose output messages useful for diagnosing issues
+- ``info`` : normal system operations
+- ``warn`` : potential issues that could become a problem
+- ``error`` : significant issues that need to be addressed
+- ``none`` : no messages will be recorded.
+
+Opening Logs
+------------
+
+The ``open_log`` action can be used to start a logging stream. While there are no required keywords,
+options to set the output log file name and location using the ``file_pattern`` keyword as well as
+the logging threshold level using the ``log_threshold`` are available. The Default ``file_pattern``
+is ``ascent_log_output.yaml`` and the default ``log_threshold`` is ``debug``. If using MPI, the
+default ``log_threshold`` is ``debug`` for rank 0 and ``warn`` for all other ranks.
+
+.. code-block:: yaml
+
+  -
+    action: "open_log"
+    file_pattern: "ascent_log_out_{rank:05d}.yaml"
+    log_threshold: "debug"
+
+Flushing Logs
+-------------
+
+The ``flush_log`` action can be used to flush the current log streams to disk.
+
+.. code-block:: yaml
+
+  -
+    action: "flush_log"
+
+Closing Logs
+------------
+
+The ``close_log`` action can be used to close the current log stream.
+
+.. code-block:: yaml
+
+  -
+    action: "close_log"
+
+Setting the Logging Threshold
+-----------------------------
+
+The ``set_log_threshold`` action allows for the adjustment of the level of log messages being
+recorded to the current log stream.
+
+.. code-block:: yaml
+
+  -
+    action: "set_log_threshold"
+    log_threshold: "all"
+
+Setting the Echo Threshold
+-----------------------------
+
+The ``set_echo_threshold`` action allows for the adjustment of the level of log messages being
+recorded to the standard output stream.
+
+.. code-block:: yaml
+
+  -
+    action: "set_echo_threshold"
+    echo_threshold: "info"

src/docs/sphinx/Actions/index.rst

@@ -16,6 +16,7 @@ Ascent Actions
    Pipelines
    Extracts
    Triggers
+   Logging
    Examples
    ExpressionsOverview
    expression_objects

src/libs/ascent/runtimes/ascent_main_runtime.cpp

@@ -12,6 +12,7 @@
 //-----------------------------------------------------------------------------
 
 #include "ascent_main_runtime.hpp"
+#include <ascent_logging.hpp>
 
 // standard lib includes
 #include <string.h>
@@ -1936,6 +1937,86 @@ AscentRuntime::BuildGraph(const conduit::Node &actions)
         // the workspace executes.
         m_save_info_actions.append() = action;
       }
+      else if(action_name == "open_log")
+      {
+        // Open Ascent Logging Stream
+        // This starts logging
+
+        if(action.has_path("log_threshold"))
+        {
+            ascent::Logger::instance().set_log_threshold(action["log_threshold"].as_string());
+        }
+        else
+        {
+        #if defined(ASCENT_MPI_ENABLED)
+            if(m_rank == 0)
+            {
+                ascent::Logger::instance().set_log_threshold(ascent::Logger::LOG_DEBUG_ID);
+            }
+            else
+            {
+                ascent::Logger::instance().set_log_threshold(ascent::Logger::LOG_WARN_ID);
+            }
+        #else
+            ascent::Logger::instance().set_log_threshold(ascent::Logger::LOG_DEBUG_ID);
+        #endif
+        }
+
+        #if defined(ASCENT_MPI_ENABLED)
+            std::string file_pattern = action.has_path("file_pattern") ? 
+                                   action["file_pattern"].as_string() : "ascent_log_output_rank_{rank:05d}.yaml";
+
+            int comm_id = flow::Workspace::default_mpi_comm();
+            MPI_Comm mpi_comm = MPI_Comm_f2c(comm_id);
+            int comm_size = 1;
+            MPI_Comm_size(mpi_comm, &comm_size);
+            ASCENT_LOG_OPEN_RANK( file_pattern, m_rank );
+            ASCENT_LOG_DEBUG(conduit_fmt::format("mpi info: rank={}, size={}",
+                                                  m_rank,
+                                                  comm_size));
+        #else
+            std::string file_pattern = action.has_path("file_pattern") ? 
+                                   action["file_pattern"].as_string() : "ascent_log_output.yaml";
+            ASCENT_LOG_OPEN(file_pattern);
+            ASCENT_LOG_DEBUG("MPI not enabled");
+        #endif
+      }
+      else if(action_name == "flush_log")
+      {
+        // Flush Current Log Streams to Disk
+        // This is so they can be seen before ascent is closed out
+        ASCENT_LOG_FLUSH();
+      }
+      else if(action_name == "set_log_threshold")
+      {
+        // Change the logging level
+        if (action.has_path("log_threshold"))
+        {
+            ascent::Logger::instance().set_log_threshold(action["log_threshold"].as_string());
+        }
+        else
+        {
+            ASCENT_WARN("No Log Threshold level given. No changes to logging behavior made.");
+        }
+      }
+      else if(action_name == "set_echo_threshold")
+      {
+        // Change the echo to standard output level
+        if (action.has_path("echo_threshold"))
+        {
+            ascent::Logger::instance().set_echo_threshold(action["echo_threshold"].as_string());
+        }
+        else
+        {
+            ASCENT_WARN("No Echo Threshold level given. No changes to echo output behavior made.");
+        }
+      }
+      else if(action_name == "close_log")
+      {
+        // Closes current log stream
+        // This stops logging
+        ASCENT_LOG_CLOSE();
+      }
       else
       {
         ASCENT_ERROR("Unknown action ' "<<action_name<<"'");

src/tests/ascent/t_ascent_logging.cpp

@@ -148,4 +148,165 @@ TEST(ascent_logging, test_logging_options)
     // check that the log file exists
     EXPECT_TRUE(conduit::utils::is_file(log_file));
 
-}
+}
+
+//-----------------------------------------------------------------------------
+TEST(ascent_logging, test_logging_actions)
+{
+    Node n;
+    ascent::about(n);
+    // only run this test if ascent was built with vtkm support
+    if(n["runtimes/ascent/vtkm/status"].as_string() == "disabled")
+    {
+        ASCENT_INFO("Ascent vtkm support disabled, skipping test");
+        return;
+    }
+
+    //
+    // Create an example mesh.
+    //
+    Node data, verify_info;
+    conduit::blueprint::mesh::examples::braid("hexs",
+                                              5,
+                                              5,
+                                              5,
+                                              data);
+    EXPECT_TRUE(conduit::blueprint::mesh::verify(data,verify_info));
+
+
+    string output_path = prepare_output_dir();
+    string output_file = conduit::utils::join_file_path(output_path,"tout_logging_render3");
+    string log_file = conduit::utils::join_file_path(output_path,"ascent_action_log.yaml");
+
+    // remove old images/log files before rendering
+    remove_test_image(output_file);
+    conduit::utils::remove_path_if_exists(log_file);
+    EXPECT_FALSE(conduit::utils::is_file(log_file));
+
+    conduit::Node actions;
+    conduit::Node &add_scenes= actions.append();
+    add_scenes["action"] = "add_scenes";
+    conduit::Node &scenes = add_scenes["scenes"];
+    scenes["s1/plots/p1/type"]         = "pseudocolor";
+    scenes["s1/plots/p1/field"] = "braid";
+    scenes["s1/image_prefix"] = output_file;
+
+    conduit::Node actions_begin_logs;
+    conduit::Node &begin_logs= actions_begin_logs.append();
+    begin_logs["action"] = "open_log";
+    begin_logs["file_pattern"] = log_file;
+
+    conduit::Node actions_flush_logs;
+    conduit::Node &flush_logs= actions_flush_logs.append();
+    flush_logs["action"] = "flush_log";
+
+    conduit::Node actions_close_logs;
+    conduit::Node &close_logs= actions_close_logs.append();
+    close_logs["action"] = "close_log";
+
+    //
+    // Run Ascent
+    //
+
+    Ascent ascent;
+
+    ascent.open();
+    ascent.publish(data);
+    ascent.execute(actions_begin_logs);
+    ascent.execute(actions);
+    ascent.execute(actions_flush_logs);
+    ascent.execute(actions_close_logs);
+    ascent.close();
+
+    // check that the log file exists
+    EXPECT_TRUE(conduit::utils::is_file(log_file));
+
+    // check that the log file has the expected number of logs in it (1 open, 3 execution, 1 close)
+    conduit::Node log_file_contents;
+    log_file_contents.load(log_file);
+    EXPECT_EQ(log_file_contents.number_of_children(), 6);
+}
+
+//-----------------------------------------------------------------------------
+TEST(ascent_logging, test_logging_actions_threshold)
+{
+    Node n;
+    ascent::about(n);
+    // only run this test if ascent was built with vtkm support
+    if(n["runtimes/ascent/vtkm/status"].as_string() == "disabled")
+    {
+        ASCENT_INFO("Ascent vtkm support disabled, skipping test");
+        return;
+    }
+
+    //
+    // Create an example mesh.
+    //
+    Node data, verify_info;
+    conduit::blueprint::mesh::examples::braid("hexs",
+                                              5,
+                                              5,
+                                              5,
+                                              data);
+    EXPECT_TRUE(conduit::blueprint::mesh::verify(data,verify_info));
+
+
+    string output_path = prepare_output_dir();
+    string output_file = conduit::utils::join_file_path(output_path,"tout_logging_render4");
+    string log_file = conduit::utils::join_file_path(output_path,"ascent_action_log_thresholded.yaml");
+
+    // remove old images/log files before rendering
+    remove_test_image(output_file);
+    conduit::utils::remove_path_if_exists(log_file);
+    EXPECT_FALSE(conduit::utils::is_file(log_file));
+
+    conduit::Node actions;
+    conduit::Node &add_scenes= actions.append();
+    add_scenes["action"] = "add_scenes";
+    conduit::Node &scenes = add_scenes["scenes"];
+    scenes["s1/plots/p1/type"]         = "pseudocolor";
+    scenes["s1/plots/p1/field"] = "braid";
+    scenes["s1/image_prefix"] = output_file;
+
+    conduit::Node actions_begin_logs;
+    conduit::Node &begin_logs= actions_begin_logs.append();
+    begin_logs["action"] = "open_log";
+    begin_logs["file_pattern"] = log_file;
+    begin_logs["log_threshold"] = "all";
+    conduit::Node &set_threshold_logs_open= actions_begin_logs.append();
+    set_threshold_logs_open["action"] = "set_log_threshold";
+    set_threshold_logs_open["log_threshold"] = "error";
+
+    conduit::Node actions_flush_logs;
+    conduit::Node &flush_logs= actions_flush_logs.append();
+    flush_logs["action"] = "flush_log";
+
+    conduit::Node actions_close_logs;
+    conduit::Node &set_threshold_logs_close= actions_close_logs.append();
+    set_threshold_logs_close["action"] = "set_log_threshold";
+    set_threshold_logs_close["log_threshold"] = "debug";
+    conduit::Node &close_logs= actions_close_logs.append();
+    close_logs["action"] = "close_log";
+
+    //
+    // Run Ascent
+    //
+
+    Ascent ascent;
+
+    ascent.open();
+    ascent.publish(data);
+    ascent.execute(actions_begin_logs);
+    ascent.execute(actions);
+    ascent.execute(actions_flush_logs);
+    ascent.execute(actions_close_logs);
+    ascent.close();
+
+    // check that the log file exists
+    EXPECT_TRUE(conduit::utils::is_file(log_file));
+
+    // check that the log file has the expected number of logs in it (1 open, 3 execution, 1 close)
+    conduit::Node log_file_contents;
+    log_file_contents.load(log_file);
+    EXPECT_EQ(log_file_contents.number_of_children(), 3);
+}