Closed Klarstein closed 2 years ago
brianhanifin
commented
3 years ago Lucky for me I haven't run into this situation. Your sanity check does the job well.
I wonder if this could be caused by the duration value not being available at startup from Home Assistant? If so then you could add a sanity check for the value of id(ui_zone1_duration).state before storing the value in irrigation_zone1_duration. What do you think?
Klarstein
commented
3 years ago Lucky for me I haven't run into this situation. Your sanity check does the job well.
I wonder if this could be caused by the duration value not being available at startup from Home Assistant? If so then you could add a sanity check for the value of
id(ui_zone1_duration).statebefore storing the value inirrigation_zone1_duration. What do you think?
Yeah, it wouldn't matter to me if it was for an outdoor system either. But since this one is indoors.. I don't know if a sanity check for the id(ui_zone1_duration).state is the solution. It looks like it goes from NaN to 35791396.000000 way earlier in the process. Here is a VERY_VERBOSE log output from startup to where the trouble starts. Does that help?
[18:48:18][I][logger:170]: Log initialized
[18:48:18][VV][preferences:038]: LOAD 0: valid=YES, 0=0x00000009 1=0x4A164723 (Type=233825507, CRC=0x4A164723)
[18:48:18][VV][preferences:051]: SAVE 0: 0=0x0000000A 1=0x1AFA847E (Type=233825507, CRC=0x1AFA847E)
[18:48:18][VV][sensor:093]: Sensor(0x3ffb97f4)::add_filter(0x3ffb98f0)
[18:48:18][VV][sensor.filter:028]: Filter(0x3ffb98f0)::initialize(parent=0x3ffb97f4 next=0x0)
[18:48:18][I][app:029]: Running through setup()...
[18:48:18][V][app:030]: Sorting components by setup priority...
[18:48:18][VV][scheduler:026]: set_timeout(name='ON', timeout=100)
[18:48:18][VV][scheduler:026]: set_timeout(name='ON', timeout=100)
[18:48:18][C][switch.gpio:011]: Setting up GPIO Switch 'relay1'...
[18:48:18][VV][preferences:038]: LOAD 1: valid=YES, 0=0x00000001 1=0x584DDF01 (Type=391537629, CRC=0x584DDF01)
[18:48:18][D][switch:021]: 'relay1' Turning ON.
[18:48:18][VV][preferences:051]: SAVE 1: 0=0x00000001 1=0x584DDF01 (Type=391537629, CRC=0x584DDF01)
[18:48:18][D][switch:045]: 'relay1': Sending state ON
[18:48:18][V][sensor:035]: 'Irrigation Indoor Zone1 Remaining': Received new state nan
[18:48:18][D][sensor:127]: 'Irrigation Indoor Zone1 Remaining': Sending state nan minutes with 0 decimals of accuracy
[18:48:18][D][text_sensor:015]: 'Irrigation Indoor Zone1 Next': Sending state 'now'
[18:48:18][D][switch:021]: 'relay1' Turning ON.
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=4965)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=20)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=25590)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=15934)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=1561)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=29570)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=10838)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=3215)
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=60000, offset=18204)
[18:48:18][C][light:031]: Setting up light 'status_led'...
[18:48:18][VV][preferences:038]: LOAD 5: valid=YES, 0=0x00000001 1=0x3F800000 (Type=610457177, CRC=0x5AB96A85)
[18:48:18][D][light:093]: 'status_led' Setting:
[18:48:18][D][light:102]: State: ON
[18:48:18][D][light:106]: Brightness: 100%
[18:48:18][VV][preferences:051]: SAVE 5: 0=0x00000001 1=0x3F800000 (Type=610457177, CRC=0x5AB96A85)
[18:48:18][D][binary_sensor:034]: 'Irrigation Indoor Controller Status': Sending initial state OFF
[18:48:18][VV][scheduler:057]: set_interval(name='update', interval=5000, offset=1966)
[18:48:19][VV][scheduler:057]: set_interval(name='update', interval=900000, offset=219794)
[18:48:19][C][wifi:037]: Setting up WiFi...
[18:48:19][VV][preferences:264]: NVS length does not match. Assuming key changed (8!=104)
[18:48:19][V][wifi_esp32:036]: Enabling STA.
[18:48:19][VV][esp-idf:000]: I (562) wifi:
[18:48:19][VV][esp-idf:000]: wifi driver task: 3ffbbc2c, prio:23, stack:3584, core=0
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1366) wifi:
[18:48:19][VV][esp-idf:000]: wifi firmware version: dc30037
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1368) wifi:
[18:48:19][VV][esp-idf:000]: config NVS flash: enabled
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1380) wifi:
[18:48:19][VV][esp-idf:000]: config nano formating: disabled
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1392) wifi:
[18:48:19][VV][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1405) wifi:
[18:48:19][VV][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1419) wifi:
[18:48:19][VV][esp-idf:000]: Init management short buffer num: 32
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1432) wifi:
[18:48:19][VV][esp-idf:000]: Init dynamic tx buffer num: 32
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1444) wifi:
[18:48:19][VV][esp-idf:000]: Init static rx buffer size: 1600
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1457) wifi:
[18:48:19][VV][esp-idf:000]: Init static rx buffer num: 16
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1468) wifi:
[18:48:19][VV][esp-idf:000]: Init dynamic rx buffer num: 32
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][VV][esp-idf:000]: I (1572) wifi:
[18:48:19][VV][esp-idf:000]: mode : sta (00:00:00:00:00:00)
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 0 - WIFI_READY
[18:48:19][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 2 - STA_START
[18:48:19][V][wifi_esp32:376]: Event: WiFi STA start
[18:48:19][V][wifi_esp32:363]: Event: WiFi ready
[18:48:19][VV][esp-idf:000]: I (1604) wifi:
[18:48:19][VV][esp-idf:000]: Set ps type: 0
[18:48:19]
[18:48:19][VV][esp-idf:000]:
[18:48:19]
[18:48:19][D][wifi:380]: Starting scan...
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=900000 last_execution=4293848039 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294878106 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294882062 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294889496 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294891726 (now=847)
[18:48:19][V][sensor:035]: 'Irrigation Indoor Zone1 Remaining': Received new state 0.000000
[18:48:19][D][sensor:127]: 'Irrigation Indoor Zone1 Remaining': Sending state 0.00000 minutes with 0 decimals of accuracy
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294896846 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294902672 (now=847)
[18:48:19][V][sensor:035]: 'Irrigation Indoor Controller Uptime': Received new state 0.929000
[18:48:19][VV][sensor.filter:013]: Filter(0x3ffb98f0)::input(0.929000)
[18:48:19][VV][sensor.filter:215]: LambdaFilter(0x3ffb98f0)::new_value(0.929000) -> 0.000000
[18:48:19][VV][sensor.filter:020]: Filter(0x3ffb98f0)::output(0.000000) -> SENSOR
[18:48:19][D][sensor:127]: 'Irrigation Indoor Controller Uptime': Sending state 0.00000 h with 0 decimals of accuracy
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=60000 last_execution=4294904477 (now=847)
[18:48:19][VV][scheduler:152]: Running interval 'update' with interval=5000 last_execution=4294960786 (now=847)
[18:48:19][V][sensor:035]: 'Irrigation Indoor Zone1 Remaining': Received new state 35791396.000000
[18:48:19][D][sensor:127]: 'Irrigation Indoor Zone1 Remaining': Sending state 35791396.00000 minutes with 0 decimals of accuracy
sreknob
commented
3 years ago @Klarstein do you have an initial_value and restore_value set for remaining_time1 ?
Can you post your code to see if it can be reproduced? I don't see this during a reset on my ESP32. I also posted some thoughts on the homeassisant community forum as well.
To me it looks like the interval is running the remaining time update lambda sooner than it should be.
Klarstein
commented
3 years ago @sreknob Sure!! All help is welcome, thank you! Right now I'm only manually turning on the irrigation because a flooded floor is the last thing I want :).
The irrigation.h is unchanged. This is the most basic version I have, so without the soil moisture, DS1307 RTC and master-valve I added later. In this one I only changed the names and GPIOs. (I tested it and ran into the same issues with completely unchanged code)
In line 398 and 420 my workaround is included.
---
substitutions:
project: Irrigation Indoor Controller
id: irrigation_indoor
button1_gpio: GPIO16
button2_gpio: GPIO13
led_status_gpio: GPIO5
relay1_gpio: GPIO18
relay2_gpio: GPIO19
esphome:
name: $id
platform: ESP32
board: lolin_d32
includes:
- includes/irrigation.h
on_boot:
priority: -100.0
then:
# Wait to check for a Home Assistant API connection.
- delay: 15s
- if:
condition:
api.connected:
then:
# If connected, then flash the LED, and leave it at full brightness.
- logger.log: "$project is connected to the Home Assistant API!"
- light.turn_on:
id: status_led
brightness: 100%
- delay: 0.5s
- light.turn_off: status_led
- delay: 0.5s
- light.turn_on:
id: status_led
brightness: 100%
- delay: 0.5s
- light.turn_off: status_led
- delay: 0.5s
- light.turn_on:
id: status_led
brightness: 100%
- delay: 0.5s
- light.turn_off: status_led
- delay: 0.5s
- light.turn_on:
id: status_led
brightness: 100%
# Turn off the LED when the device is shutting down (like for a firmware update).
on_shutdown:
then:
- light.turn_off: status_led
wifi:
networks:
- ssid: "X"
password: "X"
# Disable rebooting due to losing connection with Home Assistant. This will allow
# the watering schedule to continue if Home Assistant goes down. Should it become
# unresponsive, we can have Home Assistant power cycle a smart plug to reboot it.
reboot_timeout: 0s
# Using these as a precaution to ensure solid WiFi connectivity.
power_save_mode: none
manual_ip:
static_ip: X
gateway: X
subnet: X
logger:
# level: VERY_VERBOSE
# Enable Home Assistant API
ota:
password: "X"
api:
password: "X"
globals:
# ============================================================================= #
# Irrigation time remaining
- id: remaining_time1
type: int
restore_value: no
initial_value: "300"
- id: remaining_time2
type: int
restore_value: no
initial_value: "300"
# ============================================================================= #
# Store previous values to verify change.
- id: remaining_time1_previous
type: int
restore_value: no
initial_value: "0"
- id: remaining_time2_previous
type: int
restore_value: no
initial_value: "0"
# Common housekeeping components.
output:
platform: ledc
pin: $led_status_gpio
inverted: True
id: _status_led
light:
platform: monochromatic
internal: True
output: _status_led
id: status_led
binary_sensor:
- platform: status
name: $project Status
# ============================================================================= #
# Buttons along the left side of the unit (R1, R2, R3, R4).
- platform: gpio
id: key1
pin:
number: $button1_gpio
mode: INPUT_PULLUP
inverted: True
filters:
- delayed_on: 100ms
- delayed_off: 100ms
on_click:
min_length: 50ms
max_length: 350ms
then:
- switch.toggle: irrigation_ind_zone1
- platform: gpio
id: key2
pin:
number: $button2_gpio
mode: INPUT_PULLUP
inverted: True
filters:
- delayed_on: 100ms
- delayed_off: 100ms
on_click:
min_length: 50ms
max_length: 350ms
then:
- switch.toggle: irrigation_ind_zone2
switch:
# ============================================================================= #
# Virtual Zone Switches which toggle the relay, and store the current state.
- platform: template
name: Irrigation Indoor Zone1
id: irrigation_ind_zone1
lambda: return id(relay1).state;
optimistic: true
turn_on_action:
# Turn on if not disabled.
if:
condition:
lambda: return id(irrigation_ind_zone1_duration) > 0;
then:
- switch.turn_on: relay1
turn_off_action:
- switch.turn_off: relay1
- platform: template
name: Irrigation Indoor Zone2
id: irrigation_ind_zone2
lambda: return id(relay2).state;
optimistic: true
turn_on_action:
# Turn on if not disabled.
if:
condition:
lambda: return id(irrigation_ind_zone2_duration) > 0;
then:
- switch.turn_on: relay2
turn_off_action:
- switch.turn_off: relay2
# ============================================================================= #
# Relays which trigger solenoids
- platform: gpio
id: relay1
pin: $relay1_gpio
on_turn_on:
then:
# Start the countdown timer.
- globals.set:
id: remaining_time1
value: !lambda return id(irrigation_ind_zone1_duration).state * 60;
# Show the remaining time.
- sensor.template.publish:
id: irrigation_ind_zone1_remaining
state: !lambda return id(irrigation_ind_zone1_duration).state;
# Show the "Next Time" as "now".
- text_sensor.template.publish:
id: irrigation_ind_zone1_next
state: "now"
on_turn_off:
then:
- sensor.template.publish:
id: irrigation_ind_zone1_remaining
state: "0"
# Update the next scheduled run time.
- text_sensor.template.publish:
id: irrigation_ind_zone1_next
state: !lambda |-
return update_next_runtime(id(irrigation_ind_zone1_times).state);
- platform: gpio
id: relay2
pin: $relay2_gpio
on_turn_on:
then:
# Start the countdown timer.
- globals.set:
id: remaining_time2
value: !lambda return id(irrigation_ind_zone2_duration).state * 60;
# Show the remaining time.
- sensor.template.publish:
id: irrigation_ind_zone2_remaining
state: !lambda return id(irrigation_ind_zone2_duration).state;
# Show the "Next Time" as "now".
- text_sensor.template.publish:
id: irrigation_ind_zone2_next
state: "now"
on_turn_off:
then:
- sensor.template.publish:
id: irrigation_ind_zone2_remaining
state: "0"
# Update the next scheduled run time.
- text_sensor.template.publish:
id: irrigation_ind_zone2_next
state: !lambda |-
return update_next_runtime(id(irrigation_ind_zone2_times).state);
sensor:
- platform: uptime
name: $project Uptime
unit_of_measurement: h
filters:
- lambda: return int((x + 1800.0) / 3600.0);
- platform: wifi_signal
name: $project WiFi Signal
update_interval: 30s
# ============================================================================= #
# Retrieve durations settings from the Home Assistant UI.
- platform: homeassistant
id: ui_ind_zone1_duration
entity_id: input_number.irrigation_ind_zone1_duration
on_value:
then:
- sensor.template.publish:
id: irrigation_ind_zone1_duration
state: !lambda return id(ui_ind_zone1_duration).state;
- platform: homeassistant
id: ui_ind_zone2_duration
entity_id: input_number.irrigation_ind_zone2_duration
on_value:
then:
- sensor.template.publish:
id: irrigation_ind_zone2_duration
state: !lambda return id(ui_ind_zone2_duration).state;
# ============================================================================= #
# Store durations.
- platform: template
name: Irrigation Indoor Zone1 Duration
id: irrigation_ind_zone1_duration
- platform: template
name: Irrigation Indoor Zone2 Duration
id: irrigation_ind_zone2_duration
# ============================================================================= #
# Countdown sensors.
- platform: template
name: Irrigation Indoor Zone1 Remaining
id: irrigation_ind_zone1_remaining
lambda: "return 0;"
accuracy_decimals: 0
unit_of_measurement: minutes
icon: mdi:timer-outline
on_value:
then:
- if:
condition:
lambda: return id(remaining_time1) == 0;
then:
- switch.turn_off: relay1
- platform: template
name: Irrigation Indoor Zone2 Remaining
id: irrigation_ind_zone2_remaining
lambda: "return 0;"
accuracy_decimals: 0
unit_of_measurement: minutes
icon: mdi:timer-outline
on_value:
then:
- if:
condition:
lambda: return id(remaining_time2) == 0;
then:
- switch.turn_off: relay2
text_sensor:
# ============================================================================= #
# Retrieve list of times from the Home Assistant UI.
- platform: homeassistant
id: ui_ind_zone1_times
entity_id: input_text.irrigation_ind_zone1_times
on_value:
then:
#- delay: 10sec
- text_sensor.template.publish:
id: irrigation_ind_zone1_times
state: !lambda return id(ui_ind_zone1_times).state;
- platform: homeassistant
id: ui_ind_zone2_times
entity_id: input_text.irrigation_ind_zone2_times
on_value:
then:
#- delay: 10sec
- text_sensor.template.publish:
id: irrigation_ind_zone2_times
state: !lambda return id(ui_ind_zone2_times).state;
# ============================================================================= #
# Store time lists.
- platform: template
name: Irrigation Indoor Zone1 Times
id: irrigation_ind_zone1_times
on_value:
then:
# Update the next scheduled run time.
- text_sensor.template.publish:
id: irrigation_ind_zone1_next
state: !lambda |-
return update_next_runtime(id(irrigation_ind_zone1_times).state);
- platform: template
name: Irrigation Indoor Zone2 Times
id: irrigation_ind_zone2_times
on_value:
then:
# Update the next scheduled run time.
- text_sensor.template.publish:
id: irrigation_ind_zone2_next
state: !lambda |-
return update_next_runtime(id(irrigation_ind_zone2_times).state);
# ============================================================================= #
# Set the next scheduled time.
- platform: template
name: Irrigation Indoor Zone1 Next
id: irrigation_ind_zone1_next
- platform: template
name: Irrigation Indoor Zone2 Next
id: irrigation_ind_zone2_next
# Update the countdown timers every 5 seconds.
interval:
- interval: 5s
then:
- lambda: |-
if (id(remaining_time1) > 0) {
// Store the previous time.
id(remaining_time1_previous) = id(remaining_time1);
// When the relay is on.
if (id(relay1).state) {
// Decrement the timer.
id(remaining_time1) -= 5;
// Turn off the relay when the time reaches zero... or the remaining time fails a sanity check!
//if (id(remaining_time1) <= 0 || id(irrigation_ind_zone1_remaining).state > id(irrigation_ind_zone1_duration).state){
if (id(remaining_time1) <= 0) {
id(relay1).turn_off();
id(remaining_time1) = 0;
}
if (id(remaining_time1) > 3600) {
id(remaining_time1) = 0;
}
}
// Update the remaining time display.
if (id(remaining_time1_previous) != id(remaining_time1)) {
id(irrigation_ind_zone1_remaining).publish_state( (id(remaining_time1)/60) + 1 );
}
}
if (id(remaining_time2) > 0) {
// Store the previous time.
id(remaining_time2_previous) = id(remaining_time2);
// When the relay is on.
if (id(relay2).state) {
// Decrement the timer.
id(remaining_time2) -= 5;
// Turn off the relay when the time reaches zero... or the remaining time fails a sanity check!
//if (id(remaining_time2) <= 0 || id(irrigation_ind_zone2_remaining).state > id(irrigation_ind_zone2_duration).state){
if (id(remaining_time2) <= 0) {
id(relay2).turn_off();
id(remaining_time2) = 0;
}
if (id(remaining_time2) > 3600) {
id(remaining_time2) = 0;
}
}
// Update the remaining time display.
if (id(remaining_time2_previous) != id(remaining_time2)) {
id(irrigation_ind_zone2_remaining).publish_state( (id(remaining_time2)/60) + 1 );
}
}
# Time based automations.
time:
- platform: homeassistant
id: homeassistant_time
timezone: Europe/Amsterdam
on_time:
- seconds: 0
minutes: /1
then:
- lambda: |-
if (scheduled_runtime(id(irrigation_ind_zone1_next).state.c_str())) {
id(irrigation_ind_zone1).turn_on();
}
if (scheduled_runtime(id(irrigation_ind_zone2_next).state.c_str())) {
id(irrigation_ind_zone2).turn_on();
}
Hey @Klarstein
Indeed, I can confirm the same behaviour with your code and the original code on this github repo using an ESP32.
It actually seems to happen with either a scheduler initiated run OR a manual run for me.
Waiting longer to start the interval code does not seem to help with this issue.
It DOES NOT, however, happen with the code that I use on my device... Will try and dig deeper into why later, but out of time for today...
Klarstein
commented
3 years ago @sreknob At least we know it’s not only me then :). Thank you for your efforts! I forgot to mention the manual-run behaviour, it has the same output after a reboot indeed.
Is there a way to dive even deeper into what happens within ESPHome than the ‘VERY_VERBOSE’ debug level gives us? For now, the switch from ‘NaN’ into thousands of seconds is kind of a black box as well.
I thought it would be best to make a new thread, to keep things separated. The irrigation controller shows some weird behaviour after a reset. If a zone was running during shutdown with a remaining time of let's say 5 minutes, those 5 minutes end up to be more then a million after a reboot.
Here I have two logs. First a log where a 5 min run is initiated by the schedule:
Then I push the reset button (or unplug the power and plug it back in, it doesn't matter) As you will see, the 'remaining time' values will sky-rocket right away.
Is this expected behaviour? I know i changed the IDs in your original configuration and added a DS1307, but it also shows this behaviour when I upload the unchanged config to ESPhome.
I found a temporary solution by adding the following lines as a sanity check in the on_time loop, but it's an ugly solution:
Do you have any clue?