Use syslog for Redfish messages

Limitations were discovered after the journal was made persistent
that reduce the benefits of using it directly for persistent event
logs.

As an alternative, we will leave the journal volatile and use
rsyslog to persist only the event logs. This change switches
to the syslog files for Redfish event messages instead of looking
directly in the journal.

Tested:
Navigated to
"/redfish/v1/Systems/system/LogServices/EventLog/Entries"
and confirmed that all of the stored Event Log Entries are returned.

Change-Id: Ib0aebda68eb95bb171fccd208350c3d073787a13
Signed-off-by: Jason M. Bills <jason.m.bills@linux.intel.com>
diff --git a/redfish-core/lib/log_services.hpp b/redfish-core/lib/log_services.hpp
index 90182a1..c5eae83 100644
--- a/redfish-core/lib/log_services.hpp
+++ b/redfish-core/lib/log_services.hpp
@@ -291,6 +291,39 @@
     return true;
 }
 
+static bool getUniqueEntryID(const std::string &logEntry, std::string &entryID)
+{
+    static uint64_t prevTs = 0;
+    static int index = 0;
+    // Get the entry timestamp
+    uint64_t curTs = 0;
+    std::tm timeStruct = {};
+    std::istringstream entryStream(logEntry);
+    if (entryStream >> std::get_time(&timeStruct, "%Y-%m-%dT%H:%M:%S"))
+    {
+        curTs = std::mktime(&timeStruct);
+    }
+    // If the timestamp isn't unique, increment the index
+    if (curTs == prevTs)
+    {
+        index++;
+    }
+    else
+    {
+        // Otherwise, reset it
+        index = 0;
+    }
+    // Save the timestamp
+    prevTs = curTs;
+
+    entryID = std::to_string(curTs);
+    if (index > 0)
+    {
+        entryID += "_" + std::to_string(index);
+    }
+    return true;
+}
+
 static bool getTimestampFromID(crow::Response &res, const std::string &entryID,
                                uint64_t &timestamp, uint16_t &index)
 {
@@ -353,6 +386,31 @@
     return true;
 }
 
+static bool
+    getRedfishLogFiles(std::vector<std::filesystem::path> &redfishLogFiles)
+{
+    static const std::filesystem::path redfishLogDir = "/var/log";
+    static const std::string redfishLogFilename = "redfish";
+
+    // Loop through the directory looking for redfish log files
+    for (const std::filesystem::directory_entry &dirEnt :
+         std::filesystem::directory_iterator(redfishLogDir))
+    {
+        // If we find a redfish log file, save the path
+        std::string filename = dirEnt.path().filename();
+        if (boost::starts_with(filename, redfishLogFilename))
+        {
+            redfishLogFiles.emplace_back(redfishLogDir / filename);
+        }
+    }
+    // As the log files rotate, they are appended with a ".#" that is higher for
+    // the older logs. Since we don't expect more than 10 log files, we
+    // can just sort the list to get them in order from newest to oldest
+    std::sort(redfishLogFiles.begin(), redfishLogFiles.end());
+
+    return !redfishLogFiles.empty();
+}
+
 class SystemLogServiceCollection : public Node
 {
   public:
@@ -440,11 +498,25 @@
     }
 };
 
-static int fillEventLogEntryJson(const std::string &bmcLogEntryID,
-                                 const std::string_view &messageID,
-                                 sd_journal *journal,
-                                 nlohmann::json &bmcLogEntryJson)
+static int fillEventLogEntryJson(const std::string &logEntryID,
+                                 const std::string logEntry,
+                                 nlohmann::json &logEntryJson)
 {
+    // The redfish log format is "<Timestamp> <MessageId>,<MessageArgs>"
+    // Use split to separate the entry into its fields
+    std::vector<std::string> logEntryFields;
+    boost::split(logEntryFields, logEntry, boost::is_any_of(" ,"),
+                 boost::token_compress_on);
+    // We need at least a MessageId to be valid
+    if (logEntryFields.size() < 2)
+    {
+        return 1;
+    }
+    std::string &timestamp = logEntryFields[0];
+    std::string &messageID = logEntryFields[1];
+    std::string &messageArgsStart = logEntryFields[2];
+    std::size_t messageArgsSize = logEntryFields.size() - 2;
+
     // Get the Message from the MessageRegistry
     const message_registries::Message *message =
         message_registries::getMessage(messageID);
@@ -457,71 +529,46 @@
         severity = message->severity;
     }
 
-    // Get the MessageArgs from the journal entry by finding all of the
-    // REDFISH_MESSAGE_ARG_x fields
-    const void *data;
-    size_t length;
-    std::vector<std::string> messageArgs;
-    SD_JOURNAL_FOREACH_DATA(journal, data, length)
-    {
-        std::string_view field(static_cast<const char *>(data), length);
-        if (boost::starts_with(field, "REDFISH_MESSAGE_ARG_"))
-        {
-            // Get the Arg number from the field name
-            field.remove_prefix(sizeof("REDFISH_MESSAGE_ARG_") - 1);
-            if (field.empty())
-            {
-                continue;
-            }
-            int argNum = std::strtoul(field.data(), nullptr, 10);
-            if (argNum == 0)
-            {
-                continue;
-            }
-            // Get the Arg value after the "=" character.
-            field.remove_prefix(std::min(field.find("=") + 1, field.size()));
-            // Make sure we have enough space in messageArgs
-            if (argNum > messageArgs.size())
-            {
-                messageArgs.resize(argNum);
-            }
-            messageArgs[argNum - 1] = std::string(field);
-        }
-    }
+    // Get the MessageArgs from the log
+    boost::beast::span messageArgs(&messageArgsStart, messageArgsSize);
 
     // Fill the MessageArgs into the Message
-    for (size_t i = 0; i < messageArgs.size(); i++)
+    int i = 0;
+    for (const std::string &messageArg : messageArgs)
     {
-        std::string argStr = "%" + std::to_string(i + 1);
+        std::string argStr = "%" + std::to_string(++i);
         size_t argPos = msg.find(argStr);
         if (argPos != std::string::npos)
         {
-            msg.replace(argPos, argStr.length(), messageArgs[i]);
+            msg.replace(argPos, argStr.length(), messageArg);
         }
     }
 
-    // Get the Created time from the timestamp
-    std::string entryTimeStr;
-    if (!getEntryTimestamp(journal, entryTimeStr))
+    // Get the Created time from the timestamp. The log timestamp is in RFC3339
+    // format which matches the Redfish format except for the fractional seconds
+    // between the '.' and the '+', so just remove them.
+    std::size_t dot = timestamp.find_first_of(".");
+    std::size_t plus = timestamp.find_first_of("+");
+    if (dot != std::string::npos && plus != std::string::npos)
     {
-        return 1;
+        timestamp.erase(dot, plus - dot);
     }
 
     // Fill in the log entry with the gathered data
-    bmcLogEntryJson = {
+    logEntryJson = {
         {"@odata.type", "#LogEntry.v1_4_0.LogEntry"},
         {"@odata.context", "/redfish/v1/$metadata#LogEntry.LogEntry"},
         {"@odata.id",
-         "/redfish/v1/Systems/system/LogServices/EventLog/Entries/" +
-             bmcLogEntryID},
+         "/redfish/v1/Systems/system/LogServices/EventLog/Entries/#" +
+             logEntryID},
         {"Name", "System Event Log Entry"},
-        {"Id", bmcLogEntryID},
-        {"Message", msg},
-        {"MessageId", messageID},
+        {"Id", logEntryID},
+        {"Message", std::move(msg)},
+        {"MessageId", std::move(messageID)},
         {"MessageArgs", std::move(messageArgs)},
         {"EntryType", "Event"},
-        {"Severity", severity},
-        {"Created", std::move(entryTimeStr)}};
+        {"Severity", std::move(severity)},
+        {"Created", std::move(timestamp)}};
     return 0;
 }
 
@@ -571,59 +618,52 @@
 #ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
         nlohmann::json &logEntryArray = asyncResp->res.jsonValue["Members"];
         logEntryArray = nlohmann::json::array();
-        // Go through the journal and create a unique ID for each entry
-        sd_journal *journalTmp = nullptr;
-        int ret = sd_journal_open(&journalTmp, SD_JOURNAL_LOCAL_ONLY);
-        if (ret < 0)
-        {
-            BMCWEB_LOG_ERROR << "failed to open journal: " << strerror(-ret);
-            messages::internalError(asyncResp->res);
-            return;
-        }
-        std::unique_ptr<sd_journal, decltype(&sd_journal_close)> journal(
-            journalTmp, sd_journal_close);
-        journalTmp = nullptr;
+        // Go through the log files and create a unique ID for each entry
+        std::vector<std::filesystem::path> redfishLogFiles;
+        getRedfishLogFiles(redfishLogFiles);
         uint64_t entryCount = 0;
-        SD_JOURNAL_FOREACH(journal.get())
+
+        // Oldest logs are in the last file, so start there and loop backwards
+        for (size_t i = redfishLogFiles.size() - 1; i >= 0; i--)
         {
-            // Look for only journal entries that contain a REDFISH_MESSAGE_ID
-            // field
-            std::string_view messageID;
-            ret = getJournalMetadata(journal.get(), "REDFISH_MESSAGE_ID",
-                                     messageID);
-            if (ret < 0)
+            std::ifstream logStream(redfishLogFiles[i]);
+            if (!logStream.is_open())
             {
                 continue;
             }
 
-            entryCount++;
-            // Handle paging using skip (number of entries to skip from the
-            // start) and top (number of entries to display)
-            if (entryCount <= skip || entryCount > skip + top)
+            std::string logEntry;
+            while (std::getline(logStream, logEntry))
             {
-                continue;
-            }
+                entryCount++;
+                // Handle paging using skip (number of entries to skip from the
+                // start) and top (number of entries to display)
+                if (entryCount <= skip || entryCount > skip + top)
+                {
+                    continue;
+                }
 
-            std::string idStr;
-            if (!getUniqueEntryID(journal.get(), idStr))
-            {
-                continue;
-            }
+                std::string idStr;
+                if (!getUniqueEntryID(logEntry, idStr))
+                {
+                    continue;
+                }
 
-            logEntryArray.push_back({});
-            nlohmann::json &bmcLogEntry = logEntryArray.back();
-            if (fillEventLogEntryJson(idStr, messageID, journal.get(),
-                                      bmcLogEntry) != 0)
-            {
-                messages::internalError(asyncResp->res);
-                return;
+                logEntryArray.push_back({});
+                nlohmann::json &bmcLogEntry = logEntryArray.back();
+                if (fillEventLogEntryJson(idStr, logEntry, bmcLogEntry) != 0)
+                {
+                    messages::internalError(asyncResp->res);
+                    return;
+                }
             }
         }
         asyncResp->res.jsonValue["Members@odata.count"] = entryCount;
         if (skip + top < entryCount)
         {
             asyncResp->res.jsonValue["Members@odata.nextLink"] =
-                "/redfish/v1/Managers/bmc/LogServices/BmcLog/Entries?$skip=" +
+                "/redfish/v1/Systems/system/LogServices/EventLog/"
+                "Entries?$skip=" +
                 std::to_string(skip + top);
         }
 #else
@@ -772,57 +812,7 @@
         }
         const std::string &entryID = params[0];
 
-#ifndef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
-        // Convert the unique ID back to a timestamp to find the entry
-        uint64_t ts = 0;
-        uint16_t index = 0;
-        if (!getTimestampFromID(asyncResp->res, entryID, ts, index))
-        {
-            return;
-        }
-
-        sd_journal *journalTmp = nullptr;
-        int ret = sd_journal_open(&journalTmp, SD_JOURNAL_LOCAL_ONLY);
-        if (ret < 0)
-        {
-            BMCWEB_LOG_ERROR << "failed to open journal: " << strerror(-ret);
-            messages::internalError(asyncResp->res);
-            return;
-        }
-        std::unique_ptr<sd_journal, decltype(&sd_journal_close)> journal(
-            journalTmp, sd_journal_close);
-        journalTmp = nullptr;
-        // Go to the timestamp in the log and move to the entry at the index
-        ret = sd_journal_seek_realtime_usec(journal.get(), ts);
-        for (int i = 0; i <= index; i++)
-        {
-            sd_journal_next(journal.get());
-        }
-        // Confirm that the entry ID matches what was requested
-        std::string idStr;
-        if (!getUniqueEntryID(journal.get(), idStr) || idStr != entryID)
-        {
-            messages::resourceMissingAtURI(asyncResp->res, entryID);
-            return;
-        }
-
-        // only use journal entries that contain a REDFISH_MESSAGE_ID field
-        std::string_view messageID;
-        ret =
-            getJournalMetadata(journal.get(), "REDFISH_MESSAGE_ID", messageID);
-        if (ret < 0)
-        {
-            messages::resourceNotFound(asyncResp->res, "LogEntry", "system");
-            return;
-        }
-
-        if (fillEventLogEntryJson(entryID, messageID, journal.get(),
-                                  asyncResp->res.jsonValue) != 0)
-        {
-            messages::internalError(asyncResp->res);
-            return;
-        }
-#else
+#ifdef BMCWEB_ENABLE_REDFISH_DBUS_LOG_ENTRIES
         // DBus implementation of EventLog/Entries
         // Make call to Logging Service to find all log entry objects
         crow::connections::systemBus->async_method_call(
@@ -900,7 +890,8 @@
                     {"Message", *message},
                     {"EntryType", "Event"},
                     {"Severity", translateSeverityDbusToRedfish(*severity)},
-                    {"Created", crow::utility::getDateTime(timestamp)}};
+                    { "Created",
+                      crow::utility::getDateTime(timestamp) }};
             },
             "xyz.openbmc_project.Logging",
             "/xyz/openbmc_project/logging/entry/" + entryID,