search

doudz / homeassistant-zigate

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

Binary sensor stuck on open #13

Closed jalme closed 5 years ago

jalme commented 5 years ago

Hi,

Binary sensor status stop to work (door was stuck on open state). Log bellow is related to a reboot and pair of the same device to see if it would reset status.

Currently the door sensor is stuck on open.

After some more analysis the sensor gets updated but the binary_sensor doesn't. I need to manually change the state of the binary sensor to go back to door closed. Although next time I open the door it gets stuck again until I manually fix it.

Using Zigate WiFi.

Regards, João

2018-12-01 15:35:22 DEBUG (SyncWorker_0) [zigate] Saving persistent file 2018-12-01 15:35:22 DEBUG (SyncWorker_0) [zigate] File already existing, make a backup before 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Try loading persistent file 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Load success 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] ZiGate found on port 9999 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0010 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Msg to send b'0010000010' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'01021010021002101003' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0010 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000010' 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', rssi:0 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8010: b'0001030d' 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8010 - Version list : major:1, installer:30d, rssi:0, version:3.0d 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0010:0 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Waiting for message 0x8010 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Stop waiting, got message 0x8010 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0021 b'\x03\x18\xc8\x00' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Msg to send b'00210004f60318c800' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'0102102102100214f6021318c8021003' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0021 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000021' 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:33, error:b'', rssi:0 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0021:0 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0023 b'\x00' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Msg to send b'002300012200' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'010210230210021122021003' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0023 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000023' 2018-12-01 15:36:08 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:35, error:b'', rssi:0 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0023:0 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Check network state 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0024 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Msg to send b'0024000024' 2018-12-01 15:36:08 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'01021024021002102403' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0024 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000024' 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:36, error:b'', rssi:0 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0024:0 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0009 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Msg to send b'0009000009' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'010210021902100210021903' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0009 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000009' 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:9, error:b'', rssi:0 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8009: b'000000158d0001edb71264f243a94141081980450b' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0009:0 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8009 - Network state response : addr:0000, ieee:00158d0001edb712, pan:25842, extend_pan:4875499819169841221, channel:11, rssi:0 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Waiting for message 0x8009 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Stop waiting, got message 0x8009 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0015 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Msg to send b'0015000015' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'01021015021002101503' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0015 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000015' 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:21, error:b'', rssi:0 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0015:0 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8015: b'00c2ff00158d0002536f0b005701baf900158d00024e60620070' 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Waiting for message 0x8015 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8015 - Device list : devices:[OrderedDict([('id', 0), ('addr', 'c2ff'), ('ieee', '00158d0002536f0b'), ('power_type', 0), ('rssi', 87)]), OrderedDict([('id', 1), ('addr', 'baf9'), ('ieee', '00158d00024e6062'), ('power_type', 0), ('rssi', 112)])], rssi:0 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Known devices in zigate : {'c2ff', 'baf9'} 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Stop waiting, got message 0x8015 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Previous devices missing : set() 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Check Need refresh Device 00158d0002536f0b (c2ff) lumi.sensor_magnet.aq2 2018-12-01 15:36:09 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_DEVICE_UPDATED 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Check Need refresh Device 00158d00024e6062 (baf9) lumi.sensor_magnet.aq2 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Auto saving /config/zigate.json 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] Saving persistent file 2018-12-01 15:36:09 DEBUG (SyncWorker_1) [zigate] File already existing, make a backup before 2018-12-01 15:36:50 DEBUG (SyncWorker_3) [zigate] REQUEST : 0x0049 FFFC1E00 2018-12-01 15:36:50 DEBUG (SyncWorker_3) [zigate] Msg to send b'0049000450fffc1e00' 2018-12-01 15:36:50 DEBUG (SyncWorker_3) [zigate] Encoded Msg to send b'010210490210021450fffc1e021003' 2018-12-01 15:36:50 DEBUG (SyncWorker_3) [zigate] Waiting for status message for command 0x0049 2018-12-01 15:36:50 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:36:50 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00730049' 2018-12-01 15:36:50 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:115, packet_type:73, error:b'', rssi:0 2018-12-01 15:36:50 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:36:50 DEBUG (SyncWorker_3) [zigate] STATUS code to command 0x0049:0 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8048: b'00158d0002536f0b00' 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8048 - Leave indication : ieee:00158d0002536f0b, rejoin_status:0, rssi:111 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_DEVICE_REMOVED 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x004d: b'5cdd00158d0002536f0b80' 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x004D - Device announce : addr:5cdd, ieee:00158d0002536f0b, mac_capability:10000000, rssi:111 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Device Announce 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_DEVICE_ADDED 2018-12-01 15:37:21 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity_platform.py", line 343, in _async_add_entity raise HomeAssistantError(msg) homeassistant.exceptions.HomeAssistantError: Entity id already exists: zigate.front_door. Platform zigate does not generate unique IDs 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] REQUEST : 0x0042 5cdd 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Msg to send b'00420002c15cdd' 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Encoded Msg to send b'0102104202100212c15cdd03' 2018-12-01 15:37:21 DEBUG (ZiGate-Event Loop) [zigate] Waiting for status message for command 0x0042 2018-12-01 15:37:24 WARNING (ZiGate-Event Loop) [zigate] No response after command 0x0042 2018-12-01 15:37:24 DEBUG (ZiGate-Event Loop) [zigate] REQUEST : 0x0045 5cdd 2018-12-01 15:37:24 DEBUG (ZiGate-Event Loop) [zigate] Msg to send b'00450002c65cdd' 2018-12-01 15:37:24 DEBUG (ZiGate-Event Loop) [zigate] Encoded Msg to send b'0102104502100212c65cdd03' 2018-12-01 15:37:24 DEBUG (ZiGate-Event Loop) [zigate] Waiting for status message for command 0x0045 2018-12-01 15:37:27 WARNING (ZiGate-Event Loop) [zigate] No response after command 0x0045 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x004d: b'5cdd00158d0002536f0b80' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x004D - Device announce : addr:5cdd, ieee:00158d0002536f0b, mac_capability:10000000, rssi:123 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Device Announce 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_DEVICE_UPDATED 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8701: b'0000' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8701 - Route Discovery Confirmation : status:0, network_status:0, rssi:123 2018-12-01 15:37:27 ERROR (ZiGate-Event Loop) [zigate] Bad length 35 != 32 : b'\x00\xdd\x01\x00\x00\x00\x05\x00B\x00\x16lumi.sens\x01\x80\x00\x00\x05\xb3\x00t\x00B' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8042: b'74005cdd103700640064000000807f4002' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8042 - Node descriptor : sequence:116, status:0, addr:5cdd, manufacturer:1037, max_rx:100, max_tx:100, server_mask:0, descriptor_capability:00000000, mac_capability:10000000, max_buffer:127, bit_field:0100000000000010, rssi:120 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00750045' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:117, packet_type:69, error:b'', rssi:0 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8045: b'75005cdd0101' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8045 - Active endpoints : endpoints:[OrderedDict([('endpoint', 1)])], sequence:117, status:0, addr:5cdd, endpoint_count:1, rssi:123 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] REQUEST : 0x0043 b'\xdd\x01' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Msg to send b'00430003c05cdd01' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Encoded Msg to send b'0102104302100213c05cdd021103' 2018-12-01 15:37:27 DEBUG (ZiGate-Event Loop) [zigate] Waiting for status message for command 0x0043 2018-12-01 15:37:30 WARNING (ZiGate-Event Loop) [zigate] No response after command 0x0043 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00760043' 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:118, packet_type:67, error:b'', rssi:0 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8043: b'76005cdd160101045f01010400000003ffff00060300000004ffff' 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8043 - Simple descriptor : sequence:118, status:0, addr:5cdd, length:22, endpoint:1, profile:260, device:24321, bit_field:00000001, inout_clusters:b'\x04\x00\x00\x00\x03\xff\xff\x00\x06\x03\x00\x00\x00\x04\xff\xff', rssi:120, in_clusters:(0, 3, 65535, 6), out_clusters:(0, 4, 65535) 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] REQUEST : 0x0100 b'\x02\xdd\x01\x01\x00\x00\x00\x00\x00\x00\n\x00\x00\x00\x01\x00\x02\x00\x03\x00\x04\x00\x05\x00\x06\x00\x07\x00\x10\xff\x01' 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Msg to send b'0100002046025cdd01010000000000000a000000010002000300040005000600070010ff01' 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Encoded Msg to send b'01021102100210204602125cdd02110211021002100210021002100210021a0210021002100211021002120210021302100214021002150210021602100217021010ff021103' 2018-12-01 15:37:30 DEBUG (ZiGate-Event Loop) [zigate] Waiting for status message for command 0x0100 2018-12-01 15:37:33 WARNING (ZiGate-Event Loop) [zigate] No response after command 0x0100 2018-12-01 15:37:33 DEBUG (ZiGate-Event Loop) [zigate] REQUEST : 0x0100 b'\x02\xdd\x01\x01\x00\x06\x00\x00\x00\x00\x02\x00\x00\x80\x00' 2018-12-01 15:37:33 DEBUG (ZiGate-Event Loop) [zigate] Msg to send b'0100001016025cdd01010006000000000200008000' 2018-12-01 15:37:33 DEBUG (ZiGate-Event Loop) [zigate] Encoded Msg to send b'01021102100210101602125cdd0211021102100216021002100210021002120210021080021003' 2018-12-01 15:37:33 DEBUG (ZiGate-Event Loop) [zigate] Waiting for status message for command 0x0100 2018-12-01 15:37:36 WARNING (ZiGate-Event Loop) [zigate] No response after command 0x0100 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00000100' 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:256, error:b'', rssi:0 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'00010100' 2018-12-01 15:37:36 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:1, packet_type:256, error:b'', rssi:0 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8102: b'015cdd010006000086ff0000' 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:1, addr:5cdd, endpoint:1, cluster:6, attribute:0, status:134, data_type:255, size:0, data:, rssi:123 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] Receive Bad status 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8102: b'015cdd010006800086ff0000' 2018-12-01 15:37:38 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:1, addr:5cdd, endpoint:1, cluster:6, attribute:32768, status:134, data_type:255, size:0, data:, rssi:123

jalme commented 5 years ago

Ok after a couple of hours going trial and error. Got this working again.

  1. Delete zigate.json
  2. Restart HA
  3. After that one of the binary sensors was working
  4. The other one was not - got suck on open (the funny part here was that before the reboot the sensor not working was the other not this one)
  5. Pressed the non working sensor button to do a range test (saw in logs that it reported back to Zigate)
  6. Bum! issue fixed.

Will continue to monitor to see if it stops working or not.

doudz commented 5 years ago

When out of range I notice that a XIAOMI device stops working if you put it closer, you'll have to push the pairing button to force the device to start communicating again

jalme commented 5 years ago

Makes sense. Although the re-pair the first time did not work.