Integration stops working after several hours

Question

Integration stops working after several hours

darootler opened this issue 5 years ago · 103 comments

Hi!

I am using Home Assistant 0.102.3 and Home Connect 0.2.3 (installed via HACS). For me this integration just stops updating the entities after several hours. If i restart HA the integration is working again for several hours.

I have set up an automation wich notifies me if the dishwasher finished the program, this automation just stops working because the sensor never updates:

Anything i am doing wrong here? Any suggestions?

Regards
Richard

Answer 1 · 2019-12-02T20:01:47.000Z

Is there anyting in the logs? If now, could you enable debug logging and check? Maybe the SSE listener drops connection and doesn't reconnect (which it should in principle) or maybe token refresh failed (which is now handled internally by Home Assistant).

When the sensor stops updating, can you try if you can still do things like starting programs or switching on/off? I'm asking because these trigger direct calls to the API rather than listening to a stream, so if they don't work either, it indicates a permission problem or the API being down.

Answer 2 · 2019-12-02T20:08:12.000Z

Is there anyting in the logs? If now, could you enable debug logging and check? Maybe the SSE listener drops connection and doesn't reconnect (which it should in principle) or maybe token refresh failed (which is now handled internally by Home Assistant).

When the sensor stops updating, can you try if you can still do things like starting programs or switching on/off? I'm asking because these trigger direct calls to the API rather than listening to a stream, so if they don't work either, it indicates a permission problem or the API being down.

I will check that tomorrow. Enabling debug logging on my raspberry will lock the SD card down and make the whole system nearly unusable, maybe we can determine the problem without that.

Regards
Richard

Answer 3 · 2019-12-02T20:17:15.000Z

OK thanks in advance!
(In principle I think one can enable debug logging for individual components, but I never actually tried.)

Answer 4 · 2019-12-02T20:19:15.000Z

OK thanks in advance!
(In principle I think one can enable debug logging for individual components, but I never actually tried.)

Yes, thats possible. If we need it i will try that.

Regards
Richard

Answer 5 · 2019-12-03T21:23:17.000Z

I just checked the entities and they are "out of sync" now:

Is there a way to help troubleshoot the problem? There are no warnings or errors according to home connect in the logs.

Regards
Richard

Answer 6 · 2019-12-04T07:26:55.000Z

Did you try if you can still switch power or start programs after they go out of sync? If no, does that lead to something in the log? If yes, I think it's defintely due to SSE dropping connection, that would be good to know.

Answer 7 · 2019-12-04T07:50:34.000Z

Did you try if you can still switch power or start programs after they go out of sync? If no, does that lead to something in the log? If yes, I think it's defintely due to SSE dropping connection, that would be good to know.

I am able to start the dishwasher but that does not update the sensors. What is SSE?

Regards
Richard

Answer 8 · 2019-12-04T21:17:23.000Z

Thanks! That's indeed useful.
SSE (server sent events) is a stream that allows the API to push events rather than requiring polling. Home Assistant opens a separate thread for each HC device and listens to events on these streams, but it seems the connection dies and is not restarted.

Answer 9 · 2019-12-04T21:27:28.000Z

I see. Are you able to reproduce that behavior? Is there anything i can do?

Regards
Richard

Answer 10 · 2019-12-05T06:52:35.000Z

Yes, I think I have also run into this problem now. I will have to look at the SSE implementation in the homeconnect Python library and see if I can find a bug there. I'll update you when there is something new to test.

Answer 11 · 2019-12-16T16:57:43.000Z

Now I am completely green with respect to this code (been using HA for two weeks now), but if nothing is going over the line, the connection will get killed by a router doing NAT.

Answer 12 · 2020-01-06T10:33:41.000Z

Oops. As stated in the commit message, this is an attempted fix. I'll now update the HA component with this and would be grateful about testing.

Answer 13 · 2020-01-06T10:59:41.000Z

Will this potential fix be part of a release or do i have to update the custom component manually?

Regards
Richard

Answer 14 · 2020-01-06T11:35:33.000Z

I will publish a release later today.

Answer 15 · 2020-01-09T13:00:53.000Z

Still same issue when used in HA.

Br
Reidar

Answer 16 · 2020-01-10T07:25:34.000Z

I had the impression that before te latest changes, with HA 103.5 it was better. Everything was still working after 24H.

Answer 17 · 2020-01-10T07:28:31.000Z

I don't see how it could have gotten worse. So what are you seeing now? Any errors in the log? Do all your appliance stop updating at the same time? (Each of them is listened to in a separate thread, so I would expect them not to fail simultaneously.)

Answer 18 · 2020-01-11T08:43:04.000Z

I can confirm that this problem still persists.

Regards
Richard

Answer 19 · 2020-02-03T19:38:21.000Z

With 104.3 HA stopps updating after 20 - 24 hours
The Log shows this:
homeassistant | File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 72, in __next__ homeassistant | File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 217, in _listen homeassistant | File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 81, in __next__ homeassistant | File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 51, in _connect

Answer 20 · 2020-02-03T19:41:39.000Z

Thanks! Does the traceback continue? I would be curious which exception it raises.

Answer 21 · 2020-02-03T19:55:29.000Z

�[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant |�[0m
�[36mhomeassistant �[36mhomeassistant |�[0m
�[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant �[36mhomeassistant |�[0m Exception in thread Thread-3:
|�[0m Traceback (most recent call last):
|�[0m File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 72, in next
|�[0m next_chunk = next(self.resp_iterator)
|�[0m StopIteration
|�[0m During handling of the above exception, another exception occurred:
|�[0m Traceback (most recent call last):
|�[0m File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner
|�[0m self.run()
|�[0m File "/usr/local/lib/python3.7/threading.py", line 870, in run
|�[0m self._target(*self._args, **self._kwargs)
|�[0m File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 217, in _listen
|�[0m for event in sse:
|�[0m File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 81, in next
|�[0m self._connect()
|�[0m File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 51, in _connect
|�[0m self.resp = requester.get(self.url, stream=True, **self.requests_kwargs)
|�[0m File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 546, in get
|�[0m return self.request('GET', url, **kwargs)
|�[0m File "/usr/local/lib/python3.7/site-packages/requests_oauthlib/oauth2_session.py", line 478, in request
|�[0m url, http_method=method, body=data, headers=headers
|�[0m File "/usr/local/lib/python3.7/site-packages/oauthlib/oauth2/rfc6749/clients/base.py", line 198, in add_token
|�[0m raise TokenExpiredError()
|�[0m oauthlib.oauth2.rfc6749.errors.TokenExpiredError: (token_expired)

Answer 22 · 2020-02-03T20:04:47.000Z

Oooh. That might be why I wasn't able to understand this. It's not actually a problem with the SSE stream, it's a problem with auth! Thanks a lot for this hint!

Now the question is why the token is not refreshed. I thought that HA internally takes care of this but maybe I misunderstood. I will ask the core devs.

Answer 23 · 2020-02-03T20:20:57.000Z

So here is my theory: Home Assistant refreshes the tokens (otherwise I wouldn't be able to switch on/off my devices several days after HA startup), but this is not propagated to the threads that listen to the SSE stream, since they are supplied with a copy of the Auth instance that becomes stale after 24h.

So a solution would probably either be catching the TokenExpiredError and restarting the thread and/or restarting the thread on token refresh.

If anyone has a more educated view on this I'd be grateful.

Answer 24 · 2020-02-12T22:07:52.000Z

I just released homeconnect v0.40 with a possible fix and this is now used in the master branch of the Home Assistant integration. I just restarted my own instance, I'll know in 24h hours whether it works... would be curious about feedback from others as well.

Answer 25 · 2020-02-15T09:50:28.000Z

I installed the "master" branch via HACS and unfortunately the problem still persists.

Regards
Richard

Answer 26 · 2020-02-15T11:22:41.000Z

Thanks, I can confirm 😕

Answer 27 · 2020-02-15T13:13:16.000Z

It might be a new issue. The log I posted in #3 (comment)
happened 20 - 24 hours after a restart of homeassistant.( with version 104.3)
Since I have updated to 105.x homeconnect stops updating between 50 to 120 minutes after restarting homeassistant - I can't see anything in the logs:
But going back to 104.3 dosn't change anything - homeconnect stops updating 50- 120 minutes after restarting homeassistant.

Answer 28 · 2020-02-17T12:53:53.000Z

Same Issue over here unfortunately.
Dishwasher and Hoven

Answer 29 · 2020-02-26T06:38:03.000Z

That it stops after 50-120 minutes I find very surprising. Is this observed by others as well? I just tested on an otherwise empty installation of HA 0.105.5 and all the devices are still reporting state updates after more than 9 hours.

Answer 30 · 2020-02-26T06:46:51.000Z

It changes, I’ve had cases where it was still working after 24h, but also cases where it stopped within 50 mins.

Answer 31 · 2020-02-26T06:54:48.000Z

Thats why I wrote that it might be a new issue. The switches work correct, I'm able to switch on the dishwasher, but the state reported in HA remains off. I will try to make a fresh installation with no other integrations.

Answer 32 · 2020-02-26T07:54:54.000Z

OK thanks. I just added some more logging to the SSE client module, released this as v0.4.1 and bumped the dependency in the homeassistant-homeconnect master branch. Hopefully this makes debugging easier.

Answer 33 · 2020-02-27T18:17:24.000Z

OK, I think we're making progress. With the new logging, I got

2020-02-27 08:46:38 ERROR (Thread-4) [homeconnect.sseclient] 
2020-02-27 08:46:38 ERROR (Thread-3) [homeconnect.sseclient] 
2020-02-27 08:46:38 ERROR (Thread-5) [homeconnect.sseclient] 
2020-02-27 08:46:39 INFO (Thread-4) [homeconnect.sseclient] Connecting ...
2020-02-27 08:46:39 INFO (Thread-3) [homeconnect.sseclient] Connecting ...
2020-02-27 08:46:39 INFO (Thread-5) [homeconnect.sseclient] Connecting ...
2020-02-27 08:46:39 ERROR (Thread-5) [homeconnect] Token expired in event stream for device Kochfeld
2020-02-27 08:46:39 ERROR (Thread-3) [homeconnect] Token expired in event stream for device Trockner
2020-02-27 08:46:39 INFO (Thread-5) [homeconnect.sseclient] Connecting ...
2020-02-27 08:46:39 ERROR (Thread-4) [homeconnect] Token expired in event stream for device Backofen
2020-02-27 08:46:39 INFO (Thread-3) [homeconnect.sseclient] Connecting ...
2020-02-27 08:46:39 INFO (Thread-4) [homeconnect.sseclient] Connecting ...

but nothing from the event stream after that.
Later, when switching on/off, I got

2020-02-27 19:12:25 DEBUG (SyncWorker_15) [custom_components.homeconnect.switch] tried to switch on Backofen
2020-02-27 19:12:25 WARNING (SyncWorker_15) [homeconnect] Token expired.
2020-02-27 19:12:27 DEBUG (SyncWorker_15) [custom_components.homeconnect.api] Entity update triggered on <Entity Backofen: off>

From this I conclude that

token refresh does work for the direct API calls
token refresh apparently fails for the SSE stream. Somehow it looks like it is reconnecting, but the events are not reaching Home Assistant.

Something is apparently wrong with multithreading & refreshing the tokens, but I still don't know what.

Answer 34 · 2020-02-27T18:17:53.000Z

If anyone can confirm that this is the problem they are seeing too, that would be helpful.

Answer 35 · 2020-02-28T15:41:05.000Z

OK, I'm optimistic that my last commit actually fixes the problem! But I didn't have time to test is myself yet. I released a new homeconnect version and bumped the homeassistant-homeconnect dependency to it in master. Please give it a try and let me know in 24h if it still works! 🙏

Answer 36 · 2020-02-28T15:46:03.000Z

@DavidMStraub can you make an update in hacs?

Answer 37 · 2020-02-28T15:49:34.000Z

You can update by selecting master in HACS, right? I'd release a proper version once the fix is confirmed.

Answer 38 · 2020-02-28T15:53:48.000Z

Ah cool! Didn’t know that.

Answer 39 · 2020-02-28T15:55:01.000Z

You can update by selecting master in HACS, right? I'd release a proper version once the fix is confirmed.

Yes, that‘s possible. I just installed the master branch and will post feedback here.

Regards
Richard

Answer 40 · 2020-02-29T07:12:47.000Z

Same problem after 15 hours.

Answer 41 · 2020-02-29T08:01:01.000Z

I am receviving the following errors:

Log Details (ERROR)
Logger: homeconnect.sseclient
First occured: 8:58:26 AM (2 occurences)
Last logged: 8:58:26 AM

Cannot refresh token in event stream.

Logger: homeconnect.sseclient
First occured: 8:58:25 AM (2 occurences)
Last logged: 8:58:25 AM

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 86, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

Regards
Richard

Answer 42 · 2020-02-29T08:51:25.000Z

Thanks a lot, I see my mistake now. We're close.

Answer 43 · 2020-02-29T09:02:37.000Z

OK, next try... DavidMStraub/homeassistant-homeconnect@921a2e6

Answer 44 · 2020-02-29T09:20:54.000Z

Now I got this error:

Error setting up entry Configuration.yaml for homeconnect
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 685, in _update_chunk_length
    self.chunk_left = int(line, 16)
ValueError: invalid literal for int() with base 16: b''

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 425, in _error_catcher
    yield
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 752, in read_chunked
    self._update_chunk_length()
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 689, in _update_chunk_length
    raise httplib.IncompleteRead(line)
http.client.IncompleteRead: IncompleteRead(0 bytes read)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 750, in generate
    for chunk in self.raw.stream(chunk_size, decode_content=True):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 560, in stream
    for line in self.read_chunked(amt, decode_content=decode_content):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 781, in read_chunked
    self._original_response.close()
  File "/usr/local/lib/python3.7/contextlib.py", line 130, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 443, in _error_catcher
    raise ProtocolError("Connection broken: %r" % e, e)
urllib3.exceptions.ProtocolError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 215, in async_setup
    hass, self
  File "/config/custom_components/homeconnect/__init__.py", line 77, in async_setup_entry
    await update_all_devices(hass, entry)
  File "/config/custom_components/homeconnect/__init__.py", line 111, in update_all_devices
    await hass.async_add_executor_job(device_dict["device"].initialize)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/homeconnect/api.py", line 93, in initialize
    self.appliance.get_settings()
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 318, in get_settings
    settings = self.get("/settings")
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 256, in get
    return self.hc.get("{}/{}{}".format(ENDPOINT_APPLIANCES, self.haId, endpoint))
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 78, in get
    res = self.request("get", endpoint)
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 69, in request
    return getattr(self._oauth, method)(url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests_oauthlib/oauth2_session.py", line 516, in request
    method, url, headers=headers, data=data, **kwargs
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 686, in send
    r.content
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 828, in content
    self._content = b''.join(self.iter_content(CONTENT_CHUNK_SIZE)) or b''
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 753, in generate
    raise ChunkedEncodingError(e)
requests.exceptions.ChunkedEncodingError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

Edit:
Ok. A second restart of ha solves this.

Answer 45 · 2020-03-01T07:03:12.000Z

The problem persists for the on/off switch.
The coffee program switches and the progress sensor are still working.

Edit: also the program switches and the sensor stopped working now.

Answer 46 · 2020-03-01T10:57:05.000Z

Can you please post your log?

Answer 47 · 2020-03-01T11:31:29.000Z

I can confirm same issue here. I would love to send some log to you, but how do I enable the debug logging that you need? My HA.log has different exception for other components, but none for your HC.

And what log-level will you prefer?

Answer 48 · 2020-03-01T11:46:20.000Z

Are you sure you are using the most recent version? homeassistant-homeconnect from master commit 921a2e6 that was committed 26 hours ago and depends on homeconnect v0.4.3? It should emit errors in the log that are displayed even if you don't have debug logging.

I have this in my configuration.yaml in addition:

logger:
  default: info
  logs:
    homeassistant.components.homeconnect: debug
    custom_components.homeconnect: debug

Answer 49 · 2020-03-01T11:48:58.000Z

Yup. HACS says - Installed: 921a2e6. And I restarted afterwards. I have added your logger example and restarting HA again. Thanks.

Answer 50 · 2020-03-01T16:48:13.000Z

I can confirm that it stopped working also for me and there is no error in the log, so it cannot be due to the token this time. Now I'm really about to give up. There is no exception raised, the stream thinks it's still connected but doesn't read any events. How can this be worked around? I have no idea.

Answer 51 · 2020-03-01T17:09:22.000Z

I saw the following in the log. Don’t know if it is related.

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

Answer 52 · 2020-03-01T17:14:05.000Z

This is usually not a problem, in my case I see the stream successfully reconnecting after this exception.

Answer 53 · 2020-03-01T17:24:32.000Z

I made another small change, but honestly I'm not very optimistic this solves the problem.

Answer 54 · 2020-03-01T17:29:37.000Z

We will know it tomorrow.

Answer 55 · 2020-03-01T17:40:47.000Z

Hi David, Could you add some debug on the response for the grant_type = refresh_token oauth/token call, do you actually get a 200 back, when the token is expired? Would be great if the refresh_token was logged too. Maybe also print the old and new token, just to see if the component is picking it up, or if it cached somehow?

Answer 56 · 2020-03-01T20:32:13.000Z

I don't think I can since the refresh_tokens method in the homeconnect library is replaced in the HA integration by HA's own token refresh logic (using config_entry_oauth2_flow.OAuth2Session.async_ensure_token_valid). But this seems to work, otherwise we couldn't make API calls more than 24h after restart. Triggering the refresh in the event stream was flawed in my previous fix and might work better after my new fix. But what confuses me is that this time I didn't even see the "Token expired in event stream" log message before it stopped working, which should have been there if it had been a token problem (https://github.com/DavidMStraub/homeconnect/blob/master/homeconnect/api.py#L231).

Answer 57 · 2020-03-02T06:10:47.000Z

Problem still persists.
But the switches still work with Alexa (homeassistant->nabucasa->Alexa)
Nothing in the log.

Edit: the switches in homeassistant also work but they goes immediately to off.

Answer 58 · 2020-03-02T11:06:26.000Z

Edit: the switches in homeassistant also work but they goes immediately to off.

You can switch the device to on and it remains on - but homeassistant don't get the new state and the state in homeassistant remains off

It seems as if there are other integrations who are responsible for stopping updating the state of the sensors - if nobody is at home and there are no actions of other integration the state will be updated correctly for many hours, but if there are actions ( not every action and I wasn't able to identify the real cause) it might stop updating only a few minutes after a restart of homeassistant.

Answer 59 · 2020-03-02T20:05:29.000Z

So for me, all three devices are still reporting updates from the event stream 27 hours after restarting HA. Moreover, after 23 hours I saw this:

2020-03-02 17:37:41 INFO (Thread-3) [homeconnect] Token expired in event stream.
2020-03-02 17:37:41 INFO (Thread-5) [homeconnect.sseclient] Connecting ...
2020-03-02 17:37:41 INFO (Thread-4) [homeconnect] Token expired in event stream.
2020-03-02 17:37:41 INFO (Thread-5) [homeconnect] Token expired in event stream.
2020-03-02 17:37:41 INFO (Thread-5) [homeconnect.sseclient] Connecting ...
2020-03-02 17:37:41 INFO (Thread-3) [homeconnect.sseclient] Connecting ...
2020-03-02 17:37:42 INFO (Thread-4) [homeconnect.sseclient] Connecting ...
2020-03-02 17:37:42 INFO (Thread-5) [homeconnect] Listening to event stream for device Kochfeld
2020-03-02 17:37:42 INFO (Thread-3) [homeconnect] Listening to event stream for device Trockner
2020-03-02 17:37:42 INFO (Thread-4) [homeconnect] Listening to event stream for device Backofen

This proves that the SSE streams all reconnected successfully after an expiration of the tokens. Are you sure @Krocko that the problem is still there and that you updated to the most recent commit? Did you see anything about tokens in your log?

Answer 60 · 2020-03-02T20:10:47.000Z

@DavidMStraub

My HA instance is up for 12 hours and no problems so far, will report back again tomorrow.

Regards
Richard

Answer 61 · 2020-03-02T21:23:07.000Z

@DavidMStraub yes i am sure.
I have version 0512cb0
There is nothing in the log.

Answer 62 · 2020-03-02T21:37:19.000Z

OK. Which log level do you have? Do INFO messages from the library like this one

2020-03-02 17:37:41 INFO (Thread-5) [homeconnect.sseclient] Connecting ...

show up at all?

Answer 63 · 2020-03-03T09:04:45.000Z

These are the last messages in the log:
2020-03-02 19:06:05 ERROR (Thread-3) [homeconnect.sseclient] Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__ next_chunk = next(self.resp_iterator) StopIteration 2020-03-02 19:06:06 INFO (Thread-3) [homeconnect.sseclient] Connecting ...

Afterwards there are no messages from homeconnect

Answer 64 · 2020-03-03T17:34:45.000Z

@DavidMStraub

My HA instance is up for 34 hours and the sensors are still reporting data. Sometimes the following error is logged:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

Regards
Richard

Answer 65 · 2020-03-03T19:37:48.000Z

That's great news 🎉

Yes that error happens when the SSE has a hiccup but should be of no concern (maybe I should convert it to a warning).

Also still working for me after 50 hours, second token refresh worked.

So I'd almost be tempted to close this!

Answer 66 · 2020-03-03T19:54:08.000Z

I also think that this should be a warning if it is nothing we should react to. From my point of view this ticket can be closed.

Regards
Richard

Answer 67 · 2020-03-04T06:31:47.000Z

@DavidMStraub

('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 685, in _update_chunk_length
    self.chunk_left = int(line, 16)
ValueError: invalid literal for int() with base 16: b''

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 425, in _error_catcher
    yield
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 752, in read_chunked
    self._update_chunk_length()
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 689, in _update_chunk_length
    raise httplib.IncompleteRead(line)
http.client.IncompleteRead: IncompleteRead(0 bytes read)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 750, in generate
    for chunk in self.raw.stream(chunk_size, decode_content=True):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 560, in stream
    for line in self.read_chunked(amt, decode_content=decode_content):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 781, in read_chunked
    self._original_response.close()
  File "/usr/local/lib/python3.7/contextlib.py", line 130, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 443, in _error_catcher
    raise ProtocolError("Connection broken: %r" % e, e)
urllib3.exceptions.ProtocolError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 753, in generate
    raise ChunkedEncodingError(e)
requests.exceptions.ChunkedEncodingError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

Failed connecting.


lookup() argument must be str, not None
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 75, in __next__
    decoder = codecs.getincrementaldecoder(self.resp.encoding)(
  File "/usr/local/lib/python3.7/codecs.py", line 994, in getincrementaldecoder
    decoder = lookup(encoding).incrementaldecoder
TypeError: lookup() argument must be str, not None

Answer 68 · 2020-03-04T08:03:29.000Z

Today i got the same error:

('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 225, in _listen
    for event in sse:
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 88, in __next__
    self._connect()
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 56, in _connect
    self.resp = requester.get(self.url, stream=True, **self.requests_kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests_oauthlib/oauth2_session.py", line 478, in request
    url, http_method=method, body=data, headers=headers
  File "/usr/local/lib/python3.7/site-packages/oauthlib/oauth2/rfc6749/clients/base.py", line 198, in add_token
    raise TokenExpiredError()
oauthlib.oauth2.rfc6749.errors.TokenExpiredError: (token_expired) 

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/api.py", line 225, in _listen
    for event in sse:
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 88, in __next__
    self._connect()
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 56, in _connect
    self.resp = requester.get(self.url, stream=True, **self.requests_kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests_oauthlib/oauth2_session.py", line 478, in request
    url, http_method=method, body=data, headers=headers
  File "/usr/local/lib/python3.7/site-packages/oauthlib/oauth2/rfc6749/clients/base.py", line 198, in add_token
    raise TokenExpiredError()
oauthlib.oauth2.rfc6749.errors.TokenExpiredError: (token_expired) 

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 685, in _update_chunk_length
    self.chunk_left = int(line, 16)
ValueError: invalid literal for int() with base 16: b''

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 425, in _error_catcher
    yield
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 752, in read_chunked
    self._update_chunk_length()
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 689, in _update_chunk_length
    raise httplib.IncompleteRead(line)
http.client.IncompleteRead: IncompleteRead(0 bytes read)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 750, in generate
    for chunk in self.raw.stream(chunk_size, decode_content=True):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 560, in stream
    for line in self.read_chunked(amt, decode_content=decode_content):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 781, in read_chunked
    self._original_response.close()
  File "/usr/local/lib/python3.7/contextlib.py", line 130, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 443, in _error_catcher
    raise ProtocolError("Connection broken: %r" % e, e)
urllib3.exceptions.ProtocolError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 753, in generate
    raise ChunkedEncodingError(e)
requests.exceptions.ChunkedEncodingError: ('Connection broken: IncompleteRead(0 bytes read)', IncompleteRead(0 bytes read))

I am not able to verify if the integration is still running, can do this at the evening.

Regards
Richard

Answer 69 · 2020-03-04T17:08:41.000Z

Sensors still updating.

Regards
Richard

Answer 70 · 2020-03-05T17:23:04.000Z

Sensors not updating anymore. No errors in the logs :-(

Regards
Richard

Answer 71 · 2020-03-05T21:03:40.000Z

Hmm. Still working for me.

Concerning the error above, Failed connecting, this means the HTTP status was not 200 when trying to connect to the stream. Perhaps the API server was not reachable.

Answer 72 · 2020-03-07T09:27:03.000Z

I also still getting issues. Can it be an issue with the HA version? Im using 106.5.

@DavidMStraub Are you also installing your HC lib thru HACS? Do you uninstall and install, or just reinstall?

If I look into the HA.log I only got this:

Answer 73 · 2020-03-07T09:34:22.000Z

Hmm. Still working for me.

Concerning the error above, Failed connecting, this means the HTTP status was not 200 when trying to connect to the stream. Perhaps the API server was not reachable.

Well, i restarted my firewall/router and maybe the connection to the web api broke. Does
Home Connect reconnect to the web api if that happens?

Regards
Richard

Answer 74 · 2020-03-08T09:24:09.000Z

It goes dead after a while. This is the latest entry in the log:

Answer 75 · 2020-03-12T12:02:20.000Z

Is this a new one?

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

Answer 76 · 2020-03-21T12:14:38.000Z

Now i installed a new instance of homeassistant with no other integrations than homeconnect. I set the default loglevel to debug and got this
`
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] [<Entity Geschirrspüler Remaining Program Time: 3120>, <Entity Geschirrspüler Elapsed Program Time: None>, <Entity Geschirrspüler Duration: None>, <Entity Geschirrspüler Program Progress: None>, <Entity Geschirrspüler Door: off>, <Entity Geschirrspüler Program Auto1: off>, <Entity Geschirrspüler Program Auto2: off>, <Entity Geschirrspüler Program Auto3: off>, <Entity Geschirrspüler Program Eco50: on>, <Entity Geschirrspüler Program Quick45: off>, <Entity Geschirrspüler Program Intensiv70: off>, <Entity Geschirrspüler Program Normal65: off>, <Entity Geschirrspüler Program Glas40: off>, <Entity Geschirrspüler Program GlassCare: off>, <Entity Geschirrspüler Program NightWash: off>, <Entity Geschirrspüler Program Quick65: off>, <Entity Geschirrspüler Program Normal45: off>, <Entity Geschirrspüler Program Intensiv45: off>, <Entity Geschirrspüler Program AutoHalfLoad: off>, <Entity Geschirrspüler Program IntensivPower: off>, <Entity Geschirrspüler Program MagicDaily: off>, <Entity Geschirrspüler Program Super60: off>, <Entity Geschirrspüler Program Kurz60: off>, <Entity Geschirrspüler Program ExpressSparkle65: off>, <Entity Geschirrspüler Program MachineCare: off>, <Entity Geschirrspüler Program SteamFresh: off>, <Entity Geschirrspüler Program MaximumCleaning: off>, <Entity Geschirrspüler: on>]
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] {'BSH.Common.Status.DoorState': {'value': 'BSH.Common.EnumType.DoorState.Closed'}, 'BSH.Common.Status.OperationState': {'value': 'BSH.Common.EnumType.OperationState.Run'}, 'BSH.Common.Status.RemoteControlActive': {'value': True}, 'BSH.Common.Status.RemoteControlStartAllowed': {'value': False}, 'BSH.Common.Setting.PowerState': {'value': 'BSH.Common.EnumType.PowerState.On'}, 'BSH.Common.Root.ActiveProgram': {'value': 'Dishcare.Dishwasher.Program.Eco50'}, 'BSH.Common.Option.RemainingProgramTime': {'timestamp': 1584789811, 'handling': 'none', 'uri': '/api/homeappliances/SIEMENS-SX658X06TE-XXXXX/programs/active/options/BSH.Common.Option.RemainingProgramTime', 'unit': 'seconds', 'value': 3060, 'level': 'hint'}, 'BSH.Common.Option.ProgramProgress': {'timestamp': 1584789811, 'handling': 'none', 'uri': '/api/homeappliances/SIEMENS-SX658X06TE-XXXX/programs/active/options/BSH.Common.Option.ProgramProgress', 'unit': '%', 'value': 74, 'level': 'hint'}}
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Remaining Program Time: 3120>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Elapsed Program Time: None>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Duration: None>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Progress: None>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Door: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Auto1: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Auto2: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Auto3: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Eco50: on>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Quick45: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Intensiv70: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Normal65: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Glas40: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program GlassCare: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program NightWash: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Quick65: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Normal45: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Intensiv45: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program AutoHalfLoad: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program IntensivPower: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program MagicDaily: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Super60: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program Kurz60: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program ExpressSparkle65: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program MachineCare: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program SteamFresh: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler Program MaximumCleaning: off>
2020-03-21 12:23:31 DEBUG (Thread-2) [custom_components.homeconnect.api] Entity update triggered on <Entity Geschirrspüler: on>
2020-03-21 12:23:32 DEBUG (SyncWorker_9) [custom_components.homeconnect.sensor] Updated, new state: 3060
2020-03-21 12:23:32 DEBUG (SyncWorker_3) [custom_components.homeconnect.binary_sensor] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_9) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=switch.geschirrspuler, old_state=<state switch.geschirrspuler=on; door_state=closed, operation_state=run, remote_control_active=True, remote_control_start_allowed=False, power_state=on, active_program=eco50, remaining_program_time=3120, friendly_name=Geschirrspüler @ 2020-03-21T12:21:41.554515+01:00>, new_state=<state switch.geschirrspuler=on; door_state=closed, operation_state=run, remote_control_active=True, remote_control_start_allowed=False, power_state=on, active_program=eco50, remaining_program_time=3060, program_progress=74, friendly_name=Geschirrspüler @ 2020-03-21T12:21:41.554515+01:00>>
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.geschirrspuler_remaining_program_time, old_state=<state sensor.geschirrspuler_remaining_program_time=3120; unit_of_measurement=s, friendly_name=Geschirrspüler Remaining Program Time, icon=mdi:progress-clock @ 2020-03-21T12:22:32.009717+01:00>, new_state=<state sensor.geschirrspuler_remaining_program_time=3060; unit_of_measurement=s, friendly_name=Geschirrspüler Remaining Program Time, icon=mdi:progress-clock @ 2020-03-21T12:23:32.033631+01:00>>
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.1931261648] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.geschirrspuler, old_state=<state switch.geschirrspuler=on; door_state=closed, operation_state=run, remote_control_active=True, remote_control_start_allowed=False, power_state=on, active_program=eco50, remaining_program_time=3120, friendly_name=Geschirrspüler @ 2020-03-21T12:21:41.554515+01:00>, new_state=<state switch.geschirrspuler=on; door_state=closed, operation_state=run, remote_control_active=True, remote_control_start_allowed=False, power_state=on, active_program=eco50, remaining_program_time=3060, program_progress=74, friendly_name=Geschirrspüler @ 2020-03-21T12:21:41.554515+01:00>>}
2020-03-21 12:23:32 DEBUG (SyncWorker_17) [custom_components.homeconnect.sensor] Updated, new state: None
2020-03-21 12:23:32 DEBUG (SyncWorker_2) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.1931261648] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.geschirrspuler_remaining_program_time, old_state=<state sensor.geschirrspuler_remaining_program_time=3120; unit_of_measurement=s, friendly_name=Geschirrspüler Remaining Program Time, icon=mdi:progress-clock @ 2020-03-21T12:22:32.009717+01:00>, new_state=<state sensor.geschirrspuler_remaining_program_time=3060; unit_of_measurement=s, friendly_name=Geschirrspüler Remaining Program Time, icon=mdi:progress-clock @ 2020-03-21T12:23:32.033631+01:00>>}
2020-03-21 12:23:32 DEBUG (SyncWorker_11) [custom_components.homeconnect.sensor] Updated, new state: None
2020-03-21 12:23:32 DEBUG (SyncWorker_14) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_6) [custom_components.homeconnect.sensor] Updated, new state: 74
2020-03-21 12:23:32 DEBUG (SyncWorker_10) [custom_components.homeconnect.switch] Updated, new state: True
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.geschirrspuler_program_progress, old_state=<state sensor.geschirrspuler_program_progress=unavailable; unit_of_measurement=%, friendly_name=Geschirrspüler Program Progress @ 2020-03-21T12:21:41.301036+01:00>, new_state=<state sensor.geschirrspuler_program_progress=74; unit_of_measurement=%, friendly_name=Geschirrspüler Program Progress @ 2020-03-21T12:23:32.079065+01:00>>
2020-03-21 12:23:32 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.1931261648] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.geschirrspuler_program_progress, old_state=<state sensor.geschirrspuler_program_progress=unavailable; unit_of_measurement=%, friendly_name=Geschirrspüler Program Progress @ 2020-03-21T12:21:41.301036+01:00>, new_state=<state sensor.geschirrspuler_program_progress=74; unit_of_measurement=%, friendly_name=Geschirrspüler Program Progress @ 2020-03-21T12:23:32.079065+01:00>>}
2020-03-21 12:23:32 DEBUG (SyncWorker_19) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_15) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_16) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_0) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_13) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_9) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_2) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_7) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_14) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_6) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_4) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_8) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_1) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_18) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_3) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_5) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_17) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_11) [custom_components.homeconnect.switch] Updated, new state: False
2020-03-21 12:23:32 DEBUG (SyncWorker_12) [custom_components.homeconnect.switch] Updated, new state: True
2020-03-21 12:36:42 DEBUG (MainThread) [homeassistant.helpers.restore_state] Dumping states
2020-03-21 12:36:42 DEBUG (SyncWorker_10) [homeassistant.helpers.storage] Writing data for core.restore_state
2020-03-21 12:51:43 DEBUG (MainThread) [homeassistant.helpers.restore_state] Dumping states
2020-03-21 12:51:43 DEBUG (SyncWorker_19) [homeassistant.helpers.storage] Writing data for core.restore_state

`

Answer 77 · 2020-03-22T14:38:33.000Z

@DavidMStraub

I am using the actual master branch (0512cb0) and for me the integration is working. Could you please change the following error to a warning like we already discussed above?

Logger: homeconnect.sseclient
Source: /usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py:86
First occurred: 1:23:54 PM (2 occurrences)
Last logged: 1:23:54 PM

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeconnect/sseclient.py", line 78, in __next__
    next_chunk = next(self.resp_iterator)
StopIteration

I am monitoring my HA instance for errors and i am getting a few messages a day about this error. Also maybe a new release with the actual master should be released?

Regards
Richard

Answer 78 · 2020-03-26T17:29:54.000Z

Now it's clear that it's not an issue of homeconnect. I've made a new installation on a new raspberrypi 4 and transfered some other tools from my old raspi3 to the new one. Now the old installation updates scince a few days, but the installation on the new stopped updating.
@DavidMStraub Thank for your good work

Answer 79 · 2020-04-05T15:43:50.000Z

I am using the actual master branch (0512cb0) and for me the integration is working. Could you please change the following error to a warning like we already discussed above?

I am monitoring my HA instance for errors and i am getting a few messages a day about this error. Also maybe a new release with the actual master should be released?

Finally done.

Closing 🎉

Answer 80 · 2020-04-05T15:59:16.000Z

@DavidMStraub

Thank you.

I am using HACS to maintain Home Connect and i am only able to choose version 0.2.4, am i doing something wrong?

Regards
Richard

Answer 81 · 2020-04-05T18:00:28.000Z

Hi,

I haven't made any change to the homeassistant-homeconnect repository yet, I will make a new release there later or tomorrow.

Answer 82 · 2020-04-10T16:50:25.000Z

Hi,

I haven't made any change to the homeassistant-homeconnect repository yet, I will make a new release there later or tomorrow.

Hi David,

did you manage to make a new release by chance?

Regards
Richard

Answer 83 · 2020-04-10T17:36:55.000Z

No, but you can use the master branch in the meantime.

Answer 84 · 2020-06-11T06:21:55.000Z

Hi,
i still have this problem, i'm using the official HA integration. I need to use the beta version?
Thanks

Answer 85 · 2020-06-11T08:01:13.000Z

No, they are the same. Enable debug logging and monitor the log.

Answer 86 · 2020-09-14T15:22:07.000Z

I still have this issue. I prepared a log with enabled debug information:
debug file
First I restarted HA. The home connect entities in HA are still unavailable. After a while I turned on my washing machine. You can see it in the log. HA still shows unavailable entities. After 1,5 hours I started by washing machine once again. This time there are no log entries any more and still no HA entities availabilities.

Pls reopen this issue and help to find the root course why this integrations does not update the current status and why the integrations stop working after a while.

Answer 87 · 2020-09-14T16:37:14.000Z

I'm happy to reopen the issue, but honestly I don't know what to do about it.

Answer 88 · 2020-09-16T14:23:05.000Z

Hi David,
I setup a Docker dev environment, pulled the last sources and run HA with debug informations. Please see my two debug fines. debug file 1 and debug file 2
One shows a lost connection after 1,5hours. The other did not show an update of the integration anyhow. This is what I noticed on my UI.

HA started
UI Integrations shows "unavailable"
Turn on ma washing machine
Selected different washing program
UI Integrations shows still "unavailable"
Turned off the washing machine
HA terminated

There seems to be a connection established but no update to the corresponding integration. After a while the integration loose it's connection. Do you have any idea how to improve it? Pls help.

Answer 89 · 2020-09-30T16:07:48.000Z

Hi David, It seems that the connections get lost after 1,5 hours and it failed to reconnect. Any update or idea on that? Is there a way to support you?

Answer 90 · 2020-09-30T17:36:49.000Z

Hi,

thanks for your debug logs, but I still don't know what the cause could be.

The second log doesn't show any hint.

In the first log, there is an exception in the SSE stream, which I also observed to happen occasionally, which is why I implemented the automatic reconnection. That's aso why this exception is actually not logged as an error, but only as a warning in HA. The log shows that the reconnection is triggered, but I don't know if it succeeded. It's the second to last entry in the log. The last entry, homeassistant.components.websocket_api.http.connection.140059420551200, I think is unrelated to the SSE stream as it is raised in the main thread. No idea what is causing that.

Don't get me wrong, I don't doubt that there is a problem - I also lose the connection to my appliances. In my current HA run, it occured after 48 hours. But since I don't know what's causing it, I don't know how to debug.

My suspicion is actually that it is a problem with the token refresh, which is handled by HA internally and is unrelated to the homeconnect library.

My suggestion is to open an issue in the HA core library, unless you can reproduce the issue with this Python library directly.

Answer 91 · 2020-10-01T16:53:31.000Z

Hi David,
thanks for taking a closer look. It's good to know that you are also seeing a disconnection. Will the reconnect establish a new connection? if so, that is the difference. As you can see from the log, homeconnect tries to reconnect for 90 minutes without success before I finished HA. I have to restart HA to get a new connection.
Further I tried your example program of homeconnect. Again, the connection is terminated after a certain time.
Is there something wrong with the _connect (reconnect)? If I understand your code correctly there is a timeout of 3 sec. Would the sample program log helpful for you?

Answer 92 · 2020-10-03T07:36:35.000Z

What I just noticed is that I can actually still switch on my oven, even 3 days after the integration stopped updating. This proves that it is a problem with the SSE after all and not with the tokens, as the tokens still work (they need to be refreshed at least once every 24 h and HA takes care of that).

Can you please check whether that also works for you?

Answer 93 · 2020-10-03T08:01:04.000Z

I can confirm this scenario as well. I can turn on the coffee machine, but the integration has stopped reporting

Answer 94 · 2020-10-03T13:22:52.000Z

Well, I have to turn on my washer manually and after that it reports during this time (after I restarted HA). But already after the second run the report update stops.

Answer 95 · 2020-10-06T18:36:25.000Z

OK so I observed something interesting. This time I had an internet outage and the updates just stopped, without any messages in the log. So my theory is that the SSE just drops from time to time when there is a network bottleneck or a hiccup of the API server. The question is just how to detect those disconnects ...

Answer 96 · 2020-10-06T19:24:17.000Z

Oh wow I think I finally found a way to solve this. By getting inspiration from the competition: the API server actually sends a KEEP-ALIVE event once a minute. I hadn't used that at all so far. So in principle, all we need to do is listen for it and disconnect-reconnect when we haven't seen one for more than a minute. I'm confident this will work!

Answer 97 · 2020-10-06T20:28:51.000Z

I just released a new version (and updated the dependency in the custom component repo) that should be able to reconnect in case of a stale connection.

However, it does not yet address what happens if the connection is closed and the reconnection fails (e.g. if the server is temporarily unavailable or the internet connection temporarily interrupted).

Still, it would be great if someone could test this - it may well be that this solves most problems.

Answer 98 · 2020-10-06T20:58:38.000Z

I think you are on the right track. My washing machine is in the basement and there I have a powerline connection. May be there is an unreliable connection. I will test your fix.

Answer 99 · 2020-10-08T15:21:23.000Z

Unfortunately, I still have this issue. I prepared another log. I merged your changes in tip revision, restarted HA, and started my washer. HC updated accordantly. After a while I noticed a read time out. And after another time a lost the connection and HA does not update the integration.

Answer 100 · 2020-10-08T18:11:39.000Z

OK thanks. At 11:26 the new timeout fired and the reconnection was successful. At 11:47 it fired again and then at 11:52 it failed to connect. This is basically what I mentioned above, a failing reconnection because the server cannot be reached is still not handled. But I don't now what's causing it.