Send additional FSP progress messages during long isteps (e.g. memdiags)

Updated sendProgressCode() so that it would only output trace or
console messages once per step/substep.  Replaced most calls to
IPMIWATCHDOG::resetWatchDogTimer() with calls to sendProgressCode()
which calls resetWatchDogTimer() if communicating with a BMC, or
updates the FSP with its progress on FSP-based systems.

Change-Id: I29beb7ce5cdae467d26a0b2c5fee9e3cc4629161
RTC: 169682
Reviewed-on: http://ralgit01.raleigh.ibm.com/gerrit1/53995
Reviewed-by: William G. Hoffa <wghoffa@us.ibm.com>
Reviewed-by: Prachi Gupta <pragupta@us.ibm.com>
Tested-by: Jenkins Server <pfd-jenkins+hostboot@us.ibm.com>
Tested-by: Jenkins OP Build CI <op-jenkins+hostboot@us.ibm.com>
Tested-by: Jenkins OP HW <op-hw-jenkins+hostboot@us.ibm.com>
Tested-by: FSP CI Jenkins <fsp-CI-jenkins+hostboot@us.ibm.com>
Reviewed-by: Daniel M. Crowell <dcrowell@us.ibm.com>

2 files changed, 60 insertions, 30 deletions

diff --git a/src/usr/initservice/istepdispatcher/istepdispatcher.C b/src/usr/initservice/istepdispatcher/istepdispatcher.C
index 2e27ac6bd..65c549629 100644
--- a/src/usr/initservice/istepdispatcher/istepdispatcher.C
+++ b/src/usr/initservice/istepdispatcher/istepdispatcher.C
@@ -180,7 +180,7 @@ IStepDispatcher::~IStepDispatcher ()
 
     // Singleton destructor gets run when module gets unloaded.
     // The istepdispatcher module never gets unloaded. So rather to send a
-    // message to error log daemon and tell it to shutdow and delete
+    // message to error log daemon and tell it to shutdown and delete
     // the queue we will assert here because the destructor never gets
     // call.
     assert(0);
@@ -204,7 +204,7 @@ void IStepDispatcher::init(errlHndl_t &io_rtaskRetErrl)
     printk( "IStepDispatcher entry.\n" );
     TRACFCOMP( g_trac_initsvc, "IStepDispatcher entry." );
 
-    //  Read the and process the Hostboot configuration flags
+    //  Read and process the Hostboot configuration flags
     BOOTCONFIG::readAndProcessBootConfig();
 
     TARGETING::Target* l_pTopLevelTarget = NULL;
@@ -214,7 +214,7 @@ void IStepDispatcher::init(errlHndl_t &io_rtaskRetErrl)
 
     do
     {
-        //Need to get ATTR overides first if non FSP system
+        // Need to get ATTR overrides first if non FSP system
         if(!iv_spBaseServicesEnabled)
         {
             PNOR::SectionInfo_t l_sectionInfo;
@@ -2291,18 +2291,23 @@ void IStepDispatcher::handlePerstMsg(msg_t * & io_pMsg)
 // ----------------------------------------------------------------------------
 errlHndl_t IStepDispatcher::sendProgressCode(bool i_needsLock)
 {
+    static uint8_t lastIstep = 0, lastSubstep = 0;
+    errlHndl_t err = NULL;
+
     if (i_needsLock)
     {
         mutex_lock( &iv_mutex );
     }
 
-    TRACDCOMP( g_trac_initsvc,ENTER_MRK"IStepDispatcher::sendProgressCode()");
-    errlHndl_t err = NULL;
-
-
-    //--- Display istep in Simics console
-    MAGIC_INST_PRINT_ISTEP( iv_curIStep, iv_curSubStep );
+    // Reduce output to once per step/substep
+    if ((iv_curIStep != lastIstep) || (iv_curSubStep != lastSubstep))
+    {
+        TRACDCOMP( g_trac_initsvc,
+                   ENTER_MRK"IStepDispatcher::sendProgressCode()");
 
+        //--- Display istep in Simics console
+        MAGIC_INST_PRINT_ISTEP( iv_curIStep, iv_curSubStep );
+    }
 
     //--- Save step to a scratch reg
     SPLESS::MboxScratch5_HB_t l_scratch5;
@@ -2326,14 +2331,16 @@ errlHndl_t IStepDispatcher::sendProgressCode(bool i_needsLock)
     port80_val++;
 #endif
 
-    //--- Display step on serial console
 #ifdef CONFIG_CONSOLE_OUTPUT_PROGRESS
-    // Note If we ever send progress codes multiple times, we may need to
-    // eliminate the console write on subsequent.
-    const TaskInfo *taskinfo = findTaskInfo(iv_curIStep, iv_curSubStep);
-    CONSOLE::displayf(NULL, "ISTEP %2d.%2d - %s", iv_curIStep, iv_curSubStep,
-                      taskinfo && taskinfo->taskname ? taskinfo->taskname : "");
-    CONSOLE::flush();
+    //--- Display step on serial console
+    if ((iv_curIStep != lastIstep) || (iv_curSubStep != lastSubstep))
+    {
+        const TaskInfo *taskinfo = findTaskInfo(iv_curIStep, iv_curSubStep);
+        CONSOLE::displayf(NULL, "ISTEP %2d.%2d - %s",
+                     iv_curIStep, iv_curSubStep,
+                     taskinfo && taskinfo->taskname ? taskinfo->taskname : "");
+        CONSOLE::flush();
+    }
 #endif
 
 
@@ -2365,11 +2372,21 @@ errlHndl_t IStepDispatcher::sendProgressCode(bool i_needsLock)
             err->setSev(ERRORLOG::ERRL_SEV_UNRECOVERABLE);
         }
         clock_gettime(CLOCK_MONOTONIC, &iv_lastProgressMsgTime);
-        TRACFCOMP( g_trac_initsvc,INFO_MRK"Progress Code %d.%d Sent",
-                   myMsg->data[0],myMsg->data[1]);
+        if ((iv_curIStep != lastIstep) || (iv_curSubStep != lastSubstep))
+        {
+            TRACFCOMP( g_trac_initsvc,INFO_MRK"Progress Code %d.%d Sent",
+                       myMsg->data[0],myMsg->data[1]);
+        }
     }
 
-    TRACDCOMP( g_trac_initsvc,EXIT_MRK"IStepDispatcher::sendProgressCode()" );
+    if ((iv_curIStep != lastIstep) || (iv_curSubStep != lastSubstep))
+    {
+        TRACDCOMP( g_trac_initsvc,
+                   EXIT_MRK"IStepDispatcher::sendProgressCode()" );
+    }
+
+    lastIstep = iv_curIStep;
+    lastSubstep = iv_curSubStep;
 
     if (i_needsLock)
     {
@@ -2488,7 +2505,7 @@ bool IStepDispatcher::checkReconfig(const uint8_t i_curIstep,
 }
 
 // ----------------------------------------------------------------------------
-// Extarnal functions defined that map directly to IStepDispatcher public member
+// External functions defined that map directly to IStepDispatcher public member
 // functions.
 // Defined in istepdispatcherif.H, initsvcbreakpoint.H
 // ----------------------------------------------------------------------------
@@ -2502,6 +2519,19 @@ errlHndl_t sendSyncPoint()
     return IStepDispatcher::getTheInstance().sendSyncPoint();
 }
 
+void sendProgressCode(bool i_needsLock)
+{
+    errlHndl_t err = NULL;
+
+    err = IStepDispatcher::getTheInstance().sendProgressCode(i_needsLock);
+
+    if (err)
+    {
+        // Commit the error and continue
+        errlCommit(err, INITSVC_COMP_ID);
+    }
+}
+
 errlHndl_t sendIstepCompleteMsg()
 {
     return IStepDispatcher::getTheInstance().sendIstepCompleteMsg();
diff --git a/src/usr/initservice/istepdispatcher/istepdispatcher.H b/src/usr/initservice/istepdispatcher/istepdispatcher.H
index ef6798372..fa50501ee 100644
--- a/src/usr/initservice/istepdispatcher/istepdispatcher.H
+++ b/src/usr/initservice/istepdispatcher/istepdispatcher.H
@@ -141,9 +141,18 @@ public:
     void waitForSyncPoint();
 
     /**
+     * @brief Sends a progress message from Hostboot to Fsp.
+     *
+     * param[in] i_needsLock flag to acquire mutex or not
+     *
+     * @return errlHndl_t
+     */
+    errlHndl_t sendProgressCode(bool i_needsLock = true);
+
+    /**
      * @brief Sends an IStepComplete message
      *
-     * Only called by ISteps that do not return and need to repsond to the
+     * Only called by ISteps that do not return and need to respond to the
      * IStep request message (i.e. start_payload), this should only be called
      * in IStep mode.
      *
@@ -403,15 +412,6 @@ private:
                               uint8_t & o_newSubstep);
 
     /**
-     * @brief Sends a progress message from Hostboot to Fsp.
-     *
-     * param[in] i_needsLock flag to acquire mutex or not
-     *
-     * @return errlHndl_t
-     */
-    errlHndl_t sendProgressCode(bool i_needsLock = true);
-
-    /**
      * @brief This function is called on a dedicated task to post progress codes
      *
      * param[in] p Pointer to any args