Merge branch 'master' into enable_to_skip_complete_step

config/esp32/components/chip/Kconfig

@@ -108,6 +108,14 @@ menu "CHIP Core"
             help
                 Build CHIP test binaries.
 
+        config DISPATCH_EVENT_LONG_DISPATCH_TIME_WARNING_THRESHOLD_MS
+            int  "Set threshold in ms"
+            default 700
+            help
+                 Time threshold for events dispatching. By default set to 0 to
+                 to disable event dispatching time measurement and suppress the
+                 logs for Long dispatch time.
+
         # TODO: add log level selection
 
     endmenu # "General Options"

src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp

@@ -59,6 +59,8 @@ CHIP_ERROR GenericPlatformManagerImpl_POSIX<ImplClass>::_InitChipStack()
     // Call up to the base class _InitChipStack() to perform the bulk of the initialization.
     ReturnErrorOnFailure(GenericPlatformManagerImpl<ImplClass>::_InitChipStack());
 
+    mShouldRunEventLoop.store(true, std::memory_order_relaxed);
+
     int ret = pthread_cond_init(&mEventQueueStoppedCond, nullptr);
     VerifyOrReturnError(ret == 0, CHIP_ERROR_POSIX(ret));
 
@@ -225,6 +227,8 @@ CHIP_ERROR GenericPlatformManagerImpl_POSIX<ImplClass>::_StartEventLoopTask()
     VerifyOrReturnError(err == 0, CHIP_ERROR_POSIX(err));
 #endif
 
+    mShouldRunEventLoop.store(true, std::memory_order_relaxed);
+
     //
     // We need to grab the lock here since we have to protect setting
     // mHasValidChipTask, which will be read right away upon creating the

src/platform/ESP32/CHIPPlatformConfig.h

@@ -51,6 +51,7 @@
 
 // The following values are configured via the ESP-IDF Kconfig mechanism.
 
+#define CHIP_DISPATCH_EVENT_LONG_DISPATCH_TIME_WARNING_THRESHOLD_MS CONFIG_DISPATCH_EVENT_LONG_DISPATCH_TIME_WARNING_THRESHOLD_MS
 #define CHIP_CONFIG_MAX_UNSOLICITED_MESSAGE_HANDLERS CONFIG_MAX_UNSOLICITED_MESSAGE_HANDLERS
 #define CHIP_CONFIG_MAX_EXCHANGE_CONTEXTS CONFIG_MAX_EXCHANGE_CONTEXTS
 #define CHIP_CONFIG_SECURITY_TEST_MODE CONFIG_SECURITY_TEST_MODE

src/platform/ESP32/Logging.cpp

@@ -26,20 +26,35 @@ void ENFORCE_FORMAT(3, 0) LogV(const char * module, uint8_t category, const char
     snprintf(tag, sizeof(tag), "chip[%s]", module);
     tag[sizeof(tag) - 1] = 0;
 
-    char formattedMsg[CHIP_CONFIG_LOG_MESSAGE_MAX_SIZE];
-    vsnprintf(formattedMsg, sizeof(formattedMsg), msg, v);
-
     switch (category)
     {
     case kLogCategory_Error:
-        ESP_LOGE(tag, "%s", formattedMsg);
+        if (esp_log_default_level >= ESP_LOG_ERROR)
+        {
+            printf(LOG_COLOR_E "E");                        // set color
+            printf(" (%u) %s: ", esp_log_timestamp(), tag); // add timestamp
+            esp_log_writev(ESP_LOG_ERROR, tag, msg, v);
+            printf(LOG_RESET_COLOR "\n");
+        }
         break;
     case kLogCategory_Progress:
     default:
-        ESP_LOGI(tag, "%s", formattedMsg);
+        if (esp_log_default_level >= ESP_LOG_INFO)
+        {
+            printf(LOG_COLOR_I "I");                        // set color
+            printf(" (%u) %s: ", esp_log_timestamp(), tag); // add timestamp
+            esp_log_writev(ESP_LOG_INFO, tag, msg, v);
+            printf(LOG_RESET_COLOR "\n");
+        }
         break;
     case kLogCategory_Detail:
-        ESP_LOGD(tag, "%s", formattedMsg);
+        if (esp_log_default_level >= ESP_LOG_DEBUG)
+        {
+            printf(LOG_COLOR_D "D");                        // set color
+            printf(" (%u) %s: ", esp_log_timestamp(), tag); // add timestamp
+            esp_log_writev(ESP_LOG_DEBUG, tag, msg, v);
+            printf(LOG_RESET_COLOR "\n");
+        }
         break;
     }
 }

src/platform/tests/TestPlatformMgr.cpp

@@ -28,6 +28,8 @@
 #include <stdlib.h>
 #include <string.h>
 
+#include <atomic>
+
 #include <lib/support/CHIPMem.h>
 #include <lib/support/CodeUtils.h>
 #include <lib/support/UnitTestRegistration.h>
@@ -55,14 +57,52 @@ static void TestPlatformMgr_InitShutdown(nlTestSuite * inSuite, void * inContext
 
 static void TestPlatformMgr_BasicEventLoopTask(nlTestSuite * inSuite, void * inContext)
 {
+    std::atomic<int> counterRun{ 0 };
+
     CHIP_ERROR err = PlatformMgr().InitChipStack();
     NL_TEST_ASSERT(inSuite, err == CHIP_NO_ERROR);
 
-    err = PlatformMgr().StartEventLoopTask();
-    NL_TEST_ASSERT(inSuite, err == CHIP_NO_ERROR);
+    // Start/stop the event loop task a few times.
+    for (size_t i = 0; i < 3; i++)
+    {
+        err = PlatformMgr().StartEventLoopTask();
+        NL_TEST_ASSERT(inSuite, err == CHIP_NO_ERROR);
+
+        std::atomic<int> counterSync{ 2 };
+
+        // Verify that the event loop will not exit until we tell it to by
+        // scheduling few lambdas (for the test to pass, the event loop will
+        // have to process more than one event).
+        DeviceLayer::SystemLayer().ScheduleLambda([&]() {
+            counterRun++;
+            counterSync--;
+        });
+
+        // Sleep for a short time to allow the event loop to process the
+        // scheduled event and go to idle state. Without this sleep, the
+        // event loop may process both scheduled lambdas during single
+        // iteration of the event loop which would defeat the purpose of
+        // this test on POSIX platforms where the event loop is implemented
+        // using a "do { ... } while (shouldRun)" construct.
+        chip::test_utils::SleepMillis(10);
+
+        DeviceLayer::SystemLayer().ScheduleLambda([&]() {
+            counterRun++;
+            counterSync--;
+        });
+
+        // Wait for the event loop to process the scheduled events.
+        // Note, that we can not use any synchronization primitives like
+        // condition variables or barriers, because the test has to compile
+        // on all platforms. Instead we use a busy loop with a timeout.
+        for (size_t t = 0; counterSync != 0 && t < 1000; t++)
+            chip::test_utils::SleepMillis(1);
+
+        err = PlatformMgr().StopEventLoopTask();
+        NL_TEST_ASSERT(inSuite, err == CHIP_NO_ERROR);
+    }
 
-    err = PlatformMgr().StopEventLoopTask();
-    NL_TEST_ASSERT(inSuite, err == CHIP_NO_ERROR);
+    NL_TEST_ASSERT(inSuite, counterRun == (3 * 2));
 
     PlatformMgr().Shutdown();
 }