core: Message send failure with YRD226 TSDB as a child of a router
The problem
When my Yale YRD226 TSDB connect thru a router (Philips Hue or IKEA Tradfri bulbs) instead of the coordinator directly, some lock / unlock commands fails. This issue does not happen when the door lock is directly connected to the coordinator.
The issue has been replicated with both IKEA Tradfri White Spectrum and Philips Hue White ambiance bulbs (tried the Philips Hue in the hope it would solve the problem)
The problem is intermitent. It works for a while and other times it get stucked for a short while.
Thank you in advance for your great work and help!
Environment
- Home Assistant Core release with the issue: 2021.1.0
- Last working Home Assistant Core release (if known): none
- Operating environment (OS/Container/Supervised/Core): Container
- Integration causing this issue: ZHA
- ZigBee radio : HUSBZB-1
- Link to integration documentation on our website: https://www.home-assistant.io/integrations/zha/
Problem-relevant device signature
{
"node_descriptor": "NodeDescriptor(byte1=2, byte2=64, mac_capability_flags=128, manufacturer_code=4125, maximum_buffer_size=82, maximum_incoming_transfer_size=255, server_mask=0, maximum_outgoing_transfer_size=255, descriptor_capability_field=0)",
"endpoints": {
"1": {
"profile_id": 260,
"device_type": "0x000a",
"in_clusters": [
"0x0000",
"0x0001",
"0x0003",
"0x0009",
"0x000a",
"0x0020",
"0x0101",
"0x0b05"
],
"out_clusters": [
"0x000a",
"0x0019"
]
}
},
"manufacturer": "Yale",
"model": "YRD226 TSDB",
"class": "zigpy.device.Device"
}
{
"node_descriptor": "NodeDescriptor(byte1=1, byte2=64, mac_capability_flags=142, manufacturer_code=4107, maximum_buffer_size=82, maximum_incoming_transfer_size=128, server_mask=11264, maximum_outgoing_transfer_size=128, descriptor_capability_field=0)",
"endpoints": {
"11": {
"profile_id": 260,
"device_type": "0x010c",
"in_clusters": [
"0x0000",
"0x0003",
"0x0004",
"0x0005",
"0x0006",
"0x0008",
"0x0300",
"0x1000",
"0xfc02"
],
"out_clusters": [
"0x0019"
]
},
"242": {
"profile_id": 41440,
"device_type": "0x0061",
"in_clusters": [],
"out_clusters": [
"0x0021"
]
}
},
"manufacturer": "Philips",
"model": "LTA003",
"class": "zigpy.device.Device"
}
Problem-relevant configuration.yaml
# Configuration pannel
config:
# Logger
logger:
default: info
logs:
homeassistant.core: debug
homeassistant.components.zha: debug
bellows.zigbee.application: debug
bellows.ezsp: debug
zigpy: debug
zigpy_cc: debug
zigpy_deconz.zigbee.application: debug
zigpy_deconz.api: debug
zigpy_xbee.zigbee.application: debug
zigpy_xbee.api: debug
zigpy_zigate: debug
zigpy_znp: debug
zhaquirks: debug
# Frontend
frontend:
themes: !include_dir_merge_named themes
# History
history:
use_include_order: true
include:
entities:
- lock.porte_appartement
- binary_sensor.porte_appartement
- binary_sensor.porte_patio
- binary_sensor.mouvement_salle_a_manger
- binary_sensor.mouvement_entree
domains:
- climate
# Input Boolean
input_boolean:
# Input Datetime
input_datetime:
# Input Number
input_number:
# Input Select
input_select:
# Input Text
input_text:
# Logbook
logbook:
include:
entities:
- lock.porte_appartement
- binary_sensor.porte_appartement
- binary_sensor.porte_patio
domains:
- climate
# Map
map:
# Mobile App
mobile_app:
# Person
person:
# Simple Service Discovery Protocol (SSDP)
ssdp:
# Sun
sun:
# System Health
system_health:
# Zero-configuration networking (zeroconf)
zeroconf:
# Zone
zone:
# Text to speech
tts:
- platform: google_translate
language: 'fr'
# Configuration files
group: !include groups.yaml
automation: !include automations.yaml
script: !include scripts.yaml
scene: !include scenes.yaml
sensor: !include sensors.yaml
homeassistant:
customize: !include customize.yaml
packages: !include_dir_named packages
# Home Assistant SSL
http:
ssl_certificate: ---
ssl_key: ---
# Environment Canada weather
weather:
- platform: environment_canada
station: QC/s0000635
# Locks
lock:
# Lock template building
- platform: template
name: Porte Édifice
value_template: "{{ is_state('switch.verrou_porte_edifice', 'off') }}"
lock:
service: switch.turn_off
data:
entity_id: switch.verrou_porte_edifice
unlock:
service: switch.turn_on
data:
entity_id: switch.verrou_porte_edifice
# Plant configuration file
plant: !include plant.yaml
# Nest integration
nest:
client_id: ---
client_secret: ---
# WOL integration
wake_on_lan:
switch:
# Flux integration
# Bedroom lights Flux
- platform: flux
name: Autopilote lumières chambre
lights:
- light.lampe_chevet
- light.lampe_plancher
mode: mired
start_time: '7:00'
stop_time: '22:00'
start_colortemp: 4000
sunset_colortemp: 3600
stop_colortemp: 2200
disable_brightness_adjust: true
# Secret room light Flux
- platform: flux
name: Autopilote lumière pièce secrète
lights:
- light.lampe_secrete
mode: mired
start_time: '7:00'
stop_time: '22:00'
start_colortemp: 2700
sunset_colortemp: 2600
stop_colortemp: 2200
disable_brightness_adjust: true
# Salon light Flux
- platform: flux
name: Autopilote lumières salon
lights:
- light.lampe_rouge
- light.lampe_jaune
mode: mired
start_time: '7:00'
stop_time: '22:00'
start_colortemp: 4000
sunset_colortemp: 3600
stop_colortemp: 2200
disable_brightness_adjust: true
# Salle à manger light Flux
- platform: flux
name: Autopilote lumières salle à manger
lights:
- light.luminaire_salle_a_manger
mode: mired
start_time: '7:00'
stop_time: '22:00'
start_colortemp: 4000
sunset_colortemp: 3000
stop_colortemp: 2200
disable_brightness_adjust: true
# Light groups
light:
- platform: group
name: Luminaire salle à manger
entities:
- light.luminaire_salle_manger_1
- light.luminaire_salle_manger_2
- light.luminaire_salle_manger_3
# Climate
climate:
# Office thermostat
- platform: generic_thermostat
name: Climatiseur bureau
heater: switch.climatiseur_bureau
target_sensor: sensor.xiaomi_cgg1_temperature
ac_mode: true
# Living room thermostat
- platform: generic_thermostat
name: Climatiseur salon
heater: switch.climatiseur_salon
target_sensor: sensor.temperature_xiaomi_cgg1_corridor
ac_mode: true
# ZHA
#zha:
# zigpy_config:
# ota:
# ikea_provider: true
# Alarm
alarm_control_panel:
- platform: manual
name: Alarme --- Rue ------
arming_time: 30
delay_time: 0
trigger_time: 60
disarmed:
trigger_time: 0
armed_home:
arming_time: 0
delay_time: 0
armed_night:
arming_time: 0
delay_time: 0
# APCUPSD
apcupsd:
# Alerts
alert:
lave_vaiselle:
name: Humidité lave-vaiselle
message: De l’humidité à été détectée sous le lave-vaiselle.
done_message: L’humidité sous le lave-vaiselle s’est dissipée.
entity_id: binary_sensor.humidite_lave_vaiselle
state: 'on'
repeat:
- 5
- 15
- 15
- 15
- 30
notifiers:
- notify
data:
push:
sound:
critical: 1
name: default
volume: 1
title: Dégât d’eau
laveuse_a_linge:
name: Humidité machine à laver
message: De l’humidité à été détectée sous la machine à laver.
done_message: L’humidité sous la machine à laver s’est dissipée.
entity_id: binary_sensor.humidite_machine_a_laver
state: 'on'
repeat:
- 5
- 15
- 15
- 15
- 30
notifiers:
- notify
data:
push:
sound:
critical: 1
name: default
volume: 1
title: Dégât d’eau
# Media players
media_player:
# BOSE
- platform: soundtouch
host: ---
port: 8090
name: Soundtouch bureau
Traceback/Error logs
Full log : HALog.zip
2021-01-07 18:15:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_default_level>
2021-01-07 18:15:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_level>
2021-01-07 18:15:07 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds
2021-01-07 18:15:08 INFO (MainThread) [homeassistant.setup] Setting up recorder
2021-01-07 18:15:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=purge>
2021-01-07 18:15:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logger>
2021-01-07 18:15:08 INFO (MainThread) [homeassistant.setup] Setting up http
2021-01-07 18:15:08 INFO (MainThread) [homeassistant.setup] Setup of domain http took 0.0 seconds
2021-01-07 18:15:08 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 0.2 seconds
2021-01-07 18:15:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=http>
2021-01-07 18:15:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=recorder>
2021-01-07 18:15:08 INFO (MainThread) [homeassistant.setup] Setting up system_log
2021-01-07 18:15:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=system_log, service=clear>
<---------------------------Trunkated, see full log here : https://github.com/home-assistant/core/files/5784962/HALog.zip--------------------------->
2021-01-07 20:33:34 DEBUG (MainThread) [zigpy.zcl] [0xb9bb:11:0x0008] Attribute report received: current_level=153
2021-01-07 20:33:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB9BB:11:0x0008]: received attribute: 0 update with value: 153
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'9bdd8f97520901881700ffc700'
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xdd9b, 00:17:88:01:09:52:97:8f, 255, -57, []]
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xdd9b, 00:17:88:01:09:52:97:8f, 255, -57, [])
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000b010001000075ffc79bddffff0718f10a0000209902'
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=11, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=117), 255, -57, 0xdd9b, 255, 255, b'\x18\xf1\n\x00\x00 \x99']
2021-01-07 20:33:34 DEBUG (MainThread) [zigpy.zcl] [0xdd9b:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=241 command_id=Command.Report_Attributes>
2021-01-07 20:33:34 DEBUG (MainThread) [zigpy.zcl] [0xdd9b:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=153>)]]
2021-01-07 20:33:34 DEBUG (MainThread) [zigpy.zcl] [0xdd9b:11:0x0008] Attribute report received: current_level=153
2021-01-07 20:33:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDD9B:11:0x0008]: received attribute: 0 update with value: 153
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2021-01-07 20:33:34 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2021-01-07 20:33:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.lumiere_phoenix_roebelenii, old_state=<state sensor.lumiere_phoenix_roebelenii=882; unit_of_measurement=lx, friendly_name=Lumière Phoenix roebelenii, icon=mdi:brightness-5 @ 2021-01-07T20:33:04.149597-05:00>, new_state=<state sensor.lumiere_phoenix_roebelenii=886; unit_of_measurement=lx, friendly_name=Lumière Phoenix roebelenii, icon=mdi:brightness-5 @ 2021-01-07T20:33:37.138999-05:00>>
2021-01-07 20:33:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=plant.phoenix_roebelenii, old_state=<state plant.phoenix_roebelenii=problem; problem=moisture low, conductivity low, sensors=moisture=sensor.humidite_phoenix_roebelenii, temperature=sensor.temperature_phoenix_roebelenii, conductivity=sensor.conductivite_phoenix_roebelenii, brightness=sensor.lumiere_phoenix_roebelenii, unit_of_measurement_dict=temperature=°C, moisture=%, brightness=lx, conductivity=µS/cm, moisture=0, temperature=21.3, conductivity=0, brightness=882, max_brightness=935, friendly_name=Phoenix roebelenii @ 2021-01-07T18:15:31.816012-05:00>, new_state=<state plant.phoenix_roebelenii=problem; problem=moisture low, conductivity low, sensors=moisture=sensor.humidite_phoenix_roebelenii, temperature=sensor.temperature_phoenix_roebelenii, conductivity=sensor.conductivite_phoenix_roebelenii, brightness=sensor.lumiere_phoenix_roebelenii, unit_of_measurement_dict=temperature=°C, moisture=%, brightness=lx, conductivity=µS/cm, moisture=0, temperature=21.3, conductivity=0, brightness=886, max_brightness=935, friendly_name=Phoenix roebelenii @ 2021-01-07T18:15:31.816012-05:00>>
2021-01-07 20:33:44 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2021-01-07 20:33:44 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
Additional information
About this issue
- Original URL
- State: closed
- Created 3 years ago
- Comments: 16 (10 by maintainers)
@Adminiuga I was able to recreate a
message send failure
as well to conclude my findings but here’s the catch : I see[0xbb33] Extending timeout for 0x57 request
in the Home Assistant logs but when looking at the frames , it took a little more time than usual but still only 6 seconds before the coordinator got a confirmation from the lock that it has received the command (The bulb was waiting for a data request from the lock and I guess the lock was waiting for the channel to be free.) The network was able to deliver every frame correctly and the lock got unlocked just fine.I can see the coordinator sent 3 unlock commands initially (in less than 3 seconds) and got all passed to the bulb correctly meaning the two other commands were really unnecessary here. Why is the coordinator doing this? And why does it tell ZigPy that a failure happened (most of the time, even if it says there was a network failure, everything is fine).
In resume
ACK
on the MAC link andZCL Door Lock: Lock Door Response = success
on the application level but fails to physically do anything.data request
from the lock to send anything. And does not spit many commands at once thereafter since it has direct feedback.message send failure
’s I get from time to time doesn’t look rights as the lock still does unlock (outside the bug it has) and there is no miscommunication on the network.It is clear to me the lock has a software issue. Considering this, I will reach Yale about it. Meanwhile including the previous questions, can we somehow mitigate the number of commands the coordinator spits on the network and why does the coordinator report a
message send failure
when the frames look all good? Does it mean it was not capable to place the frame on the network?Thank you for your time and help, it is really appreciated.
@dmulcahey I also have seen the same issue, although only when routing through various repeaters. When the lock connects directly to the coordinator (NORTEK stick), it works perfectly, but when going through a repeater (in my case, SmartThings smart plugs and/or Ikea signal repeaters), the message fails getting to the lock.