From 0d422bd74ff3a12c507d9a25c1deffa1129ef8f0 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Fri, 18 Jul 2025 02:26:54 -1000 Subject: [PATCH] [scheduler] Add integration tests for set_retry functionality (#9644) --- .../fixtures/scheduler_retry_test.yaml | 207 ++++++++++++++++ .../integration/test_scheduler_retry_test.py | 234 ++++++++++++++++++ 2 files changed, 441 insertions(+) create mode 100644 tests/integration/fixtures/scheduler_retry_test.yaml create mode 100644 tests/integration/test_scheduler_retry_test.py diff --git a/tests/integration/fixtures/scheduler_retry_test.yaml b/tests/integration/fixtures/scheduler_retry_test.yaml new file mode 100644 index 0000000000..bae50e9ed7 --- /dev/null +++ b/tests/integration/fixtures/scheduler_retry_test.yaml @@ -0,0 +1,207 @@ +esphome: + name: scheduler-retry-test + on_boot: + priority: -100 + then: + - logger.log: "Starting scheduler retry tests" + # Run all tests sequentially with delays + - script.execute: run_all_tests + +host: +api: +logger: + level: VERBOSE + +globals: + - id: simple_retry_counter + type: int + initial_value: '0' + - id: backoff_retry_counter + type: int + initial_value: '0' + - id: immediate_done_counter + type: int + initial_value: '0' + - id: cancel_retry_counter + type: int + initial_value: '0' + - id: empty_name_retry_counter + type: int + initial_value: '0' + - id: script_retry_counter + type: int + initial_value: '0' + - id: multiple_same_name_counter + type: int + initial_value: '0' + +sensor: + - platform: template + name: Test Sensor + id: test_sensor + lambda: return 1.0; + update_interval: never + +script: + - id: run_all_tests + then: + # Test 1: Simple retry + - logger.log: "=== Test 1: Simple retry ===" + - lambda: |- + auto *component = id(test_sensor); + App.scheduler.set_retry(component, "simple_retry", 50, 3, + [](uint8_t retry_countdown) { + id(simple_retry_counter)++; + ESP_LOGI("test", "Simple retry attempt %d (countdown=%d)", + id(simple_retry_counter), retry_countdown); + + if (id(simple_retry_counter) >= 2) { + ESP_LOGI("test", "Simple retry succeeded on attempt %d", id(simple_retry_counter)); + return RetryResult::DONE; + } + return RetryResult::RETRY; + }); + + # Test 2: Backoff retry + - logger.log: "=== Test 2: Retry with backoff ===" + - lambda: |- + auto *component = id(test_sensor); + static uint32_t backoff_start_time = 0; + static uint32_t last_attempt_time = 0; + + backoff_start_time = millis(); + last_attempt_time = backoff_start_time; + + App.scheduler.set_retry(component, "backoff_retry", 50, 4, + [](uint8_t retry_countdown) { + id(backoff_retry_counter)++; + uint32_t now = millis(); + uint32_t interval = now - last_attempt_time; + last_attempt_time = now; + + ESP_LOGI("test", "Backoff retry attempt %d (countdown=%d, interval=%dms)", + id(backoff_retry_counter), retry_countdown, interval); + + if (id(backoff_retry_counter) == 1) { + ESP_LOGI("test", "First call was immediate"); + } else if (id(backoff_retry_counter) == 2) { + ESP_LOGI("test", "Second call interval: %dms (expected ~50ms)", interval); + } else if (id(backoff_retry_counter) == 3) { + ESP_LOGI("test", "Third call interval: %dms (expected ~100ms)", interval); + } else if (id(backoff_retry_counter) == 4) { + ESP_LOGI("test", "Fourth call interval: %dms (expected ~200ms)", interval); + ESP_LOGI("test", "Backoff retry completed"); + return RetryResult::DONE; + } + + return RetryResult::RETRY; + }, 2.0f); + + # Test 3: Immediate done + - logger.log: "=== Test 3: Immediate done ===" + - lambda: |- + auto *component = id(test_sensor); + App.scheduler.set_retry(component, "immediate_done", 50, 5, + [](uint8_t retry_countdown) { + id(immediate_done_counter)++; + ESP_LOGI("test", "Immediate done retry called (countdown=%d)", retry_countdown); + return RetryResult::DONE; + }); + + # Test 4: Cancel retry + - logger.log: "=== Test 4: Cancel retry ===" + - lambda: |- + auto *component = id(test_sensor); + App.scheduler.set_retry(component, "cancel_test", 25, 10, + [](uint8_t retry_countdown) { + id(cancel_retry_counter)++; + ESP_LOGI("test", "Cancel test retry attempt %d", id(cancel_retry_counter)); + return RetryResult::RETRY; + }); + + // Cancel it after 100ms + App.scheduler.set_timeout(component, "cancel_timer", 100, []() { + bool cancelled = App.scheduler.cancel_retry(id(test_sensor), "cancel_test"); + ESP_LOGI("test", "Retry cancellation result: %s", cancelled ? "true" : "false"); + ESP_LOGI("test", "Cancel retry ran %d times before cancellation", id(cancel_retry_counter)); + }); + + # Test 5: Empty name retry + - logger.log: "=== Test 5: Empty name retry ===" + - lambda: |- + auto *component = id(test_sensor); + App.scheduler.set_retry(component, "", 50, 5, + [](uint8_t retry_countdown) { + id(empty_name_retry_counter)++; + ESP_LOGI("test", "Empty name retry attempt %d", id(empty_name_retry_counter)); + return RetryResult::RETRY; + }); + + // Try to cancel after 75ms + App.scheduler.set_timeout(component, "empty_cancel_timer", 75, []() { + bool cancelled = App.scheduler.cancel_retry(id(test_sensor), ""); + ESP_LOGI("test", "Empty name retry cancel result: %s", + cancelled ? "true" : "false"); + ESP_LOGI("test", "Empty name retry ran %d times", id(empty_name_retry_counter)); + }); + + # Test 6: Component method + - logger.log: "=== Test 6: Component::set_retry method ===" + - lambda: |- + class TestRetryComponent : public Component { + public: + void test_retry() { + this->set_retry(50, 3, + [](uint8_t retry_countdown) { + id(script_retry_counter)++; + ESP_LOGI("test", "Component retry attempt %d", id(script_retry_counter)); + if (id(script_retry_counter) >= 2) { + return RetryResult::DONE; + } + return RetryResult::RETRY; + }, 1.5f); + } + }; + + static TestRetryComponent test_component; + test_component.test_retry(); + + # Test 7: Multiple same name + - logger.log: "=== Test 7: Multiple retries with same name ===" + - lambda: |- + auto *component = id(test_sensor); + + // Set first retry + App.scheduler.set_retry(component, "duplicate_retry", 100, 5, + [](uint8_t retry_countdown) { + id(multiple_same_name_counter) += 1; + ESP_LOGI("test", "First duplicate retry - should not run"); + return RetryResult::RETRY; + }); + + // Set second retry with same name (should cancel first) + App.scheduler.set_retry(component, "duplicate_retry", 50, 3, + [](uint8_t retry_countdown) { + id(multiple_same_name_counter) += 10; + ESP_LOGI("test", "Second duplicate retry attempt (counter=%d)", + id(multiple_same_name_counter)); + if (id(multiple_same_name_counter) >= 20) { + return RetryResult::DONE; + } + return RetryResult::RETRY; + }); + + # Wait for all tests to complete before reporting + - delay: 500ms + + # Final report + - logger.log: "=== Retry Test Results ===" + - lambda: |- + ESP_LOGI("test", "Simple retry counter: %d (expected 2)", id(simple_retry_counter)); + ESP_LOGI("test", "Backoff retry counter: %d (expected 4)", id(backoff_retry_counter)); + ESP_LOGI("test", "Immediate done counter: %d (expected 1)", id(immediate_done_counter)); + ESP_LOGI("test", "Cancel retry counter: %d (expected ~3-4)", id(cancel_retry_counter)); + ESP_LOGI("test", "Empty name retry counter: %d (expected 1-2)", id(empty_name_retry_counter)); + ESP_LOGI("test", "Component retry counter: %d (expected 2)", id(script_retry_counter)); + ESP_LOGI("test", "Multiple same name counter: %d (expected 20+)", id(multiple_same_name_counter)); + ESP_LOGI("test", "All retry tests completed"); diff --git a/tests/integration/test_scheduler_retry_test.py b/tests/integration/test_scheduler_retry_test.py new file mode 100644 index 0000000000..0c4d573c1b --- /dev/null +++ b/tests/integration/test_scheduler_retry_test.py @@ -0,0 +1,234 @@ +"""Test scheduler retry functionality.""" + +import asyncio +import re + +import pytest + +from .types import APIClientConnectedFactory, RunCompiledFunction + + +@pytest.mark.asyncio +async def test_scheduler_retry_test( + yaml_config: str, + run_compiled: RunCompiledFunction, + api_client_connected: APIClientConnectedFactory, +) -> None: + """Test that scheduler retry functionality works correctly.""" + # Track test progress + simple_retry_done = asyncio.Event() + backoff_retry_done = asyncio.Event() + immediate_done_done = asyncio.Event() + cancel_retry_done = asyncio.Event() + empty_name_retry_done = asyncio.Event() + component_retry_done = asyncio.Event() + multiple_name_done = asyncio.Event() + test_complete = asyncio.Event() + + # Track retry counts + simple_retry_count = 0 + backoff_retry_count = 0 + immediate_done_count = 0 + cancel_retry_count = 0 + empty_name_retry_count = 0 + component_retry_count = 0 + multiple_name_count = 0 + + # Track specific test results + cancel_result = None + empty_cancel_result = None + backoff_intervals = [] + + def on_log_line(line: str) -> None: + nonlocal simple_retry_count, backoff_retry_count, immediate_done_count + nonlocal cancel_retry_count, empty_name_retry_count, component_retry_count + nonlocal multiple_name_count, cancel_result, empty_cancel_result + + # Strip ANSI color codes + clean_line = re.sub(r"\x1b\[[0-9;]*m", "", line) + + # Simple retry test + if "Simple retry attempt" in clean_line: + if match := re.search(r"Simple retry attempt (\d+)", clean_line): + simple_retry_count = int(match.group(1)) + + elif "Simple retry succeeded on attempt" in clean_line: + simple_retry_done.set() + + # Backoff retry test + elif "Backoff retry attempt" in clean_line: + if match := re.search( + r"Backoff retry attempt (\d+).*interval=(\d+)ms", clean_line + ): + backoff_retry_count = int(match.group(1)) + interval = int(match.group(2)) + if backoff_retry_count > 1: # Skip first (immediate) call + backoff_intervals.append(interval) + + elif "Backoff retry completed" in clean_line: + backoff_retry_done.set() + + # Immediate done test + elif "Immediate done retry called" in clean_line: + immediate_done_count += 1 + immediate_done_done.set() + + # Cancel retry test + elif "Cancel test retry attempt" in clean_line: + cancel_retry_count += 1 + + elif "Retry cancellation result:" in clean_line: + cancel_result = "true" in clean_line + cancel_retry_done.set() + + # Empty name retry test + elif "Empty name retry attempt" in clean_line: + if match := re.search(r"Empty name retry attempt (\d+)", clean_line): + empty_name_retry_count = int(match.group(1)) + + elif "Empty name retry cancel result:" in clean_line: + empty_cancel_result = "true" in clean_line + + elif "Empty name retry ran" in clean_line: + empty_name_retry_done.set() + + # Component retry test + elif "Component retry attempt" in clean_line: + if match := re.search(r"Component retry attempt (\d+)", clean_line): + component_retry_count = int(match.group(1)) + if component_retry_count >= 2: + component_retry_done.set() + + # Multiple same name test + elif "Second duplicate retry attempt" in clean_line: + if match := re.search(r"counter=(\d+)", clean_line): + multiple_name_count = int(match.group(1)) + if multiple_name_count >= 20: + multiple_name_done.set() + + # Test completion + elif "All retry tests completed" in clean_line: + test_complete.set() + + async with ( + run_compiled(yaml_config, line_callback=on_log_line), + api_client_connected() as client, + ): + # Verify we can connect + device_info = await client.device_info() + assert device_info is not None + assert device_info.name == "scheduler-retry-test" + + # Wait for simple retry test + try: + await asyncio.wait_for(simple_retry_done.wait(), timeout=1.0) + except TimeoutError: + pytest.fail( + f"Simple retry test did not complete. Count: {simple_retry_count}" + ) + + assert simple_retry_count == 2, ( + f"Expected 2 simple retry attempts, got {simple_retry_count}" + ) + + # Wait for backoff retry test + try: + await asyncio.wait_for(backoff_retry_done.wait(), timeout=3.0) + except TimeoutError: + pytest.fail( + f"Backoff retry test did not complete. Count: {backoff_retry_count}" + ) + + assert backoff_retry_count == 4, ( + f"Expected 4 backoff retry attempts, got {backoff_retry_count}" + ) + + # Verify backoff intervals (allowing for timing variations) + assert len(backoff_intervals) >= 2, ( + f"Expected at least 2 intervals, got {len(backoff_intervals)}" + ) + if len(backoff_intervals) >= 3: + # First interval should be ~50ms + assert 30 <= backoff_intervals[0] <= 70, ( + f"First interval {backoff_intervals[0]}ms not ~50ms" + ) + # Second interval should be ~100ms (50ms * 2.0) + assert 80 <= backoff_intervals[1] <= 120, ( + f"Second interval {backoff_intervals[1]}ms not ~100ms" + ) + # Third interval should be ~200ms (100ms * 2.0) + assert 180 <= backoff_intervals[2] <= 220, ( + f"Third interval {backoff_intervals[2]}ms not ~200ms" + ) + + # Wait for immediate done test + try: + await asyncio.wait_for(immediate_done_done.wait(), timeout=3.0) + except TimeoutError: + pytest.fail( + f"Immediate done test did not complete. Count: {immediate_done_count}" + ) + + assert immediate_done_count == 1, ( + f"Expected 1 immediate done call, got {immediate_done_count}" + ) + + # Wait for cancel retry test + try: + await asyncio.wait_for(cancel_retry_done.wait(), timeout=2.0) + except TimeoutError: + pytest.fail( + f"Cancel retry test did not complete. Count: {cancel_retry_count}" + ) + + assert cancel_result is True, "Retry cancellation should have succeeded" + assert 2 <= cancel_retry_count <= 5, ( + f"Expected 2-5 cancel retry attempts before cancellation, got {cancel_retry_count}" + ) + + # Wait for empty name retry test + try: + await asyncio.wait_for(empty_name_retry_done.wait(), timeout=1.0) + except TimeoutError: + pytest.fail( + f"Empty name retry test did not complete. Count: {empty_name_retry_count}" + ) + + # Empty name retry should run at least once before being cancelled + assert 1 <= empty_name_retry_count <= 2, ( + f"Expected 1-2 empty name retry attempts, got {empty_name_retry_count}" + ) + assert empty_cancel_result is True, ( + "Empty name retry cancel should have succeeded" + ) + + # Wait for component retry test + try: + await asyncio.wait_for(component_retry_done.wait(), timeout=1.0) + except TimeoutError: + pytest.fail( + f"Component retry test did not complete. Count: {component_retry_count}" + ) + + assert component_retry_count >= 2, ( + f"Expected at least 2 component retry attempts, got {component_retry_count}" + ) + + # Wait for multiple same name test + try: + await asyncio.wait_for(multiple_name_done.wait(), timeout=1.0) + except TimeoutError: + pytest.fail( + f"Multiple same name test did not complete. Count: {multiple_name_count}" + ) + + # Should be 20+ (only second retry should run) + assert multiple_name_count >= 20, ( + f"Expected multiple name count >= 20 (second retry only), got {multiple_name_count}" + ) + + # Wait for test completion + try: + await asyncio.wait_for(test_complete.wait(), timeout=1.0) + except TimeoutError: + pytest.fail("Test did not complete within timeout")