Fix ESP32 platform manager shutdown. (#22417)

* Fix ESP32 platform manager shutdown.

The QEMU ESP32 tests start and stop the platform manager several times, and the
lack of a shutdown implementation was putting things in a bad state.

Also adjusts the test runner script to trigger a test failure when we do end up
in that bad state: we were passing even though we crashed quite early in the
test run and most of the tests did not run.

* Address review comments.

* Fix unlocking in FreeRTOS _RunEventLoop.

Ensure we always start with an empty event queue after FreeRTOS _InitChipStack.

Author: bzbarsky-apple

.restyled.yaml

@@ -98,6 +98,7 @@ restylers:
           - "**/*.c"
           - "**/*.cc"
           - "**/*.cpp"
+          - "**/*.ipp"
           - "**/*.cxx"
           - "**/*.c++"
           - "**/*.C"
@@ -137,6 +138,7 @@ restylers:
           - "**/*.c"
           - "**/*.cc"
           - "**/*.cpp"
+          - "**/*.ipp"
           - "**/*.cxx"
           - "**/*.c++"
           - "**/*.C"

src/include/platform/internal/GenericPlatformManagerImpl_FreeRTOS.h

@@ -60,9 +60,9 @@ class GenericPlatformManagerImpl_FreeRTOS : public GenericPlatformManagerImpl<Im
 protected:
     TimeOut_t mNextTimerBaseTime;
     TickType_t mNextTimerDurationTicks;
-    SemaphoreHandle_t mChipStackLock;
-    QueueHandle_t mChipEventQueue;
-    TaskHandle_t mEventLoopTask;
+    SemaphoreHandle_t mChipStackLock = NULL;
+    QueueHandle_t mChipEventQueue    = NULL;
+    TaskHandle_t mEventLoopTask      = NULL;
     bool mChipTimerActive;
 
     // ===== Methods that implement the PlatformManager abstract interface.

src/include/platform/internal/GenericPlatformManagerImpl_FreeRTOS.ipp

@@ -46,31 +46,50 @@ CHIP_ERROR GenericPlatformManagerImpl_FreeRTOS<ImplClass>::_InitChipStack(void)
 
     vTaskSetTimeOutState(&mNextTimerBaseTime);
     mNextTimerDurationTicks = 0;
-    mEventLoopTask          = NULL;
-    mChipTimerActive        = false;
+    // TODO: This nulling out of mEventLoopTask should happen when we shut down
+    // the task, not here!
+    mEventLoopTask   = NULL;
+    mChipTimerActive = false;
 
+    // We support calling Shutdown followed by InitChipStack, because some tests
+    // do that.  To keep things simple for existing consumers, we keep not
+    // destroying our lock and queue in shutdown, but rather check whether they
+    // already exist here before trying to create them.
+
+    if (mChipStackLock == NULL)
+    {
 #if defined(CHIP_CONFIG_FREERTOS_USE_STATIC_SEMAPHORE) && CHIP_CONFIG_FREERTOS_USE_STATIC_SEMAPHORE
-    mChipStackLock = xSemaphoreCreateMutexStatic(&mChipStackLockMutex);
+        mChipStackLock = xSemaphoreCreateMutexStatic(&mChipStackLockMutex);
 #else
-    mChipStackLock  = xSemaphoreCreateMutex();
+        mChipStackLock  = xSemaphoreCreateMutex();
 #endif // CHIP_CONFIG_FREERTOS_USE_STATIC_SEMAPHORE
 
-    if (mChipStackLock == NULL)
-    {
-        ChipLogError(DeviceLayer, "Failed to create CHIP stack lock");
-        ExitNow(err = CHIP_ERROR_NO_MEMORY);
+        if (mChipStackLock == NULL)
+        {
+            ChipLogError(DeviceLayer, "Failed to create CHIP stack lock");
+            ExitNow(err = CHIP_ERROR_NO_MEMORY);
+        }
     }
 
+    if (mChipEventQueue == NULL)
+    {
 #if defined(CHIP_CONFIG_FREERTOS_USE_STATIC_QUEUE) && CHIP_CONFIG_FREERTOS_USE_STATIC_QUEUE
-    mChipEventQueue =
-        xQueueCreateStatic(CHIP_DEVICE_CONFIG_MAX_EVENT_QUEUE_SIZE, sizeof(ChipDeviceEvent), mEventQueueBuffer, &mEventQueueStruct);
+        mChipEventQueue = xQueueCreateStatic(CHIP_DEVICE_CONFIG_MAX_EVENT_QUEUE_SIZE, sizeof(ChipDeviceEvent), mEventQueueBuffer,
+                                             &mEventQueueStruct);
 #else
-    mChipEventQueue = xQueueCreate(CHIP_DEVICE_CONFIG_MAX_EVENT_QUEUE_SIZE, sizeof(ChipDeviceEvent));
+        mChipEventQueue = xQueueCreate(CHIP_DEVICE_CONFIG_MAX_EVENT_QUEUE_SIZE, sizeof(ChipDeviceEvent));
 #endif
-    if (mChipEventQueue == NULL)
+        if (mChipEventQueue == NULL)
+        {
+            ChipLogError(DeviceLayer, "Failed to allocate CHIP event queue");
+            ExitNow(err = CHIP_ERROR_NO_MEMORY);
+        }
+    }
+    else
     {
-        ChipLogError(DeviceLayer, "Failed to allocate CHIP event queue");
-        ExitNow(err = CHIP_ERROR_NO_MEMORY);
+        // Clear out any events that might be stuck in the queue, so we start
+        // with a clean slate, as if we had just re-created the queue.
+        xQueueReset(mChipEventQueue);
     }
 
     mShouldRunEventLoop.store(false);
@@ -145,7 +164,7 @@ void GenericPlatformManagerImpl_FreeRTOS<ImplClass>::_RunEventLoop(void)
     ChipDeviceEvent event;
 
     // Lock the CHIP stack.
-    Impl()->LockChipStack();
+    StackLock lock;
 
     bool oldShouldRunEventLoop = false;
     if (!mShouldRunEventLoop.compare_exchange_strong(oldShouldRunEventLoop /* expected */, true /* desired */))
@@ -198,13 +217,13 @@ void GenericPlatformManagerImpl_FreeRTOS<ImplClass>::_RunEventLoop(void)
             waitTime = portMAX_DELAY;
         }
 
-        // Unlock the CHIP stack, allowing other threads to enter CHIP while the event loop thread is sleeping.
-        Impl()->UnlockChipStack();
-
-        BaseType_t eventReceived = xQueueReceive(mChipEventQueue, &event, waitTime);
-
-        // Lock the CHIP stack.
-        Impl()->LockChipStack();
+        BaseType_t eventReceived = pdFALSE;
+        {
+            // Unlock the CHIP stack, allowing other threads to enter CHIP while
+            // the event loop thread is sleeping.
+            StackUnlock unlock;
+            eventReceived = xQueueReceive(mChipEventQueue, &event, waitTime);
+        }
 
         // If an event was received, dispatch it.  Continue receiving events from the queue and
         // dispatching them until the queue is empty.
@@ -236,6 +255,9 @@ void GenericPlatformManagerImpl_FreeRTOS<ImplClass>::EventLoopTaskMain(void * ar
 {
     ChipLogDetail(DeviceLayer, "CHIP task running");
     static_cast<GenericPlatformManagerImpl_FreeRTOS<ImplClass> *>(arg)->Impl()->RunEventLoop();
+    // TODO: At this point, should we not
+    // vTaskDelete(static_cast<GenericPlatformManagerImpl_FreeRTOS<ImplClass> *>(arg)->mEventLoopTask)?
+    // Or somehow get our caller to do it once this thread is joined?
 }
 
 template <class ImplClass>
@@ -275,6 +297,7 @@ void GenericPlatformManagerImpl_FreeRTOS<ImplClass>::PostEventFromISR(const Chip
 template <class ImplClass>
 void GenericPlatformManagerImpl_FreeRTOS<ImplClass>::_Shutdown(void)
 {
+    GenericPlatformManagerImpl<ImplClass>::_Shutdown();
 }
 
 template <class ImplClass>

src/platform/ESP32/PlatformManagerImpl.cpp

@@ -150,6 +150,8 @@ void PlatformManagerImpl::_Shutdown()
     }
 
     Internal::GenericPlatformManagerImpl_FreeRTOS<PlatformManagerImpl>::_Shutdown();
+
+    esp_event_loop_delete_default();
 }
 
 void PlatformManagerImpl::HandleESPSystemEvent(void * arg, esp_event_base_t eventBase, int32_t eventId, void * eventData)

src/system/tests/BUILD.gn

@@ -31,7 +31,7 @@ chip_test_suite("tests") {
     "TestTimeSource.cpp",
   ]
 
-  if (chip_device_platform != "esp32" && chip_device_platform != "fake") {
+  if (chip_device_platform != "fake") {
     test_sources += [ "TestSystemScheduleWork.cpp" ]
   }
 

src/test_driver/esp32/run_qemu_image.py

@@ -17,6 +17,7 @@
 import click
 import logging
 import os
+import re
 import sys
 import subprocess
 
@@ -104,19 +105,41 @@ def main(log_level, no_log_timestamps, image, file_image_list, qemu, verbose):
                                 (path, status.returncode))
 
             # Parse output of the unit test. Generally expect things like:
+            # I (3034) CHIP-tests: Starting CHIP tests!
+            # ...
+            # Various test lines, none ending with "] : FAILED"
+            # ...
             # Failed Tests:   0 / 5
             # Failed Asserts: 0 / 77
             # I (3034) CHIP-tests: CHIP test status: 0
+            in_test = False
             for line in output.split('\n'):
+                if line.endswith('CHIP-tests: Starting CHIP tests!'):
+                    in_test = True
+
                 if line.startswith('Failed Tests:') and not line.startswith('Failed Tests:   0 /'):
                     raise Exception("Tests seem failed: %s" % line)
 
                 if line.startswith('Failed Asserts:') and not line.startswith('Failed Asserts: 0 /'):
                     raise Exception("Asserts seem failed: %s" % line)
 
-                if 'CHIP test status: ' in line and 'CHIP test status: 0' not in line:
+                if 'CHIP-tests: CHIP test status: 0' in line:
+                    in_test = False
+                elif 'CHIP-tests: CHIP test status: ' in line:
                     raise Exception("CHIP test status is NOT 0: %s" % line)
 
+                # Ignore FAILED messages not in the middle of a test, to reduce
+                # the chance of false posisitves from other logging.
+                if in_test and re.match('.*] : FAILED$', line):
+                    raise Exception("Step failed: %s" % line)
+
+                # TODO: Figure out why exit(0) in man_app.cpp's tester_task is aborting and fix that.
+                if in_test and line.startswith('abort() was called at PC'):
+                    raise Exception("Unexpected crash: %s" % line)
+
+            if in_test:
+                raise Exception('Not expected to be in the middle of a test when the log ends')
+
             if verbose:
                 print("========== TEST OUTPUT BEGIN ============")
                 print(output)
@@ -125,7 +148,9 @@ def main(log_level, no_log_timestamps, image, file_image_list, qemu, verbose):
             logging.info("Image %s PASSED", path)
         except:
             # make sure output is visible in stdout
+            print("========== TEST OUTPUT BEGIN ============")
             print(output)
+            print("========== TEST OUTPUT END   ============")
             raise