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

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 48e11e68a1
commit d1a02e1854
5 changed files with 103 additions and 27 deletions

View File

@ -1,5 +1,5 @@
/*
* SPDX-FileCopyrightText: 2018-2023 Espressif Systems (Shanghai) CO LTD
* SPDX-FileCopyrightText: 2018-2025 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Apache-2.0
*/
@ -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"
@ -148,14 +148,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);
@ -894,7 +922,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;
@ -942,7 +970,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;
@ -971,13 +999,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);
PRINT_DUMP_INFO(dst, sz, LOOP_DUMP_FORMAT, loop_it, loop_it->task != NULL ? loop_it->name : "none",
events_received, events_dropped);
int sz_bak = sz;

View File

@ -1,16 +1,8 @@
// Copyright 2018 Espressif Systems (Shanghai) PTE LTD
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
/*
* SPDX-FileCopyrightText: 2018-2025 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Apache-2.0
*/
#ifndef ESP_EVENT_INTERNAL_H_
#define ESP_EVENT_INTERNAL_H_
@ -84,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 */

View File

@ -1,5 +1,5 @@
/*
* SPDX-FileCopyrightText: 2023 Espressif Systems (Shanghai) CO LTD
* SPDX-FileCopyrightText: 2023-2025 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Unlicense OR CC0-1.0
*/
@ -1571,3 +1571,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

View File

@ -1,6 +1,5 @@
# SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2022-2025 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: CC0-1.0
import pytest
from pytest_embedded import Dut
@ -43,3 +42,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)

View File

@ -403,7 +403,6 @@ components/esp_event/esp_event_private.c
components/esp_event/host_test/esp_event_unit_test/main/esp_event_test.cpp
components/esp_event/host_test/fixtures.hpp
components/esp_event/include/esp_event_loop.h
components/esp_event/private_include/esp_event_internal.h
components/esp_event/private_include/esp_event_private.h
components/esp_hid/include/esp_hid_common.h
components/esp_hid/include/esp_hidd.h