Integrate LogService core framework and add more detail to exception …

…messsages (#680) * Adding better logging to the core framework * Added CFRLogger (core framework version of (DS|CM)Logger to the core framework for logging messages we want to be exposed outside of the framework. Initialization is performed in the CoreBundleContext (which is also where the shared_ptr for the CFRLogger exists). * Added bundle locations and id (where missing) to exception messages. * Added log messages before and after dlopen()/LoadLibrary() * Made usLogService header-only * No longer creates a shared library (similar to cm) Signed-off-by: The MathWorks, Inc. <alchrist@mathworks.com>
CppMicroServices · Jun 16, 2022 · 25472c5 · 25472c5
1 parent 6822e8e
commit 25472c5
Show file tree

Hide file tree

Showing 18 changed files with 542 additions and 149 deletions.
diff --git a/compendium/ConfigurationAdmin/CMakeLists.txt b/compendium/ConfigurationAdmin/CMakeLists.txt
@@ -43,7 +43,7 @@ usMacroCreateBundle(ConfigurationAdmin
   SYMBOLIC_NAME configuration_admin
   EMBED_RESOURCE_METHOD LINK
   PRIVATE_INCLUDE_DIRS src/util src/service src/bundle ../third_party
-  LINK_LIBRARIES ${_link_libraries} usLogService usAsyncWorkService
+  LINK_LIBRARIES ${_link_libraries} usAsyncWorkService
   PUBLIC_HEADERS ${_ca_public_headers}
   PRIVATE_HEADERS ${_ca_private_headers}
   SOURCES $<TARGET_OBJECTS:ConfigurationAdminObjs> src/CMActivator.cpp

diff --git a/compendium/DeclarativeServices/CMakeLists.txt b/compendium/DeclarativeServices/CMakeLists.txt
@@ -44,7 +44,7 @@ usMacroCreateBundle(DeclarativeServices
   TARGET DeclarativeServices
   SYMBOLIC_NAME declarative_services
   EMBED_RESOURCE_METHOD LINK
-  LINK_LIBRARIES ${_link_libraries} usLogService usServiceComponent usAsyncWorkService
+  LINK_LIBRARIES ${_link_libraries} usServiceComponent usAsyncWorkService
   PRIVATE_HEADERS ${_ds_private_headers}
   SOURCES $<TARGET_OBJECTS:DeclarativeServicesObjs> src/SCRActivator.cpp
   BINARY_RESOURCES manifest.json

diff --git a/compendium/DeclarativeServices/src/manager/BundleLoader.cpp b/compendium/DeclarativeServices/src/manager/BundleLoader.cpp
@@ -36,6 +36,26 @@
 
 namespace cppmicroservices {
 namespace scrimpl {
+namespace {
+/**
+ * @brief Convert parameter to string
+ * 
+ * @tparam T type of the value to convert to a string
+ * @param val value to convert to a string
+ * @return std::string the value converted to a string
+ */
+template<typename T>
+std::string ToString(T val)
+{
+#if defined(__ANDROID__)
+  std::ostringstream os;
+  os << val;
+  return os.str();
+#else
+  return std::to_string(val);
+#endif
+}
+}
 
 #if defined(_WIN32)
 /**
@@ -60,8 +80,10 @@ std::wstring UTF8StrToWStr(const std::string& inStr)
 
 std::tuple<std::function<ComponentInstance*(void)>,
            std::function<void(ComponentInstance*)>>
-GetComponentCreatorDeletors(const std::string& compName,
-                            const cppmicroservices::Bundle& fromBundle)
+GetComponentCreatorDeletors(
+  const std::string& compName,
+  const cppmicroservices::Bundle& fromBundle,
+  const std::shared_ptr<cppmicroservices::logservice::LogService>& logger)
 {
   // cannot use bundle id as key because id is reused when the framework is restarted.
   // strings are not optimal but will work fine as long as a binary is not unloaded
@@ -78,7 +100,15 @@ GetComponentCreatorDeletors(const std::string& compName,
     try {
       auto ctx = fromBundle.GetBundleContext();
       auto opts = ctx.GetProperty(Constants::LIBRARY_LOAD_OPTIONS);
+      logger->Log(logservice::SeverityLevel::LOG_INFO,
+                  "Loading shared library for Bundle #" +
+                    ToString(fromBundle.GetBundleId()) +
+                    " (location=" + bundleLoc + ")");
       sh.Load(any_cast<int>(opts));
+      logger->Log(logservice::SeverityLevel::LOG_INFO,
+                  "Finished loading shared library for Bundle #" +
+                    ToString(fromBundle.GetBundleId()) +
+                    " (location=" + bundleLoc + ")");
     } catch (const std::system_error& ex) {
       // SharedLibrary::Load() will throw a std::system_error when a shared library
       // fails to load. Creating a SharedLibraryException here to throw with fromBundle information.

diff --git a/compendium/DeclarativeServices/src/manager/BundleLoader.hpp b/compendium/DeclarativeServices/src/manager/BundleLoader.hpp
@@ -24,6 +24,7 @@
 #define __BUNDLELOADER_HPP__
 
 #include "ConcurrencyUtil.hpp"
+#include "cppmicroservices/logservice/LogService.hpp"
 #include "cppmicroservices/servicecomponent/detail/ComponentInstance.hpp"
 #include <map>
 
@@ -40,6 +41,7 @@ namespace scrimpl {
  *
  * \param compName is a unique identifier for the component
  * \param fromBundle is the bundle where the component is located
+ * \param logger the logger to use for logging messages
  *
  * \throws \c cppmicroservices::SharedLibraryException on failure to load the bundle binary.
  *         \c std::runtime_error if the entry points for \c compName are
@@ -49,8 +51,10 @@ namespace scrimpl {
  */
 std::tuple<std::function<ComponentInstance*(void)>,
            std::function<void(ComponentInstance*)>>
-GetComponentCreatorDeletors(const std::string& compName,
-                            const cppmicroservices::Bundle& fromBundle);
+GetComponentCreatorDeletors(
+  const std::string& compName,
+  const cppmicroservices::Bundle& fromBundle,
+  const std::shared_ptr<cppmicroservices::logservice::LogService>& logger);
 }
 }
 #endif /* __BUNDLELOADER_HPP__ */
diff --git a/compendium/DeclarativeServices/src/manager/ComponentConfigurationImpl.cpp b/compendium/DeclarativeServices/src/manager/ComponentConfigurationImpl.cpp
@@ -23,9 +23,9 @@
 #include "cppmicroservices/FrameworkFactory.h"
 #include "cppmicroservices/SecurityException.h"
 
-#include "ComponentConfigurationImpl.hpp"
 #include "../ConfigurationListenerImpl.hpp"
 #include "BundleLoader.hpp"
+#include "ComponentConfigurationImpl.hpp"
 #include "ComponentManager.hpp"
 #include "ConfigurationManager.hpp"
 #include "ReferenceManager.hpp"
@@ -393,7 +393,7 @@ bool ComponentConfigurationImpl::Modified()
 
 ComponentState ComponentConfigurationImpl::GetConfigState() const
 {
-   return GetState()->GetValue();
+  return GetState()->GetValue();
 }
 
 bool ComponentConfigurationImpl::CompareAndSetState(
@@ -426,7 +426,7 @@ void ComponentConfigurationImpl::LoadComponentCreatorDestructor()
     }
 
     std::tie(newCompInstanceFunc, deleteCompInstanceFunc) =
-      GetComponentCreatorDeletors(compName, GetBundle());
+      GetComponentCreatorDeletors(compName, GetBundle(), logger);
   }
 }
 
@@ -444,10 +444,11 @@ ComponentConfigurationImpl::CreateAndActivateComponentInstanceHelper(
 {
   Any func = this->bundle.GetBundleContext().GetProperty(
     cppmicroservices::Constants::FRAMEWORK_BUNDLE_VALIDATION_FUNC);
-  
+
   try {
-    if (!func.Empty() && !any_cast<std::function<bool(const cppmicroservices::Bundle&)>>(
-                           func)(this->bundle)) {
+    if (!func.Empty() &&
+        !any_cast<std::function<bool(const cppmicroservices::Bundle&)>>(func)(
+          this->bundle)) {
       std::string errMsg("Bundle at location ");
       errMsg += this->bundle.GetLocation();
       errMsg += " failed bundle validation.";
@@ -456,8 +457,9 @@ ComponentConfigurationImpl::CreateAndActivateComponentInstanceHelper(
   } catch (const cppmicroservices::SecurityException&) {
     throw;
   } catch (...) {
-    throw SecurityException{ "The bundle validation callback threw an exception",
-                             this->bundle };
+    throw SecurityException{
+      "The bundle validation callback threw an exception", this->bundle
+    };
   }
 
   auto componentInstance = CreateComponentInstance();

diff --git a/compendium/DeclarativeServices/test/TestComponentConfigurationImpl.cpp b/compendium/DeclarativeServices/test/TestComponentConfigurationImpl.cpp
@@ -23,6 +23,8 @@
 #include <random>
 
 #include "../src/SCRAsyncWorkService.hpp"
+#include "../src/SCRLogger.hpp"
+#include "../src/manager/BundleLoader.hpp"
 #include "../src/manager/BundleOrPrototypeComponentConfiguration.hpp"
 #include "../src/manager/ComponentConfigurationImpl.hpp"
 #include "../src/manager/ReferenceManager.hpp"
@@ -845,13 +847,15 @@ TEST_F(ComponentConfigurationImplTest, VerifyStateChangeWithSvcRefAndConfig)
   // a service reference and a config object dependency will trigger a state change
   // when the config object is satisfied before the config object change listener is
   // registered.
-  mockMetadata->serviceMetadata.interfaces = { us_service_interface_iid<dummy::Reference1>() };
+  mockMetadata->serviceMetadata.interfaces = {
+    us_service_interface_iid<dummy::Reference1>()
+  };
   scrimpl::metadata::ReferenceMetadata refMetadata{};
   refMetadata.interfaceName = "cppmicroservices::scrimpl::dummy::ServiceImpl";
   mockMetadata->refsMetadata.push_back(refMetadata);
   mockMetadata->configurationPolicy = "require";
-  mockMetadata->configurationPids = {"foo"};
-  
+  mockMetadata->configurationPids = { "foo" };
+
   auto fakeLogger = std::make_shared<FakeLogger>();
   auto asyncWorkService =
     std::make_shared<cppmicroservices::scrimpl::SCRAsyncWorkService>(
@@ -867,38 +871,47 @@ TEST_F(ComponentConfigurationImplTest, VerifyStateChangeWithSvcRefAndConfig)
     notifier,
     std::make_shared<std::vector<std::shared_ptr<ComponentManager>>>());
 
-  auto fakeBundleProtoCompConfig = std::make_shared<BundleOrPrototypeComponentConfigurationImpl>(
-    mockMetadata,
-    GetFramework(),
-    std::make_shared<MockComponentRegistry>(),
-    fakeLogger,
-    notifier,
-    std::make_shared<std::vector<std::shared_ptr<ComponentManager>>>());
+  auto fakeBundleProtoCompConfig =
+    std::make_shared<BundleOrPrototypeComponentConfigurationImpl>(
+      mockMetadata,
+      GetFramework(),
+      std::make_shared<MockComponentRegistry>(),
+      fakeLogger,
+      notifier,
+      std::make_shared<std::vector<std::shared_ptr<ComponentManager>>>());
+
+  auto svcReg =
+    GetFramework().GetBundleContext().RegisterService<dummy::ServiceImpl>(
+      std::make_shared<dummy::ServiceImpl>());
 
-  auto svcReg = GetFramework().GetBundleContext().RegisterService<dummy::ServiceImpl>(std::make_shared<dummy::ServiceImpl>());
-
   // update config object to satisfy component configuration
   test::InstallAndStartConfigAdmin(GetFramework().GetBundleContext());
-  auto svcRef = GetFramework().GetBundleContext().GetServiceReference<cppmicroservices::service::cm::ConfigurationAdmin>();
+  auto svcRef =
+    GetFramework()
+      .GetBundleContext()
+      .GetServiceReference<cppmicroservices::service::cm::ConfigurationAdmin>();
   ASSERT_TRUE(svcRef);
   auto configAdminSvc = GetFramework().GetBundleContext().GetService(svcRef);
   ASSERT_TRUE(configAdminSvc);
   auto fooConfig = configAdminSvc->GetConfiguration("foo");
-  cppmicroservices::AnyMap configData(cppmicroservices::AnyMap::UNORDERED_MAP_CASEINSENSITIVE_KEYS);
-  configData["bar"] = std::string{"baz"};
+  cppmicroservices::AnyMap configData(
+    cppmicroservices::AnyMap::UNORDERED_MAP_CASEINSENSITIVE_KEYS);
+  configData["bar"] = std::string{ "baz" };
   // update the config object before calling fakeCompConfig->Initialize(), which simulates the config object
   // being updated before the ComponentConfigurationImpl has a chance to setup config change listeners.
   ASSERT_NO_THROW(fooConfig->UpdateIfDifferent(configData).second.get());
 
   // Initialize should set the component state to Satisfied, even if the config object update was missed
   // by the config object change listener.
   fakeCompConfig->Initialize();
-  EXPECT_EQ(cppmicroservices::service::component::runtime::dto::ComponentState::SATISFIED,
-      fakeCompConfig->GetConfigState());
+  EXPECT_EQ(cppmicroservices::service::component::runtime::dto::ComponentState::
+              SATISFIED,
+            fakeCompConfig->GetConfigState());
 
   fakeBundleProtoCompConfig->Initialize();
-  EXPECT_EQ(cppmicroservices::service::component::runtime::dto::ComponentState::SATISFIED,
-      fakeBundleProtoCompConfig->GetConfigState());
+  EXPECT_EQ(cppmicroservices::service::component::runtime::dto::ComponentState::
+              SATISFIED,
+            fakeBundleProtoCompConfig->GetConfigState());
 
   fakeCompConfig->Deactivate();
   fakeCompConfig->Stop();
@@ -907,5 +920,104 @@ TEST_F(ComponentConfigurationImplTest, VerifyStateChangeWithSvcRefAndConfig)
   svcReg.Unregister();
   svcReg = nullptr;
 }
+
+#if !defined(__MINGW32__)
+// Note: This is different than the other tests in this suite as Declarative Services is actually
+// installed and started rather than using mocks.
+TEST(ComponentConfigurationImplLogTest, LoadLibraryLogsMessagesImmediateTest)
+{
+  auto framework = cppmicroservices::FrameworkFactory().NewFramework();
+  framework.Start();
+  ASSERT_TRUE(framework);
+
+  auto context = framework.GetBundleContext();
+  ASSERT_TRUE(context);
+
+  test::InstallAndStartDS(context);
+
+  // The logger should receive 2 Log() calls from creating the SCRBundleExtension and 2 from the
+  // code which actually calls SharedLibrary::Load()
+  //
+  // The logger is created and registered before InstallAndStartBundle since it done after, it would
+  // miss the log messages.
+  auto logger = std::make_shared<MockLogger>();
+
+  // Because we are actually installing DS and creating the logger before installing and starting
+  // the bundle (since it is immediate), there are 2 other log messages that are sent. They pertain
+  // to creating and having created the SCRBundleExtension. If that expectation is not set, the test
+  // fails.
+  EXPECT_CALL(*logger, Log(logservice::SeverityLevel::LOG_DEBUG, ::testing::_))
+    .Times(2);
+  // This expectation is for the actual info log messages pertaining to loading of the shared
+  // library.
+  EXPECT_CALL(*logger, Log(logservice::SeverityLevel::LOG_INFO, ::testing::_))
+    .Times(2);
+
+  auto loggerReg = context.RegisterService<logservice::LogService>(logger);
+
+  // TestBundleDSTOI1 is immediate=true so the call to InstallAndStart should cause the shared
+  // library for the bundle to be loaded. This should in turn log 4 (2 regarding shared library
+  // loading) messages with the log service.
+  //
+  // NOTE: TestBundleDSTOI1 cannot be used in the test since a previously ran test already installed
+  // it. The DS runtime service is a singleton so even though a new framework is used, DS remembers
+  // which bundles were already installed. This means that when this test tried to load
+  // TestBundleDSTOI1, it did not actually call SharedLibrary::Load(), hence the test failed.
+  // TestBundleDSTOI3 is now used as it has not been previously installed.
+  test::InstallAndStartBundle(context, "TestBundleDSTOI3");
+
+  loggerReg.Unregister();
+
+  framework.Stop();
+  framework.WaitForStop(std::chrono::milliseconds::zero());
+}
+
+// Note: This is different than the other tests in this suite as Declarative Services is actually
+// installed and started rather than using mocks.
+TEST(ComponentConfigurationImplLogTest, LoadLibraryLogsMessagesNotImmediateTest)
+{
+  auto framework = cppmicroservices::FrameworkFactory().NewFramework();
+  framework.Start();
+  ASSERT_TRUE(framework);
+
+  auto context = framework.GetBundleContext();
+  ASSERT_TRUE(context);
+
+  test::InstallAndStartDS(context);
+
+  // TestBundleDSTOI14 is immediate=false so this InstallAndStart should not
+  // load the library until GetService is called. The logger is created after
+  // this InstallAndStart so in the event that the log messages for loading the
+  // shared library are sent when the library is loaded, the test will fail.
+  test::InstallAndStartBundle(context, "TestBundleDSTOI14");
+
+  // The logger should receive 2 Log() calls from the code which actually invokes
+  // SharedLibrary::Load()
+  //
+  // The logger is registered after InstallAndStartBundle in this case to prove that
+  // for non-immediate DS bundles, the log messages are sent when the library is actually
+  // loaded (i.e., when a call to GetService is made for an interface implemented by
+  // the bundle).
+  auto logger = std::make_shared<MockLogger>();
+
+  // This expectation is for the actual info log messages pertaining to loading of
+  // the shared library.
+  EXPECT_CALL(*logger, Log(logservice::SeverityLevel::LOG_INFO, ::testing::_))
+    .Times(2);
+
+  auto loggerReg = context.RegisterService<logservice::LogService>(logger);
+
+  // The call to GetService should cause the library to be loaded, thus sending
+  // the 2 expected log messages.
+  auto sRef = context.GetServiceReference<test::Interface1>();
+  ASSERT_TRUE(sRef);
+  (void)context.GetService<test::Interface1>(sRef);
+
+  loggerReg.Unregister();
+
+  framework.Stop();
+  framework.WaitForStop(std::chrono::milliseconds::zero());
+}
+#endif
 }
 }
diff --git a/compendium/DeclarativeServices/test/TestSharedLibraryException.cpp b/compendium/DeclarativeServices/test/TestSharedLibraryException.cpp
@@ -34,6 +34,7 @@ limitations under the License.
 
 #include "../src/manager/BundleLoader.hpp"
 
+#include "Mocks.hpp"
 #include "TestInterfaces/Interfaces.hpp"
 #include "TestUtils.hpp"
 
@@ -83,7 +84,9 @@ TEST_F(SharedLibraryExceptionTest, testDSBundleLoaderFailure)
   // Using the framework bundle here, as it passes the GetLocation validity test,
   // but fails at dlopen.
   ASSERT_THROW(cppmicroservices::scrimpl::GetComponentCreatorDeletors(
-                 "invalid::name", GetFramework()),
+                 "invalid::name",
+                 GetFramework(),
+                 std::make_shared<cppmicroservices::scrimpl::FakeLogger>()),
                cppmicroservices::SharedLibraryException);
 }