Reduce ipmi trace spam for pnor hiomap messages

With the PNOR accesses now going over IPMI, the IPMI traces are
now completely overwhelmed by those messages.  This change will
skip tracing out the messages if they are the hiomap requests.

Example of trace spam:
  3.34945|IPMI|rp: queuing sync e8:5a
  3.34946|IPMI|rp: W>Got message (0xe8:0x5a): l_is_pnor: 1
  3.34952|IPMI|dd: I>write ok e8:5a seq 26 len 6
  3.35837|IPMI|dd: I>read b2h ok ec:5a seq 26 len 8 cc 0
  3.35947|IPMI|rp: queuing sync e8:5a
  3.35948|IPMI|rp: W>Got message (0xe8:0x5a): l_is_pnor: 1
  3.35953|IPMI|dd: I>write ok e8:5a seq 27 len 6
  3.36837|IPMI|dd: I>read b2h ok ec:5a seq 27 len 8 cc 0
  3.36947|IPMI|rp: queuing sync e8:5a
  3.36948|IPMI|rp: W>Got message (0xe8:0x5a): l_is_pnor: 1
  3.36953|IPMI|dd: I>write ok e8:5a seq 28 len 6
  3.43855|IPMI|dd: I>read b2h ok ec:5a seq 28 len 8 cc 0
  3.43926|IPMI|rp: queuing sync e8:5a
  3.43927|IPMI|rp: W>Got message (0xe8:0x5a): l_is_pnor: 1
  3.43933|IPMI|dd: I>write ok e8:5a seq 29 len 6
  3.50860|IPMI|dd: I>read b2h ok ec:5a seq 29 len 8 cc 0
  3.50902|IPMI|rp: queuing sync e8:5a
  3.50902|IPMI|rp: W>Got message (0xe8:0x5a): l_is_pnor: 1
In a single boot on a system there were close to 4000 of these
traces.

Change-Id: Ia8944ca7f281986ec0bca7328fa56a7c0d521339
Reviewed-on: http://rchgit01.rchland.ibm.com/gerrit1/68605
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: Christian R. Geddes <crgeddes@us.ibm.com>
Reviewed-by: William G. Hoffa <wghoffa@us.ibm.com>
Reviewed-by: Daniel M. Crowell <dcrowell@us.ibm.com>

2 files changed, 39 insertions, 14 deletions

diff --git a/src/usr/ipmibase/ipmidd.C b/src/usr/ipmibase/ipmidd.C
index 0e155a808..647930442 100644
--- a/src/usr/ipmibase/ipmidd.C
+++ b/src/usr/ipmibase/ipmidd.C
@@ -60,6 +60,10 @@ TRAC_INIT(&g_trac_ipmi, IPMI_COMP_NAME, 6*KILOBYTE, TRACE::BUFFER_SLOW);
 #define IPMI_TRAC(printf_string,args...) \
     TRACFCOMP(g_trac_ipmi,"dd: " printf_string,##args)
 
+// Set this to true if you want to see all of the pnor messages
+const bool g_PNOR_DEBUG = false;
+
+
 /**
  * @brief Performs an IPMI Message Read Operation
  * This function performs a IPMI Message Read operation. It follows a
@@ -330,10 +334,15 @@ errlHndl_t IpmiDD::send(IPMI::BTMessage* i_msg)
     // upper layers will report the re-queue or whatever.
     if (i_msg->iv_state != EAGAIN)
     {
-        IPMI_TRAC(INFO_MRK "write %s %x:%x seq %x len %x",
-                  err ? "err" : "ok",
-                  i_msg->iv_netfun, i_msg->iv_cmd, i_msg->iv_seq,
-                  i_msg->iv_len);
+        // don't trace the constant pnor hiomap stuff
+        if( !IPMI::is_pnor_req(i_msg->iv_netfun,i_msg->iv_cmd)
+            || g_PNOR_DEBUG )
+        {
+            IPMI_TRAC(INFO_MRK "write %s %x:%x seq %x len %x",
+                      err ? "err" : "ok",
+                      i_msg->iv_netfun, i_msg->iv_cmd, i_msg->iv_seq,
+                      i_msg->iv_len);
+        }
     }
 
     return err;
@@ -411,10 +420,14 @@ errlHndl_t IpmiDD::receive(IPMI::BTMessage* o_msg)
 
     mutex_unlock(&iv_mutex);
 
-    IPMI_TRAC(INFO_MRK "read b2h %s %x:%x seq %x len %x cc %x",
-              err ? "err" : "ok",
-              o_msg->iv_netfun, o_msg->iv_cmd, o_msg->iv_seq,
-              o_msg->iv_len, o_msg->iv_cc);
+    // don't trace the constant pnor hiomap stuff
+    if( !IPMI::is_pnor_req(o_msg->iv_netfun,o_msg->iv_cmd) || g_PNOR_DEBUG )
+    {
+        IPMI_TRAC(INFO_MRK "read b2h %s %x:%x seq %x len %x cc %x",
+                  err ? "err" : "ok",
+                  o_msg->iv_netfun, o_msg->iv_cmd, o_msg->iv_seq,
+                  o_msg->iv_len, o_msg->iv_cc);
+    }
 
     return err;
 }
diff --git a/src/usr/ipmibase/ipmirp.C b/src/usr/ipmibase/ipmirp.C
index 57e69059e..9a8f164cd 100644
--- a/src/usr/ipmibase/ipmirp.C
+++ b/src/usr/ipmibase/ipmirp.C
@@ -56,6 +56,10 @@ extern trace_desc_t * g_trac_ipmi;
 #define IPMI_TRAC(printf_string,args...) \
     TRACFCOMP(g_trac_ipmi,"rp: " printf_string,##args)
 
+
+// Set this to true if you want to see all of the pnor messages
+const bool g_PNOR_DEBUG = false;
+
 /**
  * setup _start and handle barrier
  */
@@ -598,11 +602,14 @@ void IpmiRP::execute(void)
         {
             IPMI::Message* l_ipmi_msg =
                 static_cast<IPMI::Message*>(msg->extra_data);
-            const IPMI::command_t l_pnor = IPMI::pnor_hiomap_request();
-            bool l_is_pnor = (l_ipmi_msg->iv_netfun == l_pnor.first &&
-                              l_ipmi_msg->iv_cmd == l_pnor.second);
-            IPMI_TRAC(WARN_MRK "Got message (0x%x:0x%x): l_is_pnor: %d",
-                      l_ipmi_msg->iv_netfun, l_ipmi_msg->iv_cmd, l_is_pnor);
+            bool l_is_pnor = IPMI::is_pnor_req(l_ipmi_msg->iv_netfun,
+                                               l_ipmi_msg->iv_cmd);
+            // don't trace the constant pnor hiomap stuff
+            if( !l_is_pnor || g_PNOR_DEBUG )
+            {
+                IPMI_TRAC(WARN_MRK "Got message (0x%x:0x%x): l_is_pnor: %d",
+                          l_ipmi_msg->iv_netfun, l_ipmi_msg->iv_cmd, l_is_pnor);
+            }
             /* PNOR requests always allowed, else we hang shutdown */
             if (!l_shutdown_pending || l_is_pnor)
             {
@@ -942,7 +949,12 @@ namespace IPMI
         // I think if the buffer is too large this is a programming error.
         assert(io_len <= max_buffer());
 
-        IPMI_TRAC("queuing sync %x:%x", ipmi_msg->iv_netfun, ipmi_msg->iv_cmd);
+        // don't trace the constant pnor hiomap stuff
+        if( !IPMI::is_pnor_req(ipmi_msg->iv_netfun,ipmi_msg->iv_cmd)
+            || g_PNOR_DEBUG )
+        {
+            IPMI_TRAC("queuing sync %x:%x", ipmi_msg->iv_netfun, ipmi_msg->iv_cmd);
+        }
         int rc = msg_sendrecv(mq, ipmi_msg->iv_msg);
 
         // If the kernel didn't give a hassle about the message, check to see if