Skip to content

Commit

Permalink
Reduce ipmi trace spam for pnor hiomap messages
Browse files Browse the repository at this point in the history
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
CQ: SW451916
Reviewed-on: http://rchgit01.rchland.ibm.com/gerrit1/69168
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>
Reviewed-by: Daniel M. Crowell <dcrowell@us.ibm.com>
  • Loading branch information
dcrowell77 committed Nov 28, 2018
1 parent 8e2f7e9 commit 9435e74
Show file tree
Hide file tree
Showing 3 changed files with 59 additions and 14 deletions.
20 changes: 20 additions & 0 deletions src/include/usr/ipmi/ipmiif.H
Original file line number Diff line number Diff line change
Expand Up @@ -116,6 +116,16 @@ namespace IPMI
NETFUN_NONE = (0x30 << 2),
};

/**
* @brief Generate the response for IPMI network function
* @param[in] Standard network function
* @return Network function in response (+1)
*/
inline const uint8_t gen_resp_netfn( network_function i_netfn )
{
return ( ( (i_netfn >> 2) + 1 ) << 2 );
};

// SMS_ATN OEM Event constants
enum oem_event
{
Expand Down Expand Up @@ -311,6 +321,16 @@ namespace IPMI
inline const command_t pnor_hiomap_request(void)
{ return std::make_pair(NETFUN_IBM, 0x5a); }

// Efficient comparator to see if the message is a pnor hiomap request
inline bool is_pnor_req( uint8_t i_netfun, uint8_t i_cmd )
{
return (((i_netfun == NETFUN_IBM) ||
(i_netfun == gen_resp_netfn(NETFUN_IBM))) //response
&&
(i_cmd == 0x5a));
}


/**
* Send message asynchronously
* @param[in] i_cmd, the network function and command
Expand Down
29 changes: 21 additions & 8 deletions src/usr/ipmibase/ipmidd.C
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
}
Expand Down
24 changes: 18 additions & 6 deletions src/usr/ipmibase/ipmirp.C
Original file line number Diff line number Diff line change
Expand Up @@ -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
*/
Expand Down Expand Up @@ -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)
{
Expand Down Expand Up @@ -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
Expand Down

0 comments on commit 9435e74

Please sign in to comment.