From 3eaba1c8ce7331ecc4511e0ce4c192b9d05b1e8a Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Thu, 18 Oct 2018 19:10:33 +0300 Subject: [PATCH 1/2] esp32: Fixes SystemView lock's IRQ state restore --- components/app_trace/app_trace.c | 1 - .../app_trace/sys_view/Config/SEGGER_SYSVIEW_Conf.h | 9 +++++---- .../Sample/Config/SEGGER_SYSVIEW_Config_FreeRTOS.c | 7 +++++-- 3 files changed, 10 insertions(+), 7 deletions(-) diff --git a/components/app_trace/app_trace.c b/components/app_trace/app_trace.c index 5552fe5e2a..20871b44dc 100644 --- a/components/app_trace/app_trace.c +++ b/components/app_trace/app_trace.c @@ -172,7 +172,6 @@ #define ESP_APPTRACE_PRINT_LOCK 0 -#define LOG_LOCAL_LEVEL CONFIG_LOG_DEFAULT_LEVEL #include "esp_log.h" const static char *TAG = "esp_apptrace"; diff --git a/components/app_trace/sys_view/Config/SEGGER_SYSVIEW_Conf.h b/components/app_trace/sys_view/Config/SEGGER_SYSVIEW_Conf.h index 787237a00b..2968c6e021 100644 --- a/components/app_trace/sys_view/Config/SEGGER_SYSVIEW_Conf.h +++ b/components/app_trace/sys_view/Config/SEGGER_SYSVIEW_Conf.h @@ -166,10 +166,11 @@ Revision: $Rev: 5927 $ #define SEGGER_SYSVIEW_GET_INTERRUPT_ID() SEGGER_SYSVIEW_X_GetInterruptId() // Get the currently active interrupt Id from the user-provided function. #endif -void SEGGER_SYSVIEW_X_SysView_Lock(); -void SEGGER_SYSVIEW_X_SysView_Unlock(); -#define SEGGER_SYSVIEW_LOCK() SEGGER_SYSVIEW_X_SysView_Lock() -#define SEGGER_SYSVIEW_UNLOCK() SEGGER_SYSVIEW_X_SysView_Unlock() +unsigned SEGGER_SYSVIEW_X_SysView_Lock(); +void SEGGER_SYSVIEW_X_SysView_Unlock(unsigned int_state); +// to be recursive save IRQ status on the stack of the caller +#define SEGGER_SYSVIEW_LOCK() unsigned _SYSVIEW_int_state = SEGGER_SYSVIEW_X_SysView_Lock() +#define SEGGER_SYSVIEW_UNLOCK() SEGGER_SYSVIEW_X_SysView_Unlock(_SYSVIEW_int_state) #endif // SEGGER_SYSVIEW_CONF_H diff --git a/components/app_trace/sys_view/Sample/Config/SEGGER_SYSVIEW_Config_FreeRTOS.c b/components/app_trace/sys_view/Sample/Config/SEGGER_SYSVIEW_Config_FreeRTOS.c index 08e85678ef..2df7ee0c12 100644 --- a/components/app_trace/sys_view/Sample/Config/SEGGER_SYSVIEW_Config_FreeRTOS.c +++ b/components/app_trace/sys_view/Sample/Config/SEGGER_SYSVIEW_Config_FreeRTOS.c @@ -337,15 +337,18 @@ void SEGGER_SYSVIEW_X_RTT_Unlock() { } -void SEGGER_SYSVIEW_X_SysView_Lock() +unsigned SEGGER_SYSVIEW_X_SysView_Lock() { esp_apptrace_tmo_t tmo; esp_apptrace_tmo_init(&tmo, SEGGER_LOCK_WAIT_TMO); esp_apptrace_lock_take(&s_sys_view_lock, &tmo); + // to be recursive save IRQ status on the stack of the caller to keep it from overwriting + return s_sys_view_lock.int_state; } -void SEGGER_SYSVIEW_X_SysView_Unlock() +void SEGGER_SYSVIEW_X_SysView_Unlock(unsigned int_state) { + s_sys_view_lock.int_state = int_state; esp_apptrace_lock_give(&s_sys_view_lock); } From 3139b2d533497fd3987065bb7b8209fdbb12b7dc Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Thu, 18 Oct 2018 19:14:44 +0300 Subject: [PATCH 2/2] example: Adds SystemView tracing example app --- .../sys_view/SEGGER/SEGGER_SYSVIEW.c | 2 +- .../system/sysview_tracing/CMakeLists.txt | 6 + examples/system/sysview_tracing/Makefile | 9 + examples/system/sysview_tracing/README.md | 144 ++++++++++++ .../sysview_tracing/SYSVIEW_FreeRTOS.txt | 110 +++++++++ examples/system/sysview_tracing/gdbinit | 15 ++ .../sysview_tracing/main/CMakeLists.txt | 4 + .../sysview_tracing/main/Kconfig.projbuild | 12 + .../system/sysview_tracing/main/component.mk | 3 + .../sysview_tracing/main/sysview_tracing.c | 216 ++++++++++++++++++ .../system/sysview_tracing/sdkconfig.defaults | 22 ++ 11 files changed, 542 insertions(+), 1 deletion(-) create mode 100644 examples/system/sysview_tracing/CMakeLists.txt create mode 100644 examples/system/sysview_tracing/Makefile create mode 100644 examples/system/sysview_tracing/README.md create mode 100644 examples/system/sysview_tracing/SYSVIEW_FreeRTOS.txt create mode 100644 examples/system/sysview_tracing/gdbinit create mode 100644 examples/system/sysview_tracing/main/CMakeLists.txt create mode 100644 examples/system/sysview_tracing/main/Kconfig.projbuild create mode 100644 examples/system/sysview_tracing/main/component.mk create mode 100644 examples/system/sysview_tracing/main/sysview_tracing.c create mode 100644 examples/system/sysview_tracing/sdkconfig.defaults diff --git a/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c b/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c index c7460903b6..e0d48aca28 100644 --- a/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c +++ b/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c @@ -2368,7 +2368,7 @@ void SEGGER_SYSVIEW_RegisterModule(SEGGER_SYSVIEW_MODULE* pModule) { _pFirstModule = pModule; _NumModules++; } - SEGGER_SYSVIEW_SendModule(0); + SEGGER_SYSVIEW_SendModule(_NumModules-1); if (pModule->pfSendModuleDesc) { pModule->pfSendModuleDesc(); } diff --git a/examples/system/sysview_tracing/CMakeLists.txt b/examples/system/sysview_tracing/CMakeLists.txt new file mode 100644 index 0000000000..8c11f89459 --- /dev/null +++ b/examples/system/sysview_tracing/CMakeLists.txt @@ -0,0 +1,6 @@ +# The following lines of boilerplate have to be in your project's CMakeLists +# in this exact order for cmake to work correctly +cmake_minimum_required(VERSION 3.5) + +include($ENV{IDF_PATH}/tools/cmake/project.cmake) +project(sysview_tracing) diff --git a/examples/system/sysview_tracing/Makefile b/examples/system/sysview_tracing/Makefile new file mode 100644 index 0000000000..0de049c436 --- /dev/null +++ b/examples/system/sysview_tracing/Makefile @@ -0,0 +1,9 @@ +# +# This is a project Makefile. It is assumed the directory this Makefile resides in is a +# project subdirectory. +# + +PROJECT_NAME := sysview_tracing + +include $(IDF_PATH)/make/project.mk + diff --git a/examples/system/sysview_tracing/README.md b/examples/system/sysview_tracing/README.md new file mode 100644 index 0000000000..960e31693e --- /dev/null +++ b/examples/system/sysview_tracing/README.md @@ -0,0 +1,144 @@ +# Example: Application Level Tracing - SystemView Tracing (sysview_tracing) + +This test code shows how to perform system-wide behavioral analysis of the program using [SEGGER SystemView tool](https://www.segger.com/products/development-tools/systemview/). + +For description of [SystemView tracing](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#system-behaviour-analysis-with-segger-systemview) please refer to **ESP32 Programming Guide**, section **Application Level Tracing library**. The following example provides practical implementation of this functionality. + + +## Use Case + +To find the reason of program's misbehaviour it is often necessary to have the whole picture of interacting components (scheduler, IRQs, tasks, semaphores etc.) in the system. In such cases tools which allow to trace the behaviour of the system as a whole can be very useful. +Consider the following situation. User program have a timer and a task. Upon every tick the timer sends an event to the task. When task receives event it prints a message. Timer should notify the task 10 times. +There can be a problem which causes the task to lose some events. +Below is the timer's ISR code: + +``` +static void example_timer_isr(void *arg) +{ + example_event_data_t *tim_arg = (example_event_data_t *)arg; + + if (tim_arg->thnd != NULL) { + if (tim_arg->count++ < 10) { + BaseType_t xHigherPriorityTaskWoken = pdFALSE; + if (xTaskNotifyFromISR(tim_arg->thnd, tim_arg->count, eSetValueWithOverwrite, &xHigherPriorityTaskWoken) != pdPASS) { + ESP_EARLY_LOGE(TAG, "Failed to notify task %p", tim_arg->thnd); + } else { + if (xHigherPriorityTaskWoken == pdTRUE) { + portYIELD_FROM_ISR(); + } + } + } + } + // re-start timer + example_timer_rearm(tim_arg->group, tim_arg->timer); +} +``` + +Below is the task's code: + +``` +static void example_task(void *p) +{ + example_event_data_t *arg = (example_event_data_t *) p; + timer_isr_handle_t inth; + + ESP_LOGI(TAG, "%p: run task", xTaskGetCurrentTaskHandle()); + + esp_err_t res = timer_isr_register(arg->group, arg->timer, example_timer_isr, arg, 0, &inth); + if (res != ESP_OK) { + ESP_LOGE(TAG, "%p: failed to register timer ISR", xTaskGetCurrentTaskHandle()); + } + else { + res = timer_start(arg->group, arg->timer); + if (res != ESP_OK) { + ESP_LOGE(TAG, "%p: failed to start timer", xTaskGetCurrentTaskHandle()); + } + } + + while (1) { + uint32_t event_val; + xTaskNotifyWait(0, 0, &event_val, portMAX_DELAY); + ESP_LOGI(TAG, "Task[%p]: received event %d", xTaskGetCurrentTaskHandle(), event_val); + } +} +``` + +Potential problem can arise in such program because task and timer has no any mechanism to acknowledge the events transfer. Task needs some time to process an event before waiting for the next one. In this case call to `ESP_LOGI` will be the most time consuming part of event processing. Therefore when timer's ISR is called at some rate it can happen that `xTaskNotifyFromISR` gets called several times before task calls `xTaskNotifyWait`. In these conditions some events will be lost. Possible solution for this is to increase timer's tick period or to use some events acknowledgement mechanism. + +Check the full example code [sysview_tracing](main/sysview_tracing.c) that when compiled in dual core mode reproduces the described problem on both cores. Below is the output of example compiled in signle core mode. It shows that task misses several events: + +``` +I (295) example: 0x3ffb6c10: run task +I (297) example: Task[0x3ffb6c10]: received event 1 +I (300) example: Task[0x3ffb6c10]: received event 2 +I (306) example: Task[0x3ffb6c10]: received event 5 +I (311) example: Task[0x3ffb6c10]: received event 8 +I (317) example: Task[0x3ffb6c10]: received event 10 +``` + + +## Detecting The Reason Of The Problem + +Besides built-in functionality to trace FreeRTOS internal operations SystemView also provides user with means to define its own trace messages and transfer problem-specific data to the host. In this example we extend SystemView with user-defined tracing module in order to +make the root cause of the problem more clear in the gathered trace. + +There are two ways to send user-defined info to SystemView: +1. Using built-in SystemView messages. This method uses `SEGGER_SYSVIEW_OnUserStart` and `SEGGER_SYSVIEW_OnUserStop` API to indicate that some user event started or stopped. Disadvantge of this way is that those API do not carry any other data except for user event ID. Advantage is that you do not need to write any additional code to use these functions. In SystemView messages sent by means of that API will be shown as `User Start` or `User Stop` with user event ID as only parameter: 0 - for timer and 1 - for task in this example. +2. Using custom SystemView messages. This is more flexible way. It implies extending SystemView with user module having its own set of events with any number of parameters (data) in each. For more details on extending see [code of this example](main/sysview_tracing.c) and [SystemView User Manual](https://www.segger.com/downloads/jlink/UM08027). + +To run the example and find out the reason of the problem: + +1. Connect JTAG interface to ESP32 board, power up both JTAG and ESP32. For details how to setup JTAG interface see [JTAG Debugging](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html). + +2. [Run OpenOCD](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html#run-openocd). If you are using the [binary distribution of OpenOCD](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html#jtag-debugging-setup-openocd) and one of versions of [ESP-WROVER-KIT](https://docs.espressif.com/projects/esp-idf/en/latest/hw-reference/modules-and-boards.html#esp-wrover-kit-v3), respective command line will look as follows: + + ``` + cd ~/esp/openocd-esp32 + bin/openocd -s share/openocd/scripts -f interface/ftdi/esp32_devkitj_v1.cfg -f board/esp-wroom-32.cfg + ``` +NOTE: In order to run this example you need OpenOCD version `v0.10.0-esp32-20181105` or later. + +3. Compile and load the example. Note to enable application tracing in menuconfig by going to `Component config > Application Level Tracing` and selecting `(X) Trace memory`. Also in order to generate SystemView trace data you need to enable this in `Component config > Application Level Tracing > FreeRTOS SystemView Tracing` by checking `(X) SystemView Tracing Enable`. Also ensure that all SystemView events are enabled there. + +4. If you are going to use custom events enable them by checking `Example Configuration > Use custom SystemView event IDs`. By default SystemView shows only numeric values of IDs and parameters for custom messages in `Events` view. To make them pretty-looking you need to define for them parsing templates in `SYSVIEW_FreeRTOS.txt` which is resided in SystemView installation directory. For this example you can use `SYSVIEW_FreeRTOS.txt` from the project's root directory. + +5. It is useful to use GDB to start and/or stop tracing automatically. To do this you need to prepare special `gdbinit` file: + + ``` + target remote :3333 + mon reset halt + b app_main + commands + mon esp32 sysview start file:///tmp/sysview_example.svdat + # For dual-core mode uncomment the line below and comment the line above + # mon esp32 sysview start file:///tmp/sysview_example0.svdat file:///tmp/sysview_example1.svdat + c + end + c + ``` + + Using this file GDB will connect to the target, reset it, and start tracing when it hit breakpoint at `app_main`. Trace data will be saved to `/tmp/sysview_example.svdat`. + +6. Run GDB using the following command from the project root directory: + + ``` + xtensa-esp32-elf-gdb -x gdbinit build/sysview_tracing.elf + ``` + +7. When program prints the last message, interrupt its execution (e.g. by pressing `CTRL+C`) and type the following command in GDB console to stop tracing: + + ``` + mon esp32 sysview stop + ``` + + You can also use another breakpoint to stop tracing and add respective lines to `gdbinit` at step 5. + +8. Open trace data file in SystemView tool. + +9. Right-click on any event in `Events` view and select: + + - `Show User Events only` if you compiled example to use only built-in event. + - `Show APIs only` if you compiled example to use custom events. + +10. Now you can navigate over user-defined messages and see when timer `TG1_T0_LEVEL` sends events (`SYSVIEW_EXAMPLE_SEND_EVENT_START/STOP` or `User Start/Stop(0)`) and when task `svtrace0` reads them (`SYSVIEW_EXAMPLE_WAIT_EVENT_START/STOP` or `User Start/Stop(1)`). + If you compiled example to use custom events you will also be able to see the values sent by timer and ones actually received by tasks. diff --git a/examples/system/sysview_tracing/SYSVIEW_FreeRTOS.txt b/examples/system/sysview_tracing/SYSVIEW_FreeRTOS.txt new file mode 100644 index 0000000000..20ecc0b632 --- /dev/null +++ b/examples/system/sysview_tracing/SYSVIEW_FreeRTOS.txt @@ -0,0 +1,110 @@ +128 vTaskAllocateMPURegions xTask=%t pxRegions=%u +33 vTaskDelete xTaskToDelete=%t +34 vTaskDelay xTicksToDelay=%u +35 vTaskDelayUntil +129 uxTaskPriorityGet xTask=%t +56 uxTaskPriorityGetFromISR xTask=%t +130 eTaskGetState xTask=%t +55 vTaskPrioritySet xTask=%t uxNewPriority=%u +36 vTaskSuspend xTaskToSuspend=%t +40 vTaskResume xTaskToResume=%t +43 xTaskResumeFromISR xTaskToResume=%t +131 vTaskStartScheduler +132 vTaskEndScheduler +133 vTaskSuspendAll +134 xTaskResumeAll +135 xTaskGetTickCount +57 xTaskGetTickCountFromISR +136 uxTaskGetNumberOfTasks +137 pcTaskGetTaskName xTaskToQuery=%t +138 uxTaskGetStackHighWaterMark xTask=%t +139 vTaskSetApplicationTaskTag xTask=%t pxHookFunction=%u +140 xTaskGetApplicationTaskTag xTask=%t +141 vTaskSetThreadLocalStoragePointer xTaskToSet=%T xIndex=%u pvValue=%u +142 pvTaskGetThreadLocalStoragePointer xTaskToQuery=%T xIndex=%u +143 xTaskCallApplicationTaskHook xTask=%T pvParameter=%u +144 xTaskGetIdleTaskHandle +145 uxTaskGetSystemState pxTaskStatusArray=%u uxArraySize=%u pulTotalRunTime=%u +146 vTaskList pcWriteBuffer=%u +147 vTaskGetRunTimeStats pcWriteBuffer=%u +44 xTaskGenericNotify xTaskToNotify=%t ulValue=%u eAction=%u pulPreviousNotificationValue=%u +45 xTaskGenericNotifyFromISR xTaskToNotify=%t ulValue=%u eAction=%u pulPreviousNotificationValue=%u pxHigherPriorityTaskWoken=%u +46 xTaskNotifyWait ulBitsToClearOnEntry=%u ulBitsToClearOnExit=%u pulNotificationValue=%u xTicksToWait=%u +38 vTaskNotifyGiveFromISR xTaskToNotify=%t pxHigherPriorityTaskWoken=%u +37 ulTaskNotifyTake xClearCountOnExit=%u xTicksToWait=%u +148 xTaskNotifyStateClear xTask=%t +149 xTaskGetCurrentTaskHandle +150 vTaskSetTimeOutState pxTimeOut=%u +151 xTaskCheckForTimeOut pxTimeOut=%u pxTicksToWait=%u +152 vTaskMissedYield +153 xTaskGetSchedulerState +39 vTaskPriorityInherit pxMutexHolder=%p +42 xTaskPriorityDisinherit pxMutexHolder=%p +154 xTaskGenericCreate pxTaskCode=%u pcName=%u usStackDepth=%u pvParameters=%u uxPriority=%u pxCreatedTask=%u puxStackBuffer=%u xRegions=%u +155 uxTaskGetTaskNumber xTask=%u +156 vTaskSetTaskNumber xTask=%u uxHandle=%u +41 vTaskStepTick xTicksToJump=%u +157 eTaskConfirmSleepModeStatus +158 xTimerCreate pcTimerName=%u xTimerPeriodInTicks=%u uxAutoReload=%u pvTimerID=%u pxCallbackFunction=%u +159 pvTimerGetTimerID xTimer=%u +160 vTimerSetTimerID xTimer=%u pvNewID=%u +161 xTimerIsTimerActive xTimer=%u +162 xTimerGetTimerDaemonTaskHandle +163 xTimerPendFunctionCallFromISR xFunctionToPend=%u pvParameter1=%u ulParameter2=%u pxHigherPriorityTaskWoken=%u +164 xTimerPendFunctionCall xFunctionToPend=%u pvParameter1=%u ulParameter2=%u xTicksToWait=%u +165 pcTimerGetTimerName xTimer=%u +166 xTimerCreateTimerTask +167 xTimerGenericCommand xTimer=%u xCommandID=%u xOptionalValue=%u pxHigherPriorityTaskWoken=%u xTicksToWait=%u +53 xQueueGenericSend xQueue=%I pvItemToQueue=%p xTicksToWait=%u xCopyPosition=%u +50 xQueuePeekFromISR xQueue=%I pvBuffer=%p +49 xQueueGenericReceive xQueue=%I pvBuffer=%p xTicksToWait=%u xJustPeek=%u +168 uxQueueMessagesWaiting xQueue=%I +169 uxQueueSpacesAvailable xQueue=%I +48 vQueueDelete xQueue=%I +54 xQueueGenericSendFromISR xQueue=%I pvItemToQueue=%p pxHigherPriorityTaskWoken=%u xCopyPosition=%u +61 xQueueGiveFromISR xQueue=%I pxHigherPriorityTaskWoken=%u +51 xQueueReceiveFromISR xQueue=%I pvBuffer=%p pxHigherPriorityTaskWoken=%u +62 xQueueIsQueueEmptyFromISR xQueue=%I +63 xQueueIsQueueFullFromISR xQueue=%I +170 uxQueueMessagesWaitingFromISR xQueue=%I +171 xQueueAltGenericSend xQueue=%I pvItemToQueue=%p xTicksToWait=%u xCopyPosition=%u +172 xQueueAltGenericReceive xQueue=%I pvBuffer=%p xTicksToWait=%u xJustPeeking=%u +173 xQueueCRSendFromISR xQueue=%I pvItemToQueue=%p xCoRoutinePreviouslyWoken=%u +174 xQueueCRReceiveFromISR xQueue=%I pvBuffer=%p pxTaskWoken=%u +175 xQueueCRSend xQueue=%I pvItemToQueue=%p xTicksToWait=%u +176 xQueueCRReceive xQueue=%I pvBuffer=%p xTicksToWait=%u +177 xQueueCreateMutex ucQueueType=%u +178 xQueueCreateCountingSemaphore uxMaxCount=%u uxInitialCount=%u +179 xQueueGetMutexHolder xSemaphore=%u +180 xQueueTakeMutexRecursive xMutex=%u xTicksToWait=%u +181 xQueueGiveMutexRecursive pxMutex=%u +52 vQueueAddToRegistry xQueue=%I pcName=%u +182 vQueueUnregisterQueue xQueue=%I +47 xQueueGenericCreate uxQueueLength=%u uxItemSize=%u ucQueueType=%u +183 xQueueCreateSet uxEventQueueLength=%u +184 xQueueAddToSet xQueueOrSemaphore=%u xQueueSet=%u +185 xQueueRemoveFromSet xQueueOrSemaphore=%u xQueueSet=%u +186 xQueueSelectFromSet xQueueSet=%u xTicksToWait=%u +187 xQueueSelectFromSetFromISR xQueueSet=%u +188 xQueueGenericReset xQueue=%I xNewQueue=%u +189 vListInitialise pxList=%u +190 vListInitialiseItem pxItem=%u +191 vListInsert pxList=%u pxNewListItem=%u +192 vListInsertEnd pxList=%u pxNewListItem=%u +193 uxListRemove pxItemToRemove=%u +194 xEventGroupCreate +195 xEventGroupWaitBits xEventGroup=%u uxBitsToWaitFor=%u xClearOnExit=%u xWaitForAllBits=%u xTicksToWait=%u +196 xEventGroupClearBits xEventGroup=%u uxBitsToClear=%u +58 xEventGroupClearBitsFromISR xEventGroup=%u uxBitsToSet=%u +197 xEventGroupSetBits xEventGroup=%u uxBitsToSet=%u +59 xEventGroupSetBitsFromISR xEventGroup=%u uxBitsToSet=%u pxHigherPriorityTaskWoken=%u +198 xEventGroupSync xEventGroup=%u uxBitsToSet=%u uxBitsToWaitFor=%u xTicksToWait=%u +60 xEventGroupGetBitsFromISR xEventGroup=%u +199 vEventGroupDelete xEventGroup=%u +200 uxEventGroupGetNumber xEventGroup=%u +512 SYSVIEW_EXAMPLE_SEND_EVENT_START +513 SYSVIEW_EXAMPLE_SEND_EVENT_END evt_val=%u +514 SYSVIEW_EXAMPLE_WAIT_EVENT_START +515 SYSVIEW_EXAMPLE_WAIT_EVENT_END evt_val=%u + + diff --git a/examples/system/sysview_tracing/gdbinit b/examples/system/sysview_tracing/gdbinit new file mode 100644 index 0000000000..03129b44a7 --- /dev/null +++ b/examples/system/sysview_tracing/gdbinit @@ -0,0 +1,15 @@ +target remote :3333 + +mon reset halt +flushregs + +b app_main +commands +mon esp32 sysview start file:///tmp/sysview_example.svdat +# For dual-core mode uncomment the line below and comment the line above +# mon esp32 sysview start file:///tmp/sysview_example0.svdat file:///tmp/sysview_example1.svdat +c +end + +c + diff --git a/examples/system/sysview_tracing/main/CMakeLists.txt b/examples/system/sysview_tracing/main/CMakeLists.txt new file mode 100644 index 0000000000..dfee658c9a --- /dev/null +++ b/examples/system/sysview_tracing/main/CMakeLists.txt @@ -0,0 +1,4 @@ +set(COMPONENT_SRCS "sysview_tracing.c") +set(COMPONENT_ADD_INCLUDEDIRS ".") + +register_component() diff --git a/examples/system/sysview_tracing/main/Kconfig.projbuild b/examples/system/sysview_tracing/main/Kconfig.projbuild new file mode 100644 index 0000000000..4a7c767053 --- /dev/null +++ b/examples/system/sysview_tracing/main/Kconfig.projbuild @@ -0,0 +1,12 @@ +menu "Example Configuration" + +config USE_CUSTOM_EVENT_ID + bool "Use custom SystemView event IDs" + default "n" + help + Use custom IDs for user events. If it is enabled, replace `SYSVIEW_FreeRTOS.txt` in SystemView + installation directory with the version from example's root directory. + + By default SYSVIEW_EVTID_USER_START/STOP are used for tracing purposes of the example. + +endmenu diff --git a/examples/system/sysview_tracing/main/component.mk b/examples/system/sysview_tracing/main/component.mk new file mode 100644 index 0000000000..44bd2b5273 --- /dev/null +++ b/examples/system/sysview_tracing/main/component.mk @@ -0,0 +1,3 @@ +# +# Main Makefile. This is basically the same as a component makefile. +# diff --git a/examples/system/sysview_tracing/main/sysview_tracing.c b/examples/system/sysview_tracing/main/sysview_tracing.c new file mode 100644 index 0000000000..3ac03d8da0 --- /dev/null +++ b/examples/system/sysview_tracing/main/sysview_tracing.c @@ -0,0 +1,216 @@ +/* Application Trace to Host Example + + This example code is in the Public Domain (or CC0 licensed, at your option.) + + Unless required by applicable law or agreed to in writing, this + software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + CONDITIONS OF ANY KIND, either express or implied. +*/ + +#include +#include +#include +#include "esp_log.h" +#include "freertos/FreeRTOS.h" +#include "freertos/task.h" +#include "driver/timer.h" + + +static const char *TAG = "example"; + +typedef struct { + int group; + int timer; + int count; + TaskHandle_t thnd; +} example_event_data_t; + + +#if CONFIG_SYSVIEW_ENABLE +#if !CONFIG_USE_CUSTOM_EVENT_ID + +#define SYSVIEW_EXAMPLE_SEND_EVENT_ID 0 +#define SYSVIEW_EXAMPLE_WAIT_EVENT_ID 1 + +#define SYSVIEW_EXAMPLE_SEND_EVENT_START() SEGGER_SYSVIEW_OnUserStart(SYSVIEW_EXAMPLE_SEND_EVENT_ID) +#define SYSVIEW_EXAMPLE_SEND_EVENT_END(_val_) SEGGER_SYSVIEW_OnUserStop(SYSVIEW_EXAMPLE_SEND_EVENT_ID) +#define SYSVIEW_EXAMPLE_WAIT_EVENT_START() SEGGER_SYSVIEW_OnUserStart(SYSVIEW_EXAMPLE_WAIT_EVENT_ID) +#define SYSVIEW_EXAMPLE_WAIT_EVENT_END(_val_) SEGGER_SYSVIEW_OnUserStop(SYSVIEW_EXAMPLE_WAIT_EVENT_ID) + +#else + +#define SYSVIEW_EXAMPLE_SEND_EVENT_START_ID 0 +#define SYSVIEW_EXAMPLE_SEND_EVENT_END_ID 1 +#define SYSVIEW_EXAMPLE_WAIT_EVENT_START_ID 2 +#define SYSVIEW_EXAMPLE_WAIT_EVENT_END_ID 3 +#define SYSVIEW_EXAMPLE_EVENT_MAX 4 + +#define SYSVIEW_EXAMPLE_SEND_EVENT_START() example_sysview_event_send(SYSVIEW_EXAMPLE_SEND_EVENT_START_ID, 0) +#define SYSVIEW_EXAMPLE_SEND_EVENT_END(_val_) example_sysview_event_send(SYSVIEW_EXAMPLE_SEND_EVENT_END_ID, _val_) +#define SYSVIEW_EXAMPLE_WAIT_EVENT_START() example_sysview_event_send(SYSVIEW_EXAMPLE_WAIT_EVENT_START_ID, 0) +#define SYSVIEW_EXAMPLE_WAIT_EVENT_END(_val_) example_sysview_event_send(SYSVIEW_EXAMPLE_WAIT_EVENT_END_ID, _val_) + +static void example_sysview_module_send_desc(void); + +static SEGGER_SYSVIEW_MODULE s_example_sysview_module = { + .sModule = "example_sysview_module", + .NumEvents = SYSVIEW_EXAMPLE_EVENT_MAX, + .pfSendModuleDesc = example_sysview_module_send_desc, +}; + +static void example_sysview_module_send_desc(void) +{ + SEGGER_SYSVIEW_RecordModuleDescription(&s_example_sysview_module, "Example SystemView User Module"); +} + +static void example_sysview_event_send(uint32_t id, uint32_t val) +{ + U8 aPacket[SEGGER_SYSVIEW_INFO_SIZE + SEGGER_SYSVIEW_QUANTA_U32]; + + U8* pPayload = SEGGER_SYSVIEW_PREPARE_PACKET(aPacket); + pPayload = SEGGER_SYSVIEW_EncodeU32(pPayload, val); // Add the parameter to the packet + SEGGER_SYSVIEW_SendPacket(&aPacket[0], pPayload, s_example_sysview_module.EventOffset + id); +} + +#endif + +#else + +#define SYSVIEW_EXAMPLE_SEND_EVENT_START() +#define SYSVIEW_EXAMPLE_SEND_EVENT_END(_val_) +#define SYSVIEW_EXAMPLE_WAIT_EVENT_START() +#define SYSVIEW_EXAMPLE_WAIT_EVENT_END(_val_) + +#endif + + +static void example_timer_init(int timer_group, int timer_idx, uint32_t period) +{ + timer_config_t config; + uint64_t alarm_val = (period * (TIMER_BASE_CLK / 1000000UL)) / 2; + + config.alarm_en = 1; + config.auto_reload = 1; + config.counter_dir = TIMER_COUNT_UP; + config.divider = 2; //Range is 2 to 65536 + config.intr_type = TIMER_INTR_LEVEL; + config.counter_en = TIMER_PAUSE; + /*Configure timer*/ + timer_init(timer_group, timer_idx, &config); + /*Stop timer counter*/ + timer_pause(timer_group, timer_idx); + /*Load counter value */ + timer_set_counter_value(timer_group, timer_idx, 0x00000000ULL); + /*Set alarm value*/ + timer_set_alarm_value(timer_group, timer_idx, alarm_val); + /*Enable timer interrupt*/ + timer_enable_intr(timer_group, timer_idx); +} + +static void example_timer_rearm(int timer_group, int timer_idx) +{ + if (timer_group == 0) { + if (timer_idx == 0) { + TIMERG0.int_clr_timers.t0 = 1; + TIMERG0.hw_timer[0].update = 1; + TIMERG0.hw_timer[0].config.alarm_en = 1; + } else { + TIMERG0.int_clr_timers.t1 = 1; + TIMERG0.hw_timer[1].update = 1; + TIMERG0.hw_timer[1].config.alarm_en = 1; + } + } + if (timer_group == 1) { + if (timer_idx == 0) { + TIMERG1.int_clr_timers.t0 = 1; + TIMERG1.hw_timer[0].update = 1; + TIMERG1.hw_timer[0].config.alarm_en = 1; + } else { + TIMERG1.int_clr_timers.t1 = 1; + TIMERG1.hw_timer[1].update = 1; + TIMERG1.hw_timer[1].config.alarm_en = 1; + } + } +} + +static void example_timer_isr(void *arg) +{ + example_event_data_t *tim_arg = (example_event_data_t *)arg; + + if (tim_arg->thnd != NULL) { + if (tim_arg->count++ < 10) { + BaseType_t xHigherPriorityTaskWoken = pdFALSE; + SYSVIEW_EXAMPLE_SEND_EVENT_START(); + if (xTaskNotifyFromISR(tim_arg->thnd, tim_arg->count, eSetValueWithOverwrite, &xHigherPriorityTaskWoken) != pdPASS) { + ESP_EARLY_LOGE(TAG, "Failed to notify task %p", tim_arg->thnd); + } else { + SYSVIEW_EXAMPLE_SEND_EVENT_END(tim_arg->count); + if (xHigherPriorityTaskWoken == pdTRUE) { + portYIELD_FROM_ISR(); + } + } + } + } + // re-start timer + example_timer_rearm(tim_arg->group, tim_arg->timer); +} + +static void example_task(void *p) +{ + example_event_data_t *arg = (example_event_data_t *) p; + timer_isr_handle_t inth; + + ESP_LOGI(TAG, "%p: run task", xTaskGetCurrentTaskHandle()); + + esp_err_t res = timer_isr_register(arg->group, arg->timer, example_timer_isr, arg, 0, &inth); + if (res != ESP_OK) { + ESP_LOGE(TAG, "%p: failed to register timer ISR", xTaskGetCurrentTaskHandle()); + } else { + res = timer_start(arg->group, arg->timer); + if (res != ESP_OK) { + ESP_LOGE(TAG, "%p: failed to start timer", xTaskGetCurrentTaskHandle()); + } + } + + while (1) { + uint32_t event_val; + SYSVIEW_EXAMPLE_WAIT_EVENT_START(); + xTaskNotifyWait(0, 0, &event_val, portMAX_DELAY); + SYSVIEW_EXAMPLE_WAIT_EVENT_END(event_val); + ESP_LOGI(TAG, "Task[%p]: received event %d", xTaskGetCurrentTaskHandle(), event_val); + } +} + +void app_main() +{ + static example_event_data_t event_data[portNUM_PROCESSORS] = { + { + .group = TIMER_GROUP_1, + .timer = TIMER_0, + }, +#if CONFIG_FREERTOS_UNICORE == 0 + { + .group = TIMER_GROUP_1, + .timer = TIMER_1, + }, +#endif + }; + +#if CONFIG_SYSVIEW_ENABLE && CONFIG_USE_CUSTOM_EVENT_ID + // Currently OpenOCD does not support requesting module info from target. So do the following... + // Give SystemView tracing module some time to handle START command from host, + // after that data can be sent to the host using onboard API, so user module description does not need to be requested by OpenOCD itself. + vTaskDelay(1); + SEGGER_SYSVIEW_RegisterModule(&s_example_sysview_module); +#endif + + example_timer_init(TIMER_GROUP_1, TIMER_0, 2000); + example_timer_init(TIMER_GROUP_1, TIMER_1, 4000); + + xTaskCreatePinnedToCore(example_task, "svtrace0", 2048, &event_data[0], 3, &event_data[0].thnd, 0); + ESP_LOGI(TAG, "Created task %p", event_data[0].thnd); +#if CONFIG_FREERTOS_UNICORE == 0 + xTaskCreatePinnedToCore(example_task, "svtrace1", 2048, &event_data[1], 3, &event_data[1].thnd, 1); + ESP_LOGI(TAG, "Created task %p", event_data[1].thnd); +#endif +} diff --git a/examples/system/sysview_tracing/sdkconfig.defaults b/examples/system/sysview_tracing/sdkconfig.defaults new file mode 100644 index 0000000000..d27d2611cd --- /dev/null +++ b/examples/system/sysview_tracing/sdkconfig.defaults @@ -0,0 +1,22 @@ +CONFIG_MEMMAP_SMP=n +CONFIG_FREERTOS_UNICORE=y +CONFIG_FREERTOS_HZ=1000 +# Enable application tracing by default +CONFIG_ESP32_APPTRACE_DEST_TRAX=y +CONFIG_ESP32_APPTRACE_ENABLE=y +# Enable FreeRTOS SystemView Tracing by default +CONFIG_SYSVIEW_ENABLE=y +CONFIG_SYSVIEW_TS_SOURCE_TIMER_00=y +CONFIG_SYSVIEW_EVT_OVERFLOW_ENABLE=y +CONFIG_SYSVIEW_EVT_ISR_ENTER_ENABLE=y +CONFIG_SYSVIEW_EVT_ISR_EXIT_ENABLE=y +CONFIG_SYSVIEW_EVT_ISR_TO_SCHEDULER_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_START_EXEC_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_STOP_EXEC_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_START_READY_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_STOP_READY_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_CREATE_ENABLE=y +CONFIG_SYSVIEW_EVT_TASK_TERMINATE_ENABLE=y +CONFIG_SYSVIEW_EVT_IDLE_ENABLE=y +CONFIG_SYSVIEW_EVT_TIMER_ENTER_ENABLE=y +CONFIG_SYSVIEW_EVT_TIMER_EXIT_ENABLE=y