"/actionList" is being fetched in an endless loop when device powered off

[dilruacs]

Happens on the v4 branch

On my BDP-S3200, only ports 50201, 50202 and 54400 are reachable when the device is powered off.

If Home Assistant is started and the device is not turned on, /actionList is being requested over and over again:

2019-04-04 19:53:50 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.bdps3200 fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 357, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/lib/python3.5/http/client.py", line 1107, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.5/http/client.py", line 1152, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.5/http/client.py", line 1103, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.5/http/client.py", line 934, in _send_output
    self.send(msg)
  File "/usr/lib/python3.5/http/client.py", line 877, in send
    self.connect()
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connection.py", line 166, in connect
    conn = self._new_conn()
  File "/srv/homeassistant/lib/python3.5/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 0x7f625afcf080>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 639, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/srv/homeassistant/lib/python3.5/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.240.4', port=50002): Max retries exceeded with url: /actionList (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f625afcf080>: Failed to establish a new connection: [Errno 111] Connection refused',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 220, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 379, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/home/homeassistant/.homeassistant/custom_components/sony/media_player.py", line 192, in update
    if not self.sonydevice.get_power_status():
  File "/srv/homeassistant/lib/python3.5/site-packages/sonyapilib/device.py", line 586, in get_power_status
    log_errors=False, raise_errors=True)
  File "/srv/homeassistant/lib/python3.5/site-packages/sonyapilib/device.py", line 421, in _send_http
    timeout=TIMEOUT)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.240.4', port=50002): Max retries exceeded with url: /actionList (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f625afcf080>: Failed to establish a new connection: [Errno 111] Connection refused',))
2019-04-04 19:54:01 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.bdps3200 fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 357, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/lib/python3.5/http/client.py", line 1107, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.5/http/client.py", line 1152, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.5/http/client.py", line 1103, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.5/http/client.py", line 934, in _send_output
    self.send(msg)
  File "/usr/lib/python3.5/http/client.py", line 877, in send
    self.connect()
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connection.py", line 166, in connect
    conn = self._new_conn()
  File "/srv/homeassistant/lib/python3.5/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 0x7f625afaeeb8>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/srv/homeassistant/lib/python3.5/site-packages/urllib3/connectionpool.py", line 639, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/srv/homeassistant/lib/python3.5/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.240.4', port=50002): Max retries exceeded with url: /actionList (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f625afaeeb8>: Failed to establish a new connection: [Errno 111] Connection refused',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 220, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 379, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/home/homeassistant/.homeassistant/custom_components/sony/media_player.py", line 192, in update
    if not self.sonydevice.get_power_status():
  File "/srv/homeassistant/lib/python3.5/site-packages/sonyapilib/device.py", line 586, in get_power_status
    log_errors=False, raise_errors=True)
  File "/srv/homeassistant/lib/python3.5/site-packages/sonyapilib/device.py", line 421, in _send_http
    timeout=TIMEOUT)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='192.168.240.4', port=50002): Max retries exceeded with url: /actionList (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f625afaeeb8>: Failed to establish a new connection: [Errno 111] Connection refused',))
[…] (repeat endlessly)

[alexmohr]

I was not able to find a service which would allow me to read the state of the device at these port. The service I could find is http://10.0.0.102:50201/dial.xml but the content is static no matter if the device is powered or not. The actual issue with this is that the requests.exceptions.ConnectionError connection was not catched in _send_http. I noticed this while writing tests and changed the catch block to the base class for the requests exceptions about an hour ago. The endless loop comes from home assistant periodically checking if the device is online.

I believe this problem exists on the current master aswell.

[dilruacs]

The version currently in your v4 branch only catches a RequestException, apparently a ConnectionError is not caught by it.

[alexmohr]

Request exception is the base for all exceptions from the requests lib which means the error is catched. http://docs.python-requests.org/en/master/_modules/requests/exceptions/

class ConnectionError(RequestException): """A Connection error occurred."""

[dilruacs]

I believe this problem exists on the current master aswell.

I do not get these stack traces when using master

Request exception is the base for all exceptions from the requests lib which means the error is catched. http://docs.python-requests.org/en/master/_modules/requests/exceptions/

class ConnectionError(RequestException): """A Connection error occurred."""

Found the cause?

    def get_power_status(self):
        """Checks if the device is online."""
        url = self.actionlist_url
        try:
            # todo parse response
            self._send_http(url, HttpMethod.GET,
                            log_errors=False, raise_errors=True)
        except requests.exceptions.HTTPError as ex:
            _LOGGER.debug(ex)
            return False
        return True

You call _send_http() with raise_errors=True which explicitly causes it to throw stacktraces ;-)

[alexmohr]

Well that is obviously stupid. The RequestException should be catched in get_power_status aswell. Thanks :)