Use MonotonicTimeStamp for bmc log id

/redfish/v1/Managers/bmc/LogServices/Journal/Entries gives the system
journal entries whose ID is based on the realtime timestmap. However,
the system realtime may go backward if the system time is changed either
manually or via NTP.

If that happens, those entries may not found via redfish GET as
`sd_journal_seek_realtime_usec()`[1] may not always work on the entries
which are not sorted in time-order.

This may cause the inconsistency between the content of
`/redfish/v1/Managers/bmc/LogServices/Journal/Entries/`
and /redfish/v1/Managers/bmc/LogServices/Journal/Entries/<bmc_journal_id>`.

For example,

```
sudo journalctl --vacuum-time=1s
<wait for a while to clear up journal>

date -s "<backward-time>"

date -s "<forward-time>"
```

Run redfish journal entries and get each entry id from the output

```
curl -k -X GET https://${bmc}/redfish/v1/Managers/bmc/LogServices/Journal/Entries > rj.out
```

Take some logEntry Id that its time going backward like
```
grep "@odata.id" rj.out
```

Run redfish query for each id, and some of them can't be successful.
```
% curl -k -X GET https://${bmc}/redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701604800002075
{
  "error": {
    "@Message.ExtendedInfo": [
      {
        "@odata.type": "#Message.v1_1_1.Message",
        "Message": "The requested resource of type LogEntry named '1701604800002075' was not found.",
        "MessageArgs": [
          "LogEntry",
          "1701604800002075"
        ],
        "MessageId": "Base.1.13.0.ResourceNotFound",
        "MessageSeverity": "Critical",
        "Resolution": "Provide a valid resource identifier and resubmit the request."
      }
    ],
    "code": "Base.1.13.0.ResourceNotFound",
    "message": "The requested resource of type LogEntry named '1701604800002075' was not found."
  }
}%

```

This can also be verified by checking the failure of Redfish Validator run
```
python3 RedfishServiceValidator.py --auth Session -i https://${bmc} -u admin -p 0penBmc0  --payload Tree /redfish/v1/Managers/bmc/LogServices/Journal/Entries
```

For example,
```
ERROR - Members: GET of resource at URI /redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701604800002075 returned HTTP error. Check URI.
ERROR - Members: GET of resource at URI /redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701604800065949 returned HTTP error. Check URI.
ERROR - Members: GET of resource at URI /redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701607680003048 returned HTTP error. Check URI.
```

```
--Time goes backwrd
        {
            "@odata.id": "/redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701604800002075",
            "@odata.type": "#LogEntry.v1_9_0.LogEntry",
            "Created": "2023-12-03T12:00:00+00:00",
            "EntryType": "Oem",
            "Id": "1701604800002075",
            "Message": "systemd-resolved: Clock change detected. Flushing caches.",
            "Name": "BMC Journal Entry",
            "OemRecordFormat": "BMC Journal Entry",
            "Severity": "OK"
        },
...
        {
            "@odata.id": "/redfish/v1/Managers/bmc/LogServices/Journal/Entries/1701607680003048",
            "@odata.type": "#LogEntry.v1_9_0.LogEntry",
            "Created": "2023-12-03T12:48:00+00:00",
            "EntryType": "Oem",
            "Id": "1701607680003048",
            "Message": "systemd-resolved: Clock change detected. Flushing caches.",
            "Name": "BMC Journal Entry",
            "OemRecordFormat": "BMC Journal Entry",
            "Severity": "OK"
        },
-- Time comes back to the previous moment
```

The solution is proposed to use <bootid> + <monototic timestamp> as the
redfish journal entry id instead of realtime timestamp.
Unlike realtime timestamp which may go backward, <monotonic timestamp>
is monotonically increasing.

Tested:
- Redfish Validator passes
- GET Journal Entry ID will be found even if its time goes backward.

[1] https://github.com/openbmc/bmcweb/blob/7164bc62dd26ec92b01985aaae97ecc48276dea5/redfish-core/lib/log_services.hpp#L2690

Change-Id: I83bfb1ed88c9cf036f594757aa4a00d2709dd196
Signed-off-by: Myung Bae <myungbae@us.ibm.com>

1 files changed, 61 insertions, 17 deletions

diff --git a/redfish-core/lib/log_services.hpp b/redfish-core/lib/log_services.hpp
index 5354f0a4c9..e634191151 100644
--- a/redfish-core/lib/log_services.hpp
+++ b/redfish-core/lib/log_services.hpp
@@ -31,6 +31,7 @@
 #include "utils/dbus_utils.hpp"
 #include "utils/time_utils.hpp"
 
+#include <systemd/sd-id128.h>
 #include <systemd/sd-journal.h>
 #include <tinyxml2.h>
 #include <unistd.h>
@@ -171,23 +172,27 @@ inline static bool getUniqueEntryID(sd_journal* journal, std::string& entryID,
                                     const bool firstEntry = true)
 {
     int ret = 0;
+    static sd_id128_t prevBootID{};
     static uint64_t prevTs = 0;
     static int index = 0;
     if (firstEntry)
     {
+        prevBootID = {};
         prevTs = 0;
     }
 
     // Get the entry timestamp
     uint64_t curTs = 0;
-    ret = sd_journal_get_realtime_usec(journal, &curTs);
+    sd_id128_t curBootID{};
+    ret = sd_journal_get_monotonic_usec(journal, &curTs, &curBootID);
     if (ret < 0)
     {
         BMCWEB_LOG_ERROR("Failed to read entry timestamp: {}", strerror(-ret));
         return false;
     }
-    // If the timestamp isn't unique, increment the index
-    if (curTs == prevTs)
+    // If the timestamp isn't unique on the same boot, increment the index
+    bool sameBootIDs = sd_id128_equal(curBootID, prevBootID) != 0;
+    if (sameBootIDs && (curTs == prevTs))
     {
         index++;
     }
@@ -196,10 +201,19 @@ inline static bool getUniqueEntryID(sd_journal* journal, std::string& entryID,
         // Otherwise, reset it
         index = 0;
     }
+
+    if (!sameBootIDs)
+    {
+        // Save the bootID
+        prevBootID = curBootID;
+    }
     // Save the timestamp
     prevTs = curTs;
 
-    entryID = std::to_string(curTs);
+    // make entryID as <bootID>_<timestamp>[_<index>]
+    std::array<char, SD_ID128_STRING_MAX> bootIDStr{};
+    sd_id128_to_string(curBootID, bootIDStr.data());
+    entryID = std::format("{}_{}", bootIDStr.data(), curTs);
     if (index > 0)
     {
         entryID += "_" + std::to_string(index);
@@ -246,25 +260,52 @@ static bool getUniqueEntryID(const std::string& logEntry, std::string& entryID,
     return true;
 }
 
+// Entry is formed like "BootID_timestamp" or "BootID_timestamp_index"
 inline static bool
     getTimestampFromID(const std::shared_ptr<bmcweb::AsyncResp>& asyncResp,
-                       const std::string& entryID, uint64_t& timestamp,
-                       uint64_t& index)
+                       const std::string& entryID, sd_id128_t& bootID,
+                       uint64_t& timestamp, uint64_t& index)
 {
     if (entryID.empty())
     {
         return false;
     }
-    // Convert the unique ID back to a timestamp to find the entry
-    std::string_view tsStr(entryID);
 
-    auto underscorePos = tsStr.find('_');
-    if (underscorePos != std::string_view::npos)
+    // Convert the unique ID back to a bootID + timestamp to find the entry
+    std::string_view entryIDStrView(entryID);
+    auto underscore1Pos = entryIDStrView.find('_');
+    if (underscore1Pos == std::string_view::npos)
+    {
+        // EntryID has no bootID or timestamp
+        messages::resourceNotFound(asyncResp->res, "LogEntry", entryID);
+        return false;
+    }
+
+    // EntryID has bootID + timestamp
+
+    // Convert entryIDViewString to BootID
+    // NOTE: bootID string which needs to be null-terminated for
+    // sd_id128_from_string()
+    std::string bootIDStr(entryID, 0, underscore1Pos);
+    if (sd_id128_from_string(bootIDStr.c_str(), &bootID) < 0)
+    {
+        messages::resourceNotFound(asyncResp->res, "LogEntry", entryID);
+        return false;
+    }
+
+    // Get the timestamp from entryID
+    std::string_view timestampStrView = entryIDStrView;
+    timestampStrView.remove_prefix(underscore1Pos + 1);
+
+    // Check the index in timestamp
+    auto underscore2Pos = timestampStrView.find('_');
+    if (underscore2Pos != std::string_view::npos)
     {
         // Timestamp has an index
-        tsStr.remove_suffix(tsStr.size() - underscorePos);
-        std::string_view indexStr(entryID);
-        indexStr.remove_prefix(underscorePos + 1);
+        timestampStrView.remove_suffix(timestampStrView.size() -
+                                       underscore2Pos);
+        std::string_view indexStr(timestampStrView);
+        indexStr.remove_prefix(underscore2Pos + 1);
         auto [ptr, ec] = std::from_chars(indexStr.begin(), indexStr.end(),
                                          index);
         if (ec != std::errc())
@@ -273,8 +314,10 @@ inline static bool
             return false;
         }
     }
-    // Timestamp has no index
-    auto [ptr, ec] = std::from_chars(tsStr.begin(), tsStr.end(), timestamp);
+
+    // Now timestamp has no index
+    auto [ptr, ec] = std::from_chars(timestampStrView.begin(),
+                                     timestampStrView.end(), timestamp);
     if (ec != std::errc())
     {
         messages::resourceNotFound(asyncResp->res, "LogEntry", entryID);
@@ -2665,9 +2708,10 @@ inline void requestRoutesBMCJournalLogEntry(App& app)
             return;
         }
         // Convert the unique ID back to a timestamp to find the entry
+        sd_id128_t bootID{};
         uint64_t ts = 0;
         uint64_t index = 0;
-        if (!getTimestampFromID(asyncResp, entryID, ts, index))
+        if (!getTimestampFromID(asyncResp, entryID, bootID, ts, index))
         {
             return;
         }
@@ -2687,7 +2731,7 @@ inline void requestRoutesBMCJournalLogEntry(App& app)
         // index tracking the unique ID
         std::string idStr;
         bool firstEntry = true;
-        ret = sd_journal_seek_realtime_usec(journal.get(), ts);
+        ret = sd_journal_seek_monotonic_usec(journal.get(), bootID, ts);
         if (ret < 0)
         {
             BMCWEB_LOG_ERROR("failed to seek to an entry in journal{}",