Crashes due to timed out read

[jbriales]

spotpris2 seems to be crashing after a while due to time outs Should the client deal with these rather than crashing?

Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 384, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 380, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib64/python3.7/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/lib64/python3.7/http/client.py", line 306, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python3.7/http/client.py", line 267, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/lib64/python3.7/socket.py", line 589, in readinto
    return self._sock.recv_into(b)
  File "/usr/lib64/python3.7/ssl.py", line 1071, in recv_into
    return self.read(nbytes, buffer)
  File "/usr/lib64/python3.7/ssl.py", line 929, in read
    return self._sslobj.read(len, buffer)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 638, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/lib/python3.7/site-packages/urllib3/util/retry.py", line 367, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3.7/site-packages/urllib3/packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 386, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 306, in _raise_timeout
    raise ReadTimeoutError(self, url, "Read timed out. (read timeout=%s)" % timeout_value)
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='api.spotify.com', port=443): Read timed out. (read timeout=5)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/jesusbriales/.local/lib/python3.7/site-packages/spotpris2/__main__.py", line 61, in timeout_handler
    manager.main_loop()
  File "/home/jesusbriales/.local/lib/python3.7/site-packages/spotpris2/BusManager.py", line 53, in main_loop
    devices = self.spotify.devices()["devices"]
  File "/home/jesusbriales/.local/lib/python3.7/site-packages/spotipy/client.py", line 1255, in devices
    return self._get("me/player/devices")
  File "/home/jesusbriales/.local/lib/python3.7/site-packages/spotipy/client.py", line 207, in _get
    return self._internal_call("GET", url, payload, kwargs)
  File "/home/jesusbriales/.local/lib/python3.7/site-packages/spotipy/client.py", line 169, in _internal_call
    timeout=self.requests_timeout, **args
  File "/usr/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3.7/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='api.spotify.com', port=443): Read timed out. (read timeout=5)

[AndydeCleyre]

BTW this state can be easily reproduced by starting spotpris2, then disconnecting from the network.

---

On one hand, it doesn't crash hard enough.

I use s6 to supervise the process, and like systemd, it will ensure the process is started again if it ever fails; but the spotpris2 process doesn't exit when it encounters this error, hiding the failure from any process supervisor, leaving it in a useless purgatory.

IMO, long-running processes like this will fail sometimes, and handling that is best left to a proper supervisor such as s6 or systemd.

---

On another hand, this issue should be handle-able without crashing.

It looks to me like BusManager.MultiBusManager.main_loop encounters a requests.exceptions.ReadTimeout, and then it bubbles up to __main__.main.timeout_handler, which was triggered by GLib.timeout_add_seconds. I guess that exceptions in loop-added timers like this don't kill the app's main process.

I peeked at some glib docs and saw for timeout_add (and I presume this is the same for timeout_add_seconds):

The function is called repeatedly until it returns False, at which point the timeout is automatically destroyed and the function will not be called again.

I think that when the exception happens, it prevents timeout_handler from returning True, which glib considers as good as returning False, so it destroys that timer.

So maybe a solution could be like:

--- __main__.py 2020-05-17 12:51:37.162663698 -0400
+++ fixed.py    2020-10-17 23:45:48.642159351 -0400
@@ -58,8 +58,10 @@
         manager = SingleBusManager(sp)

     def timeout_handler():
-        manager.main_loop()
-        return True
+        try:
+            manager.main_loop()
+        except Exception as e:
+            print(e)
+        finally:
+            return True

     GLib.timeout_add_seconds(1, timeout_handler)