This commit is contained in:
J. Nick Koston 2025-07-17 16:35:53 -10:00
parent ab354d4bec
commit 4f35151928
No known key found for this signature in database
2 changed files with 70 additions and 97 deletions

View File

@ -4,38 +4,21 @@ esphome:
host: host:
api: api:
actions: actions:
- action: start_script - action: start_delay_then_restart
then: then:
- logger.log: "Starting first script execution"
- script.execute: test_delay_script - script.execute: test_delay_script
- delay: 500ms # Give first script time to start delay
- action: restart_script - logger.log: "Restarting script (should cancel first delay)"
then:
- script.execute: test_delay_script - script.execute: test_delay_script
- action: check_result
then:
- logger.log:
format: "Test completed with %d delay completions"
args: ['id(delay_completed_count)']
logger: logger:
level: DEBUG level: DEBUG
globals:
- id: delay_completed_count
type: int
initial_value: "0"
script: script:
- id: test_delay_script - id: test_delay_script
mode: restart mode: restart
then: then:
- logger.log: - logger.log: "Script started, beginning delay"
format: "Script execution started (run number %d)" - delay: 5s # Long enough that it won't complete before restart
args: ['id(delay_completed_count) + 1'] - logger.log: "ERROR: First delay completed - this should NOT happen with restart mode!"
- delay: 150ms
- lambda: |-
id(delay_completed_count)++;
- logger.log:
format: "Delay completed! Total completions: %d"
args: ['id(delay_completed_count)']

View File

@ -19,51 +19,42 @@ async def test_delay_action_cancellation(
"""Test that delay actions can be properly cancelled when script restarts.""" """Test that delay actions can be properly cancelled when script restarts."""
loop = asyncio.get_running_loop() loop = asyncio.get_running_loop()
# Track events via futures # Track log messages
script_started_future = loop.create_future() log_lines: list[str] = []
script_restarted_future = loop.create_future() script_start_count = 0
delay_completed_future = loop.create_future() first_delay_completed = False
test_complete_future = loop.create_future() script_restart_logged = False
test_started = False
# Track counts
script_started_count = 0
delay_completed_count = 0
# Patterns to match # Patterns to match
script_start_pattern = re.compile(r"Script execution started \(run number (\d+)\)") test_start_pattern = re.compile(r"Starting first script execution")
script_restart_pattern = re.compile(r"restarting \(mode: restart\)") script_start_pattern = re.compile(r"Script started, beginning delay")
delay_complete_pattern = re.compile(r"Delay completed! Total completions: (\d+)") restart_pattern = re.compile(r"Restarting script \(should cancel first delay\)")
test_complete_pattern = re.compile(r"Test completed with (\d+) delay completions") error_pattern = re.compile(r"ERROR: First delay completed")
# Future to track when we can check results
second_script_started = loop.create_future()
def check_output(line: str) -> None: def check_output(line: str) -> None:
"""Check log output for expected messages.""" """Check log output for expected messages."""
nonlocal script_started_count, delay_completed_count nonlocal \
script_start_count, \
first_delay_completed, \
script_restart_logged, \
test_started
# Check for script start log_lines.append(line)
start_match = script_start_pattern.search(line)
if start_match:
script_started_count += 1
if not script_started_future.done():
script_started_future.set_result(True)
# Check for script restart if test_start_pattern.search(line):
if script_restart_pattern.search(line): test_started = True
if not script_restarted_future.done(): elif script_start_pattern.search(line) and test_started:
script_restarted_future.set_result(True) script_start_count += 1
if script_start_count == 2 and not second_script_started.done():
# Check for delay completion second_script_started.set_result(True)
complete_match = delay_complete_pattern.search(line) elif restart_pattern.search(line):
if complete_match: script_restart_logged = True
delay_completed_count = int(complete_match.group(1)) elif error_pattern.search(line):
if not delay_completed_future.done(): first_delay_completed = True
delay_completed_future.set_result(delay_completed_count)
# Check for test completion
test_match = test_complete_pattern.search(line)
if test_match:
final_count = int(test_match.group(1))
if not test_complete_future.done():
test_complete_future.set_result(final_count)
async with ( async with (
run_compiled(yaml_config, line_callback=check_output), run_compiled(yaml_config, line_callback=check_output),
@ -72,41 +63,40 @@ async def test_delay_action_cancellation(
# Get services # Get services
entities, services = await client.list_entities_services() entities, services = await client.list_entities_services()
# Find our test services # Find our test service
start_service = next((s for s in services if s.name == "start_script"), None) test_service = next(
restart_service = next( (s for s in services if s.name == "start_delay_then_restart"), None
(s for s in services if s.name == "restart_script"), None
) )
check_result_service = next( assert test_service is not None, "start_delay_then_restart service not found"
(s for s in services if s.name == "check_result"), None
# Execute the test sequence
client.execute_service(test_service, {})
# Wait for the second script to start
await asyncio.wait_for(second_script_started, timeout=5.0)
# Wait a bit more to ensure first delay would have completed if not cancelled
await asyncio.sleep(6.0) # Original delay was 5s
# Check results
assert script_start_count == 2, (
f"Script should have started twice, but started {script_start_count} times"
) )
assert script_restart_logged, "Script restart was not logged"
assert start_service is not None, "start_script service not found" # This is the key assertion - the first delay should NOT have completed
assert restart_service is not None, "restart_script service not found" if first_delay_completed:
assert check_result_service is not None, "check_result service not found" # Print relevant logs for debugging
relevant_logs = [
# Start the script line
client.execute_service(start_service, {}) for line in log_lines
if any(
# Wait for script to start pattern in line
await asyncio.wait_for(script_started_future, timeout=5.0) for pattern in ["Script", "delay", "ERROR", "Restart"]
assert script_started_count == 1, "Script should have started once" )
]
# Restart the script pytest.fail(
client.execute_service(restart_service, {}) "First delay completed even though script was restarted! "
"This means DelayAction is not being cancelled properly.\n"
# Wait for restart confirmation "Log output:\n" + "\n".join(relevant_logs[-20:])
await asyncio.wait_for(script_restarted_future, timeout=2.0)
# Wait for the restarted script to complete its delay
await asyncio.wait_for(delay_completed_future, timeout=1.0)
# Check the final result
client.execute_service(check_result_service, {})
final_count = await asyncio.wait_for(test_complete_future, timeout=5.0)
# If DelayAction cancellation works correctly, we should only have 1 completion
# (from the restarted script). If it doesn't work, we'd have 2 completions.
assert final_count == 1, (
f"Expected 1 delay completion after restart, but got {final_count}"
) )