diff --git a/documents/framework.md b/documents/framework.md index d18535a56..32ee40ced 100644 --- a/documents/framework.md +++ b/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. | \ No newline at end of file diff --git a/libs/framework/gtest/src/CelixFrameworkTestSuite.cc b/libs/framework/gtest/src/CelixFrameworkTestSuite.cc index 7a5f5dc08..b428dc8b4 100644 --- a/libs/framework/gtest/src/CelixFrameworkTestSuite.cc +++ b/libs/framework/gtest/src/CelixFrameworkTestSuite.cc @@ -88,6 +88,40 @@ TEST_F(CelixFrameworkTestSuite, TimedWaitEventQueueTest) { EXPECT_EQ(CELIX_SUCCESS, status); } +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(fw); + + //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(fw, -1L, -1L, "test", nullptr, callback, nullptr, nullptr); + + //Then waiting for the event queue will have logged errors + 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) << "Got " << log; + + // Cleanup framework + celix_frameworkFactory_destroyFramework(fw); +} + TEST_F(CelixFrameworkTestSuite, AsyncInstallStartStopUpdateAndUninstallBundleTest) { long bndId = celix_framework_installBundleAsync(framework.get(), SIMPLE_TEST_BUNDLE1_LOCATION, false); EXPECT_GE(bndId, 0); diff --git a/libs/framework/include/celix/Constants.h b/libs/framework/include/celix/Constants.h index 1b838bdaa..c2aac0855 100644 --- a/libs/framework/include/celix/Constants.h +++ b/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; } diff --git a/libs/framework/include/celix_constants.h b/libs/framework/include/celix_constants.h index aa5929d44..aa5395e5c 100644 --- a/libs/framework/include/celix_constants.h +++ b/libs/framework/include/celix_constants.h @@ -281,6 +281,21 @@ extern "C" { */ #define CELIX_DEFAULT_ALLOWED_PROCESSING_TIME_FOR_SCHEDULED_EVENT_IN_SECONDS 2.0 +/*! + * @brief Celix framework environment property (named "CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS") + * to configure the allowed processing time for a generic event callback or a remove callback before a warning + * log message is printed that the processing time is too long. + * Should be a double value in seconds. + */ +#define CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS \ + "CELIX_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS" + +/** + * @brief The default , in seconds, allowed processing time for a processing a generic event or a remove callback + * before a warning log message is printed. + */ +#define CELIX_DEFAULT_ALLOWED_PROCESSING_TIME_FOR_GENERIC_EVENT_IN_SECONDS 5.0 + /** * @brief Celix framework environment property (named "CELIX_FRAMEWORK_CONDITION_SERVICES_ENABLED") to configure * whether framework condition services are enabled or not. diff --git a/libs/framework/src/framework.c b/libs/framework/src/framework.c index 0bf7bda14..577099fb4 100644 --- a/libs/framework/src/framework.c +++ b/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.genericEventTimeoutInSeconds = 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); @@ -2663,37 +2667,42 @@ long celix_framework_nextScheduledEventId(framework_t *fw) { return __atomic_fetch_add(&fw->dispatcher.nextScheduledEventId, 1, __ATOMIC_RELAXED); } -/** - * @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) +static celix_framework_event_t* celix_framework_getGenericEvent(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;; + return e; } } 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 e; } } - return false; + return NULL; } void celix_framework_waitForGenericEvent(celix_framework_t* fw, long eventId) { assert(!celix_framework_isCurrentThreadTheEventLoop(fw)); - struct timespec logAbsTime = celixThreadCondition_getDelayedTime(5); + struct timespec logAbsTime = celixThreadCondition_getDelayedTime(fw->dispatcher.genericEventTimeoutInSeconds); celixThreadMutex_lock(&fw->dispatcher.mutex); - while (celix_framework_isGenericEventInProgress(fw, eventId)) { + celix_framework_event_t* event = celix_framework_getGenericEvent(fw, eventId); + while (event) { celix_status_t waitStatus = celixThreadCondition_waitUntil(&fw->dispatcher.cond, &fw->dispatcher.mutex, &logAbsTime); - if (waitStatus == ETIMEDOUT) { - fw_log(fw->logger, CELIX_LOG_LEVEL_WARNING, "Generic event with id %li not finished.", eventId); - logAbsTime = celixThreadCondition_getDelayedTime(5); + event = celix_framework_getGenericEvent(fw, eventId); + if (waitStatus == ETIMEDOUT && event != NULL) { + fw_log(fw->logger, + CELIX_LOG_LEVEL_WARNING, + "Generic event '%s' (id=%li) for bundle '%s' (id=%li) not finished", + event->genericEventName ? event->genericEventName : "unnamed", + eventId, + event->bndEntry ? celix_bundle_getSymbolicName(event->bndEntry->bnd) : "unnamed", + event->bndEntry ? event->bndEntry->bndId : -1l); + logAbsTime = celixThreadCondition_getDelayedTime(fw->dispatcher.genericEventTimeoutInSeconds); } } celixThreadMutex_unlock(&fw->dispatcher.mutex); diff --git a/libs/framework/src/framework_private.h b/libs/framework/src/framework_private.h index 7de0d844f..80bbe0b60 100644 --- a/libs/framework/src/framework_private.h +++ b/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 genericEventTimeoutInSeconds; // Timeout for printing an warning on unfinished generic events } dispatcher; celix_framework_logger_t* logger;