pexpect.exceptions.TIMEOUT: Not found "Woke up from light sleep"
Bytes in current buffer (color code eliminated): FAIL
Please check the full log here: /tmp/pytest-embedded/2024-09-27_22-03-12-086650/test_sleep/dut.log
self = <pytest_embedded_serial.dut.SerialDut object at 0x7f425ad19270>
pattern = 'Woke up from light sleep', expect_all = False, not_matching = ()
args = (), kwargs = {}, patterns = ['Woke up from light sleep'], res = []
debug_str = 'Not found "Woke up from light sleep"\nBytes in current buffer (color code eliminated): FAIL\nPlease check the full log here: /tmp/pytest-embedded/2024-09-27_22-03-12-086650/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 0x7f425aa1b6d0>
err = TIMEOUT("<pytest_embedded.log.PexpectProcess object at 0x7f425ad18d00>\nsearcher: searcher_string:\n    0: b'Woke up from light sleep'")

    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 0x7f425ad18d00>
E           searcher: searcher_string:
E               0: b'Woke up from light sleep'
E           <pytest_embedded.log.PexpectProcess object at 0x7f425ad18d00>
E           searcher: searcher_string:
E               0: b'Woke up from light sleep'

/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 0x7f425ad19270>

    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":
                    dut.write("aaa") # Send 9 positive edges
                dut.expect_exact("Woke up from light sleep")
                dut.expect_exact("Wakeup reason: {}".format(capability))
                if capability == "timer":
                    dut.write("timer_freq_light")
>                   dut.expect_exact("Woke up from light sleep")

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

self = <pytest_embedded_serial.dut.SerialDut object at 0x7f425ad19270>
pattern = 'Woke up from light sleep', expect_all = False, not_matching = ()
args = (), kwargs = {}, patterns = ['Woke up from light sleep'], res = []
debug_str = 'Not found "Woke up from light sleep"\nBytes in current buffer (color code eliminated): FAIL\nPlease check the full log here: /tmp/pytest-embedded/2024-09-27_22-03-12-086650/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 "Woke up from light sleep"
E               Bytes in current buffer (color code eliminated): FAIL
E               Please check the full log here: /tmp/pytest-embedded/2024-09-27_22-03-12-086650/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 90.0 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 153730...

Writing at 0x00010000... (10 %)
Writing at 0x0001bfb3... (20 %)
Writing at 0x00024434... (30 %)
Writing at 0x0002981e... (40 %)
Writing at 0x0002eb0f... (50 %)
Writing at 0x00033fa7... (60 %)
Writing at 0x0003c98d... (70 %)
Writing at 0x00046b52... (80 %)
Writing at 0x0004c1ff... (90 %)
Writing at 0x00051b0d... (100 %)
Wrote 277520 bytes (153730 compressed) at 0x00010000 in 13.7 seconds (effective 162.6 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 0xb5579cd0>

    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 0xb5579df0>
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 90.0 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 153730...
E           
Writing at 0x00010000... (10 %)
Writing at 0x0001bfb3... (20 %)
Writing at 0x00024434... (30 %)
Writing at 0x0002981e... (40 %)
Writing at 0x0002eb0f... (50 %)
Writing at 0x00033fa7... (60 %)
Writing at 0x0003c98d... (70 %)
Writing at 0x00046b52... (80 %)
Writing at 0x0004c1ff... (90 %)
Writing at 0x00051b0d... (100 %)
Wrote 277520 bytes (153730 compressed) at 0x00010000 in 13.7 seconds (effective 162.6 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