HA log flooded with connection errors after turning off Yamaha receiver

[derandiunddasbo]

Home Assistant release with the issue: 0.68.1

Last working Home Assistant release (if known): I encountered the issue at first with version 0.66.1, but I'm not sure, which version I was updating from to 0.66.1

Operating environment (Hass.io/Docker/Windows/etc.): Docker @ Synology

Component/platform: https://www.home-assistant.io/components/media_player.yamaha/

Description of problem:
After switching off a Yamaha (RX-V475) receiver that has been already auto-discovered by HA (i.e. the widget is shown in the frontend), the HA log get’s flooded with connection errors several times a minute, until I restart HA. This issue also seems to severely affect the HA server performance. Commands are only executed with a lag of several seconds and triggering automations seems to get unreliable:

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant): n/A

Traceback (if applicable):

requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connec
tion.HTTPConnection object at 0x7f2cb6d9aa20>: Failed to establish a new connection: [Errno 113] No route to host',))
2018-05-02 10:54:35 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.diebeatbox fails
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
OSError: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 357, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/lib/python3.6/http/client.py", line 1239, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1285, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1234, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1026, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.6/http/client.py", line 964, in send
    self.connect()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 166, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 150, in _new_conn
    self, "Failed to establish a new connection: %s" % e)
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f2cb6dba5f8>: Failed to establish a new connection: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 440, in send
    timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 639, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/retry.py", line 388, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f2cb6dba5f8>: Failed to establish a new connection: [Errno 113] No route to host',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/app/homeassistant/helpers/entity.py", line 204, in async_update_ha_state
    yield from self.async_device_update()
  File "/usr/src/app/homeassistant/helpers/entity.py", line 327, in async_device_update
    yield from self.hass.async_add_job(self.update)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/media_player/yamaha.py", line 154, in update
    self._play_status = self.receiver.play_status()
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 427, in play_status
    src_name = self._src_name(self.input)
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 239, in input
    response = self._request('GET', request_text)
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 137, in _request
    headers={"Content-Type": "text/xml"}
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 555, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 508, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 618, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 508, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f2cb6dba5f8>: Failed to establish a new connection: [Errno 113] No route to host',))
2018-05-02 10:54:35 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/xknx/io/tunnel.py", line 183, in do_heartbeat
    await self.do_heartbeat_impl()
  File "/usr/local/lib/python3.6/site-packages/xknx/io/tunnel.py", line 187, in do_heartbeat_impl
    connectionsstate = await self.connectionstate()
  File "/usr/local/lib/python3.6/site-packages/xknx/io/tunnel.py", line 148, in connectionstate
    await conn_state.start()
  File "/usr/local/lib/python3.6/site-packages/xknx/io/request_response.py", line 35, in start
    await self.send_request()
  File "/usr/local/lib/python3.6/site-packages/xknx/io/request_response.py", line 45, in send_request
    self.udpclient.send(knxipframe)
  File "/usr/local/lib/python3.6/site-packages/xknx/io/udp_client.py", line 178, in send
    self.transport.sendto(bytes(knxipframe.to_knx()))
  File "uvloop/handles/udp.pyx", line 155, in uvloop.loop.UDPTransport.sendto
AttributeError: 'uvloop.loop.UDPTransport' object has no attribute '_address'

Additional information:
These devices have two different standby modes. An “active” standby, that basically turns off the display, but leaves almost everything else running. Especially the network device, which keeps the API up and running 24/7, even if the device seems to be switched off.

The second mode is a deep (i.e. real) standby, that turns off everything except the IR receiver unit. In this mode, the network device is also shut down and the receiver is no longer available via it’s IP address.

The expected behavior would be HA dealing better with a yamaha device switched off to deep standby or becoming otherwise unavailable over the network. It should give up connecting the device after a certain timeout, stop writing errors for this in the log and removing the the widget from the frontend.

[fabaff]

Please check #14748 which should suppress the traceback.

[derandiunddasbo]

Thanks for the patch, I had partial success with it, i.e. the patch suppresses the continuously tracebacks after the receiver goes offline.

But: The status of the entity doesn't update (it is still shown as 'on'). And HA still throws errors if I try to change states of the receiver, f.e. the volume:

2018-06-04 12:28:35 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.diebeatbox is taking over 10 seconds
2018-06-04 12:28:36 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:28:47 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:28:58 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:29:08 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:29:19 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:29:29 WARNING (MainThread) [homeassistant.components.media_player] Updating yamaha media_player took longer than the scheduled update interval 0:00:10
2018-06-04 12:32:47 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall media_player.volume_set: volume_level=0.66, entity_id=['media_player.diebeatbox']>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
OSError: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 357, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/lib/python3.6/http/client.py", line 1239, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1285, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1234, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1026, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.6/http/client.py", line 964, in send
    self.connect()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 166, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 150, in _new_conn
    self, "Failed to establish a new connection: %s" % e)
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7fd86406bf60>: Failed to establish a new connection: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 440, in send
    timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 639, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/retry.py", line 388, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd86406bf60>: Failed to establish a new connection: [Errno 113] No route to host',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/app/homeassistant/core.py", line 1002, in _event_to_service_call
    await service_handler.func(service_call)
  File "/usr/src/app/homeassistant/components/media_player/__init__.py", line 403, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/media_player/yamaha.py", line 261, in set_volume_level
    self.receiver.volume = negative_receiver_vol
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 540, in volume
    self._request('PUT', request_text)
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 137, in _request
    headers={"Content-Type": "text/xml"}
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 555, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 508, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 618, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 508, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd86406bf60>: Failed to establish a new connection: [Errno 113] No route to host',))
2018-06-04 12:32:47 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall media_player.volume_set: volume_level=0.6, entity_id=['media_player.diebeatbox']>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
OSError: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 357, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/lib/python3.6/http/client.py", line 1239, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1285, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1234, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1026, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.6/http/client.py", line 964, in send
    self.connect()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 166, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.6/site-packages/urllib3/connection.py", line 150, in _new_conn
    self, "Failed to establish a new connection: %s" % e)
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7fd86406b0f0>: Failed to establish a new connection: [Errno 113] No route to host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 440, in send
    timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py", line 639, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/local/lib/python3.6/site-packages/urllib3/util/retry.py", line 388, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd86406b0f0>: Failed to establish a new connection: [Errno 113] No route to host',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/app/homeassistant/core.py", line 1002, in _event_to_service_call
    await service_handler.func(service_call)
  File "/usr/src/app/homeassistant/components/media_player/__init__.py", line 403, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/media_player/yamaha.py", line 261, in set_volume_level
    self.receiver.volume = negative_receiver_vol
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 540, in volume
    self._request('PUT', request_text)
  File "/usr/local/lib/python3.6/site-packages/rxv/rxv.py", line 137, in _request
    headers={"Content-Type": "text/xml"}
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 555, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 508, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/sessions.py", line 618, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/requests/adapters.py", line 508, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.4.14', port=80): Max retries exceeded with url: /YamahaRemoteControl/ctrl (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd86406b0f0>: Failed to establish a new connection: [Errno 113] No route to host',))

[derandiunddasbo]

Update: The component is still shown as 'on' after more than 1 hour. Changing attributes still throws three Tracebacks for every change.