Merge branch 'feature/gcov_dump_in_thread_v4.1' into 'release/v4.1'

Feature/gcov dump in thread v4.1

See merge request espressif/esp-idf!15918

components/app_trace/CMakeLists.txt

@@ -30,7 +30,7 @@ endif()
 
 idf_component_register(SRCS "${srcs}"
                        INCLUDE_DIRS "${include_dirs}"
-                       PRIV_REQUIRES soc
+                       PRIV_REQUIRES soc esp_common
                        LDFRAGMENTS linker.lf)
 
 

components/app_trace/gcov/gcov_rtio.c

@@ -22,8 +22,9 @@
 #include "soc/cpu.h"
 #include "soc/timer_periph.h"
 #include "esp_app_trace.h"
+#include "esp_freertos_hooks.h"
 #include "esp_private/dbg_stubs.h"
-#include "hal/timer_ll.h"
+#include "esp_ipc.h"
 #if CONFIG_IDF_TARGET_ESP32
 #include "esp32/rom/libc_stubs.h"
 #elif CONFIG_IDF_TARGET_ESP32S2BETA
@@ -37,117 +38,106 @@
 #define LOG_LOCAL_LEVEL CONFIG_LOG_DEFAULT_LEVEL
 #include "esp_log.h"
 const static char *TAG = "esp_gcov_rtio";
+static volatile bool s_create_gcov_task = false;
+static volatile bool s_gcov_task_running = false;
 
 extern void __gcov_dump(void);
 extern void __gcov_reset(void);
 
-static struct syscall_stub_table s_gcov_stub_table;
-
-
-static int gcov_stub_lock_try_acquire_recursive(_lock_t *lock)
-{
-    if (*lock && uxSemaphoreGetCount((xSemaphoreHandle)(*lock)) == 0) {
-        // we can do nothing here, gcov dump is initiated with some resource locked
-        // which is also used by gcov functions
-        ESP_EARLY_LOGE(TAG, "Lock 0x%x is busy during GCOV dump! System state can be inconsistent after dump!", lock);
-    }
-    return pdTRUE;
-}
-
-static void gcov_stub_lock_acquire_recursive(_lock_t *lock)
-{
-    gcov_stub_lock_try_acquire_recursive(lock);
-}
-
-static void gcov_stub_lock_release_recursive(_lock_t *lock)
+void gcov_dump_task(void *pvParameter)
 {
-}
+    int dump_result = 0;
+    bool *running = (bool *)pvParameter;
 
-static int esp_dbg_stub_gcov_dump_do(void)
-{
-    int ret = ESP_OK;
-    FILE* old_stderr = stderr;
-    FILE* old_stdout = stdout;
-    struct syscall_stub_table* old_table = syscall_table_ptr_pro;
+    ESP_EARLY_LOGV(TAG, "%s stack use in %d", __FUNCTION__, uxTaskGetStackHighWaterMark(NULL));
 
     ESP_EARLY_LOGV(TAG, "Alloc apptrace down buf %d bytes", ESP_GCOV_DOWN_BUF_SIZE);
     void *down_buf = malloc(ESP_GCOV_DOWN_BUF_SIZE);
     if (down_buf == NULL) {
         ESP_EARLY_LOGE(TAG, "Could not allocate memory for the buffer");
-        return ESP_ERR_NO_MEM;
+        dump_result = ESP_ERR_NO_MEM;
+        goto gcov_exit;
     }
     ESP_EARLY_LOGV(TAG, "Config apptrace down buf");
     esp_apptrace_down_buffer_config(down_buf, ESP_GCOV_DOWN_BUF_SIZE);
     ESP_EARLY_LOGV(TAG, "Dump data...");
-    // incase of dual-core chip APP and PRO CPUs share the same table, so it is safe to save only PRO's table
-    memcpy(&s_gcov_stub_table, old_table, sizeof(s_gcov_stub_table));
-    s_gcov_stub_table._lock_acquire_recursive = &gcov_stub_lock_acquire_recursive;
-    s_gcov_stub_table._lock_release_recursive = &gcov_stub_lock_release_recursive;
-    s_gcov_stub_table._lock_try_acquire_recursive = &gcov_stub_lock_try_acquire_recursive,
-
-    syscall_table_ptr_pro = &s_gcov_stub_table;
-    stderr = (FILE*) &__sf_fake_stderr;
-    stdout = (FILE*) &__sf_fake_stdout;
     __gcov_dump();
     // reset dump status to allow incremental data accumulation
     __gcov_reset();
-    stdout = old_stdout;
-    stderr = old_stderr;
-    syscall_table_ptr_pro = old_table;
-
-    ESP_EARLY_LOGV(TAG, "Free apptrace down buf");
     free(down_buf);
     ESP_EARLY_LOGV(TAG, "Finish file transfer session");
-    ret = esp_apptrace_fstop(ESP_APPTRACE_DEST_TRAX);
-    if (ret != ESP_OK) {
-        ESP_EARLY_LOGE(TAG, "Failed to send files transfer stop cmd (%d)!", ret);
+    dump_result = esp_apptrace_fstop(ESP_APPTRACE_DEST_TRAX);
+    if (dump_result != ESP_OK) {
+        ESP_EARLY_LOGE(TAG, "Failed to send files transfer stop cmd (%d)!", dump_result);
+    }
+
+gcov_exit:
+    ESP_EARLY_LOGV(TAG, "dump_result %d", dump_result);
+    if (running) {
+        *running = false;
+    }
+
+    ESP_EARLY_LOGV(TAG, "%s stack use out %d", __FUNCTION__, uxTaskGetStackHighWaterMark(NULL));
+
+    vTaskDelete(NULL);
+}
+
+void gcov_create_task(void *arg)
+{
+    ESP_EARLY_LOGV(TAG, "%s", __FUNCTION__);
+    xTaskCreatePinnedToCore(&gcov_dump_task, "gcov_dump_task", 2048, (void *)&s_gcov_task_running, configMAX_PRIORITIES - 1, NULL, 0);
+}
+
+void gcov_create_task_tick_hook(void)
+{
+    extern esp_err_t esp_ipc_start_gcov_from_isr(uint32_t cpu_id, esp_ipc_func_t func, void* arg);
+    if (s_create_gcov_task) {
+        if (esp_ipc_start_gcov_from_isr(xPortGetCoreID(), &gcov_create_task, NULL) == ESP_OK) {
+            s_create_gcov_task = false;
+        }
     }
-    return ret;
 }
 
 /**
- * @brief Triggers gcov info dump.
+ * @brief Triggers gcov info dump task
  *        This function is to be called by OpenOCD, not by normal user code.
- * TODO: what about interrupted flash access (when cache disabled)???
+ * TODO: what about interrupted flash access (when cache disabled)
  *
  * @return ESP_OK on success, otherwise see esp_err_t
  */
 static int esp_dbg_stub_gcov_entry(void)
 {
-    return esp_dbg_stub_gcov_dump_do();
+    /* we are in isr context here */
+    s_create_gcov_task = true;
+    return ESP_OK;
 }
 
 int gcov_rtio_atexit(void (*function)(void) __attribute__ ((unused)))
 {
+    uint32_t capabilities = 0;
     ESP_EARLY_LOGV(TAG, "%s", __FUNCTION__);
     esp_dbg_stub_entry_set(ESP_DBG_STUB_ENTRY_GCOV, (uint32_t)&esp_dbg_stub_gcov_entry);
-    return 0;
+    if (esp_dbg_stub_entry_get(ESP_DBG_STUB_ENTRY_CAPABILITIES, &capabilities) == ESP_OK) {
+        esp_dbg_stub_entry_set(ESP_DBG_STUB_ENTRY_CAPABILITIES, capabilities | ESP_DBG_STUB_CAP_GCOV_TASK);
+    }
+    esp_register_freertos_tick_hook(gcov_create_task_tick_hook);
+    return ESP_OK;
 }
 
 void esp_gcov_dump(void)
 {
-    // disable IRQs on this CPU, other CPU is halted by OpenOCD
-    unsigned irq_state = portENTER_CRITICAL_NESTED();
-#if !CONFIG_FREERTOS_UNICORE
-    int other_core = xPortGetCoreID() ? 0 : 1;
-    esp_cpu_stall(other_core);
-#endif
+    ESP_EARLY_LOGV(TAG, "%s", __FUNCTION__);
+
     while (!esp_apptrace_host_is_connected(ESP_APPTRACE_DEST_TRAX)) {
-        // to avoid complains that task watchdog got triggered for other tasks
-        timer_ll_wdt_set_protect(&TIMERG0, false);
-        timer_ll_wdt_feed(&TIMERG0);
-        timer_ll_wdt_set_protect(&TIMERG0, true);
-        // to avoid reboot on INT_WDT
-        timer_ll_wdt_set_protect(&TIMERG1, false);
-        timer_ll_wdt_feed(&TIMERG1);
-        timer_ll_wdt_set_protect(&TIMERG1, true);
+        vTaskDelay(pdMS_TO_TICKS(10));
     }
 
-    esp_dbg_stub_gcov_dump_do();
-#if !CONFIG_FREERTOS_UNICORE
-    esp_cpu_unstall(other_core);
-#endif
-    portEXIT_CRITICAL_NESTED(irq_state);
+    /* We are not in isr context here. Waiting for the completion is safe */
+    s_gcov_task_running = true;
+    s_create_gcov_task = true;
+    while (s_gcov_task_running) {
+        vTaskDelay(pdMS_TO_TICKS(10));
+    }
 }
 
 void *gcov_rtio_fopen(const char *path, const char *mode)
@@ -164,7 +154,7 @@ int gcov_rtio_fclose(void *stream)
 
 size_t gcov_rtio_fread(void *ptr, size_t size, size_t nmemb, void *stream)
 {
-    ESP_EARLY_LOGV(TAG, "%s read %u", __FUNCTION__, size*nmemb);
+    ESP_EARLY_LOGV(TAG, "%s read %u", __FUNCTION__, size * nmemb);
     size_t sz = esp_apptrace_fread(ESP_APPTRACE_DEST_TRAX, ptr, size, nmemb, stream);
     ESP_EARLY_LOGV(TAG, "%s actually read %u", __FUNCTION__, sz);
     return sz;

components/esp_common/CMakeLists.txt

@@ -17,7 +17,7 @@ else()
              "src/system_api.c")
 
     # IPC framework is not applicable if freertos unicore config is selected
-    if(NOT CONFIG_FREERTOS_UNICORE)
+    if(NOT CONFIG_FREERTOS_UNICORE OR CONFIG_APPTRACE_GCOV_ENABLE)
         list(APPEND srcs "src/ipc.c")
     endif()
 

components/esp_common/component.mk

@@ -7,7 +7,9 @@ COMPONENT_SRCDIRS := src
 
 # IPC framework is not applicable if freertos unicore config is selected
 ifdef CONFIG_FREERTOS_UNICORE
-COMPONENT_OBJEXCLUDE := src/ipc.o
+    ifndef CONFIG_APPTRACE_GCOV_ENABLE
+        COMPONENT_OBJEXCLUDE := src/ipc.o
+    endif
 endif
 
 # disable stack protection in files which are involved in initialization of that feature

components/esp_common/include/esp_private/dbg_stubs.h

@@ -20,13 +20,19 @@
  * Debug stubs entries IDs
  */
 typedef enum {
-    ESP_DBG_STUB_CONTROL_DATA,	///< stubs descriptor entry
+    ESP_DBG_STUB_MAGIC_NUM,
+    ESP_DBG_STUB_TABLE_SIZE,
+    ESP_DBG_STUB_CONTROL_DATA,   ///< stubs descriptor entry
     ESP_DBG_STUB_ENTRY_FIRST,
-    ESP_DBG_STUB_ENTRY_GCOV		///< GCOV entry
-    						= ESP_DBG_STUB_ENTRY_FIRST,
+    ESP_DBG_STUB_ENTRY_GCOV	///< GCOV entry
+        = ESP_DBG_STUB_ENTRY_FIRST,
+    ESP_DBG_STUB_ENTRY_CAPABILITIES,
     ESP_DBG_STUB_ENTRY_MAX
 } esp_dbg_stub_id_t;
 
+#define ESP_DBG_STUB_MAGIC_NUM_VAL      0xFEEDBEEF
+#define ESP_DBG_STUB_CAP_GCOV_TASK      (1 << 0)
+
 /**
  * @brief  Initializes debug stubs.
  *
@@ -41,10 +47,22 @@ void esp_dbg_stubs_init(void);
  *
  * @param id 	Stub ID.
  * @param entry Stub entry. Usually it is stub entry function address,
- *              but can be any value meaningfull for OpenOCD command/code.
- *
+ *              but can be any value meaningfull for OpenOCD command/code
+ *              such as capabilities
  * @return ESP_OK on success, otherwise see esp_err_t
  */
 esp_err_t esp_dbg_stub_entry_set(esp_dbg_stub_id_t id, uint32_t entry);
 
-#endif //ESP_DBG_STUBS_H_
+/**
+ * @brief   Retrives the corresponding stub entry
+ *
+ * @param id 	Stub ID.
+ * @param entry Stub entry. Usually it is stub entry function address,
+ *              but can be any value meaningfull for OpenOCD command/code
+ *              such as capabilities
+ *
+ * @return ESP_OK on success, otherwise see esp_err_t
+ */
+esp_err_t esp_dbg_stub_entry_get(esp_dbg_stub_id_t id, uint32_t *entry);
+
+#endif //ESP_DBG_STUBS_H_

components/esp_common/src/dbg_stubs.c

@@ -76,11 +76,14 @@ void esp_dbg_stubs_init(void)
     s_dbg_stubs_ctl_data.data_alloc     = (uint32_t)esp_dbg_stubs_data_alloc;
     s_dbg_stubs_ctl_data.data_free      = (uint32_t)esp_dbg_stubs_data_free;
 
+    s_stub_entry[ESP_DBG_STUB_MAGIC_NUM] = ESP_DBG_STUB_MAGIC_NUM_VAL;
+    s_stub_entry[ESP_DBG_STUB_TABLE_SIZE] = ESP_DBG_STUB_ENTRY_MAX;
     s_stub_entry[ESP_DBG_STUB_CONTROL_DATA] = (uint32_t)&s_dbg_stubs_ctl_data;
     eri_write(ESP_DBG_STUBS_TRAX_REG, (uint32_t)s_stub_entry);
     ESP_LOGV(TAG, "%s stubs %x", __func__, eri_read(ESP_DBG_STUBS_TRAX_REG));
 }
 
+// TODO: add lock mechanism. Not now but in the future ESP_DBG_STUB_ENTRY_CAPABILITIES can be set from different places.
 esp_err_t esp_dbg_stub_entry_set(esp_dbg_stub_id_t id, uint32_t entry)
 {
     if (id < ESP_DBG_STUB_ENTRY_FIRST || id >= ESP_DBG_STUB_ENTRY_MAX) {
@@ -92,4 +95,15 @@ esp_err_t esp_dbg_stub_entry_set(esp_dbg_stub_id_t id, uint32_t entry)
     return ESP_OK;
 }
 
+esp_err_t esp_dbg_stub_entry_get(esp_dbg_stub_id_t id, uint32_t *entry)
+{
+    if (id < ESP_DBG_STUB_ENTRY_FIRST || id >= ESP_DBG_STUB_ENTRY_MAX) {
+        ESP_LOGE(TAG, "Invalid stub id %d!", id);
+        return ESP_ERR_INVALID_ARG;
+    }
+    *entry = s_stub_entry[id];
+
+    return ESP_OK;
+}
+
 #endif

components/esp_common/src/ipc.c

@@ -28,7 +28,7 @@ static TaskHandle_t s_ipc_task_handle[portNUM_PROCESSORS];
 static SemaphoreHandle_t s_ipc_mutex[portNUM_PROCESSORS];    // This mutex is used as a global lock for esp_ipc_* APIs
 static SemaphoreHandle_t s_ipc_sem[portNUM_PROCESSORS];      // Two semaphores used to wake each of ipc tasks
 static SemaphoreHandle_t s_ipc_ack[portNUM_PROCESSORS];      // Semaphore used to acknowledge that task was woken up,
-                                                             //   or function has finished running
+                                                             // or function has finished running
 static volatile esp_ipc_func_t s_func[portNUM_PROCESSORS];   // Function which should be called by high priority task
 static void * volatile s_func_arg[portNUM_PROCESSORS];       // Argument to pass into s_func
 typedef enum {
@@ -40,6 +40,11 @@ static volatile esp_ipc_wait_t s_ipc_wait[portNUM_PROCESSORS];// This variable t
                                                              //   s_ipc_ack semaphore: before s_func is called, or
                                                              //   after it returns
 
+#if CONFIG_APPTRACE_GCOV_ENABLE
+static volatile esp_ipc_func_t s_gcov_func = NULL;           // Gcov dump starter function which should be called by high priority task
+static void * volatile s_gcov_func_arg;                      // Argument to pass into s_gcov_func
+#endif
+
 static void IRAM_ATTR ipc_task(void* arg)
 {
     const uint32_t cpuid = (uint32_t) arg;
@@ -53,16 +58,27 @@ static void IRAM_ATTR ipc_task(void* arg)
             abort();
         }
 
-        esp_ipc_func_t func = s_func[cpuid];
-        void* arg = s_func_arg[cpuid];
-
-        if (s_ipc_wait[cpuid] == IPC_WAIT_FOR_START) {
-            xSemaphoreGive(s_ipc_ack[cpuid]);
+#if CONFIG_APPTRACE_GCOV_ENABLE
+        if (s_gcov_func) {
+            (*s_gcov_func)(s_gcov_func_arg);
+            s_gcov_func = NULL;
+            /* we can not interfer with IPC calls so no need for further processing */
+            continue;
         }
-        (*func)(arg);
-        if (s_ipc_wait[cpuid] == IPC_WAIT_FOR_END) {
-            xSemaphoreGive(s_ipc_ack[cpuid]);
+#endif
+        if (s_func[cpuid]) {
+            esp_ipc_func_t func = s_func[cpuid];
+            void* arg = s_func_arg[cpuid];
+
+            if (s_ipc_wait[cpuid] == IPC_WAIT_FOR_START) {
+                xSemaphoreGive(s_ipc_ack[cpuid]);
+            }
+            (*func)(arg);
+            if (s_ipc_wait[cpuid] == IPC_WAIT_FOR_END) {
+                xSemaphoreGive(s_ipc_ack[cpuid]);
+            }
         }
+
     }
     // TODO: currently this is unreachable code. Introduce esp_ipc_uninit
     // function which will signal to both tasks that they can shut down.
@@ -87,6 +103,7 @@ static void esp_ipc_init(void) __attribute__((constructor));
 static void esp_ipc_init(void)
 {
     char task_name[15];
+
     for (int i = 0; i < portNUM_PROCESSORS; ++i) {
         snprintf(task_name, sizeof(task_name), "ipc%d", i);
         s_ipc_mutex[i] = xSemaphoreCreateMutex();
@@ -126,6 +143,7 @@ static esp_err_t esp_ipc_call_and_wait(uint32_t cpu_id, esp_ipc_func_t func, voi
     s_ipc_wait[cpu_id] = wait_for;
     xSemaphoreGive(s_ipc_sem[cpu_id]);
     xSemaphoreTake(s_ipc_ack[cpu_id], portMAX_DELAY);
+    s_func[cpu_id] = NULL;
 #ifdef CONFIG_ESP_IPC_USES_CALLERS_PRIORITY
     xSemaphoreGive(s_ipc_mutex[cpu_id]);
 #else
@@ -144,3 +162,38 @@ esp_err_t esp_ipc_call_blocking(uint32_t cpu_id, esp_ipc_func_t func, void* arg)
     return esp_ipc_call_and_wait(cpu_id, func, arg, IPC_WAIT_FOR_END);
 }
 
+// currently this is only called from gcov component
+#if CONFIG_APPTRACE_GCOV_ENABLE
+esp_err_t esp_ipc_start_gcov_from_isr(uint32_t cpu_id, esp_ipc_func_t func, void* arg)
+{
+    portBASE_TYPE ret = pdFALSE;
+
+    if (xTaskGetSchedulerState() != taskSCHEDULER_RUNNING) {
+        return ESP_ERR_INVALID_STATE;
+    }
+
+    /* Lock IPC to avoid interferring with normal IPC calls, e.g.
+       avoid situation when esp_ipc_start_gcov_from_isr() is called from IRQ
+       in the middle of IPC call between `s_func` and `s_func_arg` modification. See esp_ipc_call_and_wait() */
+#ifdef CONFIG_ESP_IPC_USES_CALLERS_PRIORITY
+    ret = xSemaphoreTakeFromISR(s_ipc_mutex[cpu_id], NULL);
+#else
+    ret = xSemaphoreTakeFromISR(s_ipc_mutex[0], NULL);
+#endif
+    if (ret != pdTRUE) {
+        return ESP_ERR_TIMEOUT;
+    }
+
+    s_gcov_func = func;
+    s_gcov_func_arg = arg;
+    ret = xSemaphoreGiveFromISR(s_ipc_sem[cpu_id], NULL);
+
+#ifdef CONFIG_ESP_IPC_USES_CALLERS_PRIORITY
+    xSemaphoreGiveFromISR(s_ipc_mutex[cpu_id], NULL);
+#else
+    xSemaphoreGiveFromISR(s_ipc_mutex[0], NULL);
+#endif
+
+    return ret == pdTRUE ? ESP_OK : ESP_FAIL;
+}
+#endif

examples/system/gcov/README.md

@@ -1,3 +1,6 @@
+| Supported Targets | ESP32 | ESP32-S2 |
+| ----------------- | ----- | -------- |
+
 # Blink Example With Coverage Info (Gcov)
 
 (See the README.md file in the upper level 'examples' directory for more information about examples.)
@@ -13,10 +16,10 @@ This example implements a simple blink application but with code coverage enable
 
 ### Hardware Required
 
-To run this example, you need an ESP32 dev board connected to a JTAG adapter, which can come in the following forms:
+To run this example, you need a supported dev board connected to a JTAG adapter, which can come in the following forms:
 
 * [ESP-WROVER-KIT](https://docs.espressif.com/projects/esp-idf/en/latest/hw-reference/modules-and-boards.html#esp-wrover-kit-v4-1) which integrates an on-board JTAG adapter. Ensure that the [required jumpers to enable JTAG are connected](https://docs.espressif.com/projects/esp-idf/en/latest/get-started/get-started-wrover-kit.html#setup-options) on the WROVER-KIT.
-* ESP32 core board (e.g. ESP32-DevKitC) can also work as long as you connect it to an external JTAG adapter (e.g. FT2232H, J-LINK).
+* ESP32 or ESP32-S2 core board (e.g. ESP32-DevKitC, [ESP32-S2-Saola-1](https://docs.espressif.com/projects/esp-idf/en/latest/esp32s2/hw-reference/esp32s2/user-guide-saola-1-v1.2.html)) can also work as long as you connect it to an external JTAG adapter (e.g. FT2232H, J-LINK).
 
 This example will assume that that an ESP-WROVER-KIT is used.
 

examples/system/gcov/sdkconfig.ci

@@ -0,0 +1 @@
+CONFIG_FREERTOS_UNICORE=y