Skip to content

Commit

Permalink
pdr: Add some FFDC for debugging
Browse files Browse the repository at this point in the history 
There is a intermittent issue that happens when we fail to send
a repo change event to HB after a PDR exchange and this scenario
is a one-off and is difficult to recreate manually. Adding these
traces will help to improve the FFDC and debugging.

The commit also made some changes to the code which was wrong in
1110 when compared to the 1060 branch.

Change-Id: I00f2226fb6a4f6a3cc2f49cd5aaa0d03230a8602
Signed-off-by: Pavithra Barithaya <[email protected]>
  • Loading branch information
@Pavithrab7
Pavithrab7 committed Oct 9, 2024
1 parent 0348897 commit 1c148a0
Show file tree
Hide file tree
Showing 5 changed files with 117 additions and 17 deletions.
19 changes: 13 additions & 6 deletions common/utils.cpp
View file
Original file line number Diff line number Diff line change
@@ -1,7 +1,10 @@
#include "utils.hpp"

#include "libpldm/platform.h"

#include <libpldm/pdr.h>
#include <libpldm/pldm_types.h>
#include <stdio.h>

#include <phosphor-logging/lg2.hpp>
#include <xyz/openbmc_project/Common/error.hpp>
Expand Down Expand Up @@ -555,16 +558,20 @@ void printBuffer(bool isTx, const std::vector<uint8_t>& buffer)
{
if (buffer.empty())
{
std::cerr << "Buffer is empty" << std::endl;
return;
}
else if (buffer[2] == PLDM_GET_PDR ||
buffer[2] == PLDM_PLATFORM_EVENT_MESSAGE)
{
std::cout << (isTx ? "Tx: " : "Rx: ");

std::cout << (isTx ? "Tx: " : "Rx: ");

std::ranges::for_each(buffer, [](uint8_t byte) {
std::cout << std::format("{:02x} ", byte);
});
std::ranges::for_each(buffer, [](uint8_t byte) {
std::cout << std::format("{:02x} ", byte);
});

std::cout << std::endl;
std::cout << std::endl;
}
}

std::string toString(const struct variable_field& var)
Expand Down
50 changes: 41 additions & 9 deletions host-bmc/host_pdr_handler.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
#include "dbus/serialize.hpp"

#include <assert.h>
#include <stdio.h>

#include <nlohmann/json.hpp>
#include <phosphor-logging/lg2.hpp>
Expand Down Expand Up @@ -191,9 +192,14 @@ void HostPDRHandler::setPresenceFrus()

void HostPDRHandler::fetchPDR(PDRRecordHandles&& recordHandles, uint8_t tid)
{
std::cerr << "Inside the fetchPDR in host-bmc with tid:" << tid
<< std::endl;
pdrRecordHandles.clear();
modifiedPDRRecordHandles.clear();

std::cerr << "isHostPDRModified flag is set to: " << std::boolalpha
<< isHostPdrModified << std::endl;

if (isHostPdrModified)
{
modifiedPDRRecordHandles = std::move(recordHandles);
Expand All @@ -208,13 +214,24 @@ void HostPDRHandler::fetchPDR(PDRRecordHandles&& recordHandles, uint8_t tid)
// Defer the actual fetch of PDRs from the host (by queuing the call on the
// main event loop). That way, we can respond to the platform event msg from
// the host firmware.
std::cerr << "Calling the deferred event" << std::endl;

pdrFetchEvent = std::make_unique<sdeventplus::source::Defer>(
event, std::bind(std::mem_fn(&HostPDRHandler::_fetchPDR), this,
std::placeholders::_1));
if (pdrFetchEvent)
{
std::cerr << "pdrFetchEvent is not null" << std::endl;
}
else
{
std::cerr << "PDRFetchEvent is null" << std::endl;
}
}

void HostPDRHandler::_fetchPDR(sdeventplus::source::EventBase& /*source*/)
{
std::cerr << "Calling getHostPDR" << std::endl;
getHostPDR();
}

Expand All @@ -231,18 +248,27 @@ void HostPDRHandler::getHostPDR(uint32_t nextRecordHandle)
{
recordHandle = modifiedPDRRecordHandles.front();
modifiedPDRRecordHandles.pop_front();
std::cerr << "RecordHandle assigned from modifiedHandles is : "
<< recordHandle << std::endl;
}
else if (!nextRecordHandle && (!pdrRecordHandles.empty()))
{
recordHandle = pdrRecordHandles.front();
pdrRecordHandles.pop_front();
std::cerr << "Recordhandle assigned from pdrRecordHandle is : "
<< recordHandle << std::endl;
}
else
{
recordHandle = nextRecordHandle;
std::cerr << "RecordHandle assigned to send request to: "
<< recordHandle << std::endl;
}
auto instanceId = instanceIdDb.next(mctp_eid);

std:
cerr << "Instance ID assigned to the PDr request is "
<< (unsigned)instanceId << std::endl;
auto rc = encode_get_pdr_req(instanceId, recordHandle, 0,
PLDM_GET_FIRSTPART, UINT16_MAX, 0, request,
PLDM_GET_PDR_REQ_BYTES);
Expand Down Expand Up @@ -713,6 +739,9 @@ void HostPDRHandler::processHostPDRs(mctp_eid_t /*eid*/,
if (terminus_locator_type ==
PLDM_TERMINUS_LOCATOR_TYPE_MCTP_EID)
{
std::cerr
<< "Got a terminus locator PDR with record handle "
<< rh << std::endl;
auto locatorValue = reinterpret_cast<
const pldm_terminus_locator_type_mctp_eid*>(
tlpdr->terminus_locator_value);
Expand Down Expand Up @@ -765,8 +794,14 @@ void HostPDRHandler::processHostPDRs(mctp_eid_t /*eid*/,
pldm_pdr_update_TL_pdr(repo, terminusHandle, tid, tlEid,
tlValid);

std::cerr << "the responseReceived flag is set to "
<< std::boolalpha << responseReceived
<< std::endl;
if (!isHostUp())
{
std::cerr
<< "Host is not up assign next record handle as 0"
<< std::endl;
// The terminus PDR becomes invalid when the terminus
// itself is down. We don't need to do PDR exchange in
// that case, so setting the next record handle to 0.
Expand Down Expand Up @@ -832,15 +867,6 @@ void HostPDRHandler::processHostPDRs(mctp_eid_t /*eid*/,
"Failed to add PDR when isHostPdrModified is not true");
}
}
else
{
rc = pldm_pdr_add_check(repo, pdr.data(), respCount,
true, pdrTerminusHandle, &rh);
if (rc)
{
throw std::runtime_error("Failed to add PDR");
}
}
}
}
}
Expand Down Expand Up @@ -884,6 +910,7 @@ void HostPDRHandler::processHostPDRs(mctp_eid_t /*eid*/,
entityAssociations.clear();

mergedHostParents = false;
info("the merged flag is set to : {MERGED}", "MERGED", merged);

if (merged)
{
Expand Down Expand Up @@ -922,6 +949,9 @@ void HostPDRHandler::_processPDRRepoChgEvent(
oemPlatformHandler->updateContainerID();
}
deferredPDRRepoChgEvent.reset();
info(
"Before sending repo change event the isHostPDRModified is set to: {FLAG}",
"FLAG", isHostPdrModified);
this->sendPDRRepositoryChgEvent(
std::move(std::vector<uint8_t>(1, PLDM_PDR_ENTITY_ASSOCIATION)),
FORMAT_IS_PDR_HANDLES);
Expand All @@ -941,6 +971,8 @@ void HostPDRHandler::_processFetchPDREvent(
nextRecordHandle = this->modifiedPDRRecordHandles.front();
this->modifiedPDRRecordHandles.pop_front();
}
std::cerr << "calling getHostPDR with next record handle: "
<< nextRecordHandle << std::endl;
this->getHostPDR(nextRecordHandle);
}

Expand Down
21 changes: 21 additions & 0 deletions libpldmresponder/platform.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@

#include <libpldm/entity.h>
#include <libpldm/state_set.h>
#include <stdio.h>

#include <phosphor-logging/lg2.hpp>

Expand Down Expand Up @@ -581,13 +582,15 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,
&dataOffset);
if (rc != PLDM_SUCCESS)
{
std::cerr << "decode repo change event failed" << std::endl;
return rc;
}

PDRRecordHandles pdrRecordHandles;

if (eventDataFormat == FORMAT_IS_PDR_TYPES)
{
std::cerr << "event data format is PDR_TYPES" << std::endl;
return PLDM_ERROR_INVALID_DATA;
}

Expand All @@ -606,17 +609,22 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,

if (rc != PLDM_SUCCESS)
{
std::cerr << "decode repo change record data failed"
<< std::endl;
return rc;
}

if (eventDataOperation == PLDM_RECORDS_ADDED ||
eventDataOperation == PLDM_RECORDS_MODIFIED)
{
std::cerr << "Got a added or modified event" << std::endl;
if (eventDataOperation == PLDM_RECORDS_MODIFIED)
{
info("Got a modified event from tid: {TID}", "TID", tid);
hostPDRHandler->isHostPdrModified = true;
hostPDRHandler->modifiedCounter += pdrRecordHandles.size();
info("Size of modified counter is: {MC}", "MC",
hostPDRHandler->modifiedCounter);
}

rc = getPDRRecordHandles(
Expand All @@ -628,6 +636,7 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,

if (rc != PLDM_SUCCESS)
{
std::cerr << "getPDRRecordHandles failed" << std::endl;
return rc;
}
}
Expand All @@ -636,6 +645,7 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,
changeRecordDataSize -=
dataOffset + (numberOfChangeEntries * sizeof(ChangeEntry));
}
std::cerr << "while loop exited" << std::endl;
}
if (hostPDRHandler)
{
Expand All @@ -656,6 +666,8 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,
terminusHandle);
}
}
std::cerr << "removed all remote pdrs of TID: " << (unsigned)tid
<< std::endl;
}
if (eventDataOperation == PLDM_RECORDS_DELETED)
{
Expand All @@ -669,6 +681,9 @@ int Handler::pldmPDRRepositoryChgEvent(const pldm_msg* request,
info(
"Got a records added/modified event from tid '{TID}' eventDataOperation is {ED}",
"TID", tid, "ED", eventDataOperation);
info(
"isHostPDRModified flag before we start fetching PDRs is set to: {FLAG}",
"FLAG", hostPDRHandler->isHostPdrModified);
hostPDRHandler->fetchPDR(std::move(pdrRecordHandles), tid);
}
}
Expand All @@ -683,12 +698,18 @@ int Handler::getPDRRecordHandles(const ChangeEntry* changeEntryData,
{
if (numberOfChangeEntries > (changeEntryDataSize / sizeof(ChangeEntry)))
{
info("Error in changeEntries number");
return PLDM_ERROR_INVALID_DATA;
}
for (size_t i = 0; i < numberOfChangeEntries; i++)
{
pdrRecordHandles.push_back(changeEntryData[i]);
}
for (const auto& i : pdrRecordHandles)
{
error("Record handles sent down to BMC: {PDR_REC_HNDL}", "PDR_REC_HNDL",
static_cast<unsigned>(i));
}

return PLDM_SUCCESS;
}
Expand Down
27 changes: 27 additions & 0 deletions requester/handler.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
#include "request.hpp"

#include <libpldm/base.h>
#include <stdio.h>
#include <sys/socket.h>

#include <phosphor-logging/lg2.hpp>
Expand Down Expand Up @@ -142,7 +143,10 @@ class Handler

void instanceIdExpiryCallBack(RequestKey key)
{
std::cerr << "inside instanceIdExpiryCallBack" << std::endl;
auto eid = key.eid;
auto command = key.command;
std::cerr << "key.command is: "(unsigned)command << std::endl;
if (this->handlers.contains(key))
{
info(
Expand All @@ -151,6 +155,7 @@ class Handler
(unsigned)key.instanceId);
auto& [request, responseHandler,
timerInstance] = this->handlers[key];
std::cerr << "Before calling stop()" << std::endl;
request->stop();
auto rc = timerInstance->stop();
if (rc)
Expand All @@ -168,11 +173,13 @@ class Handler
event, std::bind(&Handler::removeRequestEntry, this, key)));
endpointMessageQueues[eid]->activeRequest = false;

std::cerr << "Calling pollEndpointQueue after expiry" << std::endl;
/* try to send new request if the endpoint is free */
pollEndpointQueue(eid);
}
else
{
std::cerr << "asserting false" << std::endl;
// This condition is not possible, if a response is received
// before the instance ID expiry, then the response handler
// is executed and the entry will be removed.
Expand All @@ -186,9 +193,16 @@ class Handler
*/
int pollEndpointQueue(mctp_eid_t eid)
{
std::cerr << "Inside poll endpoint queue with eid: " << (unsigned)eid
<< std::endl;
if (endpointMessageQueues[eid]->activeRequest ||
endpointMessageQueues[eid]->requestQueue.empty())
{
std::cerr
<< "endpointMessageQueues[eid]->activeRequest is "
<< std::boolalpha << endpointMessageQueues[eid]->activeRequest
<< " or endpointMessageQueues[eid]->requestQueue.empty() returning success"
<< std::endl;
return PLDM_SUCCESS;
}

Expand All @@ -200,10 +214,13 @@ class Handler
pldmTransport, requestMsg->key.eid, event,
std::move(requestMsg->reqMsg), numRetries, responseTimeOut,
verbose);
std::cerr << "binding the instanceIdExpiryCallBack and starting timer"
<< std::endl;
auto timer = std::make_unique<sdbusplus::Timer>(
event.get(), std::bind(&Handler::instanceIdExpiryCallBack, this,
requestMsg->key));

std::cerr << "Calling start" << std::endl;
auto rc = request->start();
if (rc)
{
Expand Down Expand Up @@ -253,6 +270,10 @@ class Handler
ResponseHandler&& responseHandler)
{
RequestKey key{eid, instanceId, type, command};
std::cerr << "Inside Register request with eid " << (unsigned)eid
<< " instance ID: " << (unsigned)instanceId
<< " type: "(unsigned)type
<< " command: " << (unsigned)command << std::endl;

if (handlers.contains(key))
{
Expand All @@ -276,9 +297,15 @@ class Handler
std::make_shared<EndpointMessageQueue>(eid, reqQueue, false);
}

if (command == PLDM_GET_PDR)
{
std::cerr << "calling pollEndPointQueue with eid: " << (unsigned)eid
<< std::endl;
}
/* try to send new request if the endpoint is free */
pollEndpointQueue(eid);

std::cerr << "Returning success from register request" << std::endl;
return PLDM_SUCCESS;
}

Expand Down
Loading

0 comments on commit 1c148a0

Please sign in to comment.