doudz / homeassistant-zigate

zigate component for Home Assistant
MIT License
48 stars 13 forks source link

APS data confirm fail on battery powered devices #60

Closed biau closed 5 years ago

biau commented 5 years ago

Hi, I have this error in logs for two motion detection sensor:

2019-07-25 12:53:03 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10 X\xb4\xcf\xcc\x02\x11\x02\x10\x02\x10\xff\x02\x12\x02\x10B\x02\x10\x13\x10\x02\x11!\xa9\x02\x1b!\xa8\x13$\x02\x11\x02\
x10\x02\x10\x02\x10\x02\x10!\x14\x02\x10 T\x8d\x03'
2019-07-25 12:53:04 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-07-25 12:53:04 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'b4cfcc010000ff0200420013100121a90b21a8132401000000002114002054'
2019-07-25 12:53:04 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:180, addr:cfcc, endpoint:1, cluster:0, attribute:65282, status:0, data_type:66, size:19, data:100121a90b
21a8132401000000002114002054, lqi:141
2019-07-25 12:53:04 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2019-07-25 12:53:04 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-07-25 12:53:11 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x87\x02\x12\x02\x10\x02\x1e\x98\xf0\x02\x11\x02\x11\x02\x12\xcf\xcc\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\xe2\x02\x10\x03'
2019-07-25 12:53:11 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-07-25 12:53:11 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8702: b'f0010102cfcc000000000000e2'
2019-07-25 12:53:11 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:226, lqi:0
2019-07-25 12:53:11 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:226, lqi:0
2019-07-25 12:53:11 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED

When I look to timestamp errors this error happens every 55 minutes:

2019-07-25 06:21:37 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:223, lqi:0
2019-07-25 06:34:33 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:242, lqi:0
2019-07-25 07:16:38 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:47, lqi:0
2019-07-25 07:26:07 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:59, lqi:0
2019-07-25 08:11:42 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:121, lqi:0
2019-07-25 08:18:34 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:132, lqi:0
2019-07-25 09:06:43 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:192, lqi:0
2019-07-25 09:13:04 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:200, lqi:0
2019-07-25 09:59:04 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:13, lqi:0
2019-07-25 10:08:08 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:24, lqi:0
2019-07-25 10:54:08 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:80, lqi:0
2019-07-25 11:03:11 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:90, lqi:0
2019-07-25 11:49:09 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:148, lqi:0
2019-07-25 11:58:11 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:158, lqi:0
2019-07-25 12:44:10 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:1abc, sequence:208, lqi:0
2019-07-25 12:53:11 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:226, lqi:0

If there's no motion detection the sensor is not awake and does not respond to zigate calls so I guess the error is normal. Any idea what could generate this error ?

doudz commented 5 years ago

What kind of detector ? Maybe you could try to find the sent command with the same sequence number What's the firmware version ?

biau commented 5 years ago

xiaomi v1 without lumen sensor nothing in logs with sequence 226:

2019-07-25 09:50:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:226, addr:7376, endpoint:1, cluster:6, attribute:0, status:0, data_type:16, size:1, data:False, lqi:60
2019-07-25 10:00:13 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:226, addr:cef9, endpoint:1, cluster:0, attribute:65281, status:0, data_type:66, size:46, data:64100065100003282798390000000095392431ff42052116009a200008211f11072700000000000000000921030e, lqi:102
2019-07-25 10:02:39 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'6c1b0801040300100029000226ca'
2019-07-25 10:13:12 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'1ee49601040300100029000226c2'
2019-07-25 10:16:25 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'21c14201040300100029000226c6'
2019-07-25 11:39:58 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'98adca01040300100029000226c5'
2019-07-25 11:43:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:226, addr:7376, endpoint:1, cluster:6, attribute:0, status:0, data_type:16, size:1, data:False, lqi:60
2019-07-25 11:57:31 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'3069df01040300100029000226c4'
2019-07-25 11:59:20 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'bd953f01040300100029000226ce'
2019-07-25 12:07:40 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'782d9601040300100029000226ca'
2019-07-25 12:09:10 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'23e49601040300100029000226c2'
2019-07-25 12:49:10 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'721b0801040300100029000226c7'
2019-07-25 12:52:31 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'c1953f01040300100029000226cb'
2019-07-25 12:53:11 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:226, lqi:0
2019-07-25 12:53:11 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:240, source_endpoint:1, dst_endpoint:1, dst_address_mode:2, dst_address:cfcc, sequence:226, lqi:0

(I've grep log file with 226)

firmware version 3.0f

doudz commented 5 years ago

You should open a ticket on zigate side because I really don't know what's happening since no command is sent. Error 240 is 0xF0 MAC_ENUM_TRANSACTION_EXPIRED 0xF0 Pending transaction has expired and data discarded

doudz commented 5 years ago

Did you connect the sensor to a group or something like this ? Maybe the sensor tries to control something that couldn't be

biau commented 5 years ago

Nope only connected to hass and then an automation with node red to turn a tradfri bulb on. These sensor never failed a detection when we enter the room so it does not looks like a signal strenght issue. Ok I'll open an issue on zigate github