mirror of
https://github.com/esphome/esphome.git
synced 2025-11-05 17:41:49 +00:00
Compare commits
6 Commits
mid_loop
...
template_f
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
5dc8bfcf13 | ||
|
|
b7838671ae | ||
|
|
479f8dd85c | ||
|
|
6e2dbbf636 | ||
|
|
6b522dfee6 | ||
|
|
32975c9d8b |
@@ -174,7 +174,7 @@ static uint8_t calc_checksum(void *data, size_t size) {
|
||||
static int get_firmware_int(const char *version_string) {
|
||||
std::string version_str = version_string;
|
||||
if (version_str[0] == 'v') {
|
||||
version_str = version_str.substr(1);
|
||||
version_str.erase(0, 1);
|
||||
}
|
||||
version_str.erase(remove(version_str.begin(), version_str.end(), '.'), version_str.end());
|
||||
int version_integer = stoi(version_str);
|
||||
|
||||
@@ -59,8 +59,8 @@ class LVGLSelect : public select::Select, public Component {
|
||||
const auto &opts = this->widget_->get_options();
|
||||
FixedVector<const char *> opt_ptrs;
|
||||
opt_ptrs.init(opts.size());
|
||||
for (size_t i = 0; i < opts.size(); i++) {
|
||||
opt_ptrs[i] = opts[i].c_str();
|
||||
for (const auto &opt : opts) {
|
||||
opt_ptrs.push_back(opt.c_str());
|
||||
}
|
||||
this->traits.set_options(opt_ptrs);
|
||||
}
|
||||
|
||||
@@ -35,9 +35,9 @@ void Rtttl::dump_config() {
|
||||
|
||||
void Rtttl::play(std::string rtttl) {
|
||||
if (this->state_ != State::STATE_STOPPED && this->state_ != State::STATE_STOPPING) {
|
||||
int pos = this->rtttl_.find(':');
|
||||
auto name = this->rtttl_.substr(0, pos);
|
||||
ESP_LOGW(TAG, "Already playing: %s", name.c_str());
|
||||
size_t pos = this->rtttl_.find(':');
|
||||
size_t len = (pos != std::string::npos) ? pos : this->rtttl_.length();
|
||||
ESP_LOGW(TAG, "Already playing: %.*s", (int) len, this->rtttl_.c_str());
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -59,8 +59,7 @@ void Rtttl::play(std::string rtttl) {
|
||||
return;
|
||||
}
|
||||
|
||||
auto name = this->rtttl_.substr(0, this->position_);
|
||||
ESP_LOGD(TAG, "Playing song %s", name.c_str());
|
||||
ESP_LOGD(TAG, "Playing song %.*s", (int) this->position_, this->rtttl_.c_str());
|
||||
|
||||
// get default duration
|
||||
this->position_ = this->rtttl_.find("d=", this->position_);
|
||||
|
||||
@@ -7,8 +7,8 @@ void SelectTraits::set_options(const std::initializer_list<const char *> &option
|
||||
|
||||
void SelectTraits::set_options(const FixedVector<const char *> &options) {
|
||||
this->options_.init(options.size());
|
||||
for (size_t i = 0; i < options.size(); i++) {
|
||||
this->options_[i] = options[i];
|
||||
for (const auto &opt : options) {
|
||||
this->options_.push_back(opt);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -49,7 +49,7 @@ struct SensorInfo {
|
||||
uint8_t store_index;
|
||||
};
|
||||
|
||||
class TemplateAlarmControlPanel : public alarm_control_panel::AlarmControlPanel, public Component {
|
||||
class TemplateAlarmControlPanel final : public alarm_control_panel::AlarmControlPanel, public Component {
|
||||
public:
|
||||
TemplateAlarmControlPanel();
|
||||
void dump_config() override;
|
||||
|
||||
@@ -7,7 +7,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateBinarySensor : public Component, public binary_sensor::BinarySensor {
|
||||
class TemplateBinarySensor final : public Component, public binary_sensor::BinarySensor {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -5,7 +5,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateButton : public button::Button {
|
||||
class TemplateButton final : public button::Button {
|
||||
public:
|
||||
// Implements the abstract `press_action` but the `on_press` trigger already handles the press.
|
||||
void press_action() override{};
|
||||
|
||||
@@ -14,7 +14,7 @@ enum TemplateCoverRestoreMode {
|
||||
COVER_RESTORE_AND_CALL,
|
||||
};
|
||||
|
||||
class TemplateCover : public cover::Cover, public Component {
|
||||
class TemplateCover final : public cover::Cover, public Component {
|
||||
public:
|
||||
TemplateCover();
|
||||
|
||||
|
||||
@@ -14,7 +14,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateDate : public datetime::DateEntity, public PollingComponent {
|
||||
class TemplateDate final : public datetime::DateEntity, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -14,7 +14,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateDateTime : public datetime::DateTimeEntity, public PollingComponent {
|
||||
class TemplateDateTime final : public datetime::DateTimeEntity, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -14,7 +14,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateTime : public datetime::TimeEntity, public PollingComponent {
|
||||
class TemplateTime final : public datetime::TimeEntity, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -6,7 +6,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateEvent : public Component, public event::Event {};
|
||||
class TemplateEvent final : public Component, public event::Event {};
|
||||
|
||||
} // namespace template_
|
||||
} // namespace esphome
|
||||
|
||||
@@ -6,7 +6,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateFan : public Component, public fan::Fan {
|
||||
class TemplateFan final : public Component, public fan::Fan {
|
||||
public:
|
||||
TemplateFan() {}
|
||||
void setup() override;
|
||||
|
||||
@@ -8,7 +8,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateLock : public lock::Lock, public Component {
|
||||
class TemplateLock final : public lock::Lock, public Component {
|
||||
public:
|
||||
TemplateLock();
|
||||
|
||||
|
||||
@@ -9,7 +9,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateNumber : public number::Number, public PollingComponent {
|
||||
class TemplateNumber final : public number::Number, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -7,7 +7,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateBinaryOutput : public output::BinaryOutput {
|
||||
class TemplateBinaryOutput final : public output::BinaryOutput {
|
||||
public:
|
||||
Trigger<bool> *get_trigger() const { return trigger_; }
|
||||
|
||||
@@ -17,7 +17,7 @@ class TemplateBinaryOutput : public output::BinaryOutput {
|
||||
Trigger<bool> *trigger_ = new Trigger<bool>();
|
||||
};
|
||||
|
||||
class TemplateFloatOutput : public output::FloatOutput {
|
||||
class TemplateFloatOutput final : public output::FloatOutput {
|
||||
public:
|
||||
Trigger<float> *get_trigger() const { return trigger_; }
|
||||
|
||||
|
||||
@@ -9,7 +9,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateSelect : public select::Select, public PollingComponent {
|
||||
class TemplateSelect final : public select::Select, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -7,7 +7,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateSensor : public sensor::Sensor, public PollingComponent {
|
||||
class TemplateSensor final : public sensor::Sensor, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -8,7 +8,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateSwitch : public switch_::Switch, public Component {
|
||||
class TemplateSwitch final : public switch_::Switch, public Component {
|
||||
public:
|
||||
TemplateSwitch();
|
||||
|
||||
|
||||
@@ -60,7 +60,7 @@ template<uint8_t SZ> class TextSaver : public TemplateTextSaverBase {
|
||||
}
|
||||
};
|
||||
|
||||
class TemplateText : public text::Text, public PollingComponent {
|
||||
class TemplateText final : public text::Text, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -8,7 +8,7 @@
|
||||
namespace esphome {
|
||||
namespace template_ {
|
||||
|
||||
class TemplateTextSensor : public text_sensor::TextSensor, public PollingComponent {
|
||||
class TemplateTextSensor final : public text_sensor::TextSensor, public PollingComponent {
|
||||
public:
|
||||
template<typename F> void set_template(F &&f) { this->f_.set(std::forward<F>(f)); }
|
||||
|
||||
|
||||
@@ -14,7 +14,7 @@ enum TemplateValveRestoreMode {
|
||||
VALVE_RESTORE_AND_CALL,
|
||||
};
|
||||
|
||||
class TemplateValve : public valve::Valve, public Component {
|
||||
class TemplateValve final : public valve::Valve, public Component {
|
||||
public:
|
||||
TemplateValve();
|
||||
|
||||
|
||||
@@ -657,7 +657,8 @@ void VoiceAssistant::on_event(const api::VoiceAssistantEventResponse &msg) {
|
||||
ESP_LOGW(TAG, "No text in STT_END event");
|
||||
return;
|
||||
} else if (text.length() > 500) {
|
||||
text = text.substr(0, 497) + "...";
|
||||
text.resize(497);
|
||||
text += "...";
|
||||
}
|
||||
ESP_LOGD(TAG, "Speech recognised as: \"%s\"", text.c_str());
|
||||
this->defer([this, text]() { this->stt_end_trigger_->trigger(text); });
|
||||
@@ -714,7 +715,8 @@ void VoiceAssistant::on_event(const api::VoiceAssistantEventResponse &msg) {
|
||||
return;
|
||||
}
|
||||
if (text.length() > 500) {
|
||||
text = text.substr(0, 497) + "...";
|
||||
text.resize(497);
|
||||
text += "...";
|
||||
}
|
||||
ESP_LOGD(TAG, "Response: \"%s\"", text.c_str());
|
||||
this->defer([this, text]() {
|
||||
|
||||
@@ -10,6 +10,8 @@
|
||||
namespace esphome {
|
||||
namespace wifi_info {
|
||||
|
||||
static constexpr size_t MAX_STATE_LENGTH = 255;
|
||||
|
||||
class IPAddressWiFiInfo : public PollingComponent, public text_sensor::TextSensor {
|
||||
public:
|
||||
void update() override {
|
||||
@@ -71,11 +73,14 @@ class ScanResultsWiFiInfo : public PollingComponent, public text_sensor::TextSen
|
||||
scan_results += "dB\n";
|
||||
}
|
||||
|
||||
// There's a limit of 255 characters per state.
|
||||
// Longer states just don't get sent so we truncate it.
|
||||
if (scan_results.length() > MAX_STATE_LENGTH) {
|
||||
scan_results.resize(MAX_STATE_LENGTH);
|
||||
}
|
||||
if (this->last_scan_results_ != scan_results) {
|
||||
this->last_scan_results_ = scan_results;
|
||||
// There's a limit of 255 characters per state.
|
||||
// Longer states just don't get sent so we truncate it.
|
||||
this->publish_state(scan_results.substr(0, 255));
|
||||
this->publish_state(scan_results);
|
||||
}
|
||||
}
|
||||
float get_setup_priority() const override { return setup_priority::AFTER_WIFI; }
|
||||
|
||||
@@ -98,28 +98,22 @@ template<typename... Ts> class ForCondition : public Condition<Ts...>, public Co
|
||||
|
||||
TEMPLATABLE_VALUE(uint32_t, time);
|
||||
|
||||
void loop() override {
|
||||
// Safe to use cached time - only called from Application::loop()
|
||||
this->check_internal_(App.get_loop_component_start_time());
|
||||
}
|
||||
|
||||
void loop() override { this->check_internal(); }
|
||||
float get_setup_priority() const override { return setup_priority::DATA; }
|
||||
|
||||
bool check(const Ts &...x) override {
|
||||
auto now = millis();
|
||||
if (!this->check_internal_(now))
|
||||
return false;
|
||||
return now - this->last_inactive_ >= this->time_.value(x...);
|
||||
}
|
||||
|
||||
protected:
|
||||
bool check_internal_(uint32_t now) {
|
||||
bool check_internal() {
|
||||
bool cond = this->condition_->check();
|
||||
if (!cond)
|
||||
this->last_inactive_ = now;
|
||||
this->last_inactive_ = App.get_loop_component_start_time();
|
||||
return cond;
|
||||
}
|
||||
|
||||
bool check(const Ts &...x) override {
|
||||
if (!this->check_internal())
|
||||
return false;
|
||||
return millis() - this->last_inactive_ >= this->time_.value(x...);
|
||||
}
|
||||
|
||||
protected:
|
||||
Condition<> *condition_;
|
||||
uint32_t last_inactive_{0};
|
||||
};
|
||||
@@ -430,17 +424,34 @@ template<typename... Ts> class WaitUntilAction : public Action<Ts...>, public Co
|
||||
auto timeout = this->timeout_value_.optional_value(x...);
|
||||
this->var_queue_.emplace_front(now, timeout, std::make_tuple(x...));
|
||||
|
||||
// Do immediate check with fresh timestamp
|
||||
if (this->process_queue_(now)) {
|
||||
// Only enable loop if we still have pending items
|
||||
this->enable_loop();
|
||||
}
|
||||
// Enable loop now that we have work to do
|
||||
this->enable_loop();
|
||||
this->loop();
|
||||
}
|
||||
|
||||
void loop() override {
|
||||
// Safe to use cached time - only called from Application::loop()
|
||||
if (this->num_running_ > 0 && !this->process_queue_(App.get_loop_component_start_time())) {
|
||||
// If queue is now empty, disable loop until next play_complex
|
||||
if (this->num_running_ == 0)
|
||||
return;
|
||||
|
||||
auto now = App.get_loop_component_start_time();
|
||||
|
||||
this->var_queue_.remove_if([&](auto &queued) {
|
||||
auto start = std::get<uint32_t>(queued);
|
||||
auto timeout = std::get<optional<uint32_t>>(queued);
|
||||
auto &var = std::get<std::tuple<Ts...>>(queued);
|
||||
|
||||
auto expired = timeout && (now - start) >= *timeout;
|
||||
|
||||
if (!expired && !this->condition_->check_tuple(var)) {
|
||||
return false;
|
||||
}
|
||||
|
||||
this->play_next_tuple_(var);
|
||||
return true;
|
||||
});
|
||||
|
||||
// If queue is now empty, disable loop until next play_complex
|
||||
if (this->var_queue_.empty()) {
|
||||
this->disable_loop();
|
||||
}
|
||||
}
|
||||
@@ -456,31 +467,6 @@ template<typename... Ts> class WaitUntilAction : public Action<Ts...>, public Co
|
||||
}
|
||||
|
||||
protected:
|
||||
// Helper: Process queue, triggering completed items and removing them
|
||||
// Returns true if queue still has pending items
|
||||
bool process_queue_(uint32_t now) {
|
||||
// Process each queued wait_until and remove completed ones
|
||||
this->var_queue_.remove_if([&](auto &queued) {
|
||||
auto start = std::get<uint32_t>(queued);
|
||||
auto timeout = std::get<optional<uint32_t>>(queued);
|
||||
auto &var = std::get<std::tuple<Ts...>>(queued);
|
||||
|
||||
// Check if timeout has expired
|
||||
auto expired = timeout && (now - start) >= *timeout;
|
||||
|
||||
// Keep waiting if not expired and condition not met
|
||||
if (!expired && !this->condition_->check_tuple(var)) {
|
||||
return false;
|
||||
}
|
||||
|
||||
// Condition met or timed out - trigger next action
|
||||
this->play_next_tuple_(var);
|
||||
return true;
|
||||
});
|
||||
|
||||
return !this->var_queue_.empty();
|
||||
}
|
||||
|
||||
Condition<Ts...> *condition_;
|
||||
std::forward_list<std::tuple<uint32_t, optional<uint32_t>, std::tuple<Ts...>>> var_queue_{};
|
||||
};
|
||||
|
||||
@@ -248,6 +248,8 @@ template<typename T> class FixedVector {
|
||||
}
|
||||
|
||||
// Allocate capacity - can be called multiple times to reinit
|
||||
// IMPORTANT: After calling init(), you MUST use push_back() to add elements.
|
||||
// Direct assignment via operator[] does NOT update the size counter.
|
||||
void init(size_t n) {
|
||||
cleanup_();
|
||||
reset_();
|
||||
|
||||
@@ -1,109 +0,0 @@
|
||||
# Test for PR #11676 bug: wait_until timeout when triggered mid-component-loop
|
||||
# This demonstrates that App.get_loop_component_start_time() is stale when
|
||||
# wait_until is triggered partway through a component's loop execution
|
||||
|
||||
esphome:
|
||||
name: wait-mid-loop
|
||||
|
||||
host:
|
||||
|
||||
api:
|
||||
actions:
|
||||
- action: test_mid_loop_timeout
|
||||
then:
|
||||
- logger.log: "=== Test: wait_until triggered mid-loop should timeout correctly ==="
|
||||
|
||||
# Reset test state
|
||||
- globals.set:
|
||||
id: test_complete
|
||||
value: 'false'
|
||||
|
||||
# Trigger the slow script that will call wait_until mid-execution
|
||||
- script.execute: slow_script
|
||||
|
||||
# Wait for test to complete (should take ~300ms: 100ms delay + 200ms timeout)
|
||||
- wait_until:
|
||||
condition:
|
||||
lambda: return id(test_complete);
|
||||
timeout: 2s
|
||||
|
||||
- if:
|
||||
condition:
|
||||
lambda: return id(test_complete);
|
||||
then:
|
||||
- logger.log: "✓ Test PASSED: wait_until timed out correctly"
|
||||
else:
|
||||
- logger.log: "✗ Test FAILED: wait_until did not complete properly"
|
||||
|
||||
logger:
|
||||
level: DEBUG
|
||||
|
||||
globals:
|
||||
- id: test_complete
|
||||
type: bool
|
||||
restore_value: false
|
||||
initial_value: 'false'
|
||||
|
||||
- id: test_condition
|
||||
type: bool
|
||||
restore_value: false
|
||||
initial_value: 'false'
|
||||
|
||||
- id: timeout_start_time
|
||||
type: uint32_t
|
||||
restore_value: false
|
||||
initial_value: '0'
|
||||
|
||||
- id: timeout_end_time
|
||||
type: uint32_t
|
||||
restore_value: false
|
||||
initial_value: '0'
|
||||
|
||||
script:
|
||||
# This script simulates a component that takes time during its execution
|
||||
# When wait_until is triggered mid-script, the loop_component_start_time
|
||||
# will be stale (from when the script's component loop started)
|
||||
- id: slow_script
|
||||
then:
|
||||
- logger.log: "Script: Starting, about to do some work..."
|
||||
|
||||
# Simulate component doing work for 100ms
|
||||
# This represents time spent in a component's loop() before triggering wait_until
|
||||
- delay: 100ms
|
||||
|
||||
- logger.log: "Script: 100ms elapsed, now starting wait_until with 200ms timeout"
|
||||
- lambda: |-
|
||||
// Record when timeout starts
|
||||
id(timeout_start_time) = millis();
|
||||
id(test_condition) = false;
|
||||
|
||||
# At this point:
|
||||
# - Script component's loop started 100ms ago
|
||||
# - App.loop_component_start_time_ = time from 100ms ago (stale!)
|
||||
# - wait_until will capture millis() NOW (fresh)
|
||||
# - BUG: loop() will use stale loop_component_start_time, causing immediate timeout
|
||||
|
||||
- wait_until:
|
||||
condition:
|
||||
lambda: return id(test_condition);
|
||||
timeout: 200ms
|
||||
|
||||
- lambda: |-
|
||||
// Record when timeout completes
|
||||
id(timeout_end_time) = millis();
|
||||
uint32_t elapsed = id(timeout_end_time) - id(timeout_start_time);
|
||||
|
||||
ESP_LOGD("TEST", "wait_until completed after %u ms (expected ~200ms)", elapsed);
|
||||
|
||||
// Check if timeout took approximately correct time
|
||||
// Should be ~200ms, not <50ms (immediate timeout)
|
||||
if (elapsed >= 150 && elapsed <= 250) {
|
||||
ESP_LOGD("TEST", "✓ Timeout duration correct: %u ms", elapsed);
|
||||
id(test_complete) = true;
|
||||
} else {
|
||||
ESP_LOGE("TEST", "✗ Timeout duration WRONG: %u ms (expected 150-250ms)", elapsed);
|
||||
if (elapsed < 50) {
|
||||
ESP_LOGE("TEST", " → Likely BUG: Immediate timeout due to stale loop_component_start_time");
|
||||
}
|
||||
id(test_complete) = false;
|
||||
}
|
||||
@@ -1,112 +0,0 @@
|
||||
"""Integration test for PR #11676 mid-loop timing bug.
|
||||
|
||||
This test validates that wait_until timeouts work correctly when triggered
|
||||
mid-component-loop, where App.get_loop_component_start_time() is stale.
|
||||
|
||||
The bug: When wait_until is triggered partway through a component's loop execution
|
||||
(e.g., from a script or automation), the cached loop_component_start_time_ is stale
|
||||
relative to when the action was actually triggered. This causes timeout calculations
|
||||
to underflow and timeout immediately instead of waiting the specified duration.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import asyncio
|
||||
import re
|
||||
|
||||
import pytest
|
||||
|
||||
from .types import APIClientConnectedFactory, RunCompiledFunction
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_wait_until_mid_loop_timing(
|
||||
yaml_config: str,
|
||||
run_compiled: RunCompiledFunction,
|
||||
api_client_connected: APIClientConnectedFactory,
|
||||
) -> None:
|
||||
"""Test that wait_until timeout works when triggered mid-component-loop.
|
||||
|
||||
This test:
|
||||
1. Executes a script that delays 100ms (simulating component work)
|
||||
2. Then starts wait_until with 200ms timeout
|
||||
3. Verifies timeout takes ~200ms, not <50ms (immediate timeout bug)
|
||||
"""
|
||||
loop = asyncio.get_running_loop()
|
||||
|
||||
# Track test results
|
||||
test_results = {
|
||||
"timeout_duration": None,
|
||||
"passed": False,
|
||||
"failed": False,
|
||||
"bug_detected": False,
|
||||
}
|
||||
|
||||
# Patterns for log messages
|
||||
timeout_duration = re.compile(r"wait_until completed after (\d+) ms")
|
||||
test_pass = re.compile(r"✓ Timeout duration correct")
|
||||
test_fail = re.compile(r"✗ Timeout duration WRONG")
|
||||
bug_pattern = re.compile(r"Likely BUG: Immediate timeout")
|
||||
test_passed = re.compile(r"✓ Test PASSED")
|
||||
test_failed = re.compile(r"✗ Test FAILED")
|
||||
|
||||
test_complete = loop.create_future()
|
||||
|
||||
def check_output(line: str) -> None:
|
||||
"""Check log output for test results."""
|
||||
# Extract timeout duration
|
||||
match = timeout_duration.search(line)
|
||||
if match:
|
||||
test_results["timeout_duration"] = int(match.group(1))
|
||||
|
||||
if test_pass.search(line):
|
||||
test_results["passed"] = True
|
||||
if test_fail.search(line):
|
||||
test_results["failed"] = True
|
||||
if bug_pattern.search(line):
|
||||
test_results["bug_detected"] = True
|
||||
|
||||
# Final test result
|
||||
if (
|
||||
test_passed.search(line)
|
||||
or test_failed.search(line)
|
||||
and not test_complete.done()
|
||||
):
|
||||
test_complete.set_result(True)
|
||||
|
||||
async with (
|
||||
run_compiled(yaml_config, line_callback=check_output),
|
||||
api_client_connected() as client,
|
||||
):
|
||||
# Get the test service
|
||||
_, services = await client.list_entities_services()
|
||||
test_service = next(
|
||||
(s for s in services if s.name == "test_mid_loop_timeout"), None
|
||||
)
|
||||
assert test_service is not None, "test_mid_loop_timeout service not found"
|
||||
|
||||
# Execute the test
|
||||
client.execute_service(test_service, {})
|
||||
|
||||
# Wait for test to complete (100ms delay + 200ms timeout + margins = ~500ms)
|
||||
await asyncio.wait_for(test_complete, timeout=5.0)
|
||||
|
||||
# Verify results
|
||||
assert test_results["timeout_duration"] is not None, (
|
||||
"Timeout duration not reported"
|
||||
)
|
||||
assert test_results["passed"], (
|
||||
f"Test failed: wait_until took {test_results['timeout_duration']}ms, expected ~200ms. "
|
||||
f"Bug detected: {test_results['bug_detected']}"
|
||||
)
|
||||
assert not test_results["bug_detected"], (
|
||||
f"BUG DETECTED: wait_until timed out immediately ({test_results['timeout_duration']}ms) "
|
||||
"instead of waiting 200ms. This indicates stale loop_component_start_time."
|
||||
)
|
||||
|
||||
# Additional validation: timeout should be ~200ms (150-250ms range)
|
||||
duration = test_results["timeout_duration"]
|
||||
assert 150 <= duration <= 250, (
|
||||
f"Timeout duration {duration}ms outside expected range (150-250ms). "
|
||||
f"This suggests timing regression from PR #11676."
|
||||
)
|
||||
Reference in New Issue
Block a user