home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.82k stars 30.51k forks source link

Automation gives unintended "ON" when using "light.turn_off" with transition set #57181

Closed ahd71 closed 2 years ago

ahd71 commented 3 years ago

The problem

When using HA automations (in my case with ZHA and partly with Zigbee groups) in one single automation turning a few lights "off" and some others "on" it invalidly turns ALL of them "on" if transition time is added in the automation (see snippet below) - when removing the transition lines everything works as intended.

What is version of Home Assistant Core has the issue?

core-2021.9.7

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

LIGHT

Link to integration documentation on our website

No response

Example YAML snippet

alias: bedroom_master_statemachine
description: Master Bedroom Automation
trigger:
  - platform: state
    entity_id: input_number.state_bedroom_master
condition: []
action:
  - choose:
      - conditions:
          - condition: state
            entity_id: input_number.state_bedroom_master
            state: '0.0'
        sequence:
          - service: light.turn_off
            target:
              entity_id: light.bedroom_master_all_zha_group_0x001d
      - conditions:
          - condition: state
            entity_id: input_number.state_bedroom_master
            state: '5.0'
        sequence:
          - service: light.turn_on
            target:
              entity_id: light.bedroom_master_table_lights_zha_group_0x0007
            data:
              brightness_pct: 40
              transition: 2
          - service: light.turn_off
            target:
              entity_id: light.bedroom_master_window_lights_zha_group_0x001e
            data:
              transition: 2
          - service: light.turn_off
            target:
              entity_id: light.bedroom_master_ceiling
            data:
              transition: 2
    default: []
mode: queued
max: 10

Anything in the logs that might be useful for us?

No response

Additional information

I can reproduce the issue easily and happy to help investigation

probot-home-assistant[bot] commented 3 years ago

light documentation light source (message by IssueLinks)

emontnemery commented 3 years ago

Please enable these logs and share a log of what happens when the automation runs, both with and without the transitions:

logger:
  default: info
  logs:
    homeassistant.components.automation: debug
    homeassistant.core: debug
ahd71 commented 3 years ago

Hi,

Here is the log with transition set to 2 sec for all three actions in the automation. My analysis say that the automation parts do work correctly (one "turn_on" and two "turn_off" actions) however clearly another light source (or sometimes more) turns on within those two seconds without a prior request sent from HA.

My strong suspicion is that ZHA/Conbee II/IKEA Zigbee firmware plays a trick on me. I've of course verified that there are no other lights then expected in the zigbee group that I use for the turn_on - and also the fact that the extra lights turns on not exactly the same time but within the two seconds indicates that it is not the automation as such that sends the wrong request but rather that it is a chain effect. I also verified that the other zigbee groups involved (one for the turn_off of another group for example) does work as expected when manually fired.

Perhaps someone from the ZHA team can give their input, if any. Meanwhile I continue troubleshoot myself (or just disable the 2 sec transition that I know automation works flawless without in this scenario)

2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=input_number, service=set_value, service_data=value=5, entity_id=input_number.state_bedroom_master>
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=input_number.state_bedroom_master, old_state=<state input_number.state_bedroom_master=4.0; initial=None, editable=True, min=0.0, max=5.0, step=1.0, mode=box, friendly_name=state_bedroom_master @ 2021-10-07T09:47:33.000043+02:00>, new_state=<state input_number.state_bedroom_master=5.0; initial=None, editable=True, min=0.0, max=5.0, step=1.0, mode=box, friendly_name=state_bedroom_master @ 2021-10-07T09:47:39.659708+02:00>>

2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] Automation triggered by state of input_number.state_bedroom_master
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=bedroom_master_statemachine, entity_id=automation.bedroom_master_statemachine, source=state of input_number.state_bedroom_master>
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.bedroom_master_statemachine, old_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T09:47:33.001519+02:00, mode=queued, current=0, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T09:43:11.848320+02:00>, new_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T09:47:39.660802+02:00, mode=queued, current=1, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T09:43:11.848320+02:00>>
2021-10-07 07:47:39 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Running automation actions
2021-10-07 07:47:39 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Running automation actions
2021-10-07 07:47:39 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service

2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=40, transition=2, entity_id=['light.bedroom_master_table_lights_zha_group_0x0007']>
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:31.655072+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=unknown, brightness=102, off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:39 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=transition=2, entity_id=['light.bedroom_master_window_lights_zha_group_0x001e']>
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_anders, old_state=<state light.bedroom_master_bed_table_anders=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:31.146928+02:00>, new_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>>
2021-10-07 07:47:39 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service
2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=transition=2, entity_id=['light.bedroom_master_ceiling']>

2021-10-07 07:47:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_anders, old_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>, new_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_maria, old_state=<state light.bedroom_master_bed_table_maria=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:31.343780+02:00>, new_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.bedroom_master_statemachine, old_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T09:47:39.660802+02:00, mode=queued, current=1, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T09:43:11.848320+02:00>, new_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T09:47:39.660802+02:00, mode=queued, current=0, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T09:43:11.848320+02:00>>

2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_ceiling, old_state=<state light.bedroom_master_ceiling=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=171, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T09:47:14.252787+02:00>, new_state=<state light.bedroom_master_ceiling=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=171, color_temp=437, hs_color=(29.496, 80.799), rgb_color=(255, 150, 48), xy_color=(0.57, 0.389), off_brightness=None, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T09:47:40.178651+02:00>>

2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.sovrum_zha_group_0x0011, old_state=<state light.sovrum_zha_group_0x0011=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:31.654402+02:00>, new_state=<state light.sovrum_zha_group_0x0011=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=88, color_temp=418, hs_color=(29.174, 76.581), rgb_color=(255, 154, 59), xy_color=(0.559, 0.389), off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:40.324711+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=unknown, brightness=102, off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=54, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:31.074869+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=93, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.floor_upper_zha_group_0x0009, old_state=<state light.floor_upper_zha_group_0x0009=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp', 'hs'], color_mode=unknown, brightness=254, off_brightness=None, friendly_name=floor_upper_zha_group_0x0009, supported_features=59 @ 2021-10-07T09:44:08.994888+02:00>, new_state=<state light.floor_upper_zha_group_0x0009=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp', 'hs'], color_mode=hs, brightness=226, hs_color=(29.496, 80.799), rgb_color=(255, 150, 48), xy_color=(0.57, 0.389), color_temp=437, off_brightness=None, friendly_name=floor_upper_zha_group_0x0009, supported_features=59 @ 2021-10-07T09:44:08.994888+02:00>>

2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_anders, old_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>, new_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.sovrum_zha_group_0x0011, old_state=<state light.sovrum_zha_group_0x0011=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=88, color_temp=418, hs_color=(29.174, 76.581), rgb_color=(255, 154, 59), xy_color=(0.559, 0.389), off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:40.324711+02:00>, new_state=<state light.sovrum_zha_group_0x0011=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=113, color_temp=418, hs_color=(29.174, 76.581), rgb_color=(255, 154, 59), xy_color=(0.559, 0.389), off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:40.324711+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=54, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=79, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=93, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=109, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>>
2021-10-07 07:47:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_maria, old_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>, new_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=79, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=109, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=94, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_maria, old_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>, new_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=89, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_anders, old_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>, new_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=92, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=90, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=94, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=117, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_anders, old_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=92, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>, new_state=<state light.bedroom_master_bed_table_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T09:47:39.818998+02:00>>
2021-10-07 07:47:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_bed_table_maria, old_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=89, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>, new_state=<state light.bedroom_master_bed_table_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T09:47:40.018033+02:00>>
2021-10-07 07:47:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.sovrum_zha_group_0x0011, old_state=<state light.sovrum_zha_group_0x0011=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=113, color_temp=418, hs_color=(29.174, 76.581), rgb_color=(255, 154, 59), xy_color=(0.559, 0.389), off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:40.324711+02:00>, new_state=<state light.sovrum_zha_group_0x0011=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=136, color_temp=418, hs_color=(29.174, 76.581), rgb_color=(255, 154, 59), xy_color=(0.559, 0.389), off_brightness=None, friendly_name=Sovrum_zha_group_0x0011, supported_features=43 @ 2021-10-07T09:47:40.324711+02:00>>
2021-10-07 07:47:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=90, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T09:47:39.697065+02:00>>
2021-10-07 07:47:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=117, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=125, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T09:47:40.325868+02:00>>
probot-home-assistant[bot] commented 3 years ago

zha documentation zha source (message by IssueLinks)

probot-home-assistant[bot] commented 3 years ago

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

ahd71 commented 3 years ago

I was not in the room to test the automation but watched only the states in HA. After verifying in the room, i can say that physically the lights do NOT go on but they do "turn on" in HA state. Interesting.

ahd71 commented 3 years ago

To help analyzing the logs I'm going to collect also for the ZHA part this is the setup

Three Zigbee Groups (not HA groups!) in this context:

light.bedroom_master_table_lights_zha_group_0x0007 light.bedroom_master_window_lights_zha_group_0x001e light.bedroom_master_all_zha_group_0x001d

The group for All lights have five lights; Two in the table group and two in the window groups plus a fifth lights (ceiling) - name of the entity should be self explanatory

ahd71 commented 3 years ago

I upgraded to 2021.10.0 just to be on the latest and the same issue is still reproducible

ahd71 commented 3 years ago

Detailed logs including all zigpy events

2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=input_number, service=set_value, service_data=value=5, entity_id=input_number.state_bedroom_master> 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=input_number.state_bedroom_master, old_state=<state input_number.state_bedroom_master=4.0; initial=None, editable=True, min=0.0, max=5.0, step=1.0, mode=box, friendly_name=state_bedroom_master @ 2021-10-07T15:06:38.819688+02:00>, new_state=<state input_number.state_bedroom_master=5.0; initial=None, editable=True, min=0.0, max=5.0, step=1.0, mode=box, friendly_name=state_bedroom_master @ 2021-10-07T15:07:01.164835+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] Automation triggered by state of input_number.state_bedroom_master 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=bedroom_master_statemachine, entity_id=automation.bedroom_master_statemachine, source=state of input_number.state_bedroom_master> 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.bedroom_master_statemachine, old_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T15:06:38.822639+02:00, mode=queued, current=0, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T15:01:23.455936+02:00>, new_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T15:07:01.168031+02:00, mode=queued, current=1, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T15:01:23.455936+02:00>> 2021-10-07 13:07:01 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Running automation actions 2021-10-07 13:07:01 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Running automation actions 2021-10-07 13:07:01 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=40, transition=2, entity_id=['light.bedroom_master_table_lights_zha_group_0x0007']> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee multicast with tsn 24 under 25 request id, data: b'011804661400' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 25, 0, , 260, 8, 1, b'\x01\x18\x04f\x14\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 25] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [29, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 8, b'\x01\x18\x04f\x14\x00', 0, 175, 56, 30, 249, 225, 2, 114] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.device] Ignoring message (b'011804661400') on cluster 8: unknown endpoint or cluster id: 'No cluster ID 0x0008 on (00:21:2e:ff:ff:04:23:36, 1)' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'011804661400' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 25: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x19 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_table_lights_zha_group_0x0007: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>]} 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:06:34.889082+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=unknown, brightness=102, off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_table_light_maria: polling current state 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 26 under 27 request id, data: b'001a000000' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 27, 0, , 260, 6, 1, b'\x00\x1a\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_table_light_anders: polling current state 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 28 under 29 request id, data: b'001c000000' 2021-10-07 13:07:01 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=transition=2, entity_id=['light.bedroom_master_window_lights_zha_group_0x001e']> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee multicast with tsn 30 under 31 request id, data: b'011e04001400' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 27] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 29, 0, , 260, 6, 1, b'\x00\x1c\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 29] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 31, 0, , 260, 8, 1, b'\x01\x1e\x04\x00\x14\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 31] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [29, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 0, , 1, 260, 8, b'\x01\x1e\x04\x00\x14\x00', 0, 175, 255, 26, 249, 225, 2, -70] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.device] Ignoring message (b'011e04001400') on cluster 8: unknown endpoint or cluster id: 'No cluster ID 0x0008 on (00:21:2e:ff:ff:04:23:36, 1)' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'011e04001400' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, , 1, , 1, 260, 6, b'\x08^\n\x00\x00\x10\x01', 0, 175, 255, 122, 247, 225, 2, -75] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=94 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0006] Attribute report received: on_off=1 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_anders, old_state=<state light.bedroom_master_table_light_anders=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:06:34.405877+02:00>, new_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 94 under 32 request id, data: b'185e0b0a00' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'085e0a00001001' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 27: e9 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x1b 'aps_data_confirm' for , status: 0xe9 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 27 req id frame: TXStatus.MAC_NO_ACK 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.device] [0x9e99] Delivery error for seq # 0x1a, on endpoint id 1 cluster 0x0006: message send failure 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 33 under 34 request id, data: b'0021000000' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 32, 0, , 260, 6, 1, b'\x18^\x0b\n\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 32] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 29: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x1d 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 34, 0, , 260, 8, 1, b'\x00!\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 34] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, , 1, , 1, 260, 8, b'\x08_\n\x00\x00 \x06', 0, 175, 252, 26, 249, 225, 2, -75] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=95 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] Attribute report received: current_level=6 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C87:1:0x0008]: received attribute: 0 update with value: 6 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_anders, old_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>, new_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 95 under 35 request id, data: b'185f0b0a00' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'085f0a00002006' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 34: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x22 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 42>, , 1, , 1, 260, 8, b'\x08y\n\x00\x00 \x06', 0, 175, 255, 122, 247, 225, 2, -51] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=121 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] Attribute report received: current_level=6 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E99:1:0x0008]: received attribute: 0 update with value: 6 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 121 under 36 request id, data: b'18790b0a00' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'08790a00002006' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 35, 0, , 260, 8, 1, b'\x18_\x0b\n\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 42>, 35] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 6, b'\x08x\n\x00\x00\x10\x01', 0, 175, 255, 86, 247, 225, 2, -51] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=120 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0006] Attribute report received: on_off=1 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_maria, old_state=<state light.bedroom_master_table_light_maria=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:06:34.381412+02:00>, new_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 120 under 37 request id, data: b'18780b0a00' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'08780a00001001' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 6, b'\x18\x1c\x01\x00\x00\x00\x10\x01', 0, 175, 255, 127, 247, 225, 2, -76] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=28 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'181c010000001001' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 38 under 39 request id, data: b'0026000000' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 36, 0, , 260, 8, 1, b'\x18y\x0b\n\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, 36] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, , 1, , 1, 260, 6, b'\x08\x10\n\x00\x00\x10\x01', 0, 175, 255, 30, 249, 225, 2, -64] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=16 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] Attribute report received: on_off=1 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_window_2, old_state=<state light.bedroom_master_window_2=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Fönsterlampa 2 MA sovrum, supported_features=41 @ 2021-10-07T15:06:34.329206+02:00>, new_state=<state light.bedroom_master_window_2=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=254, off_brightness=None, friendly_name=Fönsterlampa 2 MA sovrum, supported_features=41 @ 2021-10-07T15:07:01.554554+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 16 under 40 request id, data: b'18100b0a00' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'08100a00001001' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 37, 0, , 260, 6, 1, b'\x18x\x0b\n\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, 37] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, , 1, , 1, 260, 8, b'\x18!\x01\x00\x00\x00 \r', 0, 175, 255, 30, 249, 225, 2, -51] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=33 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'182101000000200d' 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E99:1:0x0008]: received attribute: 0 update with value: 13 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 41 under 42 request id, data: b'00290008000700030004000240' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 39, 0, , 260, 8, 1, b'\x00&\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_maria, old_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>, new_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=13, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 39] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 35: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x23 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 40, 0, , 260, 6, 1, b'\x18\x10\x0b\n\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 40] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (28, 42, 0, , 260, 768, 1, b'\x00)\x00\x08\x00\x07\x00\x03\x00\x04\x00\x02@', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 42] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 31: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x1f 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_window_lights_zha_group_0x001e: turned off: [4, <Status.SUCCESS: 0>] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_window_2: polling current state 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 43 under 44 request id, data: b'002b000000' 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_window_1: polling current state 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 45 under 46 request id, data: b'002d000000' 2021-10-07 13:07:01 INFO (MainThread) [homeassistant.components.automation.bedroom_master_statemachine] bedroom_master_statemachine: Choose at step 1: choice 2: Executing step call service 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=transition=2, entity_id=['light.bedroom_master_ceiling']> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 32: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x20 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 47 under 48 request id, data: b'012f04001400' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 36: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x24 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 44, 0, , 260, 6, 1, b'\x00+\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 44] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 46, 0, , 260, 6, 1, b'\x00-\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 46] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 37: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x25 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (21, 48, 0, , 260, 8, 1, b'\x01/\x04\x00\x14\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 48] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 39: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x27 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 40: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x28 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, , 1, , 1, 260, 8, b'\x18&\x01\x00\x00\x00 \x14', 0, 175, 255, 30, 249, 225, 2, -75] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=38 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'1826010000002014' 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C87:1:0x0008]: received attribute: 0 update with value: 20 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 49 under 50 request id, data: b'00310008000700030004000240' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_anders, old_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=6, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>, new_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=20, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 42: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x2a 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (28, 50, 0, , 260, 768, 1, b'\x001\x00\x08\x00\x07\x00\x03\x00\x04\x00\x02@', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 38>, 50] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 46: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x2e 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=unknown, brightness=102, off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=16, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:06:34.221332+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=95, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 48: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x30 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 50: 00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x32 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 44: e1 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x2c 'aps_data_confirm' for , status: 0xe1 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 44 req id frame: TXStatus.MAC_CHANNEL_ACCESS_FAILURE 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.device] [0xb43b] Delivery error for seq # 0x2b, on endpoint id 1 cluster 0x0006: message send failure 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 51 under 52 request id, data: b'0033000000' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 52, 0, , 260, 8, 1, b'\x003\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 52] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 6, b'\x18-\x01\x00\x00\x00\x10\x01', 0, 175, 255, 122, 247, 225, 2, -51] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0x0567:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=45 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'182d010000001001' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 53 under 54 request id, data: b'0035000000' 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 54, 0, , 260, 8, 1, b'\x005\x00\x00\x00', 2, 0) 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_window_1, old_state=<state light.bedroom_master_window_1=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Fönsterlampa 1 MA Sovrum, supported_features=41 @ 2021-10-07T15:06:34.265565+02:00>, new_state=<state light.bedroom_master_window_1=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=254, off_brightness=None, friendly_name=Fönsterlampa 1 MA Sovrum, supported_features=41 @ 2021-10-07T15:07:01.980806+02:00>> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 54] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [52, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 768, b'\x18)\x01\x08\x00\x000\x02\x07\x00\x00!\x9d\x01\x03\x00\x00!\xbau\x04\x00\x00!\x1di\x02@\x86', 0, 175, 255, 127, 247, 225, 2, -51] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0300] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=41 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0300, data: b'1829010800003002070000219d0103000021ba75040000211d69024086' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.fonsterlampor_zha_group_0x0002, old_state=<state light.fonsterlampor_zha_group_0x0002=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Fönsterlampor, supported_features=43 @ 2021-10-07T15:06:34.773277+02:00>, new_state=<state light.fonsterlampor_zha_group_0x0002=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=unknown, brightness=254, off_brightness=None, friendly_name=Fönsterlampor, supported_features=43 @ 2021-10-07T15:07:02.067889+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_window_lights_zha_group_0x001e, old_state=<state light.bedroom_master_window_lights_zha_group_0x001e=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=bedroom_master_window_lights_zha_group_0x001e, supported_features=41 @ 2021-10-07T15:06:34.774536+02:00>, new_state=<state light.bedroom_master_window_lights_zha_group_0x001e=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=254, off_brightness=None, friendly_name=bedroom_master_window_lights_zha_group_0x001e, supported_features=41 @ 2021-10-07T15:07:02.068505+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [28, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, , 1, , 1, 260, 8, b'\x08/\x0b\x04\x00', 0, 175, 255, 30, 249, 225, 2, -75] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0xa014:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=47 command_id=Command.Default_Response> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'082f0b0400' 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA014:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(0, 20.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>] 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_master_ceiling: turned off: [4, <Status.SUCCESS: 0>] 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_ceiling, old_state=<state light.bedroom_master_ceiling=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=None, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T15:06:34.509993+02:00>, new_state=<state light.bedroom_master_ceiling=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=254, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T15:06:34.509993+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 52: 00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x34 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.bedroom_master_statemachine, old_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T15:07:01.168031+02:00, mode=queued, current=1, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T15:01:23.455936+02:00>, new_state=<state automation.bedroom_master_statemachine=on; last_triggered=2021-10-07T15:07:01.168031+02:00, mode=queued, current=0, max=10, id=1633531262372, friendly_name=bedroom_master_statemachine @ 2021-10-07T15:01:23.455936+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, , 1, , 1, 260, 6, b'\x08\x00\n\x00\x00\x10\x01', 0, 175, 255, 26, 249, 225, 2, -76] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0xa014:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=0 command_id=Command.Report_Attributes> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0xa014:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0xa014:1:0x0006] Attribute report received: on_off=1 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_ceiling, old_state=<state light.bedroom_master_ceiling=off; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], off_brightness=254, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T15:06:34.509993+02:00>, new_state=<state light.bedroom_master_ceiling=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=254, color_temp=437, hs_color=(29.496, 80.799), rgb_color=(255, 150, 48), xy_color=(0.57, 0.389), off_brightness=None, friendly_name=Taklampa (S), supported_features=43 @ 2021-10-07T15:07:02.109248+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 0 under 55 request id, data: b'18000b0a00' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0006, data: b'08000a00001001' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [52, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, , 1, , 1, 260, 768, b'\x181\x01\x08\x00\x000\x02\x07\x00\x00!\x90\x01\x03\x00\x00!\xe1:\x04\x00\x00!\x86\x96\x02@\x86', 0, 175, 255, 122, 247, 225, 2, -75] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0300] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=49 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0300, data: b'183101080000300207000021900103000021e13a040000218696024086' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 54: 00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x36 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 8, b'\x185\x01\x00\x00\x00 \xfe', 0, 175, 255, 30, 249, 225, 2, -51] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x0567:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=53 command_id=Command.Read_Attributes_rsp> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'18350100000020fe' 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0567:1:0x0008]: received attribute: 0 update with value: 254 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 55, 0, , 260, 6, 1, b'\x18\x00\x0b\n\x00', 2, 0) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 55] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 55: 00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x37 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=95, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=159, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 42>, , 1, , 1, 260, 8, b'\x08z\n\x00\x00 8', 0, 175, 255, 30, 249, 225, 2, -51] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=122 command_id=Command.Report_Attributes> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] Attribute report received: current_level=56 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E99:1:0x0008]: received attribute: 0 update with value: 56 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_maria, old_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=13, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>, new_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 122 under 56 request id, data: b'187a0b0a00' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'087a0a00002038' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 8, b'\x08\n\x00\x00 8', 0, 175, 255, 30, 249, 225, 2, -75] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=96 command_id=Command.Report_Attributes> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=56>)]] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] Attribute report received: current_level=56 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C87:1:0x0008]: received attribute: 0 update with value: 56 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_anders, old_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=20, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>, new_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 96 under 57 request id, data: b'18600b0a00' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x5c87>, ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'08600a00002038' 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 56, 0, <DeconzAddressEndpoint address_mode=2 address=0x9E99 endpoint=1>, 260, 8, 1, b'\x18z\x0b\n\x00', 2, 0) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 56] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 57, 0, <DeconzAddressEndpoint address_mode=2 address=0x5C87 endpoint=1>, 260, 8, 1, b'\x18\x0b\n\x00', 2, 0) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 57] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 56: 00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x38 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 57: 00 2021-10-07 13:07:02 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x39 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.floor_upper_zha_group_0x0009, old_state=<state light.floor_upper_zha_group_0x0009=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp', 'hs'], color_mode=unknown, brightness=254, off_brightness=None, friendly_name=floor_upper_zha_group_0x0009, supported_features=59 @ 2021-10-07T15:05:57.624800+02:00>, new_state=<state light.floor_upper_zha_group_0x0009=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp', 'hs'], color_mode=hs, brightness=254, hs_color=(29.496, 80.799), rgb_color=(255, 150, 48), xy_color=(0.57, 0.389), color_temp=437, off_brightness=None, friendly_name=floor_upper_zha_group_0x0009, supported_features=59 @ 2021-10-07T15:05:57.624800+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=159, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=174, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>> 2021-10-07 13:07:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=16, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 8, b'\x08a\n\x00\x00 f', 0, 175, 255, 30, 249, 225, 2, -75] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=97 command_id=Command.Report_Attributes> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x5c87:1:0x0008] Attribute report received: current_level=102 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C87:1:0x0008]: received attribute: 0 update with value: 102 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_anders, old_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>, new_state=<state light.bedroom_master_table_light_anders=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=400, hs_color=(28.874, 72.522), rgb_color=(255, 159, 70), xy_color=(0.546, 0.389), off_brightness=None, friendly_name=Anders Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.327890+02:00>> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 97 under 58 request id, data: b'18610b0a00' 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'08610a00002066' 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 58, 0, , 260, 8, 1, b'\x18a\x0b\n\x00', 2, 0) 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 58] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 58: 00 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x3a 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1) 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [30, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, , 1, , 1, 260, 8, b'\x08{\n\x00\x00 f', 0, 175, 255, 30, 249, 225, 2, -51] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=123 command_id=Command.Report_Attributes> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy.zcl] [0x9e99:1:0x0008] Attribute report received: current_level=102 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E99:1:0x0008]: received attribute: 0 update with value: 102 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_light_maria, old_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>, new_state=<state light.bedroom_master_table_light_maria=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=413, hs_color=(29.091, 75.461), rgb_color=(255, 155, 62), xy_color=(0.556, 0.389), off_brightness=None, friendly_name=Marias Sänglampa, supported_features=43 @ 2021-10-07T15:07:01.481707+02:00>> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 123 under 59 request id, data: b'187b0b0a00' 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0008, data: b'087b0a00002066' 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (20, 59, 0, , 260, 8, 1, b'\x18{\x0b\n\x00', 2, 0) 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_table_lights_zha_group_0x0007, old_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=56, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>, new_state=<state light.bedroom_master_table_lights_zha_group_0x0007=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=102, color_temp=406, hs_color=(28.974, 73.879), rgb_color=(255, 157, 66), xy_color=(0.551, 0.389), off_brightness=None, friendly_name=bedroom_master_table_lights_zha_group_0x0007, supported_features=43 @ 2021-10-07T15:07:01.228493+02:00>> 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 59] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0] 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,) 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 59: 00 2021-10-07 13:07:03 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x3b 'aps_data_confirm' for , status: 0x00 2021-10-07 13:07:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_all_zha_group_0x001d, old_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=174, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>, new_state=<state light.bedroom_master_all_zha_group_0x001d=on; min_mireds=250, max_mireds=454, supported_color_modes=['color_temp'], color_mode=color_temp, brightness=193, color_temp=416, hs_color=(29.142, 76.154), rgb_color=(255, 155, 60), xy_color=(0.557, 0.39), off_brightness=None, friendly_name=bedroom_master_all_zha_group_0x001d, supported_features=43 @ 2021-10-07T15:07:01.836836+02:00>>

Adminiuga commented 3 years ago

Are those two lights part of the same group 0x0007?

ahd71 commented 3 years ago

Four lines of interest from above log. Shall I interpret this like the light that shows turned on invalidly in HA (but not physically) sends an attribute report (received: on_off=1) or that some layer in between (zigpy?) do that?

2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=16 command_id=Command.Report_Attributes> 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=)]] 2021-10-07 13:07:01 DEBUG (MainThread) [zigpy.zcl] [0xb43b:1:0x0006] Attribute report received: on_off=1 2021-10-07 13:07:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_master_window_2, old_state=<state light.bedroom_master_window_2=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Fönsterlampa 2 MA sovrum, supported_features=41 @ 2021-10-07T15:06:34.329206+02:00>, new_state=<state light.bedroom_master_window_2=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=254, off_brightness=None, friendly_name=Fönsterlampa 2 MA sovrum, supported_features=41 @ 2021-10-07T15:07:01.554554+02:00>>

Adminiuga commented 3 years ago

light 0xb43b reports itself as Off ON. This is coming from the light itself.

ahd71 commented 3 years ago

image

the numbers represent the number of groups a light is member of respectively how many members each group has.

Adminiuga commented 3 years ago

For each entity id can you list their NWK address?

ahd71 commented 3 years ago

Sure!

image

ps. Feel free to steal inspiration from my supporting dashboards for the native ZHA GUI or a new Lovelace Card! :-)

Adminiuga commented 3 years ago

100% the group membership looks fantastic. But I have to defer the UI to @dmulcahey :) I'm more of a backend guy

ahd71 commented 3 years ago

Let's work together all three ;-)

The group membership visualization cannot take many minutes / hours to put together in the front end as the data is easily available from the back end. If any of you would help me out with a code stub I can continue and develop/refine it! The other LQI plot takes a bit more of work but as I over the last month refined my prototype (in Tableau based on the core config files and the zigbee.db dump) I have the requirement spec more or less done to cover a lot of use cases for troubleshooting/verification of the mesh!

ahd71 commented 3 years ago

If the light reports itself as on it is indeed very interesting to understand why. Yes, they are part of the same groups but that is also a lot of other lights (i have an "upper_floor" group for example which a number of other lights. The only common nominator I see here is that they are all in the same HA Area.

dmulcahey commented 3 years ago

Sure!

image

ps. Feel free to steal inspiration from my supporting dashboards for the native ZHA GUI or a new Lovelace Card! :-)

I'm game. Same handle on discord. DM me and we can chat

ahd71 commented 3 years ago

To break the problem down further I exclude Zigbee groups from the equation and added an automation that turns on and off the five lights individually without groups. The exact same happens, some other lights that is supposed to be turned off (regardless of previous state) turns off in HA (but not in physical reality).

One observation though, if I entire remove the turn off parts from the automation they don't turn on so it doesn't seem to be directly related to that the "turn on lights" part but also needs the simultaneous turn off for other lights to happen.

Adminiuga commented 3 years ago

Does it happen if you don't use transition parameter?

ahd71 commented 3 years ago

I've conducted several tests after your question and the problem disappears as soon as I remove the transition (and data:) from respectively turn_off statement.

So for example with an automation with light a, b, c, d, e where a, b should turn_on and c, d, e t7rn_off, all with transition to 2s, everything physically works as expected but c, d, e also show state "on" in HA after.

Removing the transition on a, b does not change anything so it is not related to turn_on.

Removing the transition from for example c makes c behave correctly while d, e still show wrong state. Same thing resolves the issue for each light's transition statement I remove from an turn_off action.

I have IKEA bulbs and Conbee II if that has an impact

Try2Fly commented 2 years ago

Is there any progress on this? I have the same issue since sept/oct. I’m using ikea lights with conbee II and deconz. After turning the lights off with transition they turn on (physically and in HA). It used to work perfectly.

ahd71 commented 2 years ago

I dont know. Not much more I can do but can assist with debug if needed for some more time. I'm about to migrate to zigbee2mqtt to overcome some other issues but still have lights in the ZHA integration too. Running two networks in parallel and moving device by device.

Try2Fly commented 2 years ago

I made some progress. Namely I have an automation that sets the brightness of the bulbs to a certain value when turning on. If I disable this automation, the turning off with transition works again correctly. So some how when light is turned off with tea transition it gives a turn on signal to HA activating the automation to set the brightness again. See also #52301

Adminiuga commented 2 years ago

Well, that would explain it. This happen because during the transition, light does send an update saying hey, I'm on and my level is 50.

emontnemery commented 2 years ago

Can the issue be closed, or should status updates during the transition to off be blocked by ZHA?

ahd71 commented 2 years ago

Good question. Behaviour is unwanted but blocking it may perhaps have other consequnces?

Adminiuga commented 2 years ago

AFAIK Dave was looking into this in the past, but there were some other use cases which broke if this behavior was disabled.

As a workaround, can you modify the automation, so when turn off with transition is called, it disables automation which turns the lights on, wait for transition to expire,then re-enabke automation.

Alternatively, modify the turn_on automation so it only fires if the triggering light was off for a certain amount of time

ahd71 commented 2 years ago

I can work around it but still wanted to report it as it was strange behaviour from this point of view. Fine with closing it if you don't have time or ideas how to solve it.

emontnemery commented 2 years ago

Should the LightEntity expose an attribute if it's in the middle of a transition if it's not wanted to block updates?

ZuluWhiskey commented 2 years ago

I spotted this issue a while back (#44996), I thought it was resolved but spotted it happening again in the HA logbook today 😞 DeCONZ for me but same issue

emontnemery commented 2 years ago

can you modify the automation, so when turn off with transition is called, it disables automation which turns the lights on, wait for transition to expire,then re-enabke automation

This workaround seems a bit meh.

Can someone give an example of what goes wrong when ZHA sends status updates during a transition to off? The automation in the OP triggers on an input number, so that's not helpful to illustrate the problem.

luciotorelli commented 2 years ago

I was having the same issue, removed transition from all automations and it still happens after calling Turn_off service. Not sure it's the same issue but I am using Hue and Ikea bulbs with ZHA/conbee2. The log for the entity shows Turned on by state_changed. the light switch on UI shows as on but the light itself is off.

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.