PEL: Add HostNotifier related debug traces

Add some debug traces that make it easier to debug issues in the code
paths that send PELs to the host.  They will only show up when the
journald conf files are modified to turn on debug journal entries.

Signed-off-by: Matt Spinler <spinler@us.ibm.com>
Change-Id: I1ad6b584bed8c6b58aee94ac2178c4d0b6e3e5d8
diff --git a/extensions/openpower-pels/host_notifier.cpp b/extensions/openpower-pels/host_notifier.cpp
index b268c9c..8760a8b 100644
--- a/extensions/openpower-pels/host_notifier.cpp
+++ b/extensions/openpower-pels/host_notifier.cpp
@@ -168,6 +168,8 @@
         return;
     }
 
+    log<level::DEBUG>("new PEL added to queue", entry("PEL_ID=0x%X", pel.id()));
+
     _pelQueue.push_back(pel.id());
 
     // Notify shouldn't happen if host is down or full
@@ -284,6 +286,10 @@
         {
             auto size = static_cast<size_t>(
                 std::filesystem::file_size((*attributes).get().path));
+
+            log<level::DEBUG>("sendNewLogCmd", entry("PEL_ID=0x%X", id),
+                              entry("PEL_SIZE=%d", size));
+
             auto rc = _hostIface->sendNewLogCmd(id, size);
 
             if (rc == CmdStatus::success)
@@ -314,10 +320,14 @@
 
     if (hostUp && !_pelQueue.empty())
     {
+        log<level::DEBUG>("Host state change to on");
+
         doNewLogNotify();
     }
     else if (!hostUp)
     {
+        log<level::DEBUG>("Host state change to off");
+
         stopCommand();
 
         // Reset the state on any PELs that were sent but not acked back
@@ -344,6 +354,8 @@
 
     if (status == ResponseStatus::success)
     {
+        log<level::DEBUG>("HostNotifier command response success",
+                          entry("PEL_ID=0x%X", id));
         _retryCount = 0;
 
         _sentPELs.push_back(id);
@@ -379,6 +391,7 @@
 
 void HostNotifier::hostFullTimerExpired()
 {
+    log<level::DEBUG>("Host full timer expired, trying send again");
     doNewLogNotify();
 }
 
@@ -422,6 +435,8 @@
     {
         _hostFull = false;
 
+        log<level::DEBUG>("Host previously full, not anymore after this ack");
+
         // Start sending PELs again, from the event loop
         if (!_pelQueue.empty())
         {
@@ -454,6 +469,7 @@
     // host is full is from this timer callback.
     if (!_hostFullTimer.isEnabled())
     {
+        log<level::DEBUG>("Starting host full timer");
         _hostFullTimer.restartOnce(_hostIface->getHostFullRetryDelay());
     }
 }
diff --git a/extensions/openpower-pels/manager.cpp b/extensions/openpower-pels/manager.cpp
index 4eb6772..2e6a07e 100644
--- a/extensions/openpower-pels/manager.cpp
+++ b/extensions/openpower-pels/manager.cpp
@@ -112,6 +112,9 @@
 
         try
         {
+            log<level::DEBUG>("Adding external PEL to repo",
+                              entry("PEL_ID=0x%X", pel->id()));
+
             _repo.add(pel);
         }
         catch (std::exception& e)
@@ -149,6 +152,9 @@
 {
     std::vector<uint8_t> data;
 
+    log<level::DEBUG>("Adding PEL from ESEL",
+                      entry("OBMC_LOG_ID=%d", obmcLogID));
+
     try
     {
         data = std::move(eselToRawData(esel));
@@ -256,6 +262,8 @@
     Repository::LogID id{Repository::LogID::Pel(pelID)};
     std::optional<int> fd;
 
+    log<level::DEBUG>("getPEL", entry("PEL_ID=0x%X", pelID));
+
     try
     {
         fd = _repo.getPELFD(id);
@@ -294,6 +302,8 @@
     Repository::LogID id{Repository::LogID::Obmc(obmcLogID)};
     std::optional<std::vector<uint8_t>> data;
 
+    log<level::DEBUG>("getPELFromOBMCID", entry("OBMC_LOG_ID=%d", obmcLogID));
+
     try
     {
         data = _repo.getPELData(id);
@@ -315,6 +325,8 @@
 {
     Repository::LogID id{Repository::LogID::Pel(pelID)};
 
+    log<level::DEBUG>("HostAck", entry("PEL_ID=0x%X", pelID));
+
     if (!_repo.hasPEL(id))
     {
         throw common_error::InvalidArgument();
@@ -330,6 +342,9 @@
 {
     Repository::LogID id{Repository::LogID::Pel(pelID)};
 
+    log<level::DEBUG>("HostReject", entry("PEL_ID=0x%X", pelID),
+                      entry("REASON=%d", static_cast<int>(reason)));
+
     if (!_repo.hasPEL(id))
     {
         throw common_error::InvalidArgument();
diff --git a/extensions/openpower-pels/repository.cpp b/extensions/openpower-pels/repository.cpp
index 3bf3cb0..2de3ee9 100644
--- a/extensions/openpower-pels/repository.cpp
+++ b/extensions/openpower-pels/repository.cpp
@@ -168,10 +168,19 @@
     auto pel = findPEL(id);
     if (pel != _pelAttributes.end())
     {
+        log<level::DEBUG>("Removing PEL from repository",
+                          entry("PEL_ID=0x%X", pel->first.pelID.id),
+                          entry("OBMC_LOG_ID=%d", pel->first.obmcID.id));
         fs::remove(pel->second.path);
         _pelAttributes.erase(pel);
 
-        processDeleteCallbacks(id.pelID.id);
+        processDeleteCallbacks(pel->first.pelID.id);
+    }
+    else
+    {
+        log<level::DEBUG>("Could not find PEL to remove",
+                          entry("PEL_ID=0x%X", id.pelID.id),
+                          entry("OBMC_LOG_ID=%d", id.obmcID.id));
     }
 }