From 75e8e218cbf9539144ee8f6aea01e158d0a9e190 Mon Sep 17 00:00:00 2001 From: Myung Bae Date: Thu, 30 Nov 2023 12:53:46 -0800 Subject: 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/`. For example, ``` sudo journalctl --vacuum-time=1s date -s "" date -s "" ``` 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 + as the redfish journal entry id instead of realtime timestamp. Unlike realtime timestamp which may go backward, 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 --- test/redfish-core/lib/log_services_test.cpp | 69 +++++++++++++++++++++++++++++ 1 file changed, 69 insertions(+) create mode 100644 test/redfish-core/lib/log_services_test.cpp (limited to 'test') diff --git a/test/redfish-core/lib/log_services_test.cpp b/test/redfish-core/lib/log_services_test.cpp new file mode 100644 index 0000000000..4f7bedb72f --- /dev/null +++ b/test/redfish-core/lib/log_services_test.cpp @@ -0,0 +1,69 @@ +#include "app.hpp" +#include "async_resp.hpp" +#include "log_services.hpp" + +#include + +#include + +#include +#include + +#include +#include + +namespace redfish +{ +namespace +{ + +TEST(LogServicesBMCJouralTest, LogServicesBMCJouralGetReturnsError) +{ + auto shareAsyncResp = std::make_shared(); + sd_id128_t bootIDOut{}; + uint64_t timestampOut = 0; + uint64_t indexOut = 0; + uint64_t timestampIn = 1740970301UL; + std::string badBootIDStr = "78770392794344a29f81507f3ce5e"; + std::string goodBootIDStr = "78770392794344a29f81507f3ce5e78c"; + sd_id128_t goodBootID{}; + + // invalid test cases + EXPECT_FALSE(getTimestampFromID(shareAsyncResp, "", bootIDOut, timestampOut, + indexOut)); + EXPECT_FALSE(getTimestampFromID(shareAsyncResp, badBootIDStr, bootIDOut, + timestampOut, indexOut)); + EXPECT_FALSE(getTimestampFromID( + shareAsyncResp, std::format("{}_{}", badBootIDStr, timestampIn), + bootIDOut, timestampOut, indexOut)); + EXPECT_FALSE(getTimestampFromID( + shareAsyncResp, std::format("{}_{}", badBootIDStr, timestampIn), + bootIDOut, timestampOut, indexOut)); + + // obtain a goodBootID + EXPECT_GE(sd_id128_from_string(goodBootIDStr.c_str(), &goodBootID), 0); + + EXPECT_FALSE(getTimestampFromID( + shareAsyncResp, std::format("{}_{}", goodBootIDStr, "InvalidNum"), + bootIDOut, timestampOut, indexOut)); + + // Success cases + EXPECT_TRUE(getTimestampFromID( + shareAsyncResp, std::format("{}_{}", goodBootIDStr, timestampIn), + bootIDOut, timestampOut, indexOut)); + EXPECT_NE(sd_id128_equal(goodBootID, bootIDOut), 0); + EXPECT_EQ(timestampIn, timestampOut); + EXPECT_EQ(indexOut, 0); + + uint64_t indexIn = 1; + EXPECT_TRUE(getTimestampFromID( + shareAsyncResp, + std::format("{}_{}_{}", goodBootIDStr, timestampIn, indexIn), bootIDOut, + timestampOut, indexOut)); + EXPECT_NE(sd_id128_equal(goodBootID, bootIDOut), 0); + EXPECT_EQ(timestampIn, timestampOut); + EXPECT_EQ(indexOut, indexIn); +} + +} // namespace +} // namespace redfish -- cgit v1.2.3