ZHA (with sonoff bridge) stopped right after 2021.1.0

[Edo78]

The problem

Right after updating HA Core to 2021.1.0 my ZHA setup started failing. The motion sensor and the coordinator aren't seen anymore.

Environment

• Home Assistant Core release with the issue: 2021.1.0
• Last working Home Assistant Core release (if known): 2020.12.2
• Operating environment (OS/Container/Supervised/Core): Raspian 10 with HA Core in a docker container
• Integration causing this issue: ZHA
• Link to integration documentation on our website: https://www.home-assistant.io/integrations/zha

Problem-relevant configuration.yaml

Traceback/Error logs

With the debug configured like https://www.home-assistant.io/integrations/zha#debug-logging I got this logs

2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for smartir which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for googlehome which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for sonoff which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for scheduler which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2021-01-07 11:40:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_default_level>
2021-01-07 11:40:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_level>
2021-01-07 11:40:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logger>
2021-01-07 11:41:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=purge>
2021-01-07 11:41:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=http>
2021-01-07 11:41:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=system_log, service=clear>
2021-01-07 11:41:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=system_log, service=write>
2021-01-07 11:41:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=system_log>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=recorder>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=auth>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.config_entries>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.scene>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.core>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.auth>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.customize>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.auth_provider_homeassistant>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.area_registry>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.device_registry>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.entity_registry>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.script>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.group>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.automation>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=device_automation>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=api>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=webhook>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=alexa>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=websocket_api>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=search>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=image>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=lovelace>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.edo, old_state=None, new_state=<state person.edo=home; editable=True, id=edo, latitude=45.7083437, longitude=8.9195762, gps_accuracy=19, source=person.edo, user_id=9dd5e1e5816343ed9b0f81b58625356e, friendly_name=Edo @ 2021-01-07T11:41:15.639406+01:00>>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.silvia, old_state=None, new_state=<state person.silvia=not_home; editable=True, id=silvia, source=person.silvia, friendly_name=Silvia @ 2021-01-07T11:41:15.639929+01:00>>
2021-01-07 11:41:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.arianna, old_state=None, new_state=<state person.arianna=not_home; editable=True, id=arianna, source=person.arianna, friendly_name=Arianna @ 2021-01-07T11:41:15.640258+01:00>>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=person, service=reload>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=person>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cloud, service=remote_connect>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cloud, service=remote_disconnect>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=onboarding>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=cloud>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=frontend, service=set_theme>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=frontend, service=reload_themes>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=frontend>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=smartir, service=check_updates>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=smartir, service=update_component>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sun.sun, old_state=None, new_state=<state sun.sun=above_horizon; next_dawn=2021-01-08T06:28:44+00:00, next_dusk=2021-01-07T16:32:02+00:00, next_midnight=2021-01-07T23:31:07+00:00, next_noon=2021-01-07T11:30:28+00:00, next_rising=2021-01-08T07:02:26+00:00, next_setting=2021-01-07T15:58:16+00:00, elevation=21.15, azimuth=167.7, rising=True, friendly_name=Sun @ 2021-01-07T11:41:16.480851+01:00>>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logbook, service=log>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=script, service=reload>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=script, service=turn_on>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=script, service=turn_off>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=script, service=toggle>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=smartir>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=history>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=sun>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=blueprint>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scene, service=reload>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scene, service=apply>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scene, service=create>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=script>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=map>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=panel_iframe>
2021-01-07 11:41:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=sensor>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scene, service=turn_on>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=group, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=group, service=set>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=group, service=remove>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_text, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_text, service=set_value>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=google_assistant, service=request_sync>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_number, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_number, service=set_value>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_number, service=increment>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_number, service=decrement>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=system_health>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zone, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logbook>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=scene>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=media_source>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=counter, service=increment>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=counter, service=decrement>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=counter, service=reset>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=counter, service=configure>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_boolean, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_boolean, service=turn_on>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_boolean, service=turn_off>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_boolean, service=toggle>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=group>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=timer, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=timer, service=start>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=timer, service=pause>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=timer, service=cancel>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=timer, service=finish>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=command_line, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=input_select.test_status_dropdown, old_state=None, new_state=<state input_select.test_status_dropdown=Home; options=['Home', 'Appena arrivato', 'Appena uscito', 'Fuori casa', 'Assenza prolungata'], editable=False, friendly_name=Test Select @ 2021-01-07T11:41:17.148385+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_text>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=google_assistant>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_number>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=tag>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=zone.home, old_state=None, new_state=<state zone.home=zoning; latitude=45.708131009718095, longitude=8.919619023799898, radius=100, passive=False, editable=True, friendly_name=Casa, icon=mdi:home @ 2021-01-07T11:41:17.156928+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=turn_on>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=turn_off>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_hvac_mode>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_preset_mode>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_aux_heat>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_temperature>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_humidity>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_fan_mode>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=climate, service=set_swing_mode>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=counter>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_boolean>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=timer>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=climate>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=cert_expiry>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=mqtt, service=publish>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=mqtt, service=dump>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zone>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scheduler, service=add>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scheduler, service=edit>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scheduler, service=remove>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=mqtt>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=input_datetime.prossimo_allarme_pixel_2_xl, old_state=None, new_state=<state input_datetime.prossimo_allarme_pixel_2_xl=2020-11-03 06:30:00; editable=True, has_date=True, has_time=True, year=2020, month=11, day=3, hour=6, minute=30, second=0, timestamp=1604382000.0, friendly_name=Prossimo allarme Pixel 2 XL @ 2021-01-07T11:41:17.249401+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=scheduler>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=climate.camera_genitori, old_state=None, new_state=<state climate.camera_genitori=off; hvac_modes=['off', 'heat_cool', 'dry', 'cool', 'fan_only', 'heat'], min_temp=18.0, max_temp=30.0, target_temp_step=1.0, fan_modes=['auto', 'night', 'low', 'lowMedium', 'medium', 'mediumHigh', 'high'], current_temperature=None, temperature=18, fan_mode=auto, last_on_operation=heat, device_code=1106, manufacturer=Daikin, supported_models=['ATX20KV1B', 'ATX25KV1B', 'ATX35KV1B'], supported_controller=Broadlink, commands_encoding=Base64, friendly_name=Camera dei genitori, supported_features=9 @ 2021-01-07T11:41:17.273400+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=climate.cameretta, old_state=None, new_state=<state climate.cameretta=off; hvac_modes=['off', 'heat_cool', 'dry', 'cool', 'fan_only', 'heat'], min_temp=18.0, max_temp=30.0, target_temp_step=1.0, fan_modes=['auto', 'night', 'low', 'lowMedium', 'medium', 'mediumHigh', 'high'], current_temperature=None, temperature=18, fan_mode=auto, last_on_operation=heat, device_code=1106, manufacturer=Daikin, supported_models=['ATX20KV1B', 'ATX25KV1B', 'ATX35KV1B'], supported_controller=Broadlink, commands_encoding=Base64, friendly_name=Cameretta, supported_features=9 @ 2021-01-07T11:41:17.274057+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_select, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_select, service=select_option>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_select, service=select_next>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_select, service=select_previous>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_select, service=set_options>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.shellies_announce, old_state=None, new_state=<state automation.shellies_announce=on; last_triggered=2021-01-07T11:27:58.524231+01:00, mode=single, current=0, id=shellies_announce, friendly_name=Shellies Announce @ 2021-01-07T11:41:17.321093+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.shellies_discovery, old_state=None, new_state=<state automation.shellies_discovery=on; last_triggered=2021-01-07T11:27:58.846200+01:00, mode=queued, current=0, max=999, id=shellies_discovery, friendly_name=Shellies Discovery @ 2021-01-07T11:41:17.321865+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_datetime, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=input_datetime, service=set_datetime>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_select>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_datetime>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=None, new_state=<state sensor.cpu_temperature=45.8; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:41:17.329279+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=automation, service=trigger>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=automation, service=toggle>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=automation, service=turn_on>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=automation, service=turn_off>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=automation, service=reload>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=automation>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cert_expiry_timestamp_home_federicogranata_dev, old_state=None, new_state=<state sensor.cert_expiry_timestamp_home_federicogranata_dev=2021-03-23T14:50:41+00:00; is_valid=True, error=None, friendly_name=Cert Expiry Timestamp (home.federicogranata.dev), icon=mdi:certificate, device_class=timestamp @ 2021-01-07T11:41:17.382979+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.taverna_cluster_size, old_state=None, new_state=<state sensor.taverna_cluster_size=unknown; unit_of_measurement=instances, friendly_name=taverna Cluster Size, icon=mdi:server @ 2021-01-07T11:41:17.438939+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.taverna_cluster_leader, old_state=None, new_state=<state sensor.taverna_cluster_leader=unknown; friendly_name=taverna Cluster Leader, icon=mdi:account-group @ 2021-01-07T11:41:17.446301+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5b_room_presence, old_state=None, new_state=<state sensor.mi_band_5b_room_presence=unknown; friendly_name=Mi Band 5b Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.448234+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=None, new_state=<state sensor.mi_band_5a_room_presence=unknown; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.455876+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_temperature, old_state=None, new_state=<state sensor.shelly_h_t_f39623_temperature=unavailable; unit_of_measurement=°C, friendly_name=Shelly H&T F39623 Temperature, device_class=temperature @ 2021-01-07T11:41:17.469866+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_temperature, old_state=<state sensor.shelly_h_t_f39623_temperature=unavailable; unit_of_measurement=°C, friendly_name=Shelly H&T F39623 Temperature, device_class=temperature @ 2021-01-07T11:41:17.469866+01:00>, new_state=<state sensor.shelly_h_t_f39623_temperature=19.1; unit_of_measurement=°C, friendly_name=Shelly H&T F39623 Temperature, device_class=temperature @ 2021-01-07T11:41:17.475211+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_humidity, old_state=None, new_state=<state sensor.shelly_h_t_f39623_humidity=unavailable; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Humidity, device_class=humidity @ 2021-01-07T11:41:17.478053+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_humidity, old_state=<state sensor.shelly_h_t_f39623_humidity=unavailable; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Humidity, device_class=humidity @ 2021-01-07T11:41:17.478053+01:00>, new_state=<state sensor.shelly_h_t_f39623_humidity=57.0; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Humidity, device_class=humidity @ 2021-01-07T11:41:17.481403+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_battery, old_state=None, new_state=<state sensor.shelly_h_t_f39623_battery=unavailable; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Battery, device_class=battery @ 2021-01-07T11:41:17.483141+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_h_t_f39623_battery, old_state=<state sensor.shelly_h_t_f39623_battery=unavailable; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Battery, device_class=battery @ 2021-01-07T11:41:17.483141+01:00>, new_state=<state sensor.shelly_h_t_f39623_battery=87; unit_of_measurement=%, friendly_name=Shelly H&T F39623 Battery, device_class=battery @ 2021-01-07T11:41:17.486723+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_1_8caab505c1c7_rssi, old_state=None, new_state=<state sensor.shelly_1_8caab505c1c7_rssi=unavailable; unit_of_measurement=dB, friendly_name=Shelly 1 8CAAB505C1C7 RSSI, device_class=signal_strength @ 2021-01-07T11:41:17.498438+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_1_8caab505c1c7_ssid, old_state=None, new_state=<state sensor.shelly_1_8caab505c1c7_ssid=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 SSID, icon=mdi:wifi @ 2021-01-07T11:41:17.501338+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_1_8caab505c1c7_uptime, old_state=None, new_state=<state sensor.shelly_1_8caab505c1c7_uptime=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 Uptime, icon=mdi:timer-outline, device_class=timestamp @ 2021-01-07T11:41:17.504775+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.shelly_1_8caab505c1c7_ip, old_state=None, new_state=<state sensor.shelly_1_8caab505c1c7_ip=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 IP @ 2021-01-07T11:41:17.505439+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.taverna_cluster_size, old_state=<state sensor.taverna_cluster_size=unknown; unit_of_measurement=instances, friendly_name=taverna Cluster Size, icon=mdi:server @ 2021-01-07T11:41:17.438939+01:00>, new_state=<state sensor.taverna_cluster_size=1; unit_of_measurement=instances, friendly_name=taverna Cluster Size, icon=mdi:server @ 2021-01-07T11:41:17.509508+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.taverna_cluster_leader, old_state=<state sensor.taverna_cluster_leader=unknown; friendly_name=taverna Cluster Leader, icon=mdi:account-group @ 2021-01-07T11:41:17.446301+01:00>, new_state=<state sensor.taverna_cluster_leader=taverna; friendly_name=taverna Cluster Leader, icon=mdi:account-group @ 2021-01-07T11:41:17.514213+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5b_room_presence, old_state=<state sensor.mi_band_5b_room_presence=unknown; friendly_name=Mi Band 5b Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.448234+01:00>, new_state=<state sensor.mi_band_5b_room_presence=not_home; friendly_name=Mi Band 5b Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.518416+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=unknown; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.455876+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.766311+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=met>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=weather>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=weather.casa, old_state=None, new_state=<state weather.casa=sunny; temperature=1.4, humidity=85, pressure=1016.5, wind_bearing=49.0, wind_speed=3.2, attribution=Weather forecast from met.no, delivered by the Norwegian Meteorological Institute., forecast=[{'condition': 'sunny', 'precipitation': 0.0, 'temperature': 4.3, 'templow': -5.0, 'datetime': '2021-01-08T11:00:00+00:00', 'wind_bearing': 279.7, 'wind_speed': 7.2}, {'condition': 'cloudy', 'precipitation': 0.0, 'temperature': 4.5, 'templow': -4.0, 'datetime': '2021-01-09T11:00:00+00:00', 'wind_bearing': 198.9, 'wind_speed': 8.6}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 3.2, 'templow': -3.0, 'datetime': '2021-01-10T11:00:00+00:00', 'wind_bearing': 252.0, 'wind_speed': 7.6}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': 4.1, 'templow': -6.7, 'datetime': '2021-01-11T11:00:00+00:00', 'wind_bearing': 249.9, 'wind_speed': 6.8}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 4.8, 'templow': -5.2, 'datetime': '2021-01-12T11:00:00+00:00', 'wind_bearing': 235.6, 'wind_speed': 7.2}], friendly_name=Casa @ 2021-01-07T11:41:17.780272+01:00>>
2021-01-07 11:41:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=weather.casa_hourly, old_state=None, new_state=<state weather.casa_hourly=sunny; temperature=1.4, humidity=85, pressure=1016.5, wind_bearing=49.0, wind_speed=3.2, attribution=Weather forecast from met.no, delivered by the Norwegian Meteorological Institute., forecast=[{'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 2.9, 'datetime': '2021-01-07T11:00:00+00:00', 'wind_bearing': 50.6, 'wind_speed': 4.0}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 4.2, 'datetime': '2021-01-07T12:00:00+00:00', 'wind_bearing': 93.1, 'wind_speed': 4.0}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 4.5, 'datetime': '2021-01-07T13:00:00+00:00', 'wind_bearing': 130.7, 'wind_speed': 4.7}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 4.3, 'datetime': '2021-01-07T14:00:00+00:00', 'wind_bearing': 130.7, 'wind_speed': 4.3}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 3.6, 'datetime': '2021-01-07T15:00:00+00:00', 'wind_bearing': 151.5, 'wind_speed': 5.0}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': 0.5, 'datetime': '2021-01-07T16:00:00+00:00', 'wind_bearing': 168.1, 'wind_speed': 6.8}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': -0.2, 'datetime': '2021-01-07T17:00:00+00:00', 'wind_bearing': 173.4, 'wind_speed': 5.8}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': -0.1, 'datetime': '2021-01-07T18:00:00+00:00', 'wind_bearing': 61.7, 'wind_speed': 1.4}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': -1.4, 'datetime': '2021-01-07T19:00:00+00:00', 'wind_bearing': 15.9, 'wind_speed': 2.9}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': -2.2, 'datetime': '2021-01-07T20:00:00+00:00', 'wind_bearing': 5.9, 'wind_speed': 1.8}, {'condition': 'fog', 'precipitation': 0.0, 'temperature': -2.1, 'datetime': '2021-01-07T21:00:00+00:00', 'wind_bearing': 346.9, 'wind_speed': 1.4}, {'condition': 'fog', 'precipitation': 0.0, 'temperature': -3.1, 'datetime': '2021-01-07T22:00:00+00:00', 'wind_bearing': 344.2, 'wind_speed': 3.2}, {'condition': 'fog', 'precipitation': 0.0, 'temperature': -3.5, 'datetime': '2021-01-07T23:00:00+00:00', 'wind_bearing': 341.7, 'wind_speed': 5.4}, {'condition': 'fog', 'precipitation': 0.0, 'temperature': -3.5, 'datetime': '2021-01-08T00:00:00+00:00', 'wind_bearing': 344.9, 'wind_speed': 6.5}, {'condition': 'fog', 'precipitation': 0.0, 'temperature': -3.3, 'datetime': '2021-01-08T01:00:00+00:00', 'wind_bearing': 342.8, 'wind_speed': 6.8}, {'condition': 'partlycloudy', 'precipitation': 0.0, 'temperature': -3.8, 'datetime': '2021-01-08T02:00:00+00:00', 'wind_bearing': 341.6, 'wind_speed': 6.8}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -4.1, 'datetime': '2021-01-08T03:00:00+00:00', 'wind_bearing': 338.2, 'wind_speed': 6.5}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -4.4, 'datetime': '2021-01-08T04:00:00+00:00', 'wind_bearing': 337.3, 'wind_speed': 6.1}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -4.7, 'datetime': '2021-01-08T05:00:00+00:00', 'wind_bearing': 337.5, 'wind_speed': 6.1}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -4.8, 'datetime': '2021-01-08T06:00:00+00:00', 'wind_bearing': 340.4, 'wind_speed': 6.1}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -5.0, 'datetime': '2021-01-08T07:00:00+00:00', 'wind_bearing': 345.7, 'wind_speed': 5.0}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -3.7, 'datetime': '2021-01-08T08:00:00+00:00', 'wind_bearing': 347.2, 'wind_speed': 5.4}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': -0.3, 'datetime': '2021-01-08T09:00:00+00:00', 'wind_bearing': 350.7, 'wind_speed': 3.6}, {'condition': 'sunny', 'precipitation': 0.0, 'temperature': 2.0, 'datetime': '2021-01-08T10:00:00+00:00', 'wind_bearing': 324.8, 'wind_speed': 1.4}], friendly_name=Casa Hourly @ 2021-01-07T11:41:17.781983+01:00>>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=switch, service=turn_off>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=switch, service=turn_on>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=switch, service=toggle>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=switch>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=scheduler, service=run_action>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=python_script, service=shellies_discovery>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=generic_thermostat, service=reload>
2021-01-07 11:41:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=python_script, service=reload>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=python_script>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=climate.taverna, old_state=None, new_state=<state climate.taverna=heat; hvac_modes=['heat', 'off'], min_temp=15.0, max_temp=22.0, preset_modes=['none', 'away'], current_temperature=None, temperature=19.0, hvac_action=idle, preset_mode=none, friendly_name=Taverna, supported_features=17 @ 2021-01-07T11:41:36.695307+01:00>>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zeroconf>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=updater>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event nodered[L]: type=loaded, version=0.4.4>
2021-01-07 11:41:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=nodered>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=nut>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=ipp>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=turn_off>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=turn_on>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=toggle>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=send_command>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=learn_command>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=remote, service=delete_command>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=switch.shelly_1_8caab505c1c7_relay_0, old_state=None, new_state=<state switch.shelly_1_8caab505c1c7_relay_0=unavailable; friendly_name=Caloriferi Taverna @ 2021-01-07T11:41:37.073489+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=remote>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=openweathermap>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_low_battery_setpoint, old_state=None, new_state=<state sensor.ups_low_battery_setpoint=10; state=Online, unit_of_measurement=%, friendly_name=Ups Low Battery Setpoint, icon=mdi:gauge @ 2021-01-07T11:41:37.141360+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_warning_battery_setpoint, old_state=None, new_state=<state sensor.ups_warning_battery_setpoint=50; state=Online, unit_of_measurement=%, friendly_name=Ups Warning Battery Setpoint, icon=mdi:gauge @ 2021-01-07T11:41:37.143093+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_runtime, old_state=None, new_state=<state sensor.ups_battery_runtime=2317; state=Online, unit_of_measurement=s, friendly_name=Ups Battery Runtime, icon=mdi:timer-outline @ 2021-01-07T11:41:37.144263+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_low_battery_runtime, old_state=None, new_state=<state sensor.ups_low_battery_runtime=120; state=Online, unit_of_measurement=s, friendly_name=Ups Low Battery Runtime, icon=mdi:timer-outline @ 2021-01-07T11:41:37.145537+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_voltage, old_state=None, new_state=<state sensor.ups_battery_voltage=13.9; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.152698+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_nominal_battery_voltage, old_state=None, new_state=<state sensor.ups_nominal_battery_voltage=12.0; state=Online, unit_of_measurement=V, friendly_name=Ups Nominal Battery Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.153804+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_power_sensitivity, old_state=None, new_state=<state sensor.ups_input_power_sensitivity=medium; state=Online, unit_of_measurement=, friendly_name=Ups Input Power Sensitivity, icon=mdi:information-outline @ 2021-01-07T11:41:37.154871+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_high_voltage_transfer, old_state=None, new_state=<state sensor.ups_high_voltage_transfer=266; state=Online, unit_of_measurement=V, friendly_name=Ups High Voltage Transfer, icon=mdi:flash @ 2021-01-07T11:41:37.156216+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_low_voltage_transfer, old_state=None, new_state=<state sensor.ups_low_voltage_transfer=180; state=Online, unit_of_measurement=V, friendly_name=Ups Low Voltage Transfer, icon=mdi:flash @ 2021-01-07T11:41:37.161207+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_voltage, old_state=None, new_state=<state sensor.ups_input_voltage=234.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.162804+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_nominal_input_voltage, old_state=None, new_state=<state sensor.ups_nominal_input_voltage=230; state=Online, unit_of_measurement=V, friendly_name=Ups Nominal Input Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.163793+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_beeper_status, old_state=None, new_state=<state sensor.ups_beeper_status=enabled; state=Online, unit_of_measurement=, friendly_name=Ups Beeper Status, icon=mdi:information-outline @ 2021-01-07T11:41:37.164761+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_ups_shutdown_delay, old_state=None, new_state=<state sensor.ups_ups_shutdown_delay=20; state=Online, unit_of_measurement=s, friendly_name=Ups UPS Shutdown Delay, icon=mdi:timer-outline @ 2021-01-07T11:41:37.168994+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_load, old_state=None, new_state=<state sensor.ups_load=4; state=Online, unit_of_measurement=%, friendly_name=Ups Load, icon=mdi:gauge @ 2021-01-07T11:41:37.169919+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_status_data, old_state=None, new_state=<state sensor.ups_status_data=OL; state=Online, unit_of_measurement=, friendly_name=Ups Status Data, icon=mdi:information-outline @ 2021-01-07T11:41:37.170708+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_status, old_state=None, new_state=<state sensor.ups_status=Online; state=Online, unit_of_measurement=, friendly_name=Ups Status, icon=mdi:information-outline @ 2021-01-07T11:41:37.171551+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_load_reboot_timer, old_state=None, new_state=<state sensor.ups_load_reboot_timer=0; state=Online, unit_of_measurement=s, friendly_name=Ups Load Reboot Timer, icon=mdi:timer-outline @ 2021-01-07T11:41:37.172433+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_load_shutdown_timer, old_state=None, new_state=<state sensor.ups_load_shutdown_timer=-1; state=Online, unit_of_measurement=s, friendly_name=Ups Load Shutdown Timer, icon=mdi:timer-outline @ 2021-01-07T11:41:37.173496+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_weather, old_state=None, new_state=<state sensor.openweathermap_weather=nubi sparse; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Weather @ 2021-01-07T11:41:37.175292+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_temperature, old_state=None, new_state=<state sensor.openweathermap_temperature=2.27; attribution=Data provided by OpenWeatherMap, unit_of_measurement=°C, friendly_name=OpenWeatherMap Temperature, device_class=temperature @ 2021-01-07T11:41:37.176104+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_wind_speed, old_state=None, new_state=<state sensor.openweathermap_wind_speed=2.1; attribution=Data provided by OpenWeatherMap, unit_of_measurement=m/s, friendly_name=OpenWeatherMap Wind speed @ 2021-01-07T11:41:37.176820+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_wind_bearing, old_state=None, new_state=<state sensor.openweathermap_wind_bearing=350; attribution=Data provided by OpenWeatherMap, unit_of_measurement=°, friendly_name=OpenWeatherMap Wind bearing @ 2021-01-07T11:41:37.177541+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_humidity, old_state=None, new_state=<state sensor.openweathermap_humidity=81; attribution=Data provided by OpenWeatherMap, unit_of_measurement=%, friendly_name=OpenWeatherMap Humidity, device_class=humidity @ 2021-01-07T11:41:37.178320+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_pressure, old_state=None, new_state=<state sensor.openweathermap_pressure=1015; attribution=Data provided by OpenWeatherMap, unit_of_measurement=hPa, friendly_name=OpenWeatherMap Pressure, device_class=pressure @ 2021-01-07T11:41:37.179138+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_cloud_coverage, old_state=None, new_state=<state sensor.openweathermap_cloud_coverage=40; attribution=Data provided by OpenWeatherMap, unit_of_measurement=%, friendly_name=OpenWeatherMap Cloud coverage @ 2021-01-07T11:41:37.180660+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_rain, old_state=None, new_state=<state sensor.openweathermap_rain=not raining; attribution=Data provided by OpenWeatherMap, unit_of_measurement=mm, friendly_name=OpenWeatherMap Rain @ 2021-01-07T11:41:37.181423+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_snow, old_state=None, new_state=<state sensor.openweathermap_snow=not snowing; attribution=Data provided by OpenWeatherMap, unit_of_measurement=mm, friendly_name=OpenWeatherMap Snow @ 2021-01-07T11:41:37.182129+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_condition, old_state=None, new_state=<state sensor.openweathermap_condition=partlycloudy; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Condition @ 2021-01-07T11:41:37.182843+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_weather_code, old_state=None, new_state=<state sensor.openweathermap_weather_code=802; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Weather Code @ 2021-01-07T11:41:37.183536+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_condition, old_state=None, new_state=<state sensor.openweathermap_forecast_condition=partlycloudy; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Forecast Condition @ 2021-01-07T11:41:37.184166+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_precipitation, old_state=None, new_state=<state sensor.openweathermap_forecast_precipitation=unknown; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Forecast Precipitation @ 2021-01-07T11:41:37.184774+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_temperature, old_state=None, new_state=<state sensor.openweathermap_forecast_temperature=2.61; attribution=Data provided by OpenWeatherMap, unit_of_measurement=°C, friendly_name=OpenWeatherMap Forecast Temperature, device_class=temperature @ 2021-01-07T11:41:37.186196+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_temperature_low, old_state=None, new_state=<state sensor.openweathermap_forecast_temperature_low=-2.4; attribution=Data provided by OpenWeatherMap, unit_of_measurement=°C, friendly_name=OpenWeatherMap Forecast Temperature Low, device_class=temperature @ 2021-01-07T11:41:37.186979+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_time, old_state=None, new_state=<state sensor.openweathermap_forecast_time=1610017200000; attribution=Data provided by OpenWeatherMap, friendly_name=OpenWeatherMap Forecast Time, device_class=timestamp @ 2021-01-07T11:41:37.187608+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_wind_bearing, old_state=None, new_state=<state sensor.openweathermap_forecast_wind_bearing=52; attribution=Data provided by OpenWeatherMap, unit_of_measurement=°, friendly_name=OpenWeatherMap Forecast Wind bearing @ 2021-01-07T11:41:37.188215+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.openweathermap_forecast_wind_speed, old_state=None, new_state=<state sensor.openweathermap_forecast_wind_speed=0.75; attribution=Data provided by OpenWeatherMap, unit_of_measurement=m/s, friendly_name=OpenWeatherMap Forecast Wind speed @ 2021-01-07T11:41:37.188787+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=weather.openweathermap, old_state=None, new_state=<state weather.openweathermap=partlycloudy; temperature=2.3, humidity=81, pressure=1015, wind_bearing=350, wind_speed=7.56, attribution=Data provided by OpenWeatherMap, forecast=[{'datetime': 1610017200000, 'precipitation': None, 'wind_speed': 0.75, 'wind_bearing': 52, 'condition': 'partlycloudy', 'temperature': 2.6, 'templow': -2.4}, {'datetime': 1610103600000, 'precipitation': None, 'wind_speed': 0.62, 'wind_bearing': 360, 'condition': 'sunny', 'temperature': 2.7, 'templow': -2.7}, {'datetime': 1610190000000, 'precipitation': None, 'wind_speed': 1.22, 'wind_bearing': 351, 'condition': 'cloudy', 'temperature': 2.7, 'templow': -1.9}, {'datetime': 1610276400000, 'precipitation': None, 'wind_speed': 2.02, 'wind_bearing': 328, 'condition': 'partlycloudy', 'temperature': 2.9, 'templow': -1.9}, {'datetime': 1610362800000, 'precipitation': None, 'wind_speed': 0.84, 'wind_bearing': 260, 'condition': 'cloudy', 'temperature': 1.9, 'templow': -0.9}, {'datetime': 1610449200000, 'precipitation': None, 'wind_speed': 0.67, 'wind_bearing': 262, 'condition': 'sunny', 'temperature': 3.5, 'templow': -1.5}, {'datetime': 1610535600000, 'precipitation': None, 'wind_speed': 0.84, 'wind_bearing': 235, 'condition': 'sunny', 'temperature': 4.2, 'templow': -0.8}, {'datetime': 1610622000000, 'precipitation': None, 'wind_speed': 0.76, 'wind_bearing': 212, 'condition': 'partlycloudy', 'temperature': 4.2, 'templow': -0.4}], friendly_name=OpenWeatherMap @ 2021-01-07T11:41:37.189899+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_charge, old_state=None, new_state=<state sensor.ups_battery_charge=100; state=Online, unit_of_measurement=%, friendly_name=Ups Battery Charge, device_class=battery @ 2021-01-07T11:41:37.289500+01:00>>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] Loading application state from %s
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0000] Attribute id: 4 value: eWeLink
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0000] Attribute id: 5 value: MS01
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for None None (60:a4:23:ff:fe:45:ce:10)
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 60:a4:23:ff:fe:45:ce:10: <class 'bellows.zigbee.application.EZSPCoordinator'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for eWeLink MS01 (00:12:4b:00:1f:90:d1:b4)
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1}
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because input cluster mismatch on at least one endpoint
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1}
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1}
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because input cluster mismatch on at least one endpoint
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0000] Attribute id: 4 value: eWeLink
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0000] Attribute id: 5 value: MS01
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0500] Attribute id: 1 value: 13
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0000] Attribute id: 7 value: 3
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0500] Attribute id: 2 value: 1
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0500] Attribute id: 0 value: 1
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0001] Attribute id: 32 value: 29
2021-01-07 11:41:37 DEBUG (MainThread) [zigpy.appdb] [0x0158:1:0x0001] Attribute id: 33 value: 161
2021-01-07 11:41:37 DEBUG (MainThread) [bellows.ezsp] Resetting EZSP
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command version: (4,)
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 0 (version) received: b'07025065'
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp] Switching to EZSP protocol version 7
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command version: (7,)
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 0 (version) received: b'07025065'
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp] EZSP Stack Type: 2, Stack Version: 6550, Protocol version: 7
2021-01-07 11:41:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_APPLICATION_ZDO_FLAGS: 42>, <EmberZdoConfigurationFlags.APP_HANDLES_UNSUPPORTED_ZDO_REQUESTS|APP_RECEIVES_SUPPORTED_ZDO_REQUESTS: 3>)
2021-01-07 11:41:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event hacs/repository[L]: action=registration, repository=hacs/integration, repository_id=172733314>
2021-01-07 11:41:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:39 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_MULTICAST_TABLE_SIZE: 6>, 16)
2021-01-07 11:41:40 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:40 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 5 seconds
2021-01-07 11:41:40 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_SUPPORTED_NETWORKS: 45>, 1)
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=broadlink>
2021-01-07 11:41:40 WARNING (MainThread) [homeassistant.components.broadlink.switch] The switch platform is deprecated, except for custom IR/RF switches. Please refer to the Broadlink documentation to catch up
2021-01-07 11:41:40 WARNING (MainThread) [homeassistant.components.broadlink.switch] The switch platform is deprecated, except for custom IR/RF switches. Please refer to the Broadlink documentation to catch up
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event hacs/stage[L]: stage=HacsStage.WAITING>
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.sensor, platform=hacs, discovered=>
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=hacs>
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.hacs, old_state=None, new_state=<state sensor.hacs=unknown; repositories=[], unit_of_measurement=pending update(s), friendly_name=hacs, icon=hacs:hacs @ 2021-01-07T11:41:40.712244+01:00>>
2021-01-07 11:41:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=remote.broadlink_camera_dei_genitori_remote, old_state=None, new_state=<state remote.broadlink_camera_dei_genitori_remote=on; friendly_name=Broadlink Camera dei Genitori Remote, supported_features=1 @ 2021-01-07T11:41:40.718581+01:00>>
2021-01-07 11:41:40 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:40 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_MAX_END_DEVICE_CHILDREN: 17>, 32)
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_SOURCE_ROUTE_TABLE_SIZE: 26>, 16)
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_SECURITY_LEVEL: 13>, 5)
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_INDIRECT_TRANSMISSION_TIMEOUT: 18>, 7680)
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:41 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_KEY_TABLE_SIZE: 30>, 12)
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_STACK_PROFILE: 12>, 2)
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_PAN_ID_CONFLICT_REPORT_THRESHOLD: 34>, 2)
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_END_DEVICE_POLL_TIMEOUT: 19>, 8)
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:42 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE: 25>, 2)
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_ADDRESS_TABLE_SIZE: 5>, 16)
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_PACKET_BUFFER_COUNT: 1>, 255)
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 83 (setConfigurationValue) received: b'00'
2021-01-07 11:41:43 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_APS_UNICAST_MESSAGE_COUNT: 3>,)
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 82 (getConfigurationValue) received: b'000a00'
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.zigbee.application] APS_UNICAST_MESSAGE_COUNT is set to 10
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Send command addEndpoint: (1, 260, 48879, 0, 0, 1, [], [1280])
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 2 (addEndpoint) received: b'00'
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.zigbee.application] Ezsp adding endpoint: [<EzspStatus.SUCCESS: 0>]
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp] getting MFG_STRING token
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_STRING: 1>,)
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 11 (getMfgToken) received: b'10ffffffffffffffffffffffffffffffff'
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp] getting MFG_BOARD_NAME token
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_BOARD_NAME: 2>,)
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 11 (getMfgToken) received: b'10ffffffffffffffffffffffffffffffff'
2021-01-07 11:41:44 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_VERSION_INFO: 17>,)
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 170 (getValue) received: b'0007b00106050500aa'
2021-01-07 11:41:45 INFO (MainThread) [bellows.zigbee.application] EZSP Radio manufacturer:
2021-01-07 11:41:45 INFO (MainThread) [bellows.zigbee.application] EZSP Radio board name:
2021-01-07 11:41:45 INFO (MainThread) [bellows.zigbee.application] EmberZNet version: 6.5.5.0 build 432
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkInit: ()
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 23 (networkInit) received: b'00'
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNetworkParameters: ()
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 25 (stackStatusHandler) received: b'90'
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 40 (getNetworkParameters) received: b'0001359f7cc800d0b104afdf080f0000000000f8ff07'
2021-01-07 11:41:45 INFO (MainThread) [bellows.zigbee.application] Node type: EmberNodeType.COORDINATOR, Network parameters: EmberNetworkParameters(extendedPanId=04:b1:d0:00:c8:7c:9f:35, panId=0xdfaf, radioTxPower=8, radioChannel=15, joinMethod=<EmberJoinMethod.USE_MAC_ASSOCIATION: 0>, nwkManagerId=0x0000, nwkUpdateId=0, channels=<Channels.ALL_CHANNELS: 134215680>)
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TC_KEY_REQUEST_POLICY: 5>, <EzspDecisionId.ALLOW_TC_KEY_REQUESTS: 81>)
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 85 (setPolicy) received: b'00'
2021-01-07 11:41:45 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TRUST_CENTER_POLICY: 0>, <EzspDecisionId.ALLOW_PRECONFIGURED_KEY_JOINS: 1>)
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 85 (setPolicy) received: b'00'
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.APP_KEY_REQUEST_POLICY: 6>, <EzspDecisionId.DENY_APP_KEY_REQUESTS: 96>)
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 85 (setPolicy) received: b'00'
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNodeId: ()
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 39 (getNodeId) received: b'0000'
2021-01-07 11:41:46 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getEui64: ()
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 38 (getEui64) received: b'10ce45feff23a460'
2021-01-07 11:41:47 INFO (MainThread) [zigpy.application] Device 0x0000 (60:a4:23:ff:fe:45:ce:10) joined the network
2021-01-07 11:41:47 DEBUG (MainThread) [zigpy.application] Skip initialization for existing device 60:a4:23:ff:fe:45:ce:10
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.zigbee.application] EZSP nwk=0x0000, IEEE=60:a4:23:ff:fe:45:ce:10
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_MULTICAST_TABLE_SIZE: 6>,)
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.zigbee.application] Starting EZSP watchdog
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 82 (getConfigurationValue) received: b'001000'
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (0,)
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (1,)
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (2,)
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (3,)
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (4,)
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (5,)
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (6,)
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (7,)
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (8,)
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (9,)
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (10,)
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (11,)
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (12,)
2021-01-07 11:41:50 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 10 seconds
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:50 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (13,)
2021-01-07 11:41:51 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:51 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (14,)
2021-01-07 11:41:51 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:51 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (15,)
2021-01-07 11:41:51 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 99 (getMulticastTableEntry) received: b'00000000'
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event device_registry_updated[L]: action=update, device_id=0fa4e7ae5cac4a689d742bb5398a1427>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0000](Silicon Labs EZSP) restored as 'unavailable', last seen: 3:42:51 ago
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0158](eWeLink MS01) restored as 'unavailable', last seen: 1 day, 0:32:30 ago
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event device_registry_updated[L]: action=update, device_id=0fa4e7ae5cac4a689d742bb5398a1427>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=permit>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=remove>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=set_zigbee_cluster_attribute>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=issue_zigbee_cluster_command>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=issue_zigbee_group_command>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=warning_device_squawk>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=warning_device_warn>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading battery powered devices
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0158](MS01): started initialization
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:ZDO](MS01): 'async_initialize' stage succeeded
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zha>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=open_cover>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=close_cover>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=set_cover_position>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=stop_cover>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=toggle>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=open_cover_tilt>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=close_cover_tilt>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=stop_cover_tilt>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=set_cover_tilt_position>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cover, service=toggle_cover_tilt>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=number, service=set_value>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=lock, service=unlock>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=lock, service=lock>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=lock, service=open>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=turn_on>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=turn_off>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=toggle>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=set_speed>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=oscillate>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=fan, service=set_direction>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0500]: initializing channel: from_cache: True
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0500]: finished channel configuration
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0001]: initializing channel: from_cache: True
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0001]: finished channel configuration
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0000]: initializing channel: from_cache: True
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0000]: finished channel configuration
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=cover>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=number>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=lock>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=fan>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=turn_on>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=turn_off>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=toggle>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0500]: 'async_initialize' stage succeeded
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0001]: 'async_initialize' stage succeeded
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0158:1:0x0000]: 'async_initialize' stage succeeded
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=light>
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0158](MS01): power source: Battery or Unknown
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0158](MS01): completed initialization
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading mains powered devices
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): started initialization
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:ZDO](EZSP): 'async_initialize' stage succeeded
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): power source: Mains
2021-01-07 11:41:51 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): completed initialization
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=binary_sensor>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.binary_sensor, platform=updater, discovered=>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=ping, service=reload>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=shelly>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=influxdb>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.updater, old_state=None, new_state=<state binary_sensor.updater=off; release_notes=https://www.home-assistant.io/latest-release-notes/, newest_version=2021.1.0, friendly_name=Updater @ 2021-01-07T11:41:56.485327+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=ssdp>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=tts, service=google_translate_say>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=syncthru>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=tts, service=clear_cache>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=notify, service=persistent_notification>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=tts>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=notify>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=upnp>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.notify, platform=mobile_app, discovered=>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=mobile_app>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=notify, service=mobile_app_pixel_2_xl>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=notify, service=notify>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_livello_della_batteria, old_state=None, new_state=<state sensor.pixel_2_xl_livello_della_batteria=90; unit_of_measurement=%, friendly_name=Pixel 2 XL Livello della batteria, icon=mdi:battery-90, device_class=battery @ 2021-01-07T11:41:56.900866+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_stato_della_batteria, old_state=None, new_state=<state sensor.pixel_2_xl_stato_della_batteria=discharging; friendly_name=Pixel 2 XL Stato della batteria, icon=mdi:battery-minus @ 2021-01-07T11:41:56.901961+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_tipo_di_caricabatterie, old_state=None, new_state=<state sensor.pixel_2_xl_tipo_di_caricabatterie=none; friendly_name=Pixel 2 XL Tipo di caricabatterie, icon=mdi:battery @ 2021-01-07T11:41:56.902646+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_integrita_della_batteria, old_state=None, new_state=<state sensor.pixel_2_xl_integrita_della_batteria=good; friendly_name=Pixel 2 XL Integrità della batteria, icon=mdi:battery-heart-variant @ 2021-01-07T11:41:56.903299+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_prossimo_allarme, old_state=None, new_state=<state sensor.pixel_2_xl_prossimo_allarme=2021-01-08T06:00:00.000Z; Local Time=Fri Jan 08 07:00:00 GMT+01:00 2021, Package=com.google.android.deskclock, Time in Milliseconds=1610085600000, friendly_name=Pixel 2 XL Prossimo Allarme, icon=mdi:alarm, device_class=timestamp @ 2021-01-07T11:41:56.903927+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_sensore_non_disturbare, old_state=None, new_state=<state sensor.pixel_2_xl_sensore_non_disturbare=off; friendly_name=Pixel 2 XL Sensore Non disturbare, icon=mdi:do-not-disturb @ 2021-01-07T11:41:56.904571+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pixel_2_xl_posizione_geocodificata, old_state=None, new_state=<state sensor.pixel_2_xl_posizione_geocodificata=Via Alessandro Scarlatti, 17, 21049 Tradate VA, Italia; Administrative Area=Lombardia, Country=Italia, ISO Country Code=IT, Latitude=45.708298, Locality=Tradate, Longitude=8.919512, Postal Code=21049, Sub Administrative Area=Provincia di Varese, Sub Locality=null, Sub Thoroughfare=17, Thoroughfare=Via Alessandro Scarlatti, friendly_name=Pixel 2 XL Posizione geocodificata, icon=mdi:map @ 2021-01-07T11:41:56.909799+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.pixel_2_xl_e_in_carica, old_state=None, new_state=<state binary_sensor.pixel_2_xl_e_in_carica=off; friendly_name=Pixel 2 XL È in carica, icon=mdi:power-plug-off, device_class=plug @ 2021-01-07T11:41:56.910787+01:00>>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=stream, service=record>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=stream>
2021-01-07 11:41:56 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.edo_awake, old_state=None, new_state=<state binary_sensor.edo_awake=off; friendly_name=Edo Awake @ 2021-01-07T11:41:56.982817+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=default_config>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cast, service=show_lovelace_view>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=turn_on>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=turn_off>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=toggle>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=volume_up>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=volume_down>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_play_pause>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_play>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_pause>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_stop>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_next_track>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_previous_track>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=clear_playlist>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=volume_set>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=volume_mute>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=media_seek>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=select_source>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=select_sound_mode>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=play_media>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=shuffle_set>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=media_player, service=repeat_set>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=cast>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.shelly_h_t_f39623_firmware_update, old_state=None, new_state=<state binary_sensor.shelly_h_t_f39623_firmware_update=off; friendly_name=Shelly H&T F39623 Firmware Update @ 2021-01-07T11:41:57.109507+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=media_player>
2021-01-07 11:41:57 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.shelly_1_8caab505c1c7_input_0, old_state=None, new_state=<state binary_sensor.shelly_1_8caab505c1c7_input_0=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 Input 0 @ 2021-01-07T11:41:57.118295+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:41:57 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 4,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.shelly_1_8caab505c1c7_longpush_0, old_state=None, new_state=<state binary_sensor.shelly_1_8caab505c1c7_longpush_0=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 Longpush 0 @ 2021-01-07T11:41:57.669399+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.tv, old_state=None, new_state=<state media_player.tv=unavailable; friendly_name=TV, supported_features=152461 @ 2021-01-07T11:41:57.675790+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.camera_dei_genitori, old_state=None, new_state=<state media_player.camera_dei_genitori=unavailable; friendly_name=Camera dei genitori, supported_features=152461 @ 2021-01-07T11:41:57.680112+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.piani_alti, old_state=None, new_state=<state media_player.piani_alti=unavailable; friendly_name=Piani alti, supported_features=152461 @ 2021-01-07T11:41:57.682349+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.zona_giorno, old_state=None, new_state=<state media_player.zona_giorno=unavailable; friendly_name=Zona Giorno, supported_features=152461 @ 2021-01-07T11:41:57.684921+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.tutta_la_casa, old_state=None, new_state=<state media_player.tutta_la_casa=unavailable; friendly_name=Tutta la Casa, supported_features=152461 @ 2021-01-07T11:41:57.687061+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.cameretta, old_state=None, new_state=<state media_player.cameretta=unavailable; friendly_name=Cameretta, supported_features=152461 @ 2021-01-07T11:41:57.689252+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.salotto, old_state=None, new_state=<state media_player.salotto=unavailable; friendly_name=Salotto, supported_features=152461 @ 2021-01-07T11:41:57.691477+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_scrivania, old_state=None, new_state=<state media_player.taverna_scrivania=unavailable; friendly_name=Taverna Scrivania, supported_features=152461 @ 2021-01-07T11:41:57.694569+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_camino, old_state=None, new_state=<state media_player.taverna_camino=unavailable; friendly_name=Taverna Camino, supported_features=152461 @ 2021-01-07T11:41:57.696786+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_2, old_state=None, new_state=<state media_player.taverna_2=unavailable; friendly_name=Taverna, supported_features=152461 @ 2021-01-07T11:41:57.701780+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.shelly_1_8caab505c1c7_shortpush_0, old_state=None, new_state=<state binary_sensor.shelly_1_8caab505c1c7_shortpush_0=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 Shortpush 0 @ 2021-01-07T11:41:57.808786+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.tv, old_state=<state media_player.tv=unavailable; friendly_name=TV, supported_features=152461 @ 2021-01-07T11:41:57.675790+01:00>, new_state=<state media_player.tv=off; friendly_name=TV, supported_features=152461 @ 2021-01-07T11:41:57.841844+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.shelly_1_8caab505c1c7_firmware_update, old_state=None, new_state=<state binary_sensor.shelly_1_8caab505c1c7_firmware_update=unavailable; friendly_name=Shelly 1 8CAAB505C1C7 Firmware Update @ 2021-01-07T11:41:57.855359+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.cameretta, old_state=<state media_player.cameretta=unavailable; friendly_name=Cameretta, supported_features=152461 @ 2021-01-07T11:41:57.689252+01:00>, new_state=<state media_player.cameretta=off; friendly_name=Cameretta, supported_features=152461 @ 2021-01-07T11:41:57.856501+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.salotto, old_state=<state media_player.salotto=unavailable; friendly_name=Salotto, supported_features=152461 @ 2021-01-07T11:41:57.691477+01:00>, new_state=<state media_player.salotto=off; friendly_name=Salotto, supported_features=152461 @ 2021-01-07T11:41:57.856946+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_scrivania, old_state=<state media_player.taverna_scrivania=unavailable; friendly_name=Taverna Scrivania, supported_features=152461 @ 2021-01-07T11:41:57.694569+01:00>, new_state=<state media_player.taverna_scrivania=off; friendly_name=Taverna Scrivania, supported_features=152461 @ 2021-01-07T11:41:57.891137+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_2, old_state=<state media_player.taverna_2=unavailable; friendly_name=Taverna, supported_features=152461 @ 2021-01-07T11:41:57.701780+01:00>, new_state=<state media_player.taverna_2=off; friendly_name=Taverna, supported_features=152461 @ 2021-01-07T11:41:57.894921+01:00>>
2021-01-07 11:41:57 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.camera_dei_genitori, old_state=<state media_player.camera_dei_genitori=unavailable; friendly_name=Camera dei genitori, supported_features=152461 @ 2021-01-07T11:41:57.680112+01:00>, new_state=<state media_player.camera_dei_genitori=off; friendly_name=Camera dei genitori, supported_features=152461 @ 2021-01-07T11:41:57.910204+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.taverna_camino, old_state=<state media_player.taverna_camino=unavailable; friendly_name=Taverna Camino, supported_features=152461 @ 2021-01-07T11:41:57.696786+01:00>, new_state=<state media_player.taverna_camino=off; friendly_name=Taverna Camino, supported_features=152461 @ 2021-01-07T11:41:59.168952+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.zona_giorno, old_state=<state media_player.zona_giorno=unavailable; friendly_name=Zona Giorno, supported_features=152461 @ 2021-01-07T11:41:57.684921+01:00>, new_state=<state media_player.zona_giorno=off; friendly_name=Zona Giorno, supported_features=152461 @ 2021-01-07T11:41:59.169696+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.google_maps_108904995052702071236, old_state=None, new_state=<state device_tracker.google_maps_108904995052702071236=home; source_type=gps, latitude=45.708277, longitude=8.9195131, gps_accuracy=20, address=Via Alessandro Scarlatti, 17, 21049 Tradate VA, Italy, full_name=Federico Granata, id=108904995052702071236, last_seen=2021-01-07T11:41:16.757000+01:00, nickname=Federico, battery_charging=False, battery_level=None, friendly_name=google_maps_108904995052702071236, entity_picture=https://lh3.googleusercontent.com/a-/AOh14Gh91wKomFaW2Eo5VJ6c-5KaN7z5Cuhj-Ub6078drOw @ 2021-01-07T11:41:59.170748+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.tutta_la_casa, old_state=<state media_player.tutta_la_casa=unavailable; friendly_name=Tutta la Casa, supported_features=152461 @ 2021-01-07T11:41:57.687061+01:00>, new_state=<state media_player.tutta_la_casa=off; friendly_name=Tutta la Casa, supported_features=152461 @ 2021-01-07T11:41:59.171148+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.piani_alti, old_state=<state media_player.piani_alti=unavailable; friendly_name=Piani alti, supported_features=152461 @ 2021-01-07T11:41:57.682349+01:00>, new_state=<state media_player.piani_alti=off; friendly_name=Piani alti, supported_features=152461 @ 2021-01-07T11:41:59.171448+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=googlehome>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=device_tracker, service=see>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.20_39_56_7b_be_86, old_state=None, new_state=<state device_tracker.20_39_56_7b_be_86=not_home; source_type=None, friendly_name=Nokia 3.1 - nmap @ 2021-01-07T11:41:59.188701+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.ca_d0_8d_b2_80_46, old_state=None, new_state=<state device_tracker.ca_d0_8d_b2_80_46=not_home; source_type=None, friendly_name=Nokia 5.3 - nmap @ 2021-01-07T11:41:59.189378+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.a8_3e_0e_45_99_9f, old_state=None, new_state=<state device_tracker.a8_3e_0e_45_99_9f=not_home; source_type=None, friendly_name=Nokia 5.1 - nmap @ 2021-01-07T11:41:59.189909+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=device_tracker>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.pixel_2_xl, old_state=None, new_state=<state device_tracker.pixel_2_xl=home; source_type=gps, latitude=45.7083437, longitude=8.9195762, gps_accuracy=19, altitude=373.0, course=210, speed=0, vertical_accuracy=24, friendly_name=Pixel 2 XL @ 2021-01-07T11:41:59.241567+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensore_di_movimento_power, old_state=None, new_state=<state sensor.sensore_di_movimento_power=unavailable; unit_of_measurement=%, friendly_name=Sensore di Movimento power, device_class=battery @ 2021-01-07T11:41:59.249244+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.sensore_di_movimento_ias_zone, old_state=None, new_state=<state binary_sensor.sensore_di_movimento_ias_zone=unavailable; friendly_name=Sensore di Movimento, device_class=motion @ 2021-01-07T11:41:59.254200+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=sonoff, service=send_command>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.light, platform=sonoff, discovered=deviceid=10003f119a, channels=None>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.switch, platform=sonoff, discovered=deviceid=1000e8bdb2, channels=None>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.binary_sensor, platform=sonoff, discovered=deviceid=a4800006ef, channels=None>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=sonoff>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:17.766311+01:00>, new_state=<state sensor.mi_band_5a_room_presence=not_home; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:59.572280+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=not_home; friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:59.572280+01:00>, new_state=<state sensor.mi_band_5a_room_presence=not_home; last_updated_at=2021-01-07T10:41:59.565Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:59.572280+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.postazione_di_lavoro, old_state=None, new_state=<state light.postazione_di_lavoro=on; manufacturer=Sonoff, model=Basic, sw_version=ITA-GZ1-GL v3.5.0, cloud=online, rssi=-35, friendly_name=Postazione di lavoro, supported_features=0 @ 2021-01-07T11:41:59.585248+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=switch.sonoff_1000e8bdb2, old_state=None, new_state=<state switch.sonoff_1000e8bdb2=unavailable; friendly_name=Zigbee Bridge , icon=mdi:zigbee, supported_features=0 @ 2021-01-07T11:41:59.586352+01:00>>
2021-01-07 11:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.sonoff_a4800006ef, old_state=None, new_state=<state binary_sensor.sonoff_a4800006ef=unavailable; friendly_name=Movimento , supported_features=0, device_class=motion @ 2021-01-07T11:41:59.588318+01:00>>
2021-01-07 11:42:00 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.televisore, old_state=None, new_state=<state binary_sensor.televisore=off; friendly_name=Televisore, device_class=connectivity, icon=mdi:television @ 2021-01-07T11:42:00.671610+01:00>>
2021-01-07 11:42:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.postazione_di_lavoro, old_state=<state light.postazione_di_lavoro=on; manufacturer=Sonoff, model=Basic, sw_version=ITA-GZ1-GL v3.5.0, cloud=online, rssi=-35, friendly_name=Postazione di lavoro, supported_features=0 @ 2021-01-07T11:41:59.585248+01:00>, new_state=<state light.postazione_di_lavoro=on; manufacturer=Sonoff, model=Basic, sw_version=ITA-GZ1-GL v3.5.0, cloud=online, rssi=-35, local=online, friendly_name=Postazione di lavoro, supported_features=0 @ 2021-01-07T11:41:59.585248+01:00>>
2021-01-07 11:42:05 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 20 seconds
2021-01-07 11:42:07 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:07 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:07 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 4,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:09 WARNING (MainThread) [homeassistant.components.device_tracker] Setup of device_tracker platform googlehome is taking over 10 seconds.
2021-01-07 11:42:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=<state sensor.cpu_temperature=45.8; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:41:17.329279+01:00>, new_state=<state sensor.cpu_temperature=44.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:42:17.395053+01:00>>
2021-01-07 11:42:17 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:17 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000500000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:17 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 5,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:27 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:27 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000500000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:27 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 5,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:31 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 40 seconds
2021-01-07 11:42:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_voltage, old_state=<state sensor.ups_battery_voltage=13.9; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.152698+01:00>, new_state=<state sensor.ups_battery_voltage=13.5; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:42:37.026796+01:00>>
2021-01-07 11:42:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_voltage, old_state=<state sensor.ups_input_voltage=234.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:41:37.162804+01:00>, new_state=<state sensor.ups_input_voltage=228.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:42:37.028488+01:00>>
2021-01-07 11:42:37 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:37 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000600000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:37 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 6,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:40 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan
2021-01-07 11:42:40 ERROR (MainThread) [googledevices] Error connecting to - 10.10.10.14
2021-01-07 11:42:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000700000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:47 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 7,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:51 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan
2021-01-07 11:42:51 ERROR (MainThread) [googledevices] Error connecting to - 10.10.10.14
2021-01-07 11:42:53 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan_results
2021-01-07 11:42:57 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:42:57 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000700000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000'
2021-01-07 11:42:57 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 7,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:42:58 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): Attempting to checkin with device - missed checkins: 1
2021-01-07 11:42:58 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): does not have a mandatory basic cluster
2021-01-07 11:43:00 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan
2021-01-07 11:43:00 ERROR (MainThread) [googledevices] Error connecting to - 10.10.10.14
2021-01-07 11:43:04 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan_results
2021-01-07 11:43:07 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:07 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000030000000000000000000000000000000000'
2021-01-07 11:43:07 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 8,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 0,COUNTER_APS_DATA_TX_UNICAST_FAILED: 0,COUNTER_ROUTE_DISCOVERY_INITIATED: 0,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 3,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:11 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0158](MS01): Attempting to checkin with device - missed checkins: 1
2021-01-07 11:43:11 DEBUG (MainThread) [zigpy.device] [0x0158] Extending timeout for 0x01 request
2021-01-07 11:43:11 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:12:4b:00:1f:90:d1:b4/0x0158
2021-01-07 11:43:11 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (00:12:4b:00:1f:90:d1:b4, True)
2021-01-07 11:43:11 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2021-01-07 11:43:11 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x0158, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=1), 2, b'\x00\x01\x00\x04\x00')
2021-01-07 11:43:11 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0039'
2021-01-07 11:43:16 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0058010401000001014000000039026600'
2021-01-07 11:43:16 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 344, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=57), 2, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2021-01-07 11:43:16 DEBUG (MainThread) [zigpy.device] [0x0158] Delivery error for seq # 0x01, on endpoint id 1 cluster 0x0000: message send failure
2021-01-07 11:43:16 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 80 seconds
2021-01-07 11:43:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=<state sensor.cpu_temperature=44.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:42:17.395053+01:00>, new_state=<state sensor.cpu_temperature=43.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:43:17.439942+01:00>>
2021-01-07 11:43:17 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:18 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000c00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:43:18 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 12,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:28 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:28 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000d00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:43:28 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 13,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_voltage, old_state=<state sensor.ups_battery_voltage=13.5; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:42:37.026796+01:00>, new_state=<state sensor.ups_battery_voltage=13.8; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:43:37.020306+01:00>>
2021-01-07 11:43:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_voltage, old_state=<state sensor.ups_input_voltage=228.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:42:37.028488+01:00>, new_state=<state sensor.ups_input_voltage=234.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:43:37.022011+01:00>>
2021-01-07 11:43:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000e00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:43:38 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 14,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:40 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3219' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:40 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3221' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3228' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3230' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3234' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:43:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...Sb51VxYHHJDpw'>
2021-01-07 11:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000e00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:43:48 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 14,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:49 ERROR (MainThread) [homeassistant.components.broadlink.updater] Error fetching Broadlink Camera dei Genitori (RM4C mini at 10.10.10.44) data: [Errno -4000] Network timeout
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3235' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3237' coro=<DataUpdateCoordinator._handle_refresh_interval() done, defined at /usr/src/homeassistant/homeassistant/helpers/update_coordinator.py:116> result=None>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished exception=NetworkTimeoutError(-4000, 'Network timeout')>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3240' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3242' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3244' coro=<async_setup_scanner_platform.<locals>.async_device_tracker_scan() done, defined at /usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py:317> result=None>
2021-01-07 11:43:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result=[]>
2021-01-07 11:43:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3247' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3249' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:43:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3253' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:43:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...LJErFAAnjzzpK'>
2021-01-07 11:43:58 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:43:58 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000f00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:43:58 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 15,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:43:59 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3254' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:05 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): Attempting to checkin with device - missed checkins: 2
2021-01-07 11:44:05 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](EZSP): does not have a mandatory basic cluster
2021-01-07 11:44:08 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:08 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00000f00000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:44:08 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 15,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:10 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3259' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:10 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3261' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:10 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3265' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:10 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result=None>
2021-01-07 11:44:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=<state sensor.cpu_temperature=43.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:43:17.439942+01:00>, new_state=<state sensor.cpu_temperature=42.8; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:44:17.448006+01:00>>
2021-01-07 11:44:18 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:18 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001000000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:44:18 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 16,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:20 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan
2021-01-07 11:44:20 ERROR (MainThread) [googledevices] Error connecting to - 10.10.10.14
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3274' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3278' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3280' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3285' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3287' coro=<async_setup_scanner_platform.<locals>.async_device_tracker_scan() done, defined at /usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py:317> result=None>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result=[]>
2021-01-07 11:44:21 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3288' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:28 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:28 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001100000000000000000000000000000000000200010001000000000000000000000000000000000000000000000000000000000000000000000000000000060000000000000000000000000000000000'
2021-01-07 11:44:28 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 17,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1,COUNTER_ROUTE_DISCOVERY_INITIATED: 1,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 6,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:30 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0158](MS01): Attempting to checkin with device - missed checkins: 2
2021-01-07 11:44:30 DEBUG (MainThread) [zigpy.device] [0x0158] Extending timeout for 0x03 request
2021-01-07 11:44:30 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:12:4b:00:1f:90:d1:b4/0x0158
2021-01-07 11:44:30 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (00:12:4b:00:1f:90:d1:b4, True)
2021-01-07 11:44:30 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2021-01-07 11:44:30 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x0158, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=3), 4, b'\x00\x03\x00\x04\x00')
2021-01-07 11:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'003a'
2021-01-07 11:44:33 ERROR (MainThread) [googledevices] Timeout contacting https://10.10.10.14:8443/setup/bluetooth/scan_results
2021-01-07 11:44:33 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3294' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:33 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3309' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:33 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3311' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:33 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3316' coro=<async_setup_scanner_platform.<locals>.async_device_tracker_scan() done, defined at /usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py:317> result=None>
2021-01-07 11:44:33 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result=[]>
2021-01-07 11:44:35 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'005801040100000101400000003a046600'
2021-01-07 11:44:35 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 344, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=58), 4, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2021-01-07 11:44:35 DEBUG (MainThread) [zigpy.device] [0x0158] Delivery error for seq # 0x03, on endpoint id 1 cluster 0x0000: message send failure
2021-01-07 11:44:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_voltage, old_state=<state sensor.ups_battery_voltage=13.8; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:43:37.020306+01:00>, new_state=<state sensor.ups_battery_voltage=13.9; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:44:37.028107+01:00>>
2021-01-07 11:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000015000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:44:38 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 21,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:42 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 80 seconds
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3318' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3330' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3332' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3335' coro=<ZHADevice._check_available() done, defined at /usr/src/homeassistant/homeassistant/components/zha/core/device.py:315> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3339' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3341' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:44:45 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...1pqgP7KI_yk7w'>
2021-01-07 11:44:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000016000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:44:48 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 22,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3364' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3369' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3371' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3378' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3380' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3384' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...gsLP5nQmKbHnQ'>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3385' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:44:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...NyTBrwCr0ewve'>
2021-01-07 11:44:58 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3386' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:44:58 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:44:59 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000017000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:44:59 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 23,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:44:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=not_home; last_updated_at=2021-01-07T10:41:59.565Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:41:59.572280+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; last_updated_at=2021-01-07T10:41:59.565Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:44:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; last_updated_at=2021-01-07T10:41:59.565Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.7, last_updated_at=2021-01-07T10:44:59.773Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:00 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3390' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:00 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3392' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.7, last_updated_at=2021-01-07T10:44:59.773Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:02.924Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3397' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3399' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3405' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:45:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...cMe3wsmOeM1BJ'>
2021-01-07 11:45:05 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:02.924Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:05.115Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:09 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:09 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000017000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:45:09 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 23,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:45:09 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3407' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:05.115Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:10.636Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:10.636Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:11.746Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:11.746Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:14.506Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3414' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3416' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3419' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sun.sun, old_state=<state sun.sun=above_horizon; next_dawn=2021-01-08T06:28:44+00:00, next_dusk=2021-01-07T16:32:02+00:00, next_midnight=2021-01-07T23:31:07+00:00, next_noon=2021-01-07T11:30:28+00:00, next_rising=2021-01-08T07:02:26+00:00, next_setting=2021-01-07T15:58:16+00:00, elevation=21.15, azimuth=167.7, rising=True, friendly_name=Sun @ 2021-01-07T11:41:16.480851+01:00>, new_state=<state sun.sun=above_horizon; next_dawn=2021-01-08T06:28:44+00:00, next_dusk=2021-01-07T16:32:02+00:00, next_midnight=2021-01-07T23:31:07+00:00, next_noon=2021-01-07T11:30:28+00:00, next_rising=2021-01-08T07:02:26+00:00, next_setting=2021-01-07T15:58:16+00:00, elevation=21.3, azimuth=168.68, rising=True, friendly_name=Sun @ 2021-01-07T11:41:16.480851+01:00>>
2021-01-07 11:45:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=<state sensor.cpu_temperature=42.8; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:44:17.448006+01:00>, new_state=<state sensor.cpu_temperature=43.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:45:17.452288+01:00>>
2021-01-07 11:45:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:14.506Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.9, last_updated_at=2021-01-07T10:45:18.376Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:19 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:19 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000018000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:45:19 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 24,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:45:20 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.9, last_updated_at=2021-01-07T10:45:18.376Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:45:20.031Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:22 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:45:20.031Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:45:21.136Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:22 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:45:21.136Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:22.245Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:22 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3430' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:24 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:22.245Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:23.898Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:26 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:23.898Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:26.654Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:28 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:45:26.654Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:28.308Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:29 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:29 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000018000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000'
2021-01-07 11:45:29 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 24,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 10,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3449' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3452' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3460' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...CHUiPwxv6XPYu'>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3462' coro=<async_setup_scanner_platform.<locals>.async_device_tracker_scan() done, defined at /usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py:317> result=None>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3463' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:29 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:28.308Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:29.961Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:32 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:29.961Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:32.715Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:32.715Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:34.371Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3471' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3473' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3477' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3481' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_voltage, old_state=<state sensor.ups_input_voltage=234.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:43:37.022011+01:00>, new_state=<state sensor.ups_input_voltage=232.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:45:37.028608+01:00>>
2021-01-07 11:45:38 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3488' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:34.371Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:39.320Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:39 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'000019000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000b0000000000000000000000000000000000'
2021-01-07 11:45:39 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 25,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 11,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:45:40 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3495' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:40 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3497' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:43 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.1, last_updated_at=2021-01-07T10:45:39.320Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:43.726Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3502' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3505' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3510' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:45:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...O44YULcH3i3jw'>
2021-01-07 11:45:45 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:43.726Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:45.376Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:47 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:45.376Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:47.027Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:48 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:45:47.027Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.3, last_updated_at=2021-01-07T10:45:48.675Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:49 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3511' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001a000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000b0000000000000000000000000000000000'
2021-01-07 11:45:49 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 26,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 11,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:45:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3517' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3519' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:52 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.3, last_updated_at=2021-01-07T10:45:48.675Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.3, last_updated_at=2021-01-07T10:45:51.433Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:52 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.3, last_updated_at=2021-01-07T10:45:51.433Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.4, last_updated_at=2021-01-07T10:45:51.981Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.4, last_updated_at=2021-01-07T10:45:51.981Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:53.624Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:53.624Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.4, last_updated_at=2021-01-07T10:45:54.170Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3527' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3530' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3535' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...b7GxODN2kDWcl'>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3536' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:45:54 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...iMi2_L0vdyEof'>
2021-01-07 11:45:58 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.4, last_updated_at=2021-01-07T10:45:54.170Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:58.580Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:59 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:45:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:58.580Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:59.686Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:45:59 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001a000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000b0000000000000000000000000000000000'
2021-01-07 11:45:59 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 26,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 11,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:46:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.5, last_updated_at=2021-01-07T10:45:59.686Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:46:01.229Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:01 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3539' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1.2, last_updated_at=2021-01-07T10:46:01.229Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:46:03.986Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3552' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3554' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3563' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:46:04 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...2JBA5o-rEI0pj'>
2021-01-07 11:46:05 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=1, last_updated_at=2021-01-07T10:46:03.986Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:46:05.093Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:06 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.8, last_updated_at=2021-01-07T10:46:05.093Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.6, last_updated_at=2021-01-07T10:46:06.751Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:08 WARNING (MainThread) [homeassistant.config_entries] Config entry for broadlink not ready yet. Retrying in 80 seconds
2021-01-07 11:46:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.6, last_updated_at=2021-01-07T10:46:06.751Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:08.966Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:09 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3565' coro=<ConfigEntry.async_setup.<locals>.setup_again() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:253> result=None>
2021-01-07 11:46:09 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3566' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:09 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished exception=NetworkTimeoutError(-4000, 'Network timeout')>
2021-01-07 11:46:09 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:46:09 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001b000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000c0000000000000000000000000000000000'
2021-01-07 11:46:09 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 27,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 12,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:46:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:08.966Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:10.618Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:10.618Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:12.263Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:12.263Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:13.921Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=device_tracker.mi_smart_band_5, old_state=None, new_state=<state device_tracker.mi_smart_band_5=home; source_type=bluetooth, ghname=Salotto, rssi=-70, friendly_name=Mi Smart Band 5 @ 2021-01-07T11:46:14.298290+01:00>>
2021-01-07 11:46:14 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event device_tracker_new_device[L]: entity_id=device_tracker.mi_smart_band_5, host_name=Mi Smart Band 5, mac=FB:7D:D1:8E:38:98>
2021-01-07 11:46:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3572' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3574' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:14 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3578' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:13.921Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:15.027Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:15.027Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:16.679Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.cpu_temperature, old_state=<state sensor.cpu_temperature=43.3; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:45:17.452288+01:00>, new_state=<state sensor.cpu_temperature=42.8; unit_of_measurement=°C, friendly_name=CPU Temperature @ 2021-01-07T11:46:17.443538+01:00>>
2021-01-07 11:46:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:16.679Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:17.783Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:19 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3581' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:19 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3590' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:19 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:46:20 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001c000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000c0000000000000000000000000000000000'
2021-01-07 11:46:20 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 28,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 12,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:46:20 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3598' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:20 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3600' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:25 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3611' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:25 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3613' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:25 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3619' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:46:25 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...xr-S-tdSjtpeB'>
2021-01-07 11:46:26 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:17.783Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:26.063Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:27 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:26.063Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:27.716Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:28 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:27.716Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:28.824Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:30 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:46:30 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001c000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000c0000000000000000000000000000000000'
2021-01-07 11:46:30 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 28,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 12,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:46:30 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3620' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:30 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3625' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:30 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3627' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:28.824Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:30.475Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:30.475Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:33.238Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3633' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3635' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3639' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...wS5wMQPvttGY8'>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3641' coro=<refresh_tokens() done, defined at /config/custom_components/googlehome/__init__.py:56> result=None>
2021-01-07 11:46:34 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result='ya29.a0AfH6S...Cu86qP_gLYB0Q'>
2021-01-07 11:46:36 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:33.238Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:36.000Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_battery_voltage, old_state=<state sensor.ups_battery_voltage=13.9; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:44:37.028107+01:00>, new_state=<state sensor.ups_battery_voltage=13.4; state=Online, unit_of_measurement=V, friendly_name=Ups Battery Voltage, icon=mdi:flash @ 2021-01-07T11:46:37.044313+01:00>>
2021-01-07 11:46:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.ups_input_voltage, old_state=<state sensor.ups_input_voltage=232.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:45:37.028608+01:00>, new_state=<state sensor.ups_input_voltage=234.0; state=Online, unit_of_measurement=V, friendly_name=Ups Input Voltage, icon=mdi:flash @ 2021-01-07T11:46:37.045718+01:00>>
2021-01-07 11:46:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.5, last_updated_at=2021-01-07T10:46:36.000Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:37.104Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:37.104Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:38.759Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:40 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:46:40 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001d000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000d0000000000000000000000000000000000'
2021-01-07 11:46:40 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 29,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 13,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0
2021-01-07 11:46:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:38.759Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:40.407Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:40.407Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:42.054Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:42 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3643' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:43 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:42.054Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:43.705Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3659' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:44 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3661' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:45 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:43.705Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:45.356Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:47 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.3, last_updated_at=2021-01-07T10:46:45.356Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:47.011Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:48 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:47.011Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:48.118Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:48 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3671' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:49 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.mi_band_5a_room_presence, old_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:48.118Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>, new_state=<state sensor.mi_band_5a_room_presence=taverna; distance=0.4, last_updated_at=2021-01-07T10:46:49.766Z, friendly_name=Mi Band 5a Room Presence, icon=mdi:bluetooth @ 2021-01-07T11:44:59.778309+01:00>>
2021-01-07 11:46:50 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2021-01-07 11:46:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3677' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3679' coro=<GoogleHomeDeviceScanner.async_update() done, defined at /config/custom_components/googlehome/device_tracker.py:108> result=None>
2021-01-07 11:46:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Task finished name='Task-3682' coro=<async_setup_scanner_platform.<locals>.async_device_tracker_scan() done, defined at /usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py:317> result=None>
2021-01-07 11:46:50 DEBUG (MainThread) [homeassistant.core] Waiting for task: <Future finished result=[]>
2021-01-07 11:46:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 241 (readCounters) received: b'00001e000000000000000000000000000000000004000200020000000000000000000000000000000000000000000000000000000000000000000000000000000d0000000000000000000000000000000000'
2021-01-07 11:46:50 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 0,COUNTER_MAC_TX_BROADCAST: 30,COUNTER_MAC_RX_UNICAST: 0,COUNTER_MAC_TX_UNICAST_SUCCESS: 0,COUNTER_MAC_TX_UNICAST_RETRY: 0,COUNTER_MAC_TX_UNICAST_FAILED: 0,COUNTER_APS_DATA_RX_BROADCAST: 0,COUNTER_APS_DATA_TX_BROADCAST: 0,COUNTER_APS_DATA_RX_UNICAST: 0,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 0,COUNTER_APS_DATA_TX_UNICAST_RETRY: 4,COUNTER_APS_DATA_TX_UNICAST_FAILED: 2,COUNTER_ROUTE_DISCOVERY_INITIATED: 2,COUNTER_NEIGHBOR_ADDED: 0,COUNTER_NEIGHBOR_REMOVED: 0,COUNTER_NEIGHBOR_STALE: 0,COUNTER_JOIN_INDICATION: 0,COUNTER_CHILD_REMOVED: 0,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 13,COUNTER_BROADCAST_TABLE_FULL: 0,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0

Additional information

The motion sensor (eWeLink MS01) last seen is exactly when I updated to 2021.1.0 but the coordinator (Silicon Labs EZSP) was last seen more recently (this morning, in my timezone, before work). The web interface of the coordinator is working so it's up and connected to the wifi.

[Adminiuga]

Ignore last seen for coordinator. Coordinator works fine. Device dropped of the network and not responding to the request -- has to be rejoined.

[Edo78]

I removed the device, paired it back and now it's working. Just wondering what it could be happened. It's the first time an upgrade made a device to be dropped of the network. It could be something in my setup or it could randomly happen?