espressif
Always get ESP log output but only reset for different pytest fixture scopes (class, module, ...) (RDT-1472)
Is your feature request related to a problem? Please describe.
We like to see the ESP serial logging output and also want to reset/reflash the ESP under certain circumstances.
So far we only found requiring the dut fixture in every test to see the log output which also resets every time.
This takes a lot of time. Describe the solution you'd like We'd like to control this via pytest's fixture scopes. I.e. for some test modules only reflash/reset on a module level. For some other tests on class level. Especially we often do not want to reset between different test parametrizations of the same test.
Describe alternatives you've considered Did not find any other way to enable us to see the log output of the ESP yet. Also checked all your fixtures and the only ones that are initialized with a non default function scope (session scope) are caches and some directories. (https://github.com/search?q=repo%3Aespressif%2Fpytest-embedded%20scope%3D&type=code)
Additional context Moving all the fixture scopes to class scope should work easily (as they behave similarly in most cases as the default function scope, unless used on a class, but IIRC even there parametrize with indirect=True allows setting the scope back to previous behavior).
Thanks for your support. :)
Hi @lovetheguitar
If you're asking about the serial output, you may enable it by pytest -s
(doc: https://docs.espressif.com/projects/pytest-embedded/en/latest/concepts/key-concepts.html#logging)
Hi @hfudev,
If you're asking about the serial output, you may enable it by
pytest -s(doc: https://docs.espressif.com/projects/pytest-embedded/en/latest/concepts/key-concepts.html#logging)
Yes, I'm taking about serial output. I'm aware of pytest's -s option and already using it.
This is not the issue though.
I'm running e.g. pytest --embedded-services 'idf,esp' --confirm-target-elf-sha256=True -s --port /dev/ttyUSB2 ./test/
and my test looks like:
test_espressif.py
import time
def test_reproducer_espressif(
# dut,
) -> None:
print("Start...")
time.sleep(5)
print("Done!")
Additionally I set up log_cli_level (and formatting etc.) in pyproject.toml via an [tool.pytest.ini_options] entry.
In case the dut fixture is commented out I get this output:
l# pytest --embedded-services 'idf,esp' --confirm-target-elf-sha256=True -s --port /dev/ttyUSB2 ./test/integration/test_debug_modbus.py
======================================================================================================================= test session starts ========================================================================================================================
platform linux -- Python 3.12.3, pytest-8.4.2, pluggy-1.6.0
rootdir: /mylocal
configfile: pyproject.toml
plugins: rerunfailures-16.0.1, embedded-1.16.2, timeout-2.4.0, ignore-test-results-0.3.0, anyio-4.10.0
collected 1 item
test/integration/test_reproducer_espressif.py::test_reproducer_espressif
-------------------------------------------------------------------------------------------------------------------------- live log setup --------------------------------------------------------------------------------------------------------------------------
2025-09-08 15:11:28.468 [ DEBUG] filelock: Attempting to acquire lock 130363059574624 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:331)
2025-09-08 15:11:28.469 [ DEBUG] filelock: Lock 130363059574624 acquired on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:334)
2025-09-08 15:11:28.470 [ DEBUG] filelock: Attempting to release lock 130363059574624 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:364)
2025-09-08 15:11:28.470 [ DEBUG] filelock: Lock 130363059574624 released on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:367)
Start...
Done!
PASSED
------------------------------------------------------------------------------------------------------------------------ live log teardown -------------------------------------------------------------------------------------------------------------------------
2025-09-08 15:11:33.503 [ DEBUG] filelock: Attempting to acquire lock 130363059574624 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:331)
2025-09-08 15:11:33.503 [ DEBUG] filelock: Lock 130363059574624 acquired on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:334)
2025-09-08 15:11:33.503 [ DEBUG] filelock: Attempting to release lock 130363059574624 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:364)
2025-09-08 15:11:33.503 [ DEBUG] filelock: Lock 130363059574624 released on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:367)
===================================================================================================================== short test summary info ======================================================================================================================
PASSED test/integration/test_debug_modbus.py::test_reproducer_esspressif
======================================================================================================================== 1 passed in 5.07s =========================================================================================================================
With the dut not commented out I get (as expected):
# pytest --embedded-services 'idf,esp' --confirm-target-elf-sha256=True -s --port /dev/ttyUSB2 ./test/integration/test_debug_modbus.py
======================================================================================================================= test session starts ========================================================================================================================
platform linux -- Python 3.12.3, pytest-8.4.2, pluggy-1.6.0
rootdir: /mylocal
configfile: pyproject.toml
plugins: rerunfailures-16.0.1, embedded-1.16.2, timeout-2.4.0, ignore-test-results-0.3.0, anyio-4.10.0
collected 1 item
test/integration/test_reproducer_espressif.py::test_reproducer_espressif
-------------------------------------------------------------------------------------------------------------------------- live log setup --------------------------------------------------------------------------------------------------------------------------
2025-09-08 15:14:50.298 [ DEBUG] filelock: Attempting to acquire lock 135601810999392 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:331)
2025-09-08 15:14:50.298 [ DEBUG] filelock: Lock 135601810999392 acquired on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:334)
2025-09-08 15:14:50.299 [ DEBUG] filelock: Attempting to release lock 135601810999392 on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:364)
2025-09-08 15:14:50.299 [ DEBUG] filelock: Lock 135601810999392 released on /tmp/pytest-embedded/pytest-embedded-cache/port_target_cache.lock (_api.py:367)
2025-09-08 15:14:50.335 [ DEBUG] root: checking if build is an absolute path... (app.py:35)
2025-09-08 15:14:50.335 [ DEBUG] root: checking if build exists in /mylocal/test/integration... (app.py:40)
2025-09-08 15:14:50.335 [ DEBUG] root: checking if build exists in /mylocal... (app.py:46)
2025-09-08 15:14:50 Serial port /dev/ttyUSB2
2025-09-08 15:14:50 Connecting....
2025-09-08 15:14:50.660 [ INFO] root: Target: esp32, Port: /dev/ttyUSB2 (serial.py:121)
2025-09-08 15:14:50.660 [ DEBUG] root: set port-target cache: /dev/ttyUSB2 - esp32 (utils.py:208)
2025-09-08 15:14:50 Connecting....
2025-09-08 15:14:50 esptool.py v4.8.1
2025-09-08 15:14:50 Found 1 serial ports
2025-09-08 15:14:51 Chip is ESP32-D0WD-V3 (revision v3.1)
2025-09-08 15:14:51 Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
2025-09-08 15:14:51 Crystal is 40MHz
2025-09-08 15:14:51 MAC: c0:5d:89:8d:4a:d8
2025-09-08 15:14:51 Uploading stub...
2025-09-08 15:14:51 Running stub...
2025-09-08 15:14:51 Stub running...
2025-09-08 15:14:51 Changing baud rate to 921600
2025-09-08 15:14:51 Changed.
2025-09-08 15:14:51 Configuring flash size...
2025-09-08 15:14:51 Flash will be erased from 0x00001000 to 0x00007fff...
2025-09-08 15:14:51 Flash will be erased from 0x00008000 to 0x00008fff...
2025-09-08 15:14:51 Flash will be erased from 0x0000f000 to 0x00010fff...
2025-09-08 15:14:51 Flash will be erased from 0x00020000 to 0x000a0fff...
2025-09-08 15:14:51 SHA digest in image updated
2025-09-08 15:14:51 Compressed 25984 bytes to 16395...
Wrote 25984 bytes (16395 compressed) at 0x00001000 in 0.6 seconds (effective 375.9 kbit/s)...
2025-09-08 15:14:52 Hash of data verified.
2025-09-08 15:14:52 Compressed 3072 bytes to 129...
Wrote 3072 bytes (129 compressed) at 0x00008000 in 0.0 seconds (effective 544.9 kbit/s)...
2025-09-08 15:14:52 Hash of data verified.
2025-09-08 15:14:52 Compressed 8192 bytes to 31...
Wrote 8192 bytes (31 compressed) at 0x0000f000 in 0.1 seconds (effective 1148.9 kbit/s)...
2025-09-08 15:14:52 Hash of data verified.
2025-09-08 15:14:52 Compressed 528032 bytes to 298706...
Wrote 528032 bytes (298706 compressed) at 0x00020000 in 5.3 seconds (effective 791.7 kbit/s)...
2025-09-08 15:14:58 Hash of data verified.
2025-09-08 15:14:58
2025-09-08 15:14:58 Leaving...
2025-09-08 15:14:58 Hard resetting via RTS pin...
2025-09-08 15:14:58.384 [ DEBUG] root: set port-app cache: /dev/ttyUSB2 - /mylocal/build (utils.py:226)
2025-09-08 15:14:58.385 [ DEBUG] root: occupied /dev/ttyUSB2 (serial.py:134)
2025-09-08 15:14:58.387 [ DEBUG] root: hit port-app cache: /dev/ttyUSB2 - /mylocal/build (utils.py:219)
Start...
2025-09-08 15:14:58 I (13) boot: ESP-IDF v5.4.1-374-gef1a5075f5 2nd stage bootloader
2025-09-08 15:14:58 I (13) boot: compile time Sep 5 2025 19:05:32
2025-09-08 15:14:58 I (13) boot: Multicore bootloader
2025-09-08 15:14:58 I (15) boot: chip revision: v3.1
2025-09-08 15:14:58 I (18) boot.esp32: SPI Speed : 40MHz
2025-09-08 15:14:58 I (21) boot.esp32: SPI Mode : DIO
2025-09-08 15:14:58 I (25) boot.esp32: SPI Flash Size : 16MB
2025-09-08 15:14:58 I (29) boot: Enabling RNG early entropy source...
2025-09-08 15:14:58 I (33) boot: Partition Table:
2025-09-08 15:14:58 I (36) boot: ## Label Usage Type ST Offset Length
2025-09-08 15:14:58 I (42) boot: 0 nvs WiFi data 01 02 00009000 00006000
2025-09-08 15:14:58 I (49) boot: 1 otadata OTA data 01 00 0000f000 00002000
2025-09-08 15:14:58 I (55) boot: 2 phy_init RF data 01 01 00011000 00001000
2025-09-08 15:14:58 I (62) boot: 3 ota_0 OTA app 00 10 00020000 001a9000
2025-09-08 15:14:58 I (68) boot: 4 ota_1 OTA app 00 11 001d0000 001a9000
2025-09-08 15:14:58 I (75) boot: End of partition table
2025-09-08 15:14:58 I (78) boot: No factory image, trying OTA 0
2025-09-08 15:14:58 I (82) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=216e0h (136928) map
2025-09-08 15:14:58 I (136) esp_image: segment 1: paddr=00041708 vaddr=3ff80000 size=0001ch ( 28) load
2025-09-08 15:14:58 I (136) esp_image: segment 2: paddr=0004172c vaddr=3ffb0000 size=0254ch ( 9548) load
2025-09-08 15:14:58 I (143) esp_image: segment 3: paddr=00043c80 vaddr=40080000 size=0c398h ( 50072) load
2025-09-08 15:14:58 I (167) esp_image: segment 4: paddr=00050020 vaddr=400d0020 size=4d544h (316740) map
2025-09-08 15:14:58 I (275) esp_image: segment 5: paddr=0009d56c vaddr=4008c398 size=03910h ( 14608) load
2025-09-08 15:14:58 I (289) boot: Loaded app from partition at offset 0x20000
2025-09-08 15:14:58 I (290) boot: Set actual ota_seq=1 in otadata[0]
2025-09-08 15:14:58 I (290) boot: Disabling RNG early entropy source...
2025-09-08 15:14:58 I (304) cpu_start: Multicore app
2025-09-08 15:14:58 I (312) cpu_start: Pro cpu start user code
2025-09-08 15:14:58 I (312) cpu_start: cpu freq: 240000000 Hz
2025-09-08 15:14:58 I (312) app_init: Application information:
2025-09-08 15:14:58 I (312) app_init: Project name: CVL2_CTRL
2025-09-08 15:14:58 I (316) app_init: App version: 1
2025-09-08 15:14:58 I (320) app_init: Compile time: Sep 5 2025 19:05:28
2025-09-08 15:14:58 I (325) app_init: ELF file SHA256: 77258daa3...
2025-09-08 15:14:58 I (329) app_init: ESP-IDF: v5.4.1-374-gef1a5075f5
2025-09-08 15:14:58 I (334) efuse_init: Min chip rev: v0.0
2025-09-08 15:14:58 I (338) efuse_init: Max chip rev: v3.99
2025-09-08 15:14:58 I (342) efuse_init: Chip rev: v3.1
2025-09-08 15:14:58 I (346) heap_init: Initializing. RAM available for dynamic allocation:
2025-09-08 15:14:58 I (352) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
2025-09-08 15:14:58 I (357) heap_init: At 3FFB3DE0 len 0002C220 (176 KiB): DRAM
2025-09-08 15:14:58 I (362) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
2025-09-08 15:14:58 I (368) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
2025-09-08 15:14:58 I (373) heap_init: At 4008FCA8 len 00010358 (64 KiB): IRAM
2025-09-08 15:14:58 I (380) spi_flash: detected chip: generic
2025-09-08 15:14:58 I (382) spi_flash: flash io: dio
2025-09-08 15:14:58 I (386) main_task: Started on CPU0
Pytest plugin versions:
pip list (truncated)
pytest 8.4.2
pytest-embedded 1.16.2
pytest-embedded-idf 1.16.2
pytest-embedded-jtag 1.16.2
pytest-embedded-qemu 1.16.2
pytest-embedded-serial 1.16.2
pytest-embedded-serial-esp 1.16.2
pytest-ignore-test-results 0.3.0
pytest-rerunfailures 16.0.1
pytest-timeout 2.4.0
I see. If you comment out the dut, then no fixtures from pytest-embedded will run. In that case, your test case won’t actually do anything except print and sleep.
The port-cache should solve your problem, and it’s enabled by default. When running multiple test cases that require the same app, only the first test case will flash the app into the DUT. The rest will just call dut.reset() instead of flashing again.
From the log, it looks like the cache is set up correctly:
2025-09-08 15:14:58.384 [ DEBUG] root: set port-app cache: /dev/ttyUSB2 - /mylocal/build (utils.py:226)
If you don’t need auto-flash between different pytest runs (for example, during local testing), you can add --skip-autoflash y to save time.
The rest will just call
dut.reset()instead of flashing again.
Exactly and this will be done for every test item, meaning if you use pytest.mark.parametrize and have a few test arguments, the ESP will be reset every single time. This really slows all our tests down to an unacceptable level.
We need autoflash and reset only for some test classes, modules etc. but not only in an either/or manner on the session level (as the CLI argument --skip-autoflash y would configure). That's why I was talking about different fixture scopes at the beginning.
Another option would be to have some "settings fixtures" which your dut fixtures check and depending on the setting then does reset, flash, etc. or not.
How can we proceed here? 🐱
From what I understand, a reset between test cases will not significantly increase execution time (should be done within 1s), and it could make the test cases more robust, since the state generated by the previous test case will not be inherited by the current one.
For now, all DUTs are scoped as function. Your feature request is somewhat against the original design, so the scope will probably not be changed.
As a workaround, you could possibly do something like this. Assume we have two test cases:
@pytest.mark.parametrize('embedded_services', 'esp,idf', indirect=True)
def test_requires_flash(dut):
# this one will be flashed
pass
@pytest.mark.parametrize('embedded_services', 'serial', indirect=True)
def test_requires_no_flash_nor_reset(dut):
pass
I think this might work (not tested), but it highly depends on the test case sequence and the previous board state. I do NOT recommend this approach.
Thanks for the hint about indirectly parametrizing the embedded_services fixture. In one of our test modules this already drastically reduced test duration.
From what I understand, a reset between test cases will not significantly increase execution time (should be done within 1s), and it could make the test cases more robust, since the state generated by the previous test case will not be inherited by the current one.
Yes, we do want to reset the ESP in some cases, but for us the difference in time is unbearable. E.g. one test module where we are testing some SCPI commands of our implementation:
Before: 84 passed in 580.14s (0:09:40)
After: 84 passed in 87.56s (0:01:27)
I didn't dig deeper but it's not only about resetting, but e.g. waiting for IP address from DHCP, connecting, ...
I'll verify how well this can work for other test modules where we'd like to do different things. I fear that we might run into some limitations with mixed behavior, but will come back with concrete examples as they show up.