PEL: Track PEL creation time for debug
Track how long it takes to create the PEL portion of an event by saving
it as journal metadata. It's only viewable with journalctl options like
'-o verbose'. This can be used for debug and to help when trying to
improve PEL creation performance.
Also move down the trace where this is logged until after the PEL D-Bus
interfaces are updated.
Tested:
Can see the new field:
MESSAGE=Created PEL 0x50000048 (BMC ID 72) with SRC BD55400C
ID=0x50000048
BMCID=72
PEL_CREATE_DURATION=181
Change-Id: I165901f49a229eacf66be76d79972240a41aa155
Signed-off-by: Matt Spinler <spinler@us.ibm.com>
diff --git a/extensions/openpower-pels/manager.cpp b/extensions/openpower-pels/manager.cpp
index ad69720bf..3315044 100644
--- a/extensions/openpower-pels/manager.cpp
+++ b/extensions/openpower-pels/manager.cpp
@@ -369,6 +369,7 @@
const std::map<std::string, std::string>& additionalData,
const std::vector<std::string>& /*associations*/, const FFDCEntries& ffdc)
{
+ auto start = std::chrono::steady_clock::now();
auto entry = _registry.lookup(message, rg::LookupType::name);
auto pelFFDC = convertToPelFFDC(ffdc);
AdditionalData ad{additionalData};
@@ -407,19 +408,6 @@
scheduleRepoPrune();
}
- auto src = pel->primarySRC();
- if (src)
- {
- auto asciiString = (*src)->asciiString();
- while (asciiString.back() == ' ')
- {
- asciiString.pop_back();
- }
- lg2::info("Created PEL {ID} (BMC ID {BMCID}) with SRC {SRC}", "ID",
- lg2::hex, pel->id(), "BMCID", pel->obmcLogID(), "SRC",
- asciiString);
- }
-
// Check for severity 0x51 and update boot progress SRC
updateProgressSRC(pel);
@@ -433,6 +421,22 @@
serializeLogEntry(obmcLogID);
createPELEntry(obmcLogID);
+ auto src = pel->primarySRC();
+ if (src)
+ {
+ auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(
+ std::chrono::steady_clock::now() - start);
+
+ auto asciiString = (*src)->asciiString();
+ while (asciiString.back() == ' ')
+ {
+ asciiString.pop_back();
+ }
+ lg2::info("Created PEL {ID} (BMC ID {BMCID}) with SRC {SRC}", "ID",
+ lg2::hex, pel->id(), "BMCID", pel->obmcLogID(), "SRC",
+ asciiString, "PEL_CREATE_DURATION", duration.count());
+ }
+
// Check if firmware should quiesce system due to error
checkPelAndQuiesce(pel);
}