Restructure Redfish EventLog Transmit code flow

In the current implementation:
 1. When Event service is disabled and enabled back after a while,
    all the logs during this time span between disable to enable
    are dumped to the Event listener.
 2. When two(or more) events occur very close (in terms of
    microseconds) and they trigger multiple iNotify events,
    the listener receives all of these events with the same
    Event ID.

This occurs as the last log timestamp read from redfish file
and previous time stamp used to generate Event ID's are not
being updated continuously.

This commit fixes this issue by tweaking the logic to continuously
update the time stamp values (even when Event Service is disabled),
and also replaces multiple string operations with file operations.
i.e. Instead of looping through the entire Redfish file until last
timestamp read is reached, this fix makes use of seekg to get to
the last read position.

Tested:
  - Subscribed to an event and successfully received Event Logs.
  - No Event Logs were received when Event Service was disabled.
  - No Dump of past Events after Event Service was enabled.
  - Redfish Validator passed

Change-Id: Id8407ff7e9fc48e7810c9193ef43f707b9615c36
Signed-off-by: P Dheeraj Srujan Kumar <p.dheeraj.srujan.kumar@intel.com>
Signed-off-by: Ankita Vilas Gawade <ankita.gawade@intel.com>

1 files changed, 50 insertions, 42 deletions

diff --git a/redfish-core/include/event_service_manager.hpp b/redfish-core/include/event_service_manager.hpp
index eb076c97e5..92349cca97 100644
--- a/redfish-core/include/event_service_manager.hpp
+++ b/redfish-core/include/event_service_manager.hpp
@@ -127,15 +127,10 @@ static const Message* formatMessage(const std::string_view& messageID)
 
 namespace event_log
 {
-inline bool getUniqueEntryID(const std::string& logEntry, std::string& entryID,
-                             const bool firstEntry = true)
+inline bool getUniqueEntryID(const std::string& logEntry, std::string& entryID)
 {
     static time_t prevTs = 0;
     static int index = 0;
-    if (firstEntry)
-    {
-        prevTs = 0;
-    }
 
     // Get the entry timestamp
     std::time_t curTs = 0;
@@ -580,7 +575,7 @@ class EventServiceManager
         initConfig();
     }
 
-    std::string lastEventTStr;
+    std::streampos redfishLogFilePosition{0};
     size_t noOfEventLogSubscribers{0};
     size_t noOfMetricReportSubscribers{0};
     std::shared_ptr<sdbusplus::bus::match::match> matchTelemetryMonitor;
@@ -657,10 +652,9 @@ class EventServiceManager
             updateNoOfSubscribersCount();
 
 #ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
-            if (lastEventTStr.empty())
-            {
-                cacheLastEventTimestamp();
-            }
+
+            cacheRedfishLogFile();
+
 #endif
             // Update retry configuration.
             subValue->updateRetryConfig(retryAttempts, retryTimeoutInterval);
@@ -912,9 +906,9 @@ class EventServiceManager
         }
 
 #ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
-        if (lastEventTStr.empty())
+        if (redfishLogFilePosition != 0)
         {
-            cacheLastEventTimestamp();
+            cacheRedfishLogFile();
         }
 #endif
         // Update retry configuration.
@@ -1064,9 +1058,20 @@ class EventServiceManager
     }
 
 #ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
-    void cacheLastEventTimestamp()
+
+    void resetRedfishFilePosition()
     {
-        lastEventTStr.clear();
+        // Control would be here when Redfish file is created.
+        // Reset File Position as new file is created
+        redfishLogFilePosition = 0;
+
+        return;
+    }
+
+    void cacheRedfishLogFile()
+    {
+        // Open the redfish file and read till the last record.
+
         std::ifstream logStream(redfishEventLogFile);
         if (!logStream.good())
         {
@@ -1076,25 +1081,14 @@ class EventServiceManager
         std::string logEntry;
         while (std::getline(logStream, logEntry))
         {
-            size_t space = logEntry.find_first_of(' ');
-            if (space == std::string::npos)
-            {
-                // Shouldn't enter here but lets skip it.
-                BMCWEB_LOG_DEBUG << "Invalid log entry found.";
-                continue;
-            }
-            lastEventTStr = logEntry.substr(0, space);
+            redfishLogFilePosition = logStream.tellg();
         }
-        BMCWEB_LOG_DEBUG << "Last Event time stamp set: " << lastEventTStr;
+
+        BMCWEB_LOG_DEBUG << "Next Log Position : " << redfishLogFilePosition;
     }
 
     void readEventLogsFromFile()
     {
-        if (!serviceEnabled || !noOfEventLogSubscribers)
-        {
-            BMCWEB_LOG_DEBUG << "EventService disabled or no Subscriptions.";
-            return;
-        }
         std::ifstream logStream(redfishEventLogFile);
         if (!logStream.good())
         {
@@ -1104,27 +1098,29 @@ class EventServiceManager
 
         std::vector<EventLogObjectsType> eventRecords;
 
-        bool startLogCollection = false;
-        bool firstEntry = true;
-
         std::string logEntry;
+
+        // Get the read pointer to the next log to be read.
+        logStream.seekg(redfishLogFilePosition);
+
         while (std::getline(logStream, logEntry))
         {
-            if (!startLogCollection && !lastEventTStr.empty())
+            // Update Pointer position
+            redfishLogFilePosition = logStream.tellg();
+
+            std::string idStr;
+            if (!event_log::getUniqueEntryID(logEntry, idStr))
             {
-                if (boost::starts_with(logEntry, lastEventTStr))
-                {
-                    startLogCollection = true;
-                }
                 continue;
             }
 
-            std::string idStr;
-            if (!event_log::getUniqueEntryID(logEntry, idStr, firstEntry))
+            if (!serviceEnabled || !noOfEventLogSubscribers)
             {
+                // If Service is not enabled, no need to compute
+                // the remaining items below.
+                // But, Loop must continue to keep track of Timestamp
                 continue;
             }
-            firstEntry = false;
 
             std::string timestamp;
             std::string messageID;
@@ -1145,11 +1141,23 @@ class EventServiceManager
                 continue;
             }
 
-            lastEventTStr = timestamp;
             eventRecords.emplace_back(idStr, timestamp, messageID, registryName,
                                       messageKey, messageArgs);
         }
 
+        if (!serviceEnabled || !noOfEventLogSubscribers)
+        {
+            BMCWEB_LOG_DEBUG << "EventService disabled or no Subscriptions.";
+            return;
+        }
+
+        if (eventRecords.empty())
+        {
+            // No Records to send
+            BMCWEB_LOG_DEBUG << "No log entries available to be transferred.";
+            return;
+        }
+
         for (const auto& it : this->subscriptionsMap)
         {
             std::shared_ptr<Subscription> entry = it.second;
@@ -1227,7 +1235,7 @@ class EventServiceManager
                             }
 
                             EventServiceManager::getInstance()
-                                .cacheLastEventTimestamp();
+                                .resetRedfishFilePosition();
                             EventServiceManager::getInstance()
                                 .readEventLogsFromFile();
                         }