Hello,
I’m struggling to understand how logging works during PlatformIO tests using the Unity framework. I’ve encountered inconsistent behaviour with TEST_MESSAGE and haven’t been able to display my logs reliably.
Here’s what I’ve observed:
- Inconsistent Log Output: I can sometimes see my logs after a clean build and initial test run, but they disappear on subsequent runs.
- Successful Initial Run: Running
pio.exe test -vin a clean project builds the test from scratch, displays the output correctly, and the test fails as expected. - Subsequent Run Issues: When I run the
pio.exe testimmediately after, the test seems to succeed, and I don’t see any test output. It should have failed. - Verbose Mode Success: Running
pio.exe test -vagain results in the test failing as expected.
My assumptions that might be causing the issue:
TEST_MESSAGEshould be displayed without needing verbose mode or a customunity_conf.h.- The framework should automatically display failure messages.
I’m unsure what I’m missing and would appreciate any guidance on how to resolve this logging issue.
Thank you!
~\repos\esp-firmware git:[feature/led_driver]
pio.exe test -v
Collected 4 tests (embedded/test_data_storage, embedded/test_driver_led, embedded/test_gpio_utils, embedded/test_sensor_data)
Processing embedded/test_driver_led in esp32-s3-devkitc-1 environment
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Building & Uploading...
src/Console/consoleCommands.c:44:13: warning: 'commandArgumentStringLengthIsValid' defined but not used [-Wunused-function]
44 | static bool commandArgumentStringLengthIsValid(const oParsedCommand_t* commandParameters, const uint16_t maxLength)
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
src/Console/CLI.c: In function 'console_driver_init':
src/Console/CLI.c:205:5: warning: 'esp_vfs_dev_uart_use_driver' is deprecated: Please use uart_vfs_dev_use_driver() instead [-Wdeprecated-declarations]
205 | esp_vfs_dev_uart_use_driver(CONFIG_ESP_CONSOLE_UART_NUM);
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~
In file included from src/Console/CLI.c:38:
C:/Users/morin/.platformio/packages/framework-espidf/components/vfs/include/esp_vfs_dev.h:20:6: note: declared here
20 | void esp_vfs_dev_uart_use_driver(int uart_num) __attribute__((deprecated("Please use uart_vfs_dev_use_driver() instead")));
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~
src/OS_tasks/OS_sensorsTask.c: In function 'os_sensorsTask':
src/OS_tasks/OS_sensorsTask.c:135:23: warning: unused variable 'revolutions' [-Wunused-variable]
135 | int32_t position, revolutions;
| ^~~~~~~~~~~
src/OS_tasks/OS_sensorsTask.c:135:13: warning: unused variable 'position' [-Wunused-variable]
135 | int32_t position, revolutions;
| ^~~~~~~~
src/OS_tasks/OS_sensorsTask.c: At top level:
src/OS_tasks/OS_sensorsTask.c:52:23: warning: 'dev' defined but not used [-Wunused-variable]
52 | static lis2dh12_dev_t dev = {
| ^~~
src/Wifi/wifi_access_point.c: In function 'wifi_init_softap':
src/Wifi/wifi_access_point.c:76:5: warning: 'esp_wifi_config_espnow_rate' is deprecated: This API can be only used when rate is non-HE rate, please use esp_now_set_peer_rate_config if you want full support of the rate. [-Wdeprecated-declarations]
76 | esp_wifi_config_espnow_rate(WIFI_IF_AP, WIFI_PHY_RATE_1M_L);
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~
In file included from src/Wifi/wifi_access_point.c:12:
C:/Users/morin/.platformio/packages/framework-espidf/components/esp_wifi/include/esp_now.h:270:11: note: declared here
270 | esp_err_t esp_wifi_config_espnow_rate(wifi_interface_t ifx, wifi_phy_rate_t rate)
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:212:13: warning: 'test_al5887_power_modes' defined but not used [-Wunused-function]
212 | static void test_al5887_power_modes(void)
| ^~~~~~~~~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:178:13: warning: 'test_al5887_global_brightness' defined but not used [-Wunused-function]
178 | static void test_al5887_global_brightness(void)
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:142:13: warning: 'test_al5887_color_control' defined but not used [-Wunused-function]
142 | static void test_al5887_color_control(void)
| ^~~~~~~~~~~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:114:13: warning: 'test_al5887_individual_led_control' defined but not used [-Wunused-function]
114 | static void test_al5887_individual_led_control(void)
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:79:13: warning: 'test_al5887_init' defined but not used [-Wunused-function]
79 | static void test_al5887_init(void)
| ^~~~~~~~~~~~~~~~
test/embedded/test_driver_led/driver_led.c:24:18: warning: 'al5887_diagnostic_check' defined but not used [-Wunused-function]
24 | static esp_err_t al5887_diagnostic_check(void)
| ^~~~~~~~~~~~~~~~~~~~~~~
Testing...
If you don't see any output for the first 10 secs, please reset board (press reset button)
I (96) boot: 5 ota_1 OTA app 00 11 017) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=0b404h ( 46084) map
I (134) esp_image: segment 1: paddr=0001b42c vaddr=3fc92800 size=02c78h ( 11384) load
I (137) esp_image: segment 2: paddr=0001e0ac vaddr=40374000 size=01f6ch ( 8044) load
I (145) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=1ce40h (118336) map
I (172) esp_image: segment 4: paddr=0003ce68 vaddr=40375f6c size=0c884h ( 51332) load
I (190) boot: Loaded app from partition at offset 0x10000
I (190) boot: Disabling RNG early entropy source...
I (202) cpu_start: Multicore app
I (211) cpu_start: Pro cpu start user code
I (211) cpu_start: cpu freq: 160000000 Hz
I (212) app_init: Application information:
I (214) app_init: Project name: esp32-firmware
I (220) app_init: App version: 0.2.1
I (225) app_init: Compile time: Nov 17 2024 09:44:22
I (231) app_init: ELF file SHA256: 6af551a2d...
I (236) app_init: ESP-IDF: 5.3.1
I (241) efuse_init: Min chip rev: v0.0
I (246) efuse_init: Max chip rev: v0.99
I (251) efuse_init: Chip rev: v0.2
I (256) heap_init: Initializing. RAM available for dynamic allocation:
I (263) heap_init: At 3FC95DD8 len 00053938 (334 KiB): RAM
I (269) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (275) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (281) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (288) spi_flash: detected chip: gd
I (292) spi_flash: flash io: dio
W (296) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
I (306) sleep: Configure to isolate all GPIO pins in sleep state
I (313) sleep: Enable automatic switching of GPIO sleep configuration
I (320) coexist: coex firmware version: 4482466
I (325) coexist: coexist rom version e7ae62f
I (331) main_task: Started on CPU0
I (341) main_task: Calling app_main()
test/embedded/test_driver_led/led_action.c:21:test_create_and_free_led_action:INFO: Testing create_led_action and free_led_action
test/embedded/test_driver_led/led_action.c:38:test_create_and_free_led_action:INFO: led_action_t freed successfully
test/embedded/test_driver_led/led_action.c:67:test_create_and_free_led_action:PASS
test/embedded/test_driver_led/led_action.c:42:test_create_and_free_led_action_group:INFO: Testing create_led_action_group and free_led_action_group
test/embedded/test_driver_led/led_action.c:43:test_create_and_free_led_action_group:FAIL: This test is intentionally failing.
-----------------------
2 Tests 1 Failures 0 Ignored
--------------------------------------------------------- esp32-s3-devkitc-1:embedded/test_driver_led [FAILED] Took 66.34 seconds ---------------------------------------------------------
========================================================================================= SUMMARY =========================================================================================
Environment Test Status Duration
------------------ -------------------------- -------- ------------
esp32-s3-devkitc-1 embedded/test_data_storage SKIPPED
esp32-s3-devkitc-1 embedded/test_driver_led FAILED 00:01:06.344
esp32-s3-devkitc-1 embedded/test_gpio_utils SKIPPED
esp32-s3-devkitc-1 embedded/test_sensor_data SKIPPED
_______________________________________________________________________ esp32-s3-devkitc-1:embedded/test_driver_led _______________________________________________________________________
test/embedded/test_driver_led/led_action.c:43:test_create_and_free_led_action_group:FAIL: This test is intentionally failing.
=================================================================== 2 test cases: 1 failed, 1 succeeded in 00:01:06.344 ===================================================================
~\repos\esp-firmware git:[feature/led_driver]
pio.exe test
Verbosity level can be increased via `-v, -vv, or -vvv` option
Collected 4 tests
Processing embedded/test_driver_led in esp32-s3-devkitc-1 environment
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Building & Uploading...
Testing...
If you don't see any output for the first 10 secs, please reset board (press reset button)
--------------------------------------------------------- esp32-s3-devkitc-1:embedded/test_driver_led [PASSED] Took 7.42 seconds ---------------------------------------------------------
======================================================================== 0 test cases: 0 succeeded in 00:00:07.421 ========================================================================
~\repos\esp-firmware git:[feature/led_driver]
pio.exe test -v
Collected 4 tests (embedded/test_data_storage, embedded/test_driver_led, embedded/test_gpio_utils, embedded/test_sensor_data)
Processing embedded/test_driver_led in esp32-s3-devkitc-1 environment
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Building & Uploading...
Testing...
If you don't see any output for the first 10 secs, please reset board (press reset button)
I (96) boot: 5 ota_1 OTA app 00 11 02s3: SPI Mode : DIO
I (42) boot.esp32s3: SPI Flash Size : 8MB
I (47) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label Usage Type ST Offset Length
I (63) boot: 0 nvs WiFi data 01 02 00009000 00004000
I (71) boot: 1 otadata OTA data 01 00 0000d000 00002000
I (78) boot: 2 phy_init RF data 01 01 0000f000 00001000
I (86) boot: 3 factory factory app 00 00 00010000 00200000
I (93) boot: 4 ota_0 OTA app 00 10 00210000 00200000
I (101) boot: 5 ota_1 OTA app 00 11 00410000 00200000
I (108) boot: End of partition table
I (113) boot: Defaulting to factory image
I (117) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=0b404h ( 46084) map
I (134) esp_image: segment 1: paddr=0001b42c vaddr=3fc92800 size=02c78h ( 11384) load
I (137) esp_image: segment 2: paddr=0001e0ac vaddr=40374000 size=01f6ch ( 8044) load
I (145) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=1ce40h (118336) map
I (172) esp_image: segment 4: paddr=0003ce68 vaddr=40375f6c size=0c884h ( 51332) load
I (190) boot: Loaded app from partition at offset 0x10000
I (190) boot: Disabling RNG early entropy source...
I (202) cpu_start: Multicore app
I (211) cpu_start: Pro cpu start user code
I (211) cpu_start: cpu freq: 160000000 Hz
I (212) app_init: Application information:
I (214) app_init: Project name: esp32-firmware
I (220) app_init: App version: 0.2.1
I (225) app_init: Compile time: Nov 17 2024 09:44:22
I (231) app_init: ELF file SHA256: 6af551a2d...
I (236) app_init: ESP-IDF: 5.3.1
I (241) efuse_init: Min chip rev: v0.0
I (246) efuse_init: Max chip rev: v0.99
I (251) efuse_init: Chip rev: v0.2
I (255) heap_init: Initializing. RAM available for dynamic allocation:
I (263) heap_init: At 3FC95DD8 len 00053938 (334 KiB): RAM
I (269) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (275) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (281) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (288) spi_flash: detected chip: gd
I (292) spi_flash: flash io: dio
W (296) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
I (306) sleep: Configure to isolate all GPIO pins in sleep state
I (313) sleep: Enable automatic switching of GPIO sleep configuration
I (320) coexist: coex firmware version: 4482466
I (325) coexist: coexist rom version e7ae62f
I (331) main_task: Started on CPU0
I (341) main_task: Calling app_main()
test/embedded/test_driver_led/led_action.c:21:test_create_and_free_led_action:INFO: Testing create_led_action and free_led_action
test/embedded/test_driver_led/led_action.c:38:test_create_and_free_led_action:INFO: led_action_t freed successfully
test/embedded/test_driver_led/led_action.c:67:test_create_and_free_led_action:PASS
test/embedded/test_driver_led/led_action.c:42:test_create_and_free_led_action_group:INFO: Testing create_led_action_group and free_led_action_group
test/embedded/test_driver_led/led_action.c:43:test_create_and_free_led_action_group:FAIL: This test is intentionally failing.
-----------------------
2 Tests 1 Failures 0 Ignored
FAIL
--------------------------------------------------------- esp32-s3-devkitc-1:embedded/test_driver_led [FAILED] Took 7.65 seconds ---------------------------------------------------------
========================================================================================= SUMMARY =========================================================================================
Environment Test Status Duration
------------------ -------------------------- -------- ------------
esp32-s3-devkitc-1 embedded/test_data_storage SKIPPED
esp32-s3-devkitc-1 embedded/test_driver_led FAILED 00:00:07.646
esp32-s3-devkitc-1 embedded/test_gpio_utils SKIPPED
esp32-s3-devkitc-1 embedded/test_sensor_data SKIPPED
_______________________________________________________________________ esp32-s3-devkitc-1:embedded/test_driver_led _______________________________________________________________________
test/embedded/test_driver_led/led_action.c:43:test_create_and_free_led_action_group:FAIL: This test is intentionally failing.
=================================================================== 2 test cases: 1 failed, 1 succeeded in 00:00:07.646 ===================================================================
Here is the test code:
// test_led_action.c
#include "event/led_event/led_action.h"
#include "event/led_event/led_position.h"
#include <esp_system.h>
#include "unity.h"
#include <stdlib.h>
// Helper function to compare two led_action_t structs
void compare_led_actions(led_action_t* expected, led_action_t* actual) {
TEST_ASSERT_EQUAL(expected->led_mask, actual->led_mask);
TEST_ASSERT_EQUAL(expected->color, actual->color);
TEST_ASSERT_EQUAL(expected->dimming, actual->dimming);
TEST_ASSERT_EQUAL(expected->duration_ms, actual->duration_ms);
}
void test_create_and_free_led_action() {
TEST_MESSAGE("Testing create_led_action and free_led_action");
// Create an LED action
led_action_t* action = create_led_action(LED_D1 | LED_D2 | LED_D3 | LED_D4, LED_COLOR_RED, DIMMING_BRIGHT_TO_LOW, 1000);
TEST_ASSERT_NOT_NULL_MESSAGE(action, "Failed to create led_action_t");
// Verify the action's values
led_action_t expected_action = {
.led_mask = LED_D1 | LED_D2 | LED_D3 | LED_D4,
.color = LED_COLOR_RED,
.dimming = DIMMING_BRIGHT_TO_LOW,
.duration_ms = 1000
};
compare_led_actions(&expected_action, action);
// Free the action
free_led_action(action);
TEST_MESSAGE("led_action_t freed successfully");
}
void test_create_and_free_led_action_group() {
TEST_MESSAGE("Testing create_led_action_group and free_led_action_group");
TEST_FAIL_MESSAGE("This test is intentionally failing.");
// Create an action group with 2 actions
led_action_group_t* group = create_led_action_group(2, 2000);
TEST_ASSERT_NOT_NULL_MESSAGE(group, "Failed to create led_action_group_t");
TEST_ASSERT_EQUAL(2, group->action_count);
TEST_ASSERT_EQUAL(2000, group->duration_ms);
// Create some actions
led_action_t* action1 = create_led_action(LED_A1 | LED_A2, LED_COLOR_GREEN, DIMMING_NONE, 500);
led_action_t* action2 = create_led_action(LED_B1 | LED_B2, LED_COLOR_BLUE, DIMMING_LOW_TO_BRIGHT, 1500);
// Add the actions to the group
group->actions[0] = action1;
group->actions[1] = action2;
// Free the action group (this should also free the actions)
free_led_action_group(group);
}
void app_main(void) {
UNITY_BEGIN();
RUN_TEST(test_create_and_free_led_action);
RUN_TEST(test_create_and_free_led_action_group);
UNITY_END();
esp_restart(); // Restart the ESP32 after the tests, seem to be the only solution to continue the test
}
Also, here the .ini file !
[env:esp32-s3-devkitc-1]
platform = espressif32
board = esp32-s3-devkitc-1
board_build.mcu = esp32s3
framework = espidf
upload_port = COM8
upload_speed = 2000000
monitor_speed = 115200
debug_tool = esp-builtin
build_type = debug
board_build.partitions = partitions.csv
test_build_src = yes
test_filter = embedded/test_driver_led