Expand logging information when genericEvent is waiting

documents/framework.md

@@ -304,3 +304,4 @@ The following framework properties are supported:
 | CELIX_AUTO_INSTALL                                           | ""            | The bundles to install after the framework is started. Multiple bundles can be provided separated by a space.                                                                         |         
 | CELIX_LOGGING_DEFAULT_ACTIVE_LOG_LEVEL                       | "info"        | The default active log level for created log services. Possible values are "trace", "debug", "info", "warning", "error" and "fatal".                                                  |
 | CELIX_ALLOWED_PROCESSING_TIME_FOR_SCHEDULED_EVENT_IN_SECONDS | "2"           | The allowed processing time for scheduled events in seconds, if processing takes longer a warning message will be logged.                                                             |
+| CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS | "5" | The allowed processing time for generic events in seconds, if processing takes longer a warning message will be logged.                                                             |

libs/framework/gtest/config.properties.in

@@ -1,5 +1,4 @@
 {
     "LOGHELPER_ENABLE_STDOUT_FALLBACK":true,
-    "CELIX_FRAMEWORK_CLEAN_CACHE_DIR_ON_CREATE":true,
-    "CELIX_LOGGING_DEFAULT_ACTIVE_LOG_LEVEL":"warning"
+    "CELIX_FRAMEWORK_CLEAN_CACHE_DIR_ON_CREATE":true
 }

libs/framework/gtest/src/CelixFrameworkTestSuite.cc

@@ -89,31 +89,37 @@ TEST_F(CelixFrameworkTestSuite, TimedWaitEventQueueTest) {
 }
 
 TEST_F(CelixFrameworkTestSuite, GenericEventTimeoutPropertyTest) {
+    celix_properties_t* config;
+    auto status = celix_properties_load("config.properties", 0, &config);
+    EXPECT_EQ(CELIX_SUCCESS, status);
+    celix_properties_set(config, "CELIX_LOGGING_DEFAULT_ACTIVE_LOG_LEVEL" , "warning");
+    celix_properties_set(config, CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS, "0.010");
+
+    framework_t* fw = celix_frameworkFactory_createFramework(config);
+    ASSERT_TRUE(fw != nullptr);
+
     // Start capturing stdout
     ::testing::internal::CaptureStderr();
 
     //When there is a emtpy event queue
-    celix_framework_waitForEmptyEventQueue(framework.get());
+    celix_framework_waitForEmptyEventQueue(fw);
 
-    // And the generic event timeout is set to 10ms
-    setenv(CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS, "0.010", 1);
-
     //And a generic event is fired, that block the queue for 20ms
     auto callback = [](void* /*data*/) {
         std::this_thread::sleep_for(std::chrono::milliseconds{20});
     };
-    long eventId = celix_framework_fireGenericEvent(framework.get(), -1L, -1L, "test", nullptr, callback, nullptr, nullptr);
+    long eventId = celix_framework_fireGenericEvent(fw, -1L, -1L, "test", nullptr, callback, nullptr, nullptr);
 
     //Then waiting for the event queue will have logged errors
-    celix_framework_waitForGenericEvent(framework.get(), eventId);
+    celix_framework_waitForGenericEvent(fw, eventId);
 
     // And the log will contain a printed warning
     auto log = ::testing::internal::GetCapturedStderr();
     auto expected = "Generic event 'test' (id=" + std::to_string(eventId) + ")";
-    EXPECT_TRUE(log.find(expected) != std::string::npos);
+    EXPECT_TRUE(log.find(expected) != std::string::npos) << "Got " << log; 
 
-    // Finally unset the timeout
-    unsetenv(CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS);
+    // Cleanup framework
+    celix_frameworkFactory_destroyFramework(fw);
 }
 
 TEST_F(CelixFrameworkTestSuite, AsyncInstallStartStopUpdateAndUninstallBundleTest) {

libs/framework/include/celix/Constants.h

@@ -223,4 +223,12 @@ namespace celix {
      * Should be a boolean value.
      */
     constexpr const char* const FRAMEWORK_CONDITION_SERVICES_ENABLED = CELIX_FRAMEWORK_CONDITION_SERVICES_ENABLED;
+
+    /**
+     * @brief Celix framework property (named "CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS") to configure the timeout time 
+     * for generic events in seconds.
+     * Default is 5.0
+     * Should be a double value.
+     */
+    constexpr const char* const ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS = CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS;
 }

libs/framework/src/framework.c

@@ -252,6 +252,10 @@ celix_status_t framework_create(framework_pt *out, celix_properties_t* config) {
     framework->dispatcher.eventQueue = malloc(sizeof(celix_framework_event_t) * framework->dispatcher.eventQueueCap);
     framework->dispatcher.dynamicEventQueue = celix_arrayList_create();
     framework->dispatcher.scheduledEvents = celix_longHashMap_create();
+    framework->dispatcher.genericEventTimeout = celix_framework_getConfigPropertyAsDouble(framework,
+                                                  CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS,
+                                                  CELIX_DEFAULT_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS,
+                                                  NULL);
 
     celix_framework_createAndStoreFrameworkUUID(framework);
 
@@ -2681,38 +2685,12 @@ static celix_framework_event_t* celix_framework_getGenericEvent(celix_framework_
     return NULL;
 }
 
-/**
- * @brief Checks if a generic event with the provided eventId is in progress.
- */
-static bool celix_framework_isGenericEventInProgress(celix_framework_t* fw, long eventId) {
-    // precondition fw->dispatcher.mutex locked)
-    for (int i = 0; i < fw->dispatcher.eventQueueSize; ++i) {
-        int index = (fw->dispatcher.eventQueueFirstEntry + i) % fw->dispatcher.eventQueueCap;
-        celix_framework_event_t* e = &fw->dispatcher.eventQueue[index];
-        if (e->type == CELIX_GENERIC_EVENT && e->genericEventId == eventId) {
-            return true;;
-        }
-    }
-    for (int i = 0; i < celix_arrayList_size(fw->dispatcher.dynamicEventQueue); ++i) {
-        celix_framework_event_t* e = celix_arrayList_get(fw->dispatcher.dynamicEventQueue, i);
-        if (e->type == CELIX_GENERIC_EVENT && e->genericEventId == eventId) {
-            return true;
-        }
-    }
-    return false;
-}
-
 void celix_framework_waitForGenericEvent(celix_framework_t* fw, long eventId) {
     assert(!celix_framework_isCurrentThreadTheEventLoop(fw));
-    double logTimeoutInSeconds =
-        celix_framework_getConfigPropertyAsDouble(fw,
-                                                  CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS,
-                                                  CELIX_DEFAULT_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS,
-                                                  NULL);
-    struct timespec logAbsTime = celixThreadCondition_getDelayedTime(logTimeoutInSeconds);
+    struct timespec logAbsTime = celixThreadCondition_getDelayedTime(fw->dispatcher.genericEventTimeout);
     celixThreadMutex_lock(&fw->dispatcher.mutex);
     celix_framework_event_t* event = celix_framework_getGenericEvent(fw, eventId);
-    while (celix_framework_isGenericEventInProgress(fw, eventId)) {
+    while (event) {
         celix_status_t waitStatus =
             celixThreadCondition_waitUntil(&fw->dispatcher.cond, &fw->dispatcher.mutex, &logAbsTime);
         if (waitStatus == ETIMEDOUT) {
@@ -2723,8 +2701,9 @@ void celix_framework_waitForGenericEvent(celix_framework_t* fw, long eventId) {
                    eventId,
                    event->bndEntry ? celix_bundle_getSymbolicName(event->bndEntry->bnd) : "unnamed",
                    event->bndEntry ? event->bndEntry->bndId : -1l);
-            logAbsTime = celixThreadCondition_getDelayedTime(logTimeoutInSeconds);
+            logAbsTime = celixThreadCondition_getDelayedTime(fw->dispatcher.genericEventTimeout);
         }
+        event = celix_framework_getGenericEvent(fw, eventId);
     }
     celixThreadMutex_unlock(&fw->dispatcher.mutex);
 }

libs/framework/src/framework_private.h

@@ -188,6 +188,8 @@ struct celix_framework {
             int nbEvent; // number of pending generic events
         } stats;
         celix_long_hash_map_t *scheduledEvents; //key = scheduled event id, entry = celix_framework_scheduled_event_t*. Used for scheduled events
+
+        double genericEventTimeout; // Timeout for printing an warning on unfinished generic events
     } dispatcher;
 
     celix_framework_logger_t* logger;