feedc0de/esp-idf
1
0
Fork 0
forked from espressif/esp-idf
Code Pull Requests Activity

fix(esp_event): Fix event loop profiling in handler_execute function

Browse Source 
handler_execute function is looking to match the handler only in the
list of loop events but does not look in the base event handler list
nor the id event handler list. So unless the event handler is
registered to be triggered for all event bases and all event ids of
an event loop, its profiling fields (invoked and time) are not updated
when it is called.

This commit updates the search for the matching handler to also look
in base event list and ID event list.

Closes https://github.com/espressif/esp-idf/issues/15041
This commit is contained in:
Guillaume Souchere
2024-12-17 11:46:58 +01:00
parent b7d6d7459e
commit 295f691e14
4 changed files with 95 additions and 9 deletions
Download Patch File Download Diff File Expand all files Collapse all files

42
components/esp_event/esp_event.c
View File

@@ -22,7 +22,7 @@
/* ---------------------------- Definitions --------------------------------- */
#ifdef CONFIG_ESP_EVENT_LOOP_PROFILING
// LOOP @<address, name> rx:<recieved events no.> dr:<dropped events no.>
// LOOP @<address, name> rx:<received events no.> dr:<dropped events no.>
#define LOOP_DUMP_FORMAT "LOOP @%p,%s rx:%" PRIu32 " dr:%" PRIu32 "\n"
// handler @<address> ev:<base, id> inv:<times invoked> time:<runtime>
#define HANDLER_DUMP_FORMAT " HANDLER @%p ev:%s,%s inv:%" PRIu32 " time:%lld us\n"
@@ -146,14 +146,42 @@ static void handler_execute(esp_event_loop_instance_t* loop, esp_event_handler_n
// This happens in "handler instance can unregister itself" test case.
// To prevent memory corruption error it's necessary to check if pointer is still valid.
esp_event_loop_node_t* loop_node;
esp_event_handler_node_t* handler_node;
SLIST_FOREACH(loop_node, &(loop->loop_nodes), next) {
// try to find the handler amongst the list of handlers that are registered on the
// loop level (i.e., registered to be triggered for all events)
esp_event_handler_node_t* handler_node;
SLIST_FOREACH(handler_node, &(loop_node->handlers), next) {
if (handler_node == handler) {
handler->invoked++;
handler->time += diff;
}
}
// try to find the handler amongst the list of handlers that are registered on the
// base level (i.e., registered to be triggered for all events of a specific event base)
esp_event_base_node_t* base_node;
SLIST_FOREACH(base_node, &(loop_node->base_nodes), next) {
esp_event_handler_node_t* base_handler_node;
SLIST_FOREACH(base_handler_node, &(base_node->handlers), next) {
if (base_handler_node == handler) {
handler->invoked++;
handler->time += diff;
}
}
// try to find the handler amongst the list of handlers that are registered on the
// ID level (i.e., registered to be triggered for a specific event ID of a specific event base)
esp_event_id_node_t* id_node;
SLIST_FOREACH(id_node, &(base_node->id_nodes), next) {
esp_event_handler_node_t* id_handler_node;
SLIST_FOREACH(id_handler_node, &(id_node->handlers), next) {
if (id_handler_node == handler) {
handler->invoked++;
handler->time += diff;
}
}
}
}
}
xSemaphoreGive(loop->profiling_mutex);
@@ -885,7 +913,7 @@ esp_err_t esp_event_post_to(esp_event_loop_handle_t event_loop, esp_event_base_t
}
#ifdef CONFIG_ESP_EVENT_LOOP_PROFILING
atomic_fetch_add(&loop->events_recieved, 1);
atomic_fetch_add(&loop->events_received, 1);
#endif
return ESP_OK;
@@ -933,7 +961,7 @@ esp_err_t esp_event_isr_post_to(esp_event_loop_handle_t event_loop, esp_event_ba
}
#ifdef CONFIG_ESP_EVENT_LOOP_PROFILING
atomic_fetch_add(&loop->events_recieved, 1);
atomic_fetch_add(&loop->events_received, 1);
#endif
return ESP_OK;
@@ -962,13 +990,13 @@ esp_err_t esp_event_dump(FILE* file)
portENTER_CRITICAL(&s_event_loops_spinlock);
SLIST_FOREACH(loop_it, &s_event_loops, next) {
uint32_t events_recieved, events_dropped;
uint32_t events_received, events_dropped;
events_recieved = atomic_load(&loop_it->events_recieved);
events_received = atomic_load(&loop_it->events_received);
events_dropped = atomic_load(&loop_it->events_dropped);
PRINT_DUMP_INFO(dst, sz, LOOP_DUMP_FORMAT, loop_it, loop_it->task != NULL ? loop_it->name : "none",
events_recieved, events_dropped);
events_received, events_dropped);
int sz_bak = sz;

2
components/esp_event/private_include/esp_event_internal.h
View File

@@ -76,7 +76,7 @@ typedef struct esp_event_loop_instance {
esp_event_loop_nodes_t loop_nodes; /**< set of linked lists containing the
registered handlers for the loop */
#ifdef CONFIG_ESP_EVENT_LOOP_PROFILING
atomic_uint_least32_t events_recieved; /**< number of events successfully posted to the loop */
atomic_uint_least32_t events_received; /**< number of events successfully posted to the loop */
atomic_uint_least32_t events_dropped; /**< number of events dropped due to queue being full */
SemaphoreHandle_t profiling_mutex; /**< mutex used for profiliing */
SLIST_ENTRY(esp_event_loop_instance) next; /**< next event loop in the list */

46
components/esp_event/test_apps/main/test_event_common.cpp
View File

@@ -1597,3 +1597,49 @@ TEST_CASE("default event loop: registering event handler instance without instan
TEST_ESP_OK(esp_event_loop_delete_default());
}
#if CONFIG_ESP_EVENT_LOOP_PROFILING
static void handler_all(void* arg, esp_event_base_t event_base, int32_t event_id, void* data)
{
printf("Event received: base=%s, id=%" PRId32 ", data=%p\n", event_base, event_id, data);
}
static void handler_base(void* arg, esp_event_base_t event_base, int32_t event_id, void* data)
{
printf("Event received: base=%s, id=%" PRId32 ", data=%p\n", event_base, event_id, data);
}
static void handler_id(void* arg, esp_event_base_t event_base, int32_t event_id, void* data)
{
printf("Event received: base=%s, id=%" PRId32 ", data=%p\n", event_base, event_id, data);
}
TEST_CASE("profiling reports valid values", "[event][default]")
{
TEST_ESP_OK(esp_event_loop_create_default());
/* register handler for event base 1 and event id 1 */
TEST_ESP_OK(esp_event_handler_register(s_test_base1, TEST_EVENT_BASE1_EV1, handler_id, NULL));
/* register handler for event base 1 and all event ids */
TEST_ESP_OK(esp_event_handler_register(s_test_base1, ESP_EVENT_ANY_ID, handler_base, NULL));
/* register handler for all event bases and all event ids */
TEST_ESP_OK(esp_event_handler_register(ESP_EVENT_ANY_BASE, ESP_EVENT_ANY_ID, handler_all, NULL));
/* post an event on event base 1, event id 1 */
TEST_ESP_OK(esp_event_post(s_test_base1, TEST_EVENT_BASE1_EV1, NULL, 0, pdMS_TO_TICKS(1000)));
/* post an event 1 from base 1 and check the dump.
* - 3 handlers invoked, exec time is not 0 */
esp_event_dump(stdout);
/* unregister handlers */
TEST_ESP_OK(esp_event_handler_unregister(ESP_EVENT_ANY_BASE, ESP_EVENT_ANY_ID, handler_all));
TEST_ESP_OK(esp_event_handler_unregister(s_test_base1, ESP_EVENT_ANY_ID, handler_base));
TEST_ESP_OK(esp_event_handler_unregister(s_test_base1, TEST_EVENT_BASE1_EV1, handler_id));
/* delete loop */
TEST_ESP_OK(esp_event_loop_delete_default());
}
#endif // CONFIG_ESP_EVENT_LOOP_PROFILING

14
components/esp_event/test_apps/pytest_esp_event.py
View File

@@ -1,4 +1,4 @@
# SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2022-2024 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: CC0-1.0
import pytest
@@ -29,3 +29,15 @@ def test_esp_event_posix_simulator(dut: Dut) -> None:
dut.expect_exact('Press ENTER to see the list of tests.')
dut.write('*')
dut.expect(r'\d{2} Tests 0 Failures 0 Ignored', timeout=120)
@pytest.mark.esp32
@pytest.mark.generic
def test_esp_event_profiling(dut: Dut) -> None:
dut.expect_exact('Press ENTER to see the list of tests.')
dut.write('"profiling reports valid values"')
# look for all references of handlers invoked at least 1 time
# with an execution time superior to 0 us
matches = dut.expect(r'HANDLER .+ inv:[1-9][0-9]{0,} time:[1-9][0-9]{0,} us', timeout=2)
matches_arr = matches.group().split(b'\r\n')
assert (len(matches_arr) == 3)