Plugwise Plugs component

hapklaar · June 1, 2020, 6:46pm

Not having much success with this release. After re-adding the integration some devices have status unknown, they were working fine before. Both my Stealth devices were discovered as Circles, but also have status unknown.

Removed integration again, then rebooted hass box, then integrated again. Now the thread seems to die a few seconds after starting HA, after which nothing ‘[plugwise]’ shows up in the logs anymore (on debug level). After another full reboot, it seems to work again, but only finds 7 of my 13 devices.

Also noticed that when I remove the stick the entire OS freezes and needs a hard power cycle to get back online. This is new, was able to do that without issue before. Not sure if this integration can even cause this, but thought I’d mention it to be sure.

Will test some more later.

brefra · June 3, 2020, 8:30pm

@hapklaar, thanks for reporting.
I did some investigation and found a nasty bug when one (or more) node is not reachable during the discover it fails completely. Discovered a second issue closing the port too.
~~Currently busy to get this resolved asap…~~

Update: I’ve updated the custom component which contains the fixes.
It also supports discovery of plugwise device after the initial scan during the startup of HA (or integration)
During the first hour it will try to discovery any missed device at every update cycle. There after it wil continues to try to discovery but only once an hour.

bouwew · June 6, 2020, 9:10am

@brefra, thanks for the update.

Unfortunately, it’s not working, I see no change from my previous reported situation: the Circle+ still shows “unknown”:

I’ve removed and readded the integration to be sure that the old setup does not interfere.

hapklaar · June 6, 2020, 10:41am

@brefra nice!

Just installed and initial findings are this one seems to work fine for me! Immediately found all my 12 Circles and 2 Stealths (still detected as Circle though). After a few minutes all entities had values

Will leave it running for a while and report back later.

@bouwew
Not sure if any of this matters, but these are the steps I took to successfully install the new version:

Remove plugwise_stick integration from HA
Stop HA through web interface
Move /custom_components/plugwise_stick folder to a backup location
Create new /custom_components/plugwise_stick folder
Download plugwise_stick.zip into that folder and unpack
Start HA (in my case with ‘sudo docker start homeassistant’)
Add integration

bouwew · June 6, 2020, 11:02am

@hapklaar I did it in the same way, I know HA Core quite well.

Tried it once more, same result, still "unkown"s for the Circle+

I wonder, have I downloaded the correct file, this is what I have:

@brefra, maybe better to use a unique filename for every new version to avoid caching issues, I suspect that’s my problem?
I did empty my browser’s cache etc.

hapklaar · June 6, 2020, 11:16am

I have a different date for the manifest.json, looks like you’re still using the old version. Easy way to tell is if it contains a reference to the new python-plugwise version 0.8:

{
  "domain": "plugwise_stick",
  "name": "Plugwise USB-stick",
  "documentation": "https://www.home-assistant.io/integrations/plugwise_stick",
  "config_flow": true,
  "codeowners": ["@brefra"],
  "requirements": ["python-plugwise==0.8"]
}

bouwew · June 6, 2020, 11:34am

In my manifest.json there is also version 0.8. Based on that I should have the correct, new files.

Based on that, the new files still result in the “unknown” state for the Circle+ sensor. So the bug is still there in my system.

In my log it says:

2020-06-06 12:59:26 DEBUG (MainThread) [custom_components.plugwise_stick] Connect to USB-Stick
2020-06-06 12:59:26 DEBUG (MainThread) [custom_components.plugwise_stick] Initialize USB-stick
2020-06-06 12:59:27 DEBUG (MainThread) [custom_components.plugwise_stick] Discover Plugwise nodes
2020-06-06 12:59:39 DEBUG (Thread-39) [custom_components.plugwise_stick] Successfully discovered 2 plugwise nodes

pposthoorn · June 6, 2020, 3:56pm

I’ve tried once more to to install this as a custom component integration with the steps mentioned by @hapklaar.
When I click the Plugwise Stick to add the integration the interfaces loads for a bit and then goes back to the integrations overview page. Looking in the logs I find this entry:

Error occurred loading configuration flow for integration plugwise_stick: cannot import name 'NetworkDown' from 'plugwise.exceptions' (/config/deps/lib/python3.7/site-packages/plugwise/exceptions.py)

bouwew · June 6, 2020, 5:13pm

@hapklaar can you please share the plugwise_stick.zip-file that you have on your HDD/SDD?

hapklaar · June 6, 2020, 6:08pm

Sure, but it’s the one I downloaded from the link provided by @brefra

Here you go https://www.dropbox.com/s/3qzo0bp5a6va0g9/plugwise_stick.zip?dl=0

bouwew · June 6, 2020, 6:35pm

Thank you! It’s the same one I have. So that is now clear

This means the “unknown”-bug is still there for the Circle+ in my system.

brefra · June 7, 2020, 9:31am

Thanks all for reporting back. Sorry about the confusion of the versions. I’ll make it more clear what’s the latest one.

I’ve to investigate the unknown issue a bit more. I guess it’s some kind of timing issue during startup. Every entity will have unknown at startup and get the actual state/value as soon as the first state update is reported back. Does the unknown value disappear overtime when the sensor should report a changed value (second update)?

About the stealth devices being detected as circles. The detection is based on the “device type ID” inside in the information message sent by the device. So the firmware is reporting it as an circle. I guess this applies to the source software as well?

hapklaar · June 7, 2020, 11:29am

Source is actually detecting them as Stealth. Anything I can check regarding the information message sent by my Stealth? How can I read this?

In the mean time everything is still working as intended for me. I’ve removed the daily reboot now and will see if it stays functional for longer than a couple of days without restarting.

bouwew · June 7, 2020, 2:25pm

My Circle+ that shows the states unknown is actually not connected to a load, so it’s values should be all zero, they were all zero before when it worked.
It’s just powered because it’s needed for detection of the Circle that is there too.

brefra · June 8, 2020, 6:13pm

@hapklaar

Anything I can check regarding the information message sent by my Stealth? How can I read this?

It would be helpful to have a debug log of the inital startup when the discovery takes places.

Edit: Found the “Unknown” issue and fixed it in plugwise_stick_0.8.zip. Only the sensor.py has changed.

bouwew · June 9, 2020, 6:37am

Thanks! The "unknown"s are gone

hapklaar · June 9, 2020, 8:20am

Running into the issue I had earlier again. After restarting HA, it starts with a discover of the Circle+ and immediately times out, then thread seems to die. No more lines follow in the log.

2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] Open USB serial connection to Plugwise Zigbee stick
2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] Open serial port
2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] Successfully connected to serial port /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A5013Y63-if00-port0
2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] Successfully connected to port /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A5013Y63-if00-port0
2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] Starting threads...
2020-06-09 10:15:45 DEBUG (SyncWorker_12) [plugwise] All threads started
2020-06-09 10:15:45 DEBUG (SyncWorker_14) [plugwise] Send init request to Plugwise Zigbee stick
2020-06-09 10:15:45 DEBUG (send_messages_deamon) [plugwise] send StickInitRequest using seq_id b'0000'
2020-06-09 10:15:45 DEBUG (write_packets_process) [plugwise] Sending StickInitRequest to plugwise stick (b'\x05\x05\x03\x03000AB43C\r\n')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Feed data: b'\x05'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Feed data: b'\x05\x03\x030000087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Parse data: b'\x05\x05\x03\x030000087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588' 
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'\x05\x05\x03\x030000087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message header found at index 0
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x030000087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message footer found at index 20
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Success acknowledge on message request with sequence id b'0871'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Reset parser : b'00087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Parse data: b'00087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588' 
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'00087100C1A501\r\n\x05\x05\x03\x0300110871000D6F0002588')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message header found at index 16
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x0300110871000D6F0002588')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] No valid message footer found yet
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Feed data: b'4'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Parse data: b'\x05\x05\x03\x0300110871000D6F00025884' 
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'\x05\x05\x03\x0300110871000D6F00025884')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message header found at index 0
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x0300110871000D6F00025884')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] No valid message footer found yet
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Feed data: b'2E0101220D6F0002588DB0DD22FF2EB2\r\n\x83'
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Parse data: b'\x05\x05\x03\x0300110871000D6F000258842E0101220D6F0002588DB0DD22FF2EB2\r\n\x83' 
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'\x05\x05\x03\x0300110871000D6F000258842E0101220D6F0002588DB0DD22FF2EB2\r\n\x83')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message header found at index 0
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x0300110871000D6F000258842E0101220D6F0002588DB0DD22FF2EB2\r\n\x83')
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Valid message footer found at index 58
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] New StickInitResponse message with seq id b'0871' for 000D6F000258842E
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] StickInitResponse request with seq id b'0000' processed
2020-06-09 10:15:45 DEBUG (Thread-2) [plugwise] Reset parser : b'\x83'
2020-06-09 10:15:47 DEBUG (MainThread) [plugwise] Discover Circle+ at 000D6F0002588DB0
2020-06-09 10:15:47 DEBUG (send_messages_deamon) [plugwise] send NodeInfoRequest to 000D6F0002588DB0 using seq_id b'0872'
2020-06-09 10:15:47 DEBUG (write_packets_process) [plugwise] Sending NodeInfoRequest to plugwise stick (b'\x05\x05\x03\x030023000D6F0002588DB02DA1\r\n')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Feed data: b'\x05'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Feed data: b'\x05\x03\x030000087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Parse data: b'\x05\x05\x03\x030000087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83' 
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'\x05\x05\x03\x030000087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Valid message header found at index 0
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x030000087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Valid message footer found at index 20
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Success acknowledge on message request with sequence id b'0872'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Reset parser : b'00087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Parse data: b'00087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83' 
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'00087200C14BD3\r\n# APSRequestNodeInfo: Source MAC: 000D6F000258842E# APSRequestNodeInfo: Destination MAC: \r\n000D6F0002588DB0\r\n\x05\x05\x03\x030000087200E1E175\r\n\x83')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Valid message header found at index 125
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Lookup message footer (b'\r\n') in (b'\x05\x05\x03\x030000087200E1E175\r\n\x83')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Valid message footer found at index 20
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Timeout acknowledge on message request with sequence id b'0872'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] NodeInfoResponse request with seq id b'0872' processed
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Network time out received for (1 of 3) of NodeInfoRequest to 000D6F0002588DB0, resend request
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Reset parser : b'00087200E1E175\r\n\x83'
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Parse data: b'00087200E1E175\r\n\x83' 
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] Lookup message header (b'\x05\x05\x03\x03') in (b'00087200E1E175\r\n\x83')
2020-06-09 10:15:47 DEBUG (Thread-2) [plugwise] No valid message header found yet

PS: one reboot and a HA restart later and it’s running again.
PS2: uploaded the debug log here. Example mac for a Shield: 000D6F000416BA68 which is seen as Node type Circle. Guess Source uses some other field to detect it as a Shield?

brefra · June 9, 2020, 6:51pm

The failed startup is because the circle+ is not responding to the initial discovery request message. The stick responds with a timeout message. Apparently the current code isn’t handling this response very well. I’ll try to get fixed.

The log shows some “network redirect” messages which indicates the circle+ is not directly reachable by the stick. You might try to get them closer together if possible

Will have a look into the other log asap.

Edit:
I’ve release a new version plugwise_stick_0.9.1.zip. This version handles communication failures to the Circle+ mutch better. During startup HA will now continue to retry the setup of the integration when it fails to communicate with the Circle+ node.
So no more restarts required of HA when the Circle+ is not reachable during startup.

hapklaar · June 20, 2020, 8:20am

Been running just fine for 11 days now, system had some reboots and due to updates and had no issues with Circle communication as far as I can see. Nice one!

bouwew · July 9, 2020, 8:11am

@All, please don’t forget to VOTE at the top of this topic, hopefully this will help getting this component into HA Core.