PEL: Add ability to create event logs
There are cases where the PEL code wants to be able to create OpenBMC
event logs (and thus PELs) for problems it encounters when trying to
create or import other PELs. For example, if the host were to send down
a malformed PEL, this code would like to create a new event log and
capture part of that bad PEL in the new PEL for debug purposes, as the
malformed PEL cannot be reported anywhere since it is malformed.
To handle this, create the EventLogger class that provides a log()
function that allows the PEL extension code to create OpenBMC event logs
(and thus PELs) from within.
The underlying function to do the event log creating is passed in via
the constructor so that it can be changed for testing.
The sd_event_add_defer function (wrapped by sdeventplus) is used to
dispatch the creation of a single event, so that the entry point is from
the event loop. If there are still events left on the queue after that,
then they will be also be scheduled with sd_event_add_defer so that the
events are always created from event loop calls.
EventLogger does not allow events to be added to the queue if it is
being done from within the creation function so that the code can't
get stuck in a loop of creating a new event every time an event is
created.
Signed-off-by: Matt Spinler <spinler@us.ibm.com>
Change-Id: I6a9062074dc62cfb6043139ff0a9f3dfcd06c708
diff --git a/extensions/openpower-pels/entry_points.cpp b/extensions/openpower-pels/entry_points.cpp
index 5c6e714..f5ef40c 100644
--- a/extensions/openpower-pels/entry_points.cpp
+++ b/extensions/openpower-pels/entry_points.cpp
@@ -15,6 +15,7 @@
*/
#include "data_interface.hpp"
#include "elog_entry.hpp"
+#include "event_logger.hpp"
#include "extensions.hpp"
#include "manager.hpp"
#include "pldm_interface.hpp"
@@ -30,6 +31,10 @@
void pelStartup(internal::Manager& logManager)
{
+ EventLogger::LogFunction logger = std::bind(
+ std::mem_fn(&internal::Manager::create), &logManager,
+ std::placeholders::_1, std::placeholders::_2, std::placeholders::_3);
+
std::unique_ptr<DataInterfaceBase> dataIface =
std::make_unique<DataInterface>(logManager.getBus());
@@ -37,10 +42,12 @@
std::unique_ptr<HostInterface> hostIface = std::make_unique<PLDMInterface>(
logManager.getBus().get_event(), *(dataIface.get()));
- manager = std::make_unique<Manager>(logManager, std::move(dataIface),
- std::move(hostIface));
+ manager =
+ std::make_unique<Manager>(logManager, std::move(dataIface),
+ std::move(logger), std::move(hostIface));
#else
- manager = std::make_unique<Manager>(logManager, std::move(dataIface));
+ manager = std::make_unique<Manager>(logManager, std::move(dataIface),
+ std::move(logger));
#endif
}
diff --git a/extensions/openpower-pels/event_logger.hpp b/extensions/openpower-pels/event_logger.hpp
new file mode 100644
index 0000000..b4df0d4
--- /dev/null
+++ b/extensions/openpower-pels/event_logger.hpp
@@ -0,0 +1,187 @@
+#pragma once
+
+#include "additional_data.hpp"
+#include "elog_entry.hpp"
+
+#include <phosphor-logging/log.hpp>
+#include <queue>
+#include <sdeventplus/event.hpp>
+#include <sdeventplus/source/event.hpp>
+#include <tuple>
+
+namespace openpower::pels
+{
+
+/**
+ * @class EventLogger
+ *
+ * This class handles creating OpenBMC event logs (and thus PELs) from
+ * within the PEL extension code.
+ *
+ * The function to actually create the event log is passed in via the
+ * constructor so that different functions can be used when testing.
+ *
+ * To create the event log, call log() with the appropriate arguments
+ * and the log will be created as soon as the flow gets back to the event
+ * loop. If the queue isn't empty after a log is created, the next
+ * one will be scheduled to be created from the event loop again.
+ *
+ * This class does not allow new events to be added while inside the
+ * creation function, because if the code added an event log every time
+ * it tried to create one, it would do so infinitely.
+ */
+class EventLogger
+{
+ public:
+ using ADMap = std::map<std::string, std::string>;
+ using LogFunction = std::function<void(
+ const std::string&, phosphor::logging::Entry::Level, const ADMap&)>;
+
+ static constexpr size_t msgPos = 0;
+ static constexpr size_t levelPos = 1;
+ static constexpr size_t adPos = 2;
+ using EventEntry = std::tuple<std::string, phosphor::logging::Entry::Level,
+ AdditionalData>;
+
+ EventLogger() = delete;
+ ~EventLogger() = default;
+ EventLogger(const EventLogger&) = delete;
+ EventLogger& operator=(const EventLogger&) = delete;
+ EventLogger(EventLogger&&) = delete;
+ EventLogger& operator=(EventLogger&&) = delete;
+
+ /**
+ * @brief Constructor
+ *
+ * @param[in] event - The sd_event object
+ * @param[in] creator - The function to use to create the event log
+ */
+ EventLogger(sd_event* event, LogFunction creator) :
+ _event(event), _creator(creator)
+ {
+ }
+
+ /**
+ * @brief Adds an event to the queue so that it will be created
+ * as soon as the code makes it back to the event loop.
+ *
+ * Won't add it to the queue if already inside the create()
+ * callback.
+ *
+ * @param[in] message - The message property of the event log
+ * @param[in] severity - The severity level of the event log
+ * @param[in] ad - The additional data property of the event log
+ */
+ void log(const std::string& message,
+ phosphor::logging::Entry::Level severity, const AdditionalData& ad)
+ {
+ if (!_inEventCreation)
+ {
+ _eventsToCreate.emplace(message, severity, ad);
+
+ if (!_eventSource)
+ {
+ scheduleCreate();
+ }
+ }
+ else
+ {
+ phosphor::logging::log<phosphor::logging::level::INFO>(
+ "Already in event create callback, skipping new create",
+ phosphor::logging::entry("ERROR_NAME=%s", message.c_str()));
+ }
+ }
+
+ /**
+ * @brief Returns the event log queue size.
+ *
+ * @return size_t - The queue size
+ */
+ size_t queueSize() const
+ {
+ return _eventsToCreate.size();
+ }
+
+ /**
+ * @brief Schedules the create() function to run using the
+ * 'defer' sd_event source.
+ */
+ void scheduleCreate()
+ {
+ _eventSource = std::make_unique<sdeventplus::source::Defer>(
+ _event, std::bind(std::mem_fn(&EventLogger::create), this,
+ std::placeholders::_1));
+ }
+
+ private:
+ /**
+ * @brief Creates an event log and schedules the next one if
+ * there is one.
+ *
+ * This gets called from the event loop by the sd_event code.
+ *
+ * @param[in] source - The event source object used
+ */
+ void create(sdeventplus::source::EventBase& source)
+ {
+ _eventSource.reset();
+
+ if (_eventsToCreate.empty())
+ {
+ return;
+ }
+
+ auto event = _eventsToCreate.front();
+ _eventsToCreate.pop();
+
+ _inEventCreation = true;
+
+ try
+ {
+ _creator(std::get<msgPos>(event), std::get<levelPos>(event),
+ std::get<adPos>(event).getData());
+ }
+ catch (std::exception& e)
+ {
+ phosphor::logging::log<phosphor::logging::level::ERR>(
+ "EventLogger's create function threw an exception",
+ phosphor::logging::entry("ERROR=%s", e.what()));
+ }
+
+ _inEventCreation = false;
+
+ if (!_eventsToCreate.empty())
+ {
+ scheduleCreate();
+ }
+ }
+
+ /**
+ * @brief The sd_event object.
+ */
+ sdeventplus::Event _event;
+
+ /**
+ * @brief The user supplied function to create the event log.
+ */
+ LogFunction _creator;
+
+ /**
+ * @brief Keeps track of if an event is currently being created.
+ *
+ * Guards against creating new events while creating events.
+ */
+ bool _inEventCreation = false;
+
+ /**
+ * @brief The event source object used for scheduling.
+ */
+ std::unique_ptr<sdeventplus::source::Defer> _eventSource;
+
+ /**
+ * @brief The queue of event logs to create.
+ */
+ std::queue<EventEntry> _eventsToCreate;
+};
+
+} // namespace openpower::pels
diff --git a/extensions/openpower-pels/manager.hpp b/extensions/openpower-pels/manager.hpp
index 14904a9..bec67ca 100644
--- a/extensions/openpower-pels/manager.hpp
+++ b/extensions/openpower-pels/manager.hpp
@@ -3,6 +3,7 @@
#include "config.h"
#include "data_interface.hpp"
+#include "event_logger.hpp"
#include "host_notifier.hpp"
#include "log_manager.hpp"
#include "paths.hpp"
@@ -40,11 +41,16 @@
*
* @param[in] logManager - internal::Manager object
* @param[in] dataIface - The data interface object
+ * @param[in] creatorFunc - The function that EventLogger will
+ * use for creating event logs
*/
Manager(phosphor::logging::internal::Manager& logManager,
- std::unique_ptr<DataInterfaceBase> dataIface) :
+ std::unique_ptr<DataInterfaceBase> dataIface,
+ EventLogger::LogFunction creatorFunc) :
PELInterface(logManager.getBus(), OBJ_LOGGING),
- _logManager(logManager), _repo(getPELRepoPath()),
+ _logManager(logManager),
+ _eventLogger(logManager.getBus().get_event(), std::move(creatorFunc)),
+ _repo(getPELRepoPath()),
_registry(getMessageRegistryPath() / message::registryFileName),
_dataIface(std::move(dataIface))
{
@@ -55,12 +61,15 @@
*
* @param[in] logManager - internal::Manager object
* @param[in] dataIface - The data interface object
+ * @param[in] creatorFunc - The function that EventLogger will
+ * use for creating event logs
* @param[in] hostIface - The hostInterface object
*/
Manager(phosphor::logging::internal::Manager& logManager,
std::unique_ptr<DataInterfaceBase> dataIface,
+ EventLogger::LogFunction creatorFunc,
std::unique_ptr<HostInterface> hostIface) :
- Manager(logManager, std::move(dataIface))
+ Manager(logManager, std::move(dataIface), std::move(creatorFunc))
{
_hostNotifier = std::make_unique<HostNotifier>(
_repo, *(_dataIface.get()), std::move(hostIface));
@@ -204,6 +213,12 @@
phosphor::logging::internal::Manager& _logManager;
/**
+ * @brief Handles creating event logs/PELs from within
+ * the PEL extension code
+ */
+ EventLogger _eventLogger;
+
+ /**
* @brief The PEL repository object
*/
Repository _repo;
diff --git a/test/openpower-pels/Makefile.include b/test/openpower-pels/Makefile.include
index a700a50..09eb36b 100644
--- a/test/openpower-pels/Makefile.include
+++ b/test/openpower-pels/Makefile.include
@@ -4,6 +4,7 @@
additional_data_test \
ascii_string_test \
bcd_time_test \
+ event_logger_test \
extended_user_header_test \
failing_mtms_test \
fru_identity_test \
@@ -353,3 +354,11 @@
$(test_ldadd) \
$(top_builddir)/extensions/openpower-pels/json_utils.o
json_utils_test_LDFLAGS = $(test_ldflags)
+
+event_logger_test_SOURCES = \
+ %reldir%/event_logger_test.cpp
+event_logger_test_CPPFLAGS = $(test_cppflags)
+event_logger_test_CXXFLAGS = $(test_cxxflags) $(SDEVENTPLUS_CFLAGS)
+event_logger_test_LDADD = \
+ $(test_ldadd)
+event_logger_test_LDFLAGS = $(test_ldflags) $(SDEVENTPLUS_LIBS)
diff --git a/test/openpower-pels/event_logger_test.cpp b/test/openpower-pels/event_logger_test.cpp
new file mode 100644
index 0000000..1a4d8fc
--- /dev/null
+++ b/test/openpower-pels/event_logger_test.cpp
@@ -0,0 +1,126 @@
+/**
+ * Copyright © 2019 IBM Corporation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#include "extensions/openpower-pels/event_logger.hpp"
+#include "log_manager.hpp"
+
+#include <gtest/gtest.h>
+
+using namespace openpower::pels;
+using namespace phosphor::logging;
+
+class CreateHelper
+{
+ public:
+ void create(const std::string& name, Entry::Level level,
+ const EventLogger::ADMap& ad)
+ {
+ _createCount++;
+ _prevName = name;
+ _prevLevel = level;
+ _prevAD = ad;
+
+ // Try to create another event from within the creation
+ // function. Should never work or else we could get stuck
+ // infinitely creating events.
+ if (_eventLogger)
+ {
+ AdditionalData d;
+ _eventLogger->log(name, level, d);
+ }
+ }
+
+ size_t _createCount = 0;
+ std::string _prevName;
+ Entry::Level _prevLevel;
+ EventLogger::ADMap _prevAD;
+ EventLogger* _eventLogger = nullptr;
+};
+
+void runEvents(sd_event* event, size_t numEvents)
+{
+ sdeventplus::Event e{event};
+
+ for (size_t i = 0; i < numEvents; i++)
+ {
+ e.run(std::chrono::milliseconds(1));
+ }
+}
+
+TEST(EventLoggerTest, TestCreateEvents)
+{
+ sd_event* sdEvent = nullptr;
+ auto r = sd_event_default(&sdEvent);
+ ASSERT_TRUE(r >= 0);
+
+ CreateHelper ch;
+
+ EventLogger eventLogger(
+ sdEvent, std::bind(std::mem_fn(&CreateHelper::create), &ch,
+ std::placeholders::_1, std::placeholders::_2,
+ std::placeholders::_3));
+
+ ch._eventLogger = &eventLogger;
+
+ AdditionalData ad;
+ ad.add("key1", "value1");
+
+ eventLogger.log("one", Entry::Level::Error, ad);
+ EXPECT_EQ(eventLogger.queueSize(), 1);
+
+ runEvents(sdEvent, 1);
+
+ // Verify 1 event was created
+ EXPECT_EQ(eventLogger.queueSize(), 0);
+ EXPECT_EQ(ch._prevName, "one");
+ EXPECT_EQ(ch._prevLevel, Entry::Level::Error);
+ EXPECT_EQ(ch._prevAD, ad.getData());
+ EXPECT_EQ(ch._createCount, 1);
+
+ // Create 2 more, and run 1 event loop at a time and check the results
+ eventLogger.log("two", Entry::Level::Error, ad);
+ eventLogger.log("three", Entry::Level::Error, ad);
+
+ EXPECT_EQ(eventLogger.queueSize(), 2);
+
+ runEvents(sdEvent, 1);
+
+ EXPECT_EQ(ch._createCount, 2);
+ EXPECT_EQ(ch._prevName, "two");
+ EXPECT_EQ(eventLogger.queueSize(), 1);
+
+ runEvents(sdEvent, 1);
+ EXPECT_EQ(ch._createCount, 3);
+ EXPECT_EQ(ch._prevName, "three");
+ EXPECT_EQ(eventLogger.queueSize(), 0);
+
+ // Add them all again and run them all at once
+ eventLogger.log("three", Entry::Level::Error, ad);
+ eventLogger.log("two", Entry::Level::Error, ad);
+ eventLogger.log("one", Entry::Level::Error, ad);
+ runEvents(sdEvent, 3);
+
+ EXPECT_EQ(ch._createCount, 6);
+ EXPECT_EQ(ch._prevName, "one");
+ EXPECT_EQ(eventLogger.queueSize(), 0);
+
+ // Run extra events - doesn't do anything
+ runEvents(sdEvent, 1);
+ EXPECT_EQ(ch._createCount, 6);
+ EXPECT_EQ(ch._prevName, "one");
+ EXPECT_EQ(eventLogger.queueSize(), 0);
+
+ sd_event_unref(sdEvent);
+}
diff --git a/test/openpower-pels/pel_manager_test.cpp b/test/openpower-pels/pel_manager_test.cpp
index 08124ff..28802f4 100644
--- a/test/openpower-pels/pel_manager_test.cpp
+++ b/test/openpower-pels/pel_manager_test.cpp
@@ -67,6 +67,11 @@
return std::nullopt;
}
+void eventLoggerStub(const std::string&, phosphor::logging::Entry::Level,
+ const EventLogger::ADMap&)
+{
+}
+
// Test that using the RAWPEL=<file> with the Manager::create() call gets
// a PEL saved in the repository.
TEST_F(ManagerTest, TestCreateWithPEL)
@@ -74,7 +79,8 @@
std::unique_ptr<DataInterfaceBase> dataIface =
std::make_unique<DataInterface>(bus);
- openpower::pels::Manager manager{logManager, std::move(dataIface)};
+ openpower::pels::Manager manager{logManager, std::move(dataIface),
+ eventLoggerStub};
// Create a PEL, write it to a file, and pass that filename into
// the create function.
@@ -141,13 +147,11 @@
registryFile << registry;
registryFile.close();
- auto bus = sdbusplus::bus::new_default();
- phosphor::logging::internal::Manager logManager(bus, "logging_path");
-
std::unique_ptr<DataInterfaceBase> dataIface =
std::make_unique<DataInterface>(logManager.getBus());
- openpower::pels::Manager manager{logManager, std::move(dataIface)};
+ openpower::pels::Manager manager{logManager, std::move(dataIface),
+ eventLoggerStub};
std::vector<std::string> additionalData;
std::vector<std::string> associations;
@@ -191,7 +195,7 @@
std::unique_ptr<DataInterfaceBase> dataIface =
std::make_unique<DataInterface>(bus);
- Manager manager{logManager, std::move(dataIface)};
+ Manager manager{logManager, std::move(dataIface), eventLoggerStub};
// Create a PEL, write it to a file, and pass that filename into
// the create function so there's one in the repo.