search

doudz / homeassistant-zigate

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

OSRAM smartplug not extending Zigbee network #18

Closed jalme closed 5 years ago

jalme commented 5 years ago

Hi,

After pairing 3 smartplugs from OSRAM (near the coordinator) and moving them to their places only one is responding to command although the others are 3 meters from the working one. Tried forcing a network reconfiguration by disconnecting the ZiGate for 15 minutes but no success.

They are supposed to act as repeaters but does't seem to be extending the Zigbee signal.

Is there a way to see the role the plugs are having in the Zigbee topology?

Regards.

Logs from the operation of trying to turn on one of the smartplugs that doesn't work:

2018-12-20 21:56:57 DEBUG (SyncWorker_0) [zigate] REQUEST : 0x0092 b'\x02\xaep\x01\x03\x01'
2018-12-20 21:56:57 DEBUG (SyncWorker_0) [zigate] Msg to send b'009200064b02ae70010301'
2018-12-20 21:56:57 DEBUG (SyncWorker_0) [zigate] Encoded Msg to send b'01021092021002164b0212ae7002110213021103'
2018-12-20 21:56:57 DEBUG (SyncWorker_0) [zigate] Waiting for status message for command 0x0092
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8000: b'001b0092'
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:27, packet_type:146, error:b'', rssi:0
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] Received response 0x8702: b'd4010302ae7000000000000036'
2018-12-20 21:56:57 DEBUG (ZiGate-Event Loop) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:212, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:12569546559991054336, sequence:54, rssi:43
2018-12-20 21:56:57 DEBUG (SyncWorker_0) [zigate] STATUS code to command 0x0092:0
jalme commented 5 years ago

Funny enough now my 0000 rogue sensor got renamed after I have paired the plugs. image

But ZigBee network is still with the same range so no change

doudz commented 5 years ago

It's funny yes, but by definition the device address 0000 is the zigate, I don't know why you have it in list Did you call refresh on that address ?

jalme commented 5 years ago

Not that I remember. I've called it now and this was the result: image

doudz commented 5 years ago

It confirms this is the zigate, I don't know how you manage to have it here

doudz commented 5 years ago

If you want to remove it, Turn off HA, edit zigate.json to remove that device, start HA

jalme commented 5 years ago

It appeared after the firmware upgrade (before calling Erase EEPROM (command 0x0012))

jalme commented 5 years ago

I'm running on docker. Can I edit the file offline. Upload it to docker and then restart HA?

doudz commented 5 years ago

You'll have to turn off HA before replacing the file, because HA will write this file on shutdown

jalme commented 5 years ago

Stopping HA means stopping the docker image which means unable to edit the files.

jalme commented 5 years ago

Actually I can replace a file inside a stopped docker image. Doing it now.

jalme commented 5 years ago

Ok after editing zigate.json the device is gone.

jalme commented 5 years ago

Happy New Year!

By any chance any clue on the osram issue?

Thanks.

doudz commented 5 years ago

Could you make some tests with the new release ?

jalme commented 5 years ago

Sure. I'll keep you posted.

jalme commented 5 years ago

Hi,

New test after updating. Plugs still not connected.

Log:

2019-01-09 18:13:27 DEBUG (SyncWorker_4) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x01'
2019-01-09 18:13:27 DEBUG (SyncWorker_4) [zigate] Msg to send b'009200060002d144010301'
2019-01-09 18:13:27 DEBUG (SyncWorker_4) [zigate] Encoded Msg to send b'010210920210021602100212d14402110213021103'
2019-01-09 18:13:27 DEBUG (SyncWorker_4) [zigate] Waiting for status message for command 0x0092
2019-01-09 18:13:27 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xfe\x02\x10\xe9\x02\x10\x92\x02\x10\x03\x01\x87\x02\x12\x02\x10\x02\x1e\x8a\xd4\x02\x11\x02\x13\x02\x12\xd1D\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10k+\x03'
2019-01-09 18:13:27 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 18:13:27 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00e90092'
2019-01-09 18:13:27 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:233, packet_type:146, error:b'', rssi:0
2019-01-09 18:13:27 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 18:13:27 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8702: b'd4010302d1440000000000006b'
2019-01-09 18:13:27 DEBUG (SyncWorker_4) [zigate] STATUS code to command 0x0092:0
2019-01-09 18:13:27 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:212, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:107, rssi:43
2019-01-09 18:13:27 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:212, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:107, rssi:43
2019-01-09 18:13:37 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x87\x02\x11\x02\x10\x02\x13U\xd0\x02\x10\x02\x10\x03'
2019-01-09 18:13:37 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 18:13:37 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8701: b'd000'
2019-01-09 18:13:37 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8701 - Route Discovery Confirmation : status:208, network_status:0, rssi:0
2019-01-09 18:13:37 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
jalme commented 5 years ago

Saw a weird behavior.

Moving the plug to a near location of ZiGate the plug start to work:

2019-01-09 18:24:43 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x01'
2019-01-09 18:24:43 DEBUG (SyncWorker_1) [zigate] Msg to send b'009200060002d144010301'
2019-01-09 18:24:43 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'010210920210021602100212d14402110213021103'
2019-01-09 18:24:43 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0092
2019-01-09 18:24:44 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xea\x02\x10\xfd\x02\x10\x92\x02\x10\x03'
2019-01-09 18:24:44 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10\x02\x1eB\x02\x17\xd1D\x02\x13\x02\x10\x02\x16\x02\x10\x02\x10\x02\x10\x10\x02\x10\x02\x11\x02\x11H\x03'
2019-01-09 18:24:44 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00fd0092'
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:253, packet_type:146, error:b'', rssi:0
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'07d14403000600000010000101'
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:7, addr:d144, endpoint:3, cluster:6, attribute:0, status:0, data_type:16, size:1, data:True, rssi:72
2019-01-09 18:24:44 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0092:0
2019-01-09 18:24:44 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED

Moving to its previous location where it is not working it respond to the first "turn on" command but then stops responding (note: this location is about 10 meters from the working plug that is supposed to extend the network). Log:

2019-01-09 18:27:43 DEBUG (SyncWorker_0) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x01'
2019-01-09 18:27:43 DEBUG (SyncWorker_0) [zigate] Msg to send b'009200060002d144010301'
2019-01-09 18:27:43 DEBUG (SyncWorker_0) [zigate] Encoded Msg to send b'010210920210021602100212d14402110213021103'
2019-01-09 18:27:43 DEBUG (SyncWorker_0) [zigate] Waiting for status message for command 0x0092
2019-01-09 18:27:43 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xe8\x02\x10\xff\x02\x10\x92\x02\x10\x03'
2019-01-09 18:27:43 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x87\x02\x12\x02\x10\x02\x1ev\xe9\x02\x11\x02\x13\x02\x12\xd1D\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x81\x02\x10\x03'
2019-01-09 18:27:44 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 18:27:44 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00ff0092'
2019-01-09 18:27:44 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:255, packet_type:146, error:b'', rssi:0
2019-01-09 18:27:44 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 18:27:44 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8702: b'e9010302d14400000000000081'
2019-01-09 18:27:44 DEBUG (SyncWorker_0) [zigate] STATUS code to command 0x0092:0
2019-01-09 18:27:44 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:233, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:129, rssi:0
2019-01-09 18:27:44 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:233, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:129, rssi:0
jalme commented 5 years ago

Hi,

Need more time to test this properly. I'm having mixed results. It seems the network has converged and things are starting to work although not at 100%. I'll keep you posted.

jalme commented 5 years ago

Ok. This is weird. After restarting HA it all works fine. Even the more distant plug work. Log of a successful turn on and then turn off operation:

2019-01-09 20:11:01 DEBUG (SyncWorker_4) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x00'
2019-01-09 20:11:01 DEBUG (SyncWorker_4) [zigate] Msg to send b'009200060102d144010300'
2019-01-09 20:11:01 DEBUG (SyncWorker_4) [zigate] Encoded Msg to send b'010210920210021602110212d14402110213021003'
2019-01-09 20:11:01 DEBUG (SyncWorker_4) [zigate] Waiting for status message for command 0x0092
2019-01-09 20:11:01 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xf3\x02\x10\xe4\x02\x10\x92\x02\x10\x03'
2019-01-09 20:11:01 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00e40092'
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:228, packet_type:146, error:b'', rssi:0
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 20:11:01 DEBUG (SyncWorker_4) [zigate] STATUS code to command 0x0092:0
2019-01-09 20:11:01 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10\x02\x1e\x1d(\xd1D\x02\x13\x02\x10\x02\x16\x02\x10\x02\x10\x02\x10\x10\x02\x10\x02\x11\x02\x109\x03'
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'28d14403000600000010000100'
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:40, addr:d144, endpoint:3, cluster:6, attribute:0, status:0, data_type:16, size:1, data:False, rssi:57
2019-01-09 20:11:01 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2019-01-09 20:11:07 DEBUG (SyncWorker_1) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x01'
2019-01-09 20:11:07 DEBUG (SyncWorker_1) [zigate] Msg to send b'009200060002d144010301'
2019-01-09 20:11:07 DEBUG (SyncWorker_1) [zigate] Encoded Msg to send b'010210920210021602100212d14402110213021103'
2019-01-09 20:11:07 DEBUG (SyncWorker_1) [zigate] Waiting for status message for command 0x0092
2019-01-09 20:11:07 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xf2\x02\x10\xe5\x02\x10\x92\x02\x10\x03'
2019-01-09 20:11:07 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00e50092'
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:229, packet_type:146, error:b'', rssi:0
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 20:11:07 DEBUG (SyncWorker_1) [zigate] STATUS code to command 0x0092:0
2019-01-09 20:11:07 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10\x02\x1e\x1b)\xd1D\x02\x13\x02\x10\x02\x16\x02\x10\x02\x10\x02\x10\x10\x02\x10\x02\x11\x02\x11?\x03'
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'29d14403000600000010000101'
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:41, addr:d144, endpoint:3, cluster:6, attribute:0, status:0, data_type:16, size:1, data:True, rssi:63
2019-01-09 20:11:07 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED

A couple of minutes later the plug stops responding to commands and gets stuck (I have 4 and only two show this behavior). Log of a turn off command that didn't succeeded:

2019-01-09 20:13:21 DEBUG (SyncWorker_0) [zigate] REQUEST : 0x0092 b'\x02\xd1D\x01\x03\x00'
2019-01-09 20:13:21 DEBUG (SyncWorker_0) [zigate] Msg to send b'009200060102d144010300'
2019-01-09 20:13:21 DEBUG (SyncWorker_0) [zigate] Encoded Msg to send b'010210920210021602110212d14402110213021003'
2019-01-09 20:13:21 DEBUG (SyncWorker_0) [zigate] Waiting for status message for command 0x0092
2019-01-09 20:13:21 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\xf1\x02\x10\xe6\x02\x10\x92\x02\x10\x03\x01\x87\x02\x12\x02\x10\x02\x1ec\xd4\x02\x11\x02\x13\x02\x12\xd1D\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x02\x10\x82+\x03'
2019-01-09 20:13:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2019-01-09 20:13:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00e60092'
2019-01-09 20:13:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:230, packet_type:146, error:b'', rssi:0
2019-01-09 20:13:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2019-01-09 20:13:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8702: b'd4010302d14400000000000082'
2019-01-09 20:13:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:212, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:130, rssi:43
2019-01-09 20:13:21 DEBUG (SyncWorker_0) [zigate] STATUS code to command 0x0092:0
2019-01-09 20:13:21 ERROR (ZiGate-Decode data) [zigate] RESPONSE 0x8702 - APS Data Confirm Fail : status:212, source_endpoint:1, dst_endpoint:3, dst_address_mode:2, dst_address:15079177452343263232, sequence:130, rssi:43
jalme commented 5 years ago

by the way if I manually turn on then turn off the plug starts working again.... (I don't unplug it)

biau commented 5 years ago

I think when you turn it on or off manually the plug discover a new route.

doudz commented 5 years ago

Closing since not related to HA component but zigate itself