Not seeing this in my end, sorry.
Is anyone here that is having an issue running dev? If so, can you change your /home-assistant/homeassistant/components/wink.py requirements line from this
REQUIREMENTS = ['python-wink==0.11.0', 'pubnubsub-handler==0.0.5']
to this
REQUIREMENTS = ['python-wink==0.11.0', 'pubnubsub-handler==0.0.6']
Then reinstall home-assistant and reboot/restart, and see if you have the same problems.
I found something (I think is new) in the pubnub docs called reconnection_policy and it defaults to None.
It allows pubnub to attempt automatic reconnects on failures. I set it to exponential reties so it will continue to retry forever with a larger and larger sleep between retries.
Also if you would like to check if you pubnub connection is active, run the following command about 2 minutes after Home-assistant starts up.
netstat -anp --tcp | grep ' 54\.'
You will get an output like this.
tcp 0 0 192.168.5.4:42808 54.209.255.73:443 ESTABLISHED -
tcp 0 0 192.168.5.4:42810 54.209.255.73:443 ESTABLISHED -
You should see two connections to two 54. address for the entire life of HA. If a pubnub connection goes down you will lose one or both of these connections.
So if would be helpful to know if those connections are still up when you guys stop getting updates.
**Note: 54. are Amazon servers so if you have any other connections to some sort of Amazon service you will see more of these.
I am not running dev. I am not getting updates to any Wink components. I do have those 2 connections.
pi@raspberrypi:~ $ netstat -anp --tcp | grep ' 54\.'
(No info could be read for "-p": geteuid()=1000 but you should be root.)
tcp 0 0 192.168.1.125:57562 54.209.255.71:443 ESTABLISHED -
tcp 0 0 192.168.1.125:41559 54.173.239.223:19853 ESTABLISHED -
Only errors are:
16-12-29 10:01:08 pywemo.ssdp: Error fetching description at https://192.168.1.106:8888
16-12-29 10:02:16 netdisco.ssdp: Error fetching description at https://192.168.1.106:8888
16-12-29 10:51:28 homeassistant.components.wink: Error in pubnub JSON for Office Remote hub polling API for current state
16-12-29 10:51:29 pubnub: take message interrupted: 'NoneType' object has no attribute 'loop'Good to know, thanks. I have also updated the version of pubnub to 4.0.4 from 4.0.2 as well so there could be some fixes for that issue possibly.
I do not have any GoControl PIR, only things connected to my Wink (1.0) are 2 different types of Cree Connected bulbs (14 total). Sometimes they do not show the current/correct state (in HA) but a restart of HA corrects it until next time. I have not review any logs. I have tried rebooting the Wink as well but the problem seem tied to HA as when this situation occurs I can still control them via Alexa/Echo and the Wink app (shows correct status).
What version of HA are you running and how long are you running when this issue starts?
Also, if you get a chance to review your logs that would be great.
0.35.3 and it has not appeared within 12 hours of a restart. The times I have noticed it have been after I come home at night or when I wake up in the morning. I often tinker with HA in the early morning so it is not uncommon for me to restart it then or after modifying something in the evening.
The invalid switches on top are from dummy switches I created for the wife (multi-fixture Crees into a simple switch) Current log (not sure if experiencing a problem until I get home later):
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:54:39 homeassistant.components.switch.template: Received invalid switch is_on state: none. Expected: on, off, true, false
16-12-28 19:55:13 netdisco.ssdp: Error fetching description at https://192.168.1.77:8888
16-12-28 19:55:35 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_upload', 'unknown', 1, 0)]
16-12-28 19:55:37 homeassistant.components.zwave: zwave not ready after 30 seconds, continuing anyway
16-12-28 19:55:40 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_upload', 'unknown', 1, 0)]
16-12-28 19:55:46 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_upload', 'unknown', 1, 0)]
16-12-28 19:57:05 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 19:58:05 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 19:58:13 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_upload', 'unknown', 1, 0)]
16-12-28 19:58:35 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 19:59:35 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 19:59:40 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 20:00:05 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 20:00:20 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created) VALUES (?, ?, ?, ?, ?, ?, ?, ?)'] [parameters: ('sensor', 'sensor.pws_precip_today_in', '0.00', '{"unit_of_measurement": "in", "icon": "mdi:weather-rainy", "attribution": "Data provided by the WUnderground weather service", "friendly_name": "Precipitation Today"}', 64050, '2016-12-29 01:54:59.328696', '2016-12-29 01:54:59.328696', '2016-12-29 02:00:15.563863')]
16-12-28 20:00:35 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 20:00:40 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 20:00:45 homeassistant.components.recorder: Error during query: (sqlite3.OperationalError) database is locked [SQL: 'SELECT states.state_id AS states_state_id, states.domain AS states_domain, states.entity_id AS states_entity_id, states.state AS states_state, states.attributes AS states_attributes, states.event_id AS states_event_id, states.last_changed AS states_last_changed, states.last_updated AS states_last_updated, states.created AS states_created \nFROM states \nWHERE states.entity_id = ? AND states.last_changed = states.last_updated AND states.state != ? ORDER BY states.state_id DESC\n LIMIT ? OFFSET ?'] [parameters: ('sensor.speedtest_download', 'unknown', 1, 0)]
16-12-28 20:55:06 homeassistant.components.updater: Got unexpected response: None
16-12-28 21:58:05 homeassistant.core: Error doing job: Fatal read error on socket transport
Traceback (most recent call last):
File "/usr/lib/python3.4/asyncio/selector_events.py", line 582, in _read_ready
data = self._sock.recv(self.max_size)
OSError: [Errno 113] No route to host
16-12-29 09:23:10 homeassistant.components.sensor.rest: Error fetching data: <PreparedRequest [GET]>
16-12-29 10:05:40 homeassistant.components.sensor.rest: Error fetching data: <PreparedRequest [GET]>Iām not running dev build (donāt have the skills yet for that) and I still havenāt seen the error again, but Iāll keep checking and if I do see it Iāll run the netstat and report back.
I changed the connection method for Wink from access token to user, pass, client ID and secret. This problem went away. (knocking on wood.) No more PubNub errors and Wink reporting states normally.
Yeah, I went that route the day it was released but still getting errors. Latest error today:
17-01-04 09:16:04 homeassistant.components.wink: Error in pubnub JSON for Wink Relay hub polling API for current state
17-01-04 09:16:05 pubnub: take message interrupted: 'NoneType' object has no attribute 'loop'Odd. Still working for me. No pubnub errors.
Not sure if it will work, but can you try to test something for me?
Copy this file https://github.com/w1ll1am23/home-assistant/blob/wink_fan/homeassistant/components/wink.py
into PATH TO YOUR CONFIG DIRECTORY/custom_components/wink.py
Then reboot home assistant. I think that will overwrite the base wink component with the updated version of pubnubsub-handler and pubnub. There are some connection handling changes that may fix this issue.
Pubnub has reached out to me again asking if we have been able to test their new version, so I would like to test this soon and not have to wait for it to get into production.
You can verify if this worked by checking to see if PATH TO YOUR CONFIG DIRECTORY/deps/pubnubsub_handler-0.0.6.dist-info exists after the reboot.
Iāll test this but I want to do a full back up first. Iāll check in later in the day.
Awesome. Can you make one small change to the file before you restart home assistant?
Change this line
REQUIREMENTS = ['python-wink==0.12.0', 'pubnubsub-handler==0.0.6']
to this
REQUIREMENTS = ['python-wink==0.12.0', 'pubnubsub-handler==0.0.7']
0.0.7 is running pubnub 4.0.5 which pubnub says they made additional changes to. 0.0.6 is running pubnub 4.0.4.
Didnāt get a chance to try this last night. Will try later today. Iāll also switch back to the access token before to see if the problem comes back. If not Iām guessing my test wonāt help much. Iāll report back either way.
Me either. I spent the night trying to get my Pi moved from the Wifi to eth0 with a static IP but no matter what I did, it wouldnāt come up with the correct IP address. I think I am having some Wifi issues and I wanted to move the Pi over but I gave up after a hour or so.
Might give this a shot later today though.
I put your file in custom_components and made the change. Everything is working fine. No pubnub errors. I did change back to access token again and itās working too. May be a bit of placebo effect but updates seem very snappy now. Anyway all working as expected. Only errors are the netdisco and pywemo not recognizing the Wink hub.
Glad to hear everything is working. How long would you run the previous version before seeing issues? If you can, please continue to provide updates good or bad. I would like to let pubnub know the status of the new version early next week.
The errors would occur very quickly. I would test using a Lutron Zigbee remote connected to Wink controlling 2 GE link bulbs in my office. As soon as I used the remote it would trip the error and then no more updates from Wink.
Iām happy to say that the only errors I have now are the same 2 I mentioned above. Thatās never happened. I almost always have a few errors in the log and they grow over time. Iām not doing any controlled tests unfortunately but so far this is working as well as it ever has.
I will keep you posted.
Still all good. I did restart HASS for another reason today but everything working as expected. Only a couple of extra errors from darksky.
homeassistant.components.sensor.darksky: Unable to connect to Dark Sky. EOF occurred in violation of protocol (_ssl.c:600)