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>

6 files changed, 77 insertions, 90 deletions

diff --git a/src/include/usr/initservice/istepdispatcherif.H b/src/include/usr/initservice/istepdispatcherif.H
index 1694c7942..402f3eb58 100644
--- a/src/include/usr/initservice/istepdispatcherif.H
+++ b/src/include/usr/initservice/istepdispatcherif.H
@@ -5,7 +5,7 @@
 /*                                                                        */
 /* OpenPOWER HostBoot Project                                             */
 /*                                                                        */
-/* Contributors Listed Below - COPYRIGHT 2012,2017                        */
+/* Contributors Listed Below - COPYRIGHT 2012,2018                        */
 /* [+] International Business Machines Corp.                              */
 /*                                                                        */
 /*                                                                        */
@@ -49,6 +49,16 @@ errlHndl_t sendSyncPoint ( void );
 
 
 /**
+* @brief This function is used by external code to send a progress message
+*      from Hostboot to Fsp.
+*
+* param[in] i_needsLock flag to acquire mutex or not
+*
+*/
+void sendProgressCode(bool i_needsLock = true);
+
+
+/**
  * @brief This function is to be used by external code to initiate a Istep
  *      complete message to be sent to the Fsp.
  *
diff --git a/src/usr/diag/mdia/mdiasm.C b/src/usr/diag/mdia/mdiasm.C
index 00fe86f82..4da90c76d 100644
--- a/src/usr/diag/mdia/mdiasm.C
+++ b/src/usr/diag/mdia/mdiasm.C
@@ -1346,18 +1346,8 @@ bool StateMachine::processMaintCommandEvent(const MaintCommandEvent & i_event)
             eventType = STOP_TESTING;
         }
 
-#ifdef CONFIG_BMC_IPMI
         // Reset the watchdog timer after running each pattern
-        errlHndl_t err_ipmi = IPMIWATCHDOG::resetWatchDogTimer();
-
-        if(err_ipmi)
-        {
-            MDIA_FAST("sm executeWorkitem: IPMI reset watchdog failed");
-            err_ipmi->collectTrace("MDIA_FAST",1024);
-            errlCommit(err_ipmi, MDIA_COMP_ID );
-
-        }
-#endif
+        INITSERVICE::sendProgressCode();
 
         switch(eventType)
         {
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
diff --git a/src/usr/sbe/sbe_update.C b/src/usr/sbe/sbe_update.C
index af032a07f..a452ea200 100644
--- a/src/usr/sbe/sbe_update.C
+++ b/src/usr/sbe/sbe_update.C
@@ -439,18 +439,7 @@ namespace SBE
                 /**********************************************/
                 /*   Reset the watchdog after each Action     */
                 /**********************************************/
-#ifdef CONFIG_BMC_IPMI
-                err = IPMIWATCHDOG::resetWatchDogTimer();
-
-                if( err )
-                {
-                    TRACFCOMP( g_trac_sbe,
-                               INFO_MRK"updateProcessorSbeSeeproms(): "
-                               "resetWatchDogTimer() Failed rc=0x%.4X",
-                               err->reasonCode());
-                    errlCommit( err, SBE_COMP_ID );
-                }
-#endif
+                INITSERVICE::sendProgressCode();
 
                 // Push this sbeState onto the vector
                 sbeStates_vector.push_back(sbeState);
diff --git a/src/usr/sbeio/common/sbe_retry_handler.C b/src/usr/sbeio/common/sbe_retry_handler.C
index b18480df4..ed7bfb11d 100644
--- a/src/usr/sbeio/common/sbe_retry_handler.C
+++ b/src/usr/sbeio/common/sbe_retry_handler.C
@@ -43,6 +43,7 @@
 #include <fapi2/plat_hwp_invoker.H>
 #include <initservice/isteps_trace.H>
 #include <initservice/initserviceif.H>
+#include <initservice/istepdispatcherif.H>
 #include <errl/errludtarget.H>
 #include <sys/time.h>
 #include <util/misc.H>
@@ -429,26 +430,10 @@ void SbeRetryHandler::handle_sbe_reg_value(TARGETING::Target * i_target)
 
             {
                 iv_retriggeredMain = true;
-#ifdef CONFIG_BMC_IPMI
+
 #ifndef __HOSTBOOT_RUNTIME
                 // This could potentially take awhile, reset watchdog
-                l_errl = IPMIWATCHDOG::resetWatchDogTimer();
-                if(l_errl)
-                {
-                    SBE_TRACF("Inside handle_sbe_reg_value before sbe_handler "
-                              "Resetting watchdog");
-                    l_errl->collectTrace("ISTEPS_TRACE",256);
-
-                    // Set the PLID of the error log to caller's PLID,
-                    // if provided
-                    if (iv_callerErrorLogPLID)
-                    {
-                       l_errl->plid(iv_callerErrorLogPLID);
-                    }
-
-                    errlCommit(l_errl,ISTEP_COMP_ID);
-                }
-#endif
+                INITSERVICE::sendProgressCode();
 #endif
                 SBE_TRACF("handle_sbe_reg_value(): Attempting "
                    "REIPL_UPD_SEEPROM failed. Recalling with BKP_SEEPROM");
@@ -910,26 +895,9 @@ bool SbeRetryHandler::sbe_boot_fail_handler(TARGETING::Target * i_target,
 #endif
         }
 
-#ifdef CONFIG_BMC_IPMI
 #ifndef __HOSTBOOT_RUNTIME
         // This could potentially take awhile, reset watchdog
-        l_errl = IPMIWATCHDOG::resetWatchDogTimer();
-        if(l_errl)
-        {
-            SBE_TRACF("sbe_boot_fail_handler "
-                      "Resetting watchdog before sbe_handler");
-            l_errl->collectTrace("ISTEPS_TRACE",KILOBYTE/4);
-
-            // Set the PLID of the error log to caller's PLID,
-            // if provided
-            if (iv_callerErrorLogPLID)
-            {
-                l_errl->plid(iv_callerErrorLogPLID);
-            }
-
-            errlCommit(l_errl,ISTEP_COMP_ID);
-        }
-#endif
+        INITSERVICE::sendProgressCode();
 #endif
         SBE_TRACF("sbe_boot_fail_handler. iv_switchSides count is %llx",
                    iv_switchSidesCount);