Core: Synology DSM timeout Error when HA starts 0.112.0

Created on 2 Jul 2020 · 16Comments · Source: home-assistant/core

The problem

I get an error in the log when HA starts related to synolgy dsm integration

Environment

Home Assistant Core release with the issue: 0.112.0
Last working Home Assistant Core release (if known): not sure
Operating environment (OS/Container/Supervised/Core): Supervised
Integration causing this issue: Synology DSM
Link to integration documentation on our website: https://www.home-assistant.io/integrations/synology_dsm/

Problem-relevant `configuration.yaml`

None. It's a GUI integration

Traceback/Error logs

Log Details (ERROR)
Logger: homeassistant.config_entries
Source: components/synology_dsm/__init__.py:311
First occurred: 7:33:31 AM (1 occurrences)
Last logged: 7:33:31 AM

Error setting up entry 10.90.11.40 for synology_dsm
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 426, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 421, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/local/lib/python3.7/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/local/lib/python3.7/http/client.py", line 306, in begin
    version, status, reason = self._read_status()
  File "/usr/local/lib/python3.7/http/client.py", line 267, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/local/lib/python3.7/socket.py", line 589, in readinto
    return self._sock.recv_into(b)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 725, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/retry.py", line 403, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/local/lib/python3.7/site-packages/urllib3/packages/six.py", line 735, in reraise
    raise value
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 677, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 428, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 336, in _raise_timeout
    self, url, "Read timed out. (read timeout=%s)" % timeout_value
urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='10.90.11.40', port=5000): Read timed out. (read timeout=10)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 256, in _execute_request
    url, params=encoded_params, timeout=self._timeout, **kwargs
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 543, in get
    return self.request('GET', url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPConnectionPool(host='10.90.11.40', port=5000): Read timed out. (read timeout=10)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 220, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 161, in async_setup_entry
    await api.async_setup()
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 253, in async_setup
    await self._hass.async_add_executor_job(self._fetch_device_configuration)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 311, in _fetch_device_configuration
    self.information = self.dsm.information
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 327, in information
    data = self.get(SynoDSMInformation.API_KEY, "getinfo")
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 179, in get
    return self._request("GET", api, method, params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 193, in _request
    self.discover_apis()
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 114, in discover_apis
    self._apis = self.get(API_INFO, "query")["data"]
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 179, in get
    return self._request("GET", api, method, params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 223, in _request
    response = self._execute_request(request_method, url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/synology_dsm/synology_dsm.py", line 275, in _execute_request
    raise SynologyDSMRequestException(exp)
synology_dsm.exceptions.SynologyDSMRequestException: {'api': None, 'code': -1, 'reason': 'Unknown', 'details': "ReadTimeout = HTTPConnectionPool(host='10.90.11.40', port=5000): Read timed out. (read timeout=10)"}

Additional information

Sample - I see this for every device. All entities unavailable

I saw this in the beta yesterday as well but deleted the integration, restarted, added and all entities were detected properly again. But it gives this error above now for every restart.

synology_dsm

Source

DavidFW1960

👍2

Most helpful comment

@Quentame seems like changing the timeout will fix it? Can this change be made?

Yes I can do that

Quentame on 13 Aug 2020

👍2

All 16 comments

Hey there @protothis, @quentame, mind taking a look at this issue as its been labeled with an integration (synology_dsm) you are listed as a codeowner for? Thanks!
_{^{(message by CodeOwnersMention)}}

probot-home-assistant[bot] on 2 Jul 2020

Issue still exists in 0.112.2

theOrakle on 6 Jul 2020

I suspect this issue could be resolved by ~quadrupling the 10s timeout.

Explanation: I have an older-ish model (DS413j, ~2013, still receiving updates from Synology). The Synology GUI always loads very slowly, even when the Synology unit isn't under much load.

It doesn't surprise me that a 10s timeout is failing, given it can take >30s for the Synology GUI browser tab to fully load. When logging in, sometimes it takes >10s to go from clicking sign-in on the login form, to loading the MFA form.

I'm running Supervised 0.112.4 and experiencing this issue. If notable, I have MFA enabled for Synology login.

adamfeldman on 13 Jul 2020

Anyone have any idea where this 10s timeout in the code can be changed? This issue is still present with HA 0.113.2

UPDATE:
I figured it out myself based on the error in the log. I connected to the HA docker container in Portainer and used vi to edit the following file: /usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py
In that file, I changed line 54 from self._timeout = timeout or 10 to self._timeout = timeout or 30
Then I restarted the HA container and the DSM sensors showed up just fine. Without this change, I had to reboot my Synology NAS to have any chance at avoiding the error.

fanaticDavid on 29 Jul 2020

Hello everyone !

Sorry for the long delay I got busy this month.

Seen your issue and it's an easy fix !

Will do shortly.

Quentame on 11 Aug 2020

I am having the same problem, rebooting did the trick.
Changing the time-out didn't work though.

sylvaindd on 11 Aug 2020

From all issues I got on this integration, rebooting is often the solution.

How are others ?

Quentame on 11 Aug 2020

👍1

For me, rebooting was the solution sometimes because it makes logins slightly faster. But if it even worked at all, then the effect was temporary. However, I've had zero issues with the DSM integration when restarting HA since I changed the timeout from 10 to 30 seconds.

In my experience, logging into DSM has always been slow, even through the web UI. I've used a DS209+II, followed by a DS412+ and my current NAS is a DS918+. These are not even entry-level models but logins have been slow on all of them, no matter which version of DSM they were/are running. I seem to recall the upcoming DSM 7.0 is supposed to address this behaviour🤞

fanaticDavid on 12 Aug 2020

@Quentame seems like changing the timeout will fix it? Can this change be made?

DavidFW1960 on 13 Aug 2020

@Quentame seems like changing the timeout will fix it? Can this change be made?

Yes I can do that

Quentame on 13 Aug 2020

👍2

In my experience, logging into DSM has always been slow, even through the web UI. I've used a DS209+II, followed by a DS412+ and my current NAS is a DS918+.

I have a DS918+ and not experiencing this slow, network issue ?

Quentame on 13 Aug 2020

In my experience, logging into DSM has always been slow, even through the web UI. I've used a DS209+II, followed by a DS412+ and my current NAS is a DS918+.

I have a DS918+ and not experiencing this slow, network issue ?

I can rule out network issues with a simple file transfer between the NAS and the same client. If the logins were slow due to a network connection issue, doing a file transfer would be incredibly slow. The same goes for my daily (not hourly) Time Machine backups to my NAS.
I used to run a docker container on the NAS to do regular speedtests, which were capable of maxing out my internet connection (100 Mbps at the time). And I have also run iperf3 tests between the NAS and a wired client, capable of maxing out the NAS' gigabit connection.

I should specify that logins are slow through the web UI or any script using the API. Logins via SSH are unaffected.

Here's a quick test using the web UI in a private window:

Firefox: 19 seconds between signing in and 2FA screen, another 10 seconds from 2FA screen to home screen
Chrome: 15 seconds between signing in and 2FA screen, another 10 seconds from 2FA screen to home screen

Other things worth noting:

CPU and RAM usage is low almost all the time, as I've offloaded most of my docker containers onto an Intel NUC
I'm using an SSD cache in my NAS, which has pretty much become obsolete (see previous point)
I use both the DSM and the Surveillance Station integrations in Home Assistant

fanaticDavid on 13 Aug 2020

Yes I can do that

I just manually edited as per previous response and it seems ok now..

DavidFW1960 on 19 Aug 2020

Please, update the integration. It is non-working now due to this tiny bug with timeout.

Spirituss on 27 Aug 2020

👍1

has this been getting any love lately?
Ive have related issues , yet somewhat different so mention them here just for completeness sake.

When my disk station is offline during night time (yes I shut it down for power savings) and a HA restart happens, the integration fails to load and even after re-startup of the Diskstation, the integration wont sense that to load correctly.

It does however throw a ridiculous amount of errors during the night:

2020-09-12 00:58:15 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry HvB Diskstation for synology_dsm
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 159, in _new_conn
    conn = connection.create_connection(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
OSError: [Errno 113] Host is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 670, in urlopen
    httplib_response = self._make_request(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 381, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 978, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 309, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 171, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0xad20a4d8>: Failed to establish a new connection: [Errno 113] Host is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 726, in urlopen
    retries = retries.increment(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/retry.py", line 439, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='192.168.1.81', port=1705): Max retries exceeded with url: /webapi/query.cgi?api=SYNO.API.Info&version=1&method=query (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xad20a4d8>: Failed to establish a new connection: [Errno 113] Host is unreachable'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 255, in _execute_request
    resp = self._session.get(
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 543, in get
    return self.request('GET', url, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='192.168.1.81', port=1705): Max retries exceeded with url: /webapi/query.cgi?api=SYNO.API.Info&version=1&method=query (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xad20a4d8>: Failed to establish a new connection: [Errno 113] Host is unreachable'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 222, in async_setup
    result = await component.async_setup_entry(  # type: ignore
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 161, in async_setup_entry
    await api.async_setup()
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 253, in async_setup
    await self._hass.async_add_executor_job(self._fetch_device_configuration)
  File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/synology_dsm/__init__.py", line 311, in _fetch_device_configuration
    self.information = self.dsm.information
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 327, in information
    data = self.get(SynoDSMInformation.API_KEY, "getinfo")
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 179, in get
    return self._request("GET", api, method, params, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 193, in _request
    self.discover_apis()
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 114, in discover_apis
    self._apis = self.get(API_INFO, "query")["data"]
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 179, in get
    return self._request("GET", api, method, params, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 223, in _request
    response = self._execute_request(request_method, url, params=params, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/synology_dsm/synology_dsm.py", line 275, in _execute_request
    raise SynologyDSMRequestException(exp)
synology_dsm.exceptions.SynologyDSMRequestException: {'api': None, 'code': -1, 'reason': 'Unknown', 'details': 'ConnectionError = <urllib3.connection.HTTPSConnection object at 0xad20a4d8>: Failed to establish a new connection: [Errno 113] Host is unreachable'}

this goes on and on...

Another integration causes identical issues (Plex) but I am not sure if it is allowed to post that here.. wont bother with the full log, suffice to post this snippet, and will start a fresh issue:

2020-09-12 01:29:01 ERROR (MainThread) [homeassistant.components.plex] Plex server (https://192-168-1-81.redactedf.plex.direct:32400) could not be reached: [HTTPSConnectionPool(host='192-168-1-81.refdactedf.plex.direct', port=32400): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xa4d4ffe8>: Failed to establish a new connection: [Errno 113] Host is unreachable'))]
2020-09-12 01:30:25 ERROR (MainThread) [homeassistant.components.plex] Plex server (https://192-168-1-81.redactedf.plex.direct:32400) could not be reached: [HTTPSConnectionPool(host='192-168-1-81.redactedf.plex.direct', port=32400): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x9cb50640>: Failed to establish a new connection: [Errno 113] Host is unreachable'))]
2020-09-12 01:31:48 ERROR (MainThread) [homeassistant.components.plex] Plex server (https://192-168-1-81.redactedf.plex.direct:32400) could not be reached: [HTTPSConnectionPool(host='192-168-1-81.redactedf.plex.direct', port=32400): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xa88cf730>: Failed to establish a new connection: [Errno 113] Host is unreachable'))]

Would be really nice if the integration would get some proper error handling, and stop throwing errors while the Nas is Offline. Just start logging again once it is back online.... please?