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>
diff --git a/redfish-core/include/event_service_manager.hpp b/redfish-core/include/event_service_manager.hpp
index eb076c9..92349cc 100644
--- a/redfish-core/include/event_service_manager.hpp
+++ b/redfish-core/include/event_service_manager.hpp
@@ -127,15 +127,10 @@
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 @@
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 @@
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 @@
}
#ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
- if (lastEventTStr.empty())
+ if (redfishLogFilePosition != 0)
{
- cacheLastEventTimestamp();
+ cacheRedfishLogFile();
}
#endif
// Update retry configuration.
@@ -1064,9 +1058,20 @@
}
#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 @@
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 @@
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 @@
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 @@
}
EventServiceManager::getInstance()
- .cacheLastEventTimestamp();
+ .resetRedfishFilePosition();
EventServiceManager::getInstance()
.readEventLogsFromFile();
}