esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
291 stars 36 forks source link

Component Light light.on_turn_off is only called after boot #2499

Closed dylan09 closed 3 years ago

dylan09 commented 3 years ago

The problem

The trigger light.on_turn_off is only called directly after boot. When light is turned off from Home Assistant the trigger isn't executed. I set default values for brightness and light temperature for my rgbww lights. This worked for version 1.20.4. But it is broken with version 2021.9.2

As you can see in log file, the trigger is called in an endless loop after boot (I call light.turn_off in on_boot). But after switching on the light from Home Assistant it is never called again.

As you can see in the log, on_turn_off is called in an endless loop until the first state switch to on. But it is never called for switching off light from HA.

Which version of ESPHome has the issue?

2021.9.2

What type of installation are you using?

pip

Which version of Home Assistant has the issue?

2021.9.7

What platform are you using?

ESP8266

Board

esp_wroom_02

Component causing the issue

light

Example YAML snippet

# esphome configuration WizLight E60 bulb living room

substitutions:
  node_name: xx-li-wiz2
  id_prefix: xx_li_wiz2
  name_prefix: xx_li_wiz2
  brightness_offset: "-20"

packages:
  wifi: !include common/wifi.yaml
  web_server: !include common/web_server.yaml
  mqtt:  !include common/mqtt.yaml
  time:  !include common/time.yaml
  sensor: !include common/def_sensor.yaml
  text_sensor: !include common/def_text_sensor.yaml

esphome:
  name: ${node_name}
  platform: ESP8266
  board: esp_wroom_02
  on_boot:
    priority: -10
    # ...
    then:
      - light.turn_off: ${id_prefix}

captive_portal:

logger:

mqtt:
  discovery: true

ota:
  password: !secret ota_passwd

sensor:
  - platform: mqtt_subscribe
    name: ${name_prefix} DefBrightPct
    id: ${id_prefix}_def_bright_pct
    topic: homeassistant/variables/wz_brightness/percent
    unit_of_measurement: '%'
    on_value:
      then:
        - light.control:
            id: ${id_prefix}
            color_mode: COLD_WARM_WHITE
            brightness: !lambda |-
              ESP_LOGI("MQTT", "New brightness %f", id(${id_prefix}_def_bright_pct).state);
              return (isnan(id(${id_prefix}_def_bright_pct).state) ? 0.5 : (id(${id_prefix}_def_bright_pct).state + ${brightness_offset}) / 100);

  - platform: mqtt_subscribe
    name: ${name_prefix} DefKelvin
    id: ${id_prefix}_def_kelvin
    topic: homeassistant/variables/wz_temperature/kelvin
    unit_of_measurement: 'K'
    on_value:
      then:
        - light.control:
            id: ${id_prefix}
            color_mode: COLD_WARM_WHITE
            color_temperature: !lambda |-
              ESP_LOGI("MQTT", "New temperature %f", id(${id_prefix}_def_kelvin).state);
              return (isnan(id(${id_prefix}_def_kelvin).state) ? 0 : 1000000 / id(${id_prefix}_def_kelvin).state);

output:
  - platform: esp8266_pwm
    id: out_red
    pin: GPIO15
    frequency: 200Hz
  - platform: esp8266_pwm
    id: out_green
    pin: GPIO12
    frequency: 200Hz
  - platform: esp8266_pwm
    id: out_blue
    pin: GPIO14
    frequency: 200Hz
  - platform: esp8266_pwm
    id: out_warm_white
    pin: GPIO4
    frequency: 1000Hz
  - platform: esp8266_pwm
    id: out_cold_white
    pin: GPIO13
    frequency: 1000Hz

light:
  - platform: rgbww
    name: ${name_prefix}
    id: ${id_prefix}
    red: out_red
    green: out_green
    blue: out_blue
    warm_white: out_warm_white
    cold_white: out_cold_white
    cold_white_color_temperature: 6500 K
    warm_white_color_temperature: 2200 K
    color_interlock: true # avoids simultaneous RGB and W/W
    default_transition_length: 500ms
    restore_mode: ALWAYS_OFF
    on_turn_off:
      light.control:
        id: ${id_prefix}
        state: off
        color_mode: COLD_WARM_WHITE
        brightness: !lambda |-
          ESP_LOGI("main", "Set brightness to %f", id(${id_prefix}_def_bright_pct).state);
          return (isnan(id(${id_prefix}_def_bright_pct).state) ? 0.5 : (id(${id_prefix}_def_bright_pct).state + ${brightness_offset}) / 100);
        color_temperature: !lambda |-
          ESP_LOGI("main", "Set temperature to %f", id(${id_prefix}_def_kelvin).state);
          return (isnan(id(${id_prefix}_def_kelvin).state) ? 0 : 1000000 / id(${id_prefix}_def_kelvin).state);

Anything in the logs that might be useful for us?

[20:40:06][I][mqtt:212]: MQTT Connected!
[20:40:06][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:06][D][light:084]:   Transition length: 0.5s
[20:40:06][I][app:060]: setup() finished successfully!
[20:40:06][D][sensor:121]: 'xx_li_wizzyS60 RSSI': Sending state -63.00000 dBm with 0 decimals of accuracy
[20:40:06][D][text_sensor:015]: 'xx_li_wizzyS60 IP': Sending state 'XXX.XXX.XXX.XXX'
[20:40:06][D][sntp:060]: Synchronized time: 2021-10-1 20:40:6
[20:40:06][I][app:102]: ESPHome version 2021.9.2 compiled on Oct  1 2021, 20:39:36
[20:40:06][C][wifi:501]: WiFi:
[20:40:06][C][wifi:361]:   SSID: 'XXXX'
[20:40:06][C][wifi:362]:   IP Address: XXX.XXX.XXX.X
[20:40:06][C][wifi:364]:   BSSID: XX:XX:XX:XX:XX:XX
[20:40:06][C][wifi:365]:   Hostname: 'xx-li-wiz2'
[20:40:06][C][wifi:369]:   Signal strength: -63 dB ▂▄▆█
[20:40:06][C][wifi:373]:   Channel: 11
[20:40:06][C][wifi:374]:   Subnet: XXX.XXX.XXX.XXX
[20:40:06][C][wifi:375]:   Gateway: XXX.XXX.XXX.XXX
[20:40:06][C][wifi:376]:   DNS1: XXX.XXX.XXX.XXX
[20:40:06][C][wifi:377]:   DNS2: (IP unset)
[20:40:06][C][uptime.sensor:030]: Uptime Sensor 'xx_li_wizzyS60 Uptime'
[20:40:06][C][uptime.sensor:030]:   State Class: 'total_increasing'
[20:40:06][C][uptime.sensor:030]:   Unit of Measurement: 's'
[20:40:06][C][uptime.sensor:030]:   Accuracy Decimals: 0
[20:40:06][C][uptime.sensor:030]:   Icon: 'mdi:timer-outline'
[20:40:06][C][esp8266_pwm:023]: ESP8266 PWM:
[20:40:06][C][esp8266_pwm:024]:   Pin: GPIO15 (Mode: OUTPUT)
[20:40:06][C][esp8266_pwm:025]:   Frequency: 200.0 Hz
[20:40:06][C][esp8266_pwm:023]: ESP8266 PWM:
[20:40:06][C][esp8266_pwm:024]:   Pin: GPIO12 (Mode: OUTPUT)
[20:40:06][C][esp8266_pwm:025]:   Frequency: 200.0 Hz
[20:40:06][C][esp8266_pwm:023]: ESP8266 PWM:
[20:40:06][C][esp8266_pwm:024]:   Pin: GPIO14 (Mode: OUTPUT)
[20:40:06][C][esp8266_pwm:025]:   Frequency: 200.0 Hz
[20:40:06][C][esp8266_pwm:023]: ESP8266 PWM:
[20:40:06][C][esp8266_pwm:024]:   Pin: GPIO4 (Mode: OUTPUT)
[20:40:06][C][esp8266_pwm:025]:   Frequency: 1000.0 Hz
[20:40:06][C][esp8266_pwm:023]: ESP8266 PWM:
[20:40:06][C][esp8266_pwm:024]:   Pin: GPIO13 (Mode: OUTPUT)
[20:40:06][C][esp8266_pwm:025]:   Frequency: 1000.0 Hz
[20:40:06][C][logger:193]: Logger:
[20:40:06][C][logger:194]:   Level: DEBUG
[20:40:06][C][logger:195]:   Log Baud Rate: 115200
[20:40:06][C][logger:196]:   Hardware UART: UART0
[20:40:06][C][light:097]: Light 'xx_li_wizzyS60'
[20:40:06][C][light:099]:   Default Transition Length: 0.5s
[20:40:06][C][light:100]:   Gamma Correct: 2.80
[20:40:06][C][version.text_sensor:021]: Version Text Sensor 'xx_li_wizzyS60 Version'
[20:40:06][C][version.text_sensor:021]:   Icon: 'mdi:new-box'
[20:40:06][C][adc:072]: ADC Sensor 'xx_li_wizzyS60 Vcc'
[20:40:06][C][adc:072]:   Device Class: 'voltage'
[20:40:06][C][adc:072]:   State Class: 'measurement'
[20:40:06][C][adc:072]:   Unit of Measurement: 'V'
[20:40:06][C][adc:072]:   Accuracy Decimals: 2
[20:40:06][C][adc:075]:   Pin: VCC
[20:40:06][C][adc:099]:   Update Interval: 60.0s
[20:40:06][C][captive_portal:148]: Captive Portal:
[20:40:06][C][web_server:152]: Web Server:
[20:40:06][C][web_server:153]:   Address: xx-li-wiz2.XXXXXXXXXX.XX:80
[20:40:06][C][ota:029]: Over-The-Air Updates:
[20:40:06][C][ota:030]:   Address: xx-li-wiz2.XXXXXXXXXX.XX:8266
[20:40:06][C][ota:032]:   Using Password.
[20:40:06][C][mqtt:061]: MQTT:
[20:40:06][C][mqtt:063]:   Server Address: XX.XXXXXXXXXX.XX:1883 (XXX.XXX.XXX.XXX)
[20:40:06][C][mqtt:064]:   Username: 'XXXXXXXX'
[20:40:06][C][mqtt:065]:   Client ID: 'xx-li-wiz2-XXXXXXXX'
[20:40:06][C][mqtt:067]:   Discovery prefix: 'homeassistant'
[20:40:06][C][mqtt:068]:   Discovery retain: YES
[20:40:06][C][mqtt:070]:   Topic Prefix: 'esphome/xx_li_wizzyS60'
[20:40:06][C][mqtt:072]:   Log Topic: 'esphome/xx_li_wizzyS60/debug'
[20:40:06][C][mqtt:075]:   Availability: 'esphome/xx_li_wizzyS60/status'
[20:40:06][I][main:129]: Set brightness to nan
[20:40:06][I][main:132]: Set temperature to nan
[20:40:06][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:06][W][light:224]: 'xx_li_wizzyS60' - Color temperature value 0.00 is out of range [153.8 - 454.5]!
[20:40:06][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:06][D][light:050]:   Brightness: 50%
[20:40:06][D][light:065]:   Color temperature: 153.8 mireds
[20:40:06][D][light:070]:   Cold white: 100%, warm white: 0%
[20:40:06][D][light:084]:   Transition length: 0.5s
[20:40:06][C][wifi_info:009]: WifiInfo IPAddress 'xx_li_wizzyS60 IP'
[20:40:06][C][wifi_info:009]:   Icon: 'mdi:ip'
[20:40:06][C][wifi_signal.sensor:009]: WiFi Signal 'xx_li_wizzyS60 RSSI'
[20:40:06][C][wifi_signal.sensor:009]:   Device Class: 'signal_strength'
[20:40:06][C][wifi_signal.sensor:009]:   State Class: 'measurement'
[20:40:06][C][wifi_signal.sensor:009]:   Unit of Measurement: 'dBm'
[20:40:06][C][wifi_signal.sensor:009]:   Accuracy Decimals: 0
[20:40:06][C][sntp:044]: SNTP Time:
[20:40:06][C][sntp:045]:   Server 1: 'XXXXXX.XXXXXXXXXX.XX'
[20:40:06][C][sntp:046]:   Server 2: ''
[20:40:06][C][sntp:047]:   Server 3: ''
[20:40:06][C][sntp:048]:   Timezone: 'CET-1CEST-2,M3.4.0/2,M10.5.0/3'
[20:40:06][C][mqtt.text_sensor:025]: MQTT Text Sensor 'xx_li_wizzyS60 IP':
[20:40:06][C][mqtt.text_sensor:026]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_ip/state'
[20:40:06][C][mqtt.text_sensor:025]: MQTT Text Sensor 'xx_li_wizzyS60 Version':
[20:40:06][C][mqtt.text_sensor:026]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_version/state'
[20:40:06][C][mqtt.sensor:024]: MQTT Sensor 'xx_li_wizzyS60 Uptime':
[20:40:06][C][mqtt.sensor:028]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_uptime/state'
[20:40:07][C][mqtt.sensor:024]: MQTT Sensor 'xx_li_wizzyS60 Vcc':
[20:40:07][C][mqtt.sensor:028]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_vcc/state'
[20:40:07][C][mqtt.sensor:024]: MQTT Sensor 'xx_li_wizzyS60 RSSI':
[20:40:07][C][mqtt.sensor:028]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_rssi/state'
[20:40:07][C][mqtt_subscribe.sensor:028]: MQTT Subscribe 'xx_li_wizzyS60 DefBrightPct'
[20:40:07][C][mqtt_subscribe.sensor:028]:   State Class: ''
[20:40:07][C][mqtt_subscribe.sensor:028]:   Unit of Measurement: '%'
[20:40:07][C][mqtt_subscribe.sensor:028]:   Accuracy Decimals: 1
[20:40:07][C][mqtt_subscribe.sensor:029]:   Topic: homeassistant/variables/wz_brightness/percent
[20:40:07][C][mqtt_subscribe.sensor:028]: MQTT Subscribe 'xx_li_wizzyS60 DefKelvin'
[20:40:07][C][mqtt_subscribe.sensor:028]:   State Class: ''
[20:40:07][C][mqtt_subscribe.sensor:028]:   Unit of Measurement: 'K'
[20:40:07][C][mqtt_subscribe.sensor:028]:   Accuracy Decimals: 1
[20:40:07][C][mqtt_subscribe.sensor:029]:   Topic: homeassistant/variables/wz_temperature/kelvin
[20:40:07][C][mqtt.light:074]: MQTT Light 'xx_li_wizzyS60':
[20:40:07][C][mqtt.light:075]:   State Topic: 'esphome/xx_li_wizzyS60/light/xx_li_wizzyS60/state'
[20:40:07][C][mqtt.light:075]:   Command Topic: 'esphome/xx_li_wizzyS60/light/xx_li_wizzyS60/command'
[20:40:07][C][mqtt.sensor:024]: MQTT Sensor 'xx_li_wizzyS60 DefBrightPct':
[20:40:07][C][mqtt.sensor:028]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_defbrightpct/state'
[20:40:07][C][mqtt.sensor:024]: MQTT Sensor 'xx_li_wizzyS60 DefKelvin':
[20:40:07][C][mqtt.sensor:028]:   State Topic: 'esphome/xx_li_wizzyS60/sensor/xx_li_wizzyS60_defkelvin/state'
[20:40:07][D][sensor:121]: 'xx_li_wizzyS60 DefBrightPct': Sending state 50.00000 % with 1 decimals of accuracy
[20:40:07][I][MQTT:063]: New brightness 50.000000
[20:40:07][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:07][D][light:050]:   Brightness: 30%
[20:40:07][D][light:084]:   Transition length: 0.5s
[20:40:07][D][sensor:121]: 'xx_li_wizzyS60 DefKelvin': Sending state 2800.00000 K with 1 decimals of accuracy
[20:40:07][I][MQTT:077]: New temperature 2800.000000
[20:40:07][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:07][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:07][D][light:065]:   Color temperature: 357.1 mireds
[20:40:07][D][light:070]:   Cold white: 77%, warm white: 100%
[20:40:07][D][light:084]:   Transition length: 0.5s
[20:40:07][I][main:129]: Set brightness to 50.000000
[20:40:07][I][main:132]: Set temperature to 2800.000000
[20:40:07][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:07][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:07][D][light:050]:   Brightness: 30%
[20:40:07][D][light:065]:   Color temperature: 357.1 mireds
[20:40:07][D][light:070]:   Cold white: 77%, warm white: 100%
[20:40:07][D][light:084]:   Transition length: 0.5s
[20:40:08][I][main:129]: Set brightness to 50.000000
[20:40:08][I][main:132]: Set temperature to 2800.000000
[20:40:08][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:08][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:08][D][light:050]:   Brightness: 30%
[20:40:08][D][light:065]:   Color temperature: 357.1 mireds
[20:40:08][D][light:070]:   Cold white: 77%, warm white: 100%
[20:40:08][D][light:084]:   Transition length: 0.5s
[20:40:08][I][main:129]: Set brightness to 50.000000
[20:40:08][I][main:132]: Set temperature to 2800.000000
[20:40:08][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:08][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:08][D][light:050]:   Brightness: 30%
[20:40:08][D][light:065]:   Color temperature: 357.1 mireds
[20:40:08][D][light:070]:   Cold white: 77%, warm white: 100%
[20:40:08][D][light:084]:   Transition length: 0.5s
[20:40:09][I][main:129]: Set brightness to 50.000000
[20:40:09][I][main:132]: Set temperature to 2800.000000

... 

[20:40:21][I][main:129]: Set brightness to 50.000000
[20:40:21][I][main:132]: Set temperature to 2800.000000
[20:40:21][D][light:346]: 'xx_li_wizzyS60' - Setting cold/warm white channels using white/color temperature values.
[20:40:21][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:21][D][light:050]:   Brightness: 30%
[20:40:21][D][light:065]:   Color temperature: 357.1 mireds
[20:40:21][D][light:070]:   Cold white: 77%, warm white: 100%
[20:40:21][D][light:084]:   Transition length: 0.5s
[20:40:21][I][light:390]: 'xx_li_wizzyS60' - Keeping current color mode Cold/warm white for call without color mode.
[20:40:21][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:21][D][light:046]:   State: ON
[20:40:21][D][light:084]:   Transition length: 0.5s
[20:40:23][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:23][D][light:046]:   State: OFF
[20:40:23][D][light:084]:   Transition length: 0.5s
[20:40:30][D][sensor:121]: 'xx_li_wizzyS60 Uptime': Sending state 39.95700 s with 0 decimals of accuracy
[20:40:30][I][light:390]: 'xx_li_wizzyS60' - Keeping current color mode Cold/warm white for call without color mode.
[20:40:30][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:30][D][light:046]:   State: ON
[20:40:30][D][light:084]:   Transition length: 0.5s
[20:40:32][D][light:035]: 'xx_li_wizzyS60' Setting:
[20:40:32][D][light:046]:   State: OFF
[20:40:32][D][light:084]:   Transition length: 0.5s

Additional information

No response

OttoWinter commented 3 years ago

state: off

So you're turning a light off from the on_turn_off trigger.

Maybe it worked before, but that doesn't seem like the correct behavior anyway.

If a light is already off it I don't think it should call on_turn_off again.

probot-esphome[bot] commented 3 years ago

Hey there @esphome/core, mind taking a look at this issue as it has been labeled with an integration (light) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

dylan09 commented 3 years ago

I think that's a copy&paste error. I think the state: off statement is obsolete. But I will check if deleting the statement will fix the error.

The main purpose of the on_turn_off trigger is to set default values for brightness and temperature. And as could be seen in the log, when the light is turned off by Home Assistant the trigger isn't executed. With version 1.20.4 it is working as expected.

dylan09 commented 3 years ago

Hi. I have checked again. This time without the state: off. For this test I have deleted the on_boot automation also.

Compiled code using esphome 2021.9.2. After upload and reboot the on_turn_off trigger is called in a loop 2-3 times per second. This loop stops immediatly when I turn on the light from Home Assistant. When I switch off the light on_turn_off trigger wasn't called.

Compiling the same code using esphome 1.20.4 it works as expected. After update and reboot the on_turn_off trigger isn't called until I turn on and turn off the light from Home Assistant.

So there must be something broken between 1.20.4 and 2021.9.2

As seen in the code I am using MQTT for communication.

OttoWinter commented 3 years ago

Try using light.turn_on or add state: on.

What your code is doing right now is changing the color_temp etc of a light that is already off.

Again, if you control a light in on_turn_off I'd expect it not to run on_turn_off again (because the light is already off)

dylan09 commented 3 years ago

That is my intention. If the light is switched off, I set the brightness/temperature to default value. So if the light is turned on and no further parameters (brightness, color, ...) is send from HA it starts with this settings.

If I set the default values in the on_turn_on trigger, parameters (color, brightness, temperature, ...) send from HA are ignored and the light always turn on with my default values.

So it makes a big difference, if I set the default values using the on_turn_off or on_turn_on

If I use the on_turn_off trigger, I am able to send different parameter from HA when light it turned on. If no parameters are given it starts with default.

If I use the on_turn_on trigger, the light always is using the default values, because the on_turn_on trigger is executed, after the light is turned on and the parameters send from HA are applied.

Maybe there is another way to get the light working as I described above:

Any hints are very welcome.

As a test, I removed all the code from the on_turn_off trigger. Only one logger output for debugging. Even without light.control the on_turn_off trigger is not executed when light is turned off.

dylan09 commented 3 years ago

I think my issue is related to issue #2458. And if I remember correctly there was also an issue where transition length was a problem.

I have found, that changing the default_transition_length to 0ms changed the behaviour how state changes are detected.

I have implemented following yaml as test to see if light conditions are working:

interval:
  - interval: 2 sec
    then:
      - if:
          condition:
            light.is_on: ${id_prefix}
          then:
            - logger.log: 
                format: "Condition check: Light is on"
                tag: "intervall 2"
      - if:
          condition:
            light.is_off: ${id_prefix}
          then:
            - logger.log: 
                format: "Condition check: Light is off"
                tag: "intervall 2"

Log output, whendefault_transition_length is set to 500ms:

[22:58:18][D][intervall 2:272]: Condition check: Light is off
[22:58:19][I][light:390]: 'xx_li_wiz1' - Keeping current color mode Cold/warm white for call without color mode.
[22:58:19][D][light:035]: 'xx_li_wiz1' Setting:
[22:58:19][D][light:046]:   State: ON
[22:58:19][D][light:084]:   Transition length: 0.5s
[22:58:20][D][intervall 2:266]: Condition check: Light is on
[22:58:22][D][intervall 2:266]: Condition check: Light is on
[22:58:24][D][intervall 2:266]: Condition check: Light is on
[22:58:26][D][light:035]: 'xx_li_wiz1' Setting:
[22:58:26][D][light:046]:   State: OFF
[22:58:26][D][light:084]:   Transition length: 0.5s
[22:58:26][D][intervall 2:266]: Condition check: Light is on
[22:58:28][D][intervall 2:266]: Condition check: Light is on

Log output, whendefault_transition_length is set to 0ms:

[23:00:09][D][intervall 2:272]: Condition check: Light is off
[23:00:09][I][light:390]: 'xx_li_wiz1' - Keeping current color mode Cold/warm white for call without color mode.
[23:00:09][D][light:035]: 'xx_li_wiz1' Setting:
[23:00:09][D][light:046]:   State: ON
[23:00:11][D][intervall 2:266]: Condition check: Light is on
[23:00:13][D][intervall 2:266]: Condition check: Light is on
[23:00:15][D][intervall 2:266]: Condition check: Light is on
[23:00:17][D][intervall 2:266]: Condition check: Light is on
[23:00:17][D][light:035]: 'xx_li_wiz1' Setting:
[23:00:17][D][light:046]:   State: OFF
[23:00:19][D][intervall 2:272]: Condition check: Light is off
[23:00:21][D][intervall 2:272]: Condition check: Light is off

With transition lenght != 0ms also the condition check light.is_off isn't working.

First log output shows, that after State: OFF, the condition for on is true. In the second log output using 0ms, the check is working.

dylan09 commented 3 years ago

Regardless of my somewhat unusual program: The error is that the state light_off is not recognized if the default_transition_length > 0.

I have now tried to use the condition light.is_off. But this is not triggered. Description and logs in the previous post.

Does anyone have a tip where in the ESPHome source code I can find the handling with the conditions/triggers?

Kaibob2 commented 3 years ago

Same here. I have a scenario where the heater of a rain sensor has to be switched off shortly to measure the resistance. This Automation worked fine until a few versions ago. I don't know exactly when.

interval:
  - interval: 60s
    then:
      - if:
          condition:
            light.is_on: heizung_light
          then:
            - logger.log: "Heizung ist AN. Wird ausgeschaltet..."  
            - light.turn_off: heizung_light
            - logger.log: "Heizung ist AUS" 
            - delay: 500ms
            - logger.log: "Regensensor Power an"
            - output.turn_on: rs_power
            - delay: 500ms
            - logger.log: "Regensensor auslesen"
            - component.update: regensensor
            - logger.log: "Regensensor Garten updaten"
            - sensor.template.publish:
                id: regensensor_garten
                state: !lambda |-
                  return id(regensensor).state;      
            - delay: 200ms
            - logger.log: "Regensensor Power aus"  
            - output.turn_off: rs_power
            - delay: 200ms            
            - light.turn_on: heizung_light
            - logger.log: "Heizung ist wieder AN"            
          else:
            - logger.log: "Heizung ist AUS" 
            - delay: 500ms
            - logger.log: "Regensensor Power an"
            - output.turn_on: rs_power
            - delay: 500ms
            - logger.log: "Regensensor auslesen"
            - component.update: regensensor
            - logger.log: "Regensensor Garten updaten"
            - sensor.template.publish:
                id: regensensor_garten
                state: !lambda |-
                  return id(regensensor).state;      
            - delay: 200ms
            - logger.log: "Regensensor Power aus"  
            - output.turn_off: rs_power

I tried everything to narrow it down and found, that when including

    on_turn_on:
    - logger.log: "Light Turned On!"
    on_turn_off:
    - logger.log: "Light Turned Off!"

to the light component only the "Light Turned On!" got logged. This led me to this thread and since I have set default_transition_length it's working again.

Kaibob2 commented 3 years ago

The problem was, that after the heizung_light switch got turned on manually in HA the automation never again saw the else condition as the light stayed "on" all the time. The switch in HA was off but the ESP still was convinced that the light is on.

ghost commented 3 years ago

Hello!, I confirm this issue and the workaround.

Please find below the code to replicate it. The "green led" has default transition to 0s, so the code inside on_turn_off runs as expected. But for "blue led" the on_turn_off trigger is ignored

In my case, "on_turn_off" is the easiest way to push the light status to my Nextion screens (while not having to pass the transition parameter on every call to service light.turn_off). I hope this is something easy to solve. I cannot help with C++ but if I can test/document or anything else... I'll be happy to help.

CODE:

output:
  - platform: ledc
    pin: GPIO27
    id: greenled_output
  - platform: ledc
    pin: GPIO25
    id: blueled_output

light:
## Green led
  - platform: monochromatic
    name: "Green led"
    output: greenled_output
    id: greenled_light
    restore_mode: ALWAYS_OFF
    default_transition_length: 0s
    on_turn_on:
      then:
        - logger.log: "green led, on_turn_on"
    on_turn_off:
      then:
        - logger.log: "green led, on_turn_off"
## Blue led
  - platform: monochromatic
    name: "Blue led"
    output: blueled_output
    id: blueled_light
    restore_mode: ALWAYS_OFF
    on_turn_on:
      then:
        - logger.log: "blue led, on_turn_on"
    on_turn_off:
      then:
        - logger.log: "blue led, on_turn_off"

LOGS:

[17:47:51][D][light:035]: 'Blue led' Setting:
[17:47:51][D][light:046]:   State: ON
[17:47:51][D][light:084]:   Transition length: 1.0s
[17:47:51][D][main:144]: blue led, on_turn_on
[17:47:54][D][light:035]: 'Blue led' Setting:
[17:47:54][D][light:046]:   State: OFF
[17:47:54][D][light:084]:   Transition length: 1.0s
[17:48:06][D][light:035]: 'Green led' Setting:
[17:48:06][D][light:046]:   State: ON
[17:48:06][D][main:229]: green led, on_turn_on
[17:48:09][D][light:035]: 'Green led' Setting:
[17:48:09][D][light:046]:   State: OFF
[17:48:09][D][main:235]: green led, on_turn_off
AZDane commented 3 years ago

Same issue observed here. on_turn_off no longer triggers after upgrade when having a transition length . Worked fine before.

AZDane commented 3 years ago

Could this issue potentially stem from this fix? https://github.com/esphome/esphome/pull/2320

dylan09 commented 3 years ago

Thanks. Will test and check the fix when next ESPHome version is officially published.