Skip to content

Commit

Permalink
Remove excessive NVDIMM tracing from normal path
Browse files Browse the repository at this point in the history
Tracing is causing a bottleneck when running NVDIMM
updates.  Should only trace the real failure and add
what is needed for debug into the error log.

Change-Id: Ifa75f85e1129efd9642a3fef0b842fc1f60cd182
Reviewed-on: http://rchgit01.rchland.ibm.com/gerrit1/75667
Tested-by: Jenkins Server <pfd-jenkins+hostboot@us.ibm.com>
Tested-by: FSP CI Jenkins <fsp-CI-jenkins+hostboot@us.ibm.com>
Reviewed-by: Glenn Miles <milesg@ibm.com>
Reviewed-by: Christian R. Geddes <crgeddes@us.ibm.com>
Reviewed-by: Daniel M. Crowell <dcrowell@us.ibm.com>
Reviewed-on: http://rchgit01.rchland.ibm.com/gerrit1/85499
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
mderkse1 authored and dcrowell77 committed Nov 6, 2019
1 parent d1260d0 commit a501159
Showing 1 changed file with 52 additions and 20 deletions.
72 changes: 52 additions & 20 deletions src/usr/isteps/nvdimm/nvdimmdd.C
Expand Up @@ -498,7 +498,7 @@ errlHndl_t nvdimmRead ( TARGETING::Target * i_target,
if( err )
{
TRACFCOMP(g_trac_nvdimm,
"Failed reading data: original read");
ERR_MRK"nvdimmRead(): Failed reading data: original read");
break;
}

Expand Down Expand Up @@ -562,12 +562,10 @@ errlHndl_t nvdimmReadData( TARGETING::Target * i_target,

if( l_err )
{
TRACFCOMP(g_trac_nvdimm,
ERR_MRK"nvdimmReadData(): I2C Read-Offset failed on "
"%d/%d/0x%X, aS=%d",
i_i2cInfo.port, i_i2cInfo.engine,
i_i2cInfo.devAddr,
i_byteAddressSize);
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
"I2C Read-Offset failed on %d/%d/0x%X, aS=%d",
i_i2cInfo.port, i_i2cInfo.engine,
i_i2cInfo.devAddr, i_byteAddressSize);

// Printing mux info separately, if combined, nothing is displayed
char* l_muxPath = i_i2cInfo.i2cMuxPath.toString();
Expand Down Expand Up @@ -600,15 +598,15 @@ errlHndl_t nvdimmReadData( TARGETING::Target * i_target,

if( l_err )
{
TRACFCOMP(g_trac_nvdimm,
TRACUCOMP(g_trac_nvdimm,
ERR_MRK"nvdimmReadData(): I2C Read failed on "
"%d/%d/0x%0X",
i_i2cInfo.port, i_i2cInfo.engine,
i_i2cInfo.devAddr );

// Printing mux info separately, if combined, nothing is displayed
char* l_muxPath = i_i2cInfo.i2cMuxPath.toString();
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
TRACUCOMP(g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
"muxSelector=0x%X, muxPath=%s",
i_i2cInfo.i2cMuxBusSelector,
l_muxPath);
Expand Down Expand Up @@ -647,9 +645,9 @@ errlHndl_t nvdimmReadData( TARGETING::Target * i_target,
// Save original retryable error
err_retryable = l_err;

TRACFCOMP( g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
TRACUCOMP( g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
"Retryable Error rc=0x%X, eid=0x%X, tgt=0x%X, "
"retry/MAX=%d/%d. Save error and retry",
"retry=%d. Save error and retry",
err_retryable->reasonCode(),
err_retryable->eid(),
TARGETING::get_huid(i_target),
Expand Down Expand Up @@ -686,13 +684,29 @@ errlHndl_t nvdimmReadData( TARGETING::Target * i_target,
.addToLog(err_retryable);

errlCommit(err_retryable, NVDIMM_COMP_ID);

// Add trace of what operation failed for returned error
TRACFCOMP(g_trac_nvdimm,
ERR_MRK"nvdimmReadData(): I2C Read failed on "
"%d/%d/0x%0X",
i_i2cInfo.port, i_i2cInfo.engine, i_i2cInfo.devAddr );

// Printing mux info separately, if combined, nothing is displayed
char* l_muxPath = i_i2cInfo.i2cMuxPath.toString();
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmReadData(): "
"muxSelector=0x%X, muxPath=%s",
i_i2cInfo.i2cMuxBusSelector,
l_muxPath);
free(l_muxPath);
l_muxPath = nullptr;
}
else
{
// Since we eventually succeeded, delete original retryable error
TRACFCOMP(g_trac_nvdimm, "nvdimmReadData(): Op successful, "
"deleting saved retryable err eid=0x%X, plid=0x%X",
err_retryable->eid(), err_retryable->plid());
TRACUCOMP(g_trac_nvdimm, "nvdimmReadData(): Op successful, "
"after %d retries. Deleting saved retryable err eid="
"0x%X, plid=0x%X",
retry, err_retryable->eid(), err_retryable->plid());

delete err_retryable;
err_retryable = nullptr;
Expand Down Expand Up @@ -890,7 +904,7 @@ errlHndl_t nvdimmWrite ( TARGETING::Target * i_target,
io_buflen = total_bytes_written;


TRACSCOMP( g_trac_nvdimmr,
TRACUCOMP( g_trac_nvdimmr,
"NVDIMM WRITE END : Offset %.2X : Len %d",
i_i2cInfo.offset, io_buflen );
} while( 0 );
Expand Down Expand Up @@ -1000,7 +1014,7 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,
}
else // Handle retryable error
{
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): I2C "
TRACUCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): I2C "
"Write retryable fail %d/%d/0x%X, "
"ldl=%d, offset=0x%X, aS=%d, writePageSize = %x",
i_i2cInfo.port, i_i2cInfo.engine,
Expand All @@ -1010,7 +1024,7 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,

// Printing mux info separately, if combined, nothing is displayed
char* l_muxPath = i_i2cInfo.i2cMuxPath.toString();
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
TRACUCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
"muxSelector=0x%X, muxPath=%s",
i_i2cInfo.i2cMuxBusSelector,
l_muxPath);
Expand All @@ -1026,7 +1040,7 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,
// Save original retryable error
err_retryable = err;

TRACFCOMP( g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
TRACUCOMP( g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
"Error rc=0x%X, eid=0x%X plid=0x%X, "
"tgt=0x%X, retry/MAX=%d/%d. Save error "
"and retry",
Expand All @@ -1041,7 +1055,7 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,
else
{
// Add data to original retryable error
TRACFCOMP( g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
TRACUCOMP( g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
"Another Retryable Error rc=0x%X, eid=0x%X "
"plid=0x%X, tgt=0x%X, retry/MAX=%d/%d. "
"Delete error and retry",
Expand Down Expand Up @@ -1086,6 +1100,24 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,
{
if (err)
{
// Trace failure write parameters
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): I2C "
"Write retryable fail %d/%d/0x%X, "
"ldl=%d, offset=0x%X, aS=%d, writePageSize = %x",
i_i2cInfo.port, i_i2cInfo.engine,
i_i2cInfo.devAddr, i_dataLen,
i_i2cInfo.offset, i_i2cInfo.addrSize,
i_i2cInfo.writePageSize);

// Printing mux info separately, if combined, nothing is displayed
char* l_muxPath = i_i2cInfo.i2cMuxPath.toString();
TRACFCOMP(g_trac_nvdimm, ERR_MRK"nvdimmWriteData(): "
"muxSelector=0x%X, muxPath=%s",
i_i2cInfo.i2cMuxBusSelector,
l_muxPath);
free(l_muxPath);
l_muxPath = nullptr;

// commit original retryable error with new err PLID
err_retryable->plid(err->plid());
TRACFCOMP(g_trac_nvdimm, "nvdimmWriteData(): Committing saved "
Expand All @@ -1101,7 +1133,7 @@ errlHndl_t nvdimmWriteData( TARGETING::Target * i_target,
else
{
// Since we eventually succeeded, delete original retryable error
TRACFCOMP(g_trac_nvdimm, "nvdimmWriteData(): Op successful, "
TRACUCOMP(g_trac_nvdimm, "nvdimmWriteData(): Op successful, "
"deleting saved retryable err eid=0x%X, plid=0x%X",
err_retryable->eid(), err_retryable->plid());

Expand Down

0 comments on commit a501159

Please sign in to comment.