pexpect.exceptions.TIMEOUT: Not found "Wakeup reason: rtc_io"
Bytes in current buffer (color code eliminated): up reason: touchpad
Please check the full log here: /tmp/pytest-embedded/2024-09-29_20-36-47-682671/test_sleep/dut.log
self = <pytest_embedded_serial.dut.SerialDut object at 0x7f79235c52d0>
pattern = 'Wakeup reason: rtc_io', expect_all = False, not_matching = ()
args = (), kwargs = {}, patterns = ['Wakeup reason: rtc_io'], res = []
debug_str = 'Not found "Wakeup reason: rtc_io"\nBytes in current buffer (color code eliminated): up reason: touchpad\nPlease check the full log here: /tmp/pytest-embedded/2024-09-29_20-36-47-682671/test_sleep/dut.log'

    @functools.wraps(func)
    def wrapper(
        self, pattern, *args, expect_all: bool = False, not_matching: List[Union[str, re.Pattern]] = (), **kwargs
    ) -> Union[Union[Match, AnyStr], List[Union[Match, AnyStr]]]:
        patterns = to_list(pattern)
        res = []
        while patterns:
            try:
>               index = func(self, pattern, *args, **kwargs)

/usr/local/lib/python3.10/site-packages/pytest_embedded/dut.py:76: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/local/lib/python3.10/site-packages/pytest_embedded/dut.py:153: in expect_exact
    return self.pexpect_proc.expect_exact(pattern, **kwargs)
/usr/local/lib/python3.10/site-packages/pexpect/spawnbase.py:432: in expect_exact
    return exp.expect_loop(timeout)
/usr/local/lib/python3.10/site-packages/pexpect/expect.py:181: in expect_loop
    return self.timeout(e)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <pexpect.expect.Expecter object at 0x7f79232cf790>
err = TIMEOUT("<pytest_embedded.log.PexpectProcess object at 0x7f79235c4d60>\nsearcher: searcher_string:\n    0: b'Wakeup reason: rtc_io'")

    def timeout(self, err=None):
        spawn = self.spawn
    
        spawn.before = spawn._before.getvalue()
        spawn.after = TIMEOUT
        index = self.searcher.timeout_index
        if index >= 0:
            spawn.match = TIMEOUT
            spawn.match_index = index
            return index
        else:
            spawn.match = None
            spawn.match_index = None
            msg = str(spawn)
            msg += '\nsearcher: %s' % self.searcher
            if err is not None:
                msg = str(err) + '\n' + msg
    
            exc = TIMEOUT(msg)
            exc.__cause__ = None    # in Python 3.x we can use "raise exc from None"
>           raise exc
E           pexpect.exceptions.TIMEOUT: <pytest_embedded.log.PexpectProcess object at 0x7f79235c4d60>
E           searcher: searcher_string:
E               0: b'Wakeup reason: rtc_io'
E           <pytest_embedded.log.PexpectProcess object at 0x7f79235c4d60>
E           searcher: searcher_string:
E               0: b'Wakeup reason: rtc_io'

/usr/local/lib/python3.10/site-packages/pexpect/expect.py:144: TIMEOUT

The above exception was the direct cause of the following exception:

dut = <pytest_embedded_serial.dut.SerialDut object at 0x7f79235c52d0>

    def test_sleep(dut):
        LOGGER = logging.getLogger(__name__)
    
        # Deep Sleep
        boot_count = 1
        dut.expect_exact("Boot number: {}".format(boot_count))
        dut.expect_exact("Wakeup reason: power_up")
    
        for capability, devices in capabilities.items():
            if dut.app.target in devices and capability not in ["gpio", "uart"]:
                LOGGER.info("Testing {} deep sleep capability".format(capability))
                boot_count += 1
                dut.write("{}_deep".format(capability))
                dut.expect_exact("Boot number: {}".format(boot_count))
                dut.expect_exact("Wakeup reason: {}".format(capability))
    
        # Light Sleep
        for capability, devices in capabilities.items():
            if dut.app.target in devices:
                LOGGER.info("Testing {} light sleep capability".format(capability))
                dut.write("{}_light".format(capability))
                if capability == "uart":
                    time.sleep(5)
                    LOGGER.info("Sending 9 positive edges")
                    dut.write("aaa") # Send 9 positive edges
                dut.expect_exact("Woke up from light sleep")
>               dut.expect_exact("Wakeup reason: {}".format(capability))

tests/validation/sleep/test_sleep.py:39: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <pytest_embedded_serial.dut.SerialDut object at 0x7f79235c52d0>
pattern = 'Wakeup reason: rtc_io', expect_all = False, not_matching = ()
args = (), kwargs = {}, patterns = ['Wakeup reason: rtc_io'], res = []
debug_str = 'Not found "Wakeup reason: rtc_io"\nBytes in current buffer (color code eliminated): up reason: touchpad\nPlease check the full log here: /tmp/pytest-embedded/2024-09-29_20-36-47-682671/test_sleep/dut.log'

    @functools.wraps(func)
    def wrapper(
        self, pattern, *args, expect_all: bool = False, not_matching: List[Union[str, re.Pattern]] = (), **kwargs
    ) -> Union[Union[Match, AnyStr], List[Union[Match, AnyStr]]]:
        patterns = to_list(pattern)
        res = []
        while patterns:
            try:
                index = func(self, pattern, *args, **kwargs)
            except (pexpect.EOF, pexpect.TIMEOUT) as e:
                debug_str = (
                    f'Not found "{pattern!s}"\n'
                    f'Bytes in current buffer (color code eliminated): {self.pexpect_proc.buffer_debug_str}\n'
                    f'Please check the full log here: {self.logfile}'
                )
>               raise e.__class__(debug_str) from e
E               pexpect.exceptions.TIMEOUT: Not found "Wakeup reason: rtc_io"
E               Bytes in current buffer (color code eliminated): up reason: touchpad
E               Please check the full log here: /tmp/pytest-embedded/2024-09-29_20-36-47-682671/test_sleep/dut.log

/usr/local/lib/python3.10/site-packages/pytest_embedded/dut.py:83: TIMEOUT

ValueError: unity test case not found, buffer:
Serial port /dev/ttyUSB0
Connecting....
Connecting......
esptool.py v4.8.1
Found 5 serial ports
Chip is ESP32-D0WD-V3 (revision v3.0)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 10:97:bd:d5:81:f4
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Auto-detected Flash size: 8MB
Flash will be erased from 0x00001000 to 0x00006fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Flash will be erased from 0x00010000 to 0x00053fff...
Flash params set to 0x023f
SHA digest in image updated
Compressed 23376 bytes to 15312...

Writing at 0x00001000... (100 %)
Wrote 23376 bytes (15312 compressed) at 0x00001000 in 2.1 seconds (effective 89.8 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 137...

Writing at 0x00008000... (100 %)
Wrote 3072 bytes (137 compressed) at 0x00008000 in 0.1 seconds (effective 210.2 kbit/s)...
Hash of data verified.
Compressed 277520 bytes to 153726...

Writing at 0x00010000... (10 %)
Writing at 0x0001bfd8... (20 %)
Writing at 0x00024439... (30 %)
Writing at 0x00029823... (40 %)
Writing at 0x0002eb16... (50 %)
Writing at 0x00033faa... (60 %)
Writing at 0x0003c994... (70 %)
Writing at 0x00046b58... (80 %)
Writing at 0x0004c206... (90 %)
Writing at 0x00051b0f... (100 %)
Wrote 277520 bytes (153726 compressed) at 0x00010000 in 13.7 seconds (effective 162.4 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:4604
ho 0 tail 12 room 4
load:0x40078000,len:15488
load:0x40080400,len:4
load:0x40080404,len:3180
entry 0x400805b8
dut = <pytest_embedded_serial.dut.SerialDut object at 0xb5585c70>

    def test_cpu_misc(dut):
>       dut.expect_unity_test_output(timeout=120)

tests/validation/cpu_misc/test_cpu_misc.py:2: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/local/lib/python3.10/site-packages/pytest_embedded/dut.py:190: in expect_unity_test_output
    self.testsuite.add_unity_test_cases(log)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <pytest_embedded.unity.TestSuite object at 0xb5585d90>
s = 'Serial port /dev/ttyUSB0\nConnecting....\nConnecting......\nesptool.py v4.8.1\nFound 5 serial ports\nChip is ESP32-D0...2 room 4\r\nload:0x40078000,len:15488\r\nload:0x40080400,len:4\r\nload:0x40080404,len:3180\r\nentry 0x400805b8\r\n\r\n'
additional_attrs = None

    def add_unity_test_cases(self, s: AnyStr, additional_attrs: Optional[Dict[str, Any]] = None) -> None:
        s = to_str(s)
    
        # check format
        check = UNITY_FIXTURE_REGEX.search(s)
        if check:
            regex = UNITY_FIXTURE_REGEX
        else:
            regex = UNITY_BASIC_REGEX
    
        # real parsing
        res = regex.finditer(s)
        for item in res:
            attrs = {k: v for k, v in item.groupdict().items() if v is not None}
    
            if additional_attrs:
                attrs.update(additional_attrs)
    
            testcase = TestCase(**attrs)
            self.testcases.append(testcase)
            if testcase.result == 'FAIL':
                self.attrs['failures'] += 1
            elif testcase.result == 'IGNORE':
                self.attrs['skipped'] += 1
    
            self.attrs['tests'] += 1
    
        if not self.testcases:
>           raise ValueError(f'unity test case not found, buffer:\n' f'{s}')
E           ValueError: unity test case not found, buffer:
E           Serial port /dev/ttyUSB0
E           Connecting....
E           Connecting......
E           esptool.py v4.8.1
E           Found 5 serial ports
E           Chip is ESP32-D0WD-V3 (revision v3.0)
E           Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
E           Crystal is 40MHz
E           MAC: 10:97:bd:d5:81:f4
E           Uploading stub...
E           Running stub...
E           Stub running...
E           Configuring flash size...
E           Auto-detected Flash size: 8MB
E           Flash will be erased from 0x00001000 to 0x00006fff...
E           Flash will be erased from 0x00008000 to 0x00008fff...
E           Flash will be erased from 0x00010000 to 0x00053fff...
E           Flash params set to 0x023f
E           SHA digest in image updated
E           Compressed 23376 bytes to 15312...
E           
Writing at 0x00001000... (100 %)
Wrote 23376 bytes (15312 compressed) at 0x00001000 in 2.1 seconds (effective 89.8 kbit/s)...
E           Hash of data verified.
E           Compressed 3072 bytes to 137...
E           
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (137 compressed) at 0x00008000 in 0.1 seconds (effective 210.2 kbit/s)...
E           Hash of data verified.
E           Compressed 277520 bytes to 153726...
E           
Writing at 0x00010000... (10 %)
Writing at 0x0001bfd8... (20 %)
Writing at 0x00024439... (30 %)
Writing at 0x00029823... (40 %)
Writing at 0x0002eb16... (50 %)
Writing at 0x00033faa... (60 %)
Writing at 0x0003c994... (70 %)
Writing at 0x00046b58... (80 %)
Writing at 0x0004c206... (90 %)
Writing at 0x00051b0f... (100 %)
Wrote 277520 bytes (153726 compressed) at 0x00010000 in 13.7 seconds (effective 162.4 kbit/s)...
E           Hash of data verified.
E           
E           Leaving...
E           Hard resetting via RTS pin...
E           ets Jul 29 2019 12:21:46
E           
E           rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
E           configsip: 0, SPIWP:0xee
E           clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
E           mode:DIO, clock div:1
E           load:0x3fff0030,len:4604
E           ho 0 tail 12 room 4
E           load:0x40078000,len:15488
E           load:0x40080400,len:4
E           load:0x40080404,len:3180
E           entry 0x400805b8

/usr/local/lib/python3.10/site-packages/pytest_embedded/unity.py:181: ValueError