From 4ee7dd73bd78b068ccf1d87de15c24e3988d9cc5 Mon Sep 17 00:00:00 2001 From: Thomas Adamcik Date: Sun, 1 Mar 2015 17:07:50 +0100 Subject: [PATCH 1/3] http: Make WS broadcast more robust against disconnect race Adds some WebSocketHandler tests that actually connect using a WS client and plugs a potential race condition. Any call to write_message could fail, either due to WebSocketClosedError like in the log below, or simply due to socket errors. To play it safe we catch all errors and debug log that a broadcast failed. 2015-02-26 21:24:02,266 ERROR [HttpServer] /home/adamcik/dev/mopidy/mopidy/http/handlers.py:116 mopidy.http.handlers WebSocket request error: deque index out of range 2015-02-26 21:24:10,098 ERROR [HttpFrontend-11] build/bdist.linux-x86_64/egg/pykka/actor.py:268 pykka Unhandled exception in HttpFrontend (urn:uuid:e376bd95-c32e-4e17-ad20-7d0b3c0cf2b2): Traceback (most recent call last): File "build/bdist.linux-x86_64/egg/pykka/actor.py", line 200, in _actor_loop response = self._handle_receive(message) File "build/bdist.linux-x86_64/egg/pykka/actor.py", line 294, in _handle_receive return callee(*message['args'], **message['kwargs']) File ".../dev/mopidy/mopidy/http/actor.py", line 77, in on_event on_event(name, **data) File ".../dev/mopidy/mopidy/http/actor.py", line 84, in on_event handlers.WebSocketHandler.broadcast(message) File ".../dev/mopidy/mopidy/http/handlers.py", line 78, in broadcast client.write_message(msg) File ".../dev/mopidy-virtualenv/local/lib/python2.7/site-packages/tornado/websocket.py", line 183, in write_message raise WebSocketClosedError() WebSocketClosedError --- mopidy/http/handlers.py | 10 +++++++- tests/http/test_handlers.py | 47 +++++++++++++++++++++++++++++++++++++ 2 files changed, 56 insertions(+), 1 deletion(-) diff --git a/mopidy/http/handlers.py b/mopidy/http/handlers.py index 52bd8217..561c34b3 100644 --- a/mopidy/http/handlers.py +++ b/mopidy/http/handlers.py @@ -75,7 +75,15 @@ class WebSocketHandler(tornado.websocket.WebSocketHandler): @classmethod def broadcast(cls, msg): for client in cls.clients: - client.write_message(msg) + # We could check for client.ws_connection, but we don't really + # care why the broadcast failed, we just want the rest of them + # to succeed, so catch everything. + try: + client.write_message(msg) + except Exception as e: + logger.debug('Broadcast of WebSocket message to %s failed: %s', + client.request.remote_ip, e) + # TODO: should this do the same cleanup as the on_message code? def initialize(self, core): self.jsonrpc = make_jsonrpc_wrapper(core) diff --git a/tests/http/test_handlers.py b/tests/http/test_handlers.py index 5c958d9a..5803adaf 100644 --- a/tests/http/test_handlers.py +++ b/tests/http/test_handlers.py @@ -2,8 +2,11 @@ from __future__ import absolute_import, unicode_literals import os +import mock + import tornado.testing import tornado.web +import tornado.websocket import mopidy from mopidy.http import handlers @@ -35,3 +38,47 @@ class StaticFileHandlerTest(tornado.testing.AsyncHTTPTestCase): response.headers['X-Mopidy-Version'], mopidy.__version__) self.assertEqual( response.headers['Cache-Control'], 'no-cache') + + +class WebSocketHandlerTest(tornado.testing.AsyncHTTPTestCase): + def get_app(self): + self.core = mock.Mock() + return tornado.web.Application([ + (r'/ws/?', handlers.WebSocketHandler, {'core': self.core}) + ]) + + def connection(self): + url = self.get_url('/ws').replace('http', 'ws') + return tornado.websocket.websocket_connect(url, self.io_loop) + + @tornado.testing.gen_test + def test_invalid_json_rpc_request_doesnt_crash_handler(self): + # An uncaught error would result in no message, so this is just a + # simplistic test to verify this. + conn = yield self.connection() + conn.write_message('invalid request') + message = yield conn.read_message() + self.assertTrue(message) + + @tornado.testing.gen_test + def test_broadcast_makes_it_to_client(self): + conn = yield self.connection() + handlers.WebSocketHandler.broadcast('message') + message = yield conn.read_message() + self.assertEqual(message, 'message') + + @tornado.testing.gen_test + def test_broadcast_to_client_that_just_closed_connection(self): + conn = yield self.connection() + conn.close() + handlers.WebSocketHandler.broadcast('message') + + @tornado.testing.gen_test + def test_broadcast_to_client_without_ws_connection_present(self): + yield self.connection() + # Tornado checks for ws_connection and raises WebSocketClosedError + # if it is missing, this test case simulates winning a race were + # this has happened but we have not yet been removed from clients. + for client in handlers.WebSocketHandler.clients: + client.ws_connection = None + handlers.WebSocketHandler.broadcast('message') From 0fb6c620dfc03da2d1f4677fafd05fd620a59ed5 Mon Sep 17 00:00:00 2001 From: Thomas Adamcik Date: Sun, 1 Mar 2015 17:19:43 +0100 Subject: [PATCH 2/3] docs: Add changelog entry for broadcast race --- docs/changelog.rst | 4 ++ tests/http/test_handlers.py | 76 +++++++++++++++++++------------------ 2 files changed, 43 insertions(+), 37 deletions(-) diff --git a/docs/changelog.rst b/docs/changelog.rst index e6e3bcf4..f832716f 100644 --- a/docs/changelog.rst +++ b/docs/changelog.rst @@ -93,6 +93,10 @@ v0.20.0 (UNRELEASED) "database". If you insist on using a client that needs these commands change :confval:`mpd/command_blacklist`. +**HTTP frontend** + +- Prevent race condition in webservice broadcast from breaking the server. + **Audio** - Deprecated :meth:`mopidy.audio.Audio.emit_end_of_stream`. Pass a diff --git a/tests/http/test_handlers.py b/tests/http/test_handlers.py index 5803adaf..8bd82e11 100644 --- a/tests/http/test_handlers.py +++ b/tests/http/test_handlers.py @@ -40,45 +40,47 @@ class StaticFileHandlerTest(tornado.testing.AsyncHTTPTestCase): response.headers['Cache-Control'], 'no-cache') -class WebSocketHandlerTest(tornado.testing.AsyncHTTPTestCase): - def get_app(self): - self.core = mock.Mock() - return tornado.web.Application([ - (r'/ws/?', handlers.WebSocketHandler, {'core': self.core}) - ]) +# We aren't bothering with skipIf as then we would need to "backport" gen_test +if hasattr(tornado.websocket, 'websocket_connect'): + class WebSocketHandlerTest(tornado.testing.AsyncHTTPTestCase): + def get_app(self): + self.core = mock.Mock() + return tornado.web.Application([ + (r'/ws/?', handlers.WebSocketHandler, {'core': self.core}) + ]) - def connection(self): - url = self.get_url('/ws').replace('http', 'ws') - return tornado.websocket.websocket_connect(url, self.io_loop) + def connection(self): + url = self.get_url('/ws').replace('http', 'ws') + return tornado.websocket.websocket_connect(url, self.io_loop) - @tornado.testing.gen_test - def test_invalid_json_rpc_request_doesnt_crash_handler(self): - # An uncaught error would result in no message, so this is just a - # simplistic test to verify this. - conn = yield self.connection() - conn.write_message('invalid request') - message = yield conn.read_message() - self.assertTrue(message) + @tornado.testing.gen_test + def test_invalid_json_rpc_request_doesnt_crash_handler(self): + # An uncaught error would result in no message, so this is just a + # simplistic test to verify this. + conn = yield self.connection() + conn.write_message('invalid request') + message = yield conn.read_message() + self.assertTrue(message) - @tornado.testing.gen_test - def test_broadcast_makes_it_to_client(self): - conn = yield self.connection() - handlers.WebSocketHandler.broadcast('message') - message = yield conn.read_message() - self.assertEqual(message, 'message') + @tornado.testing.gen_test + def test_broadcast_makes_it_to_client(self): + conn = yield self.connection() + handlers.WebSocketHandler.broadcast('message') + message = yield conn.read_message() + self.assertEqual(message, 'message') - @tornado.testing.gen_test - def test_broadcast_to_client_that_just_closed_connection(self): - conn = yield self.connection() - conn.close() - handlers.WebSocketHandler.broadcast('message') + @tornado.testing.gen_test + def test_broadcast_to_client_that_just_closed_connection(self): + conn = yield self.connection() + conn.stream.close() + handlers.WebSocketHandler.broadcast('message') - @tornado.testing.gen_test - def test_broadcast_to_client_without_ws_connection_present(self): - yield self.connection() - # Tornado checks for ws_connection and raises WebSocketClosedError - # if it is missing, this test case simulates winning a race were - # this has happened but we have not yet been removed from clients. - for client in handlers.WebSocketHandler.clients: - client.ws_connection = None - handlers.WebSocketHandler.broadcast('message') + @tornado.testing.gen_test + def test_broadcast_to_client_without_ws_connection_present(self): + yield self.connection() + # Tornado checks for ws_connection and raises WebSocketClosedError + # if it is missing, this test case simulates winning a race were + # this has happened but we have not yet been removed from clients. + for client in handlers.WebSocketHandler.clients: + client.ws_connection = None + handlers.WebSocketHandler.broadcast('message') From 6c5970ffc393ffcd907cf3e701271b1f4d8bd816 Mon Sep 17 00:00:00 2001 From: Thomas Adamcik Date: Sun, 1 Mar 2015 20:46:54 +0100 Subject: [PATCH 3/3] http: Make sure to decode exceptions for logging --- mopidy/http/handlers.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/mopidy/http/handlers.py b/mopidy/http/handlers.py index 561c34b3..a5baf992 100644 --- a/mopidy/http/handlers.py +++ b/mopidy/http/handlers.py @@ -10,7 +10,7 @@ import tornado.websocket import mopidy from mopidy import core, models -from mopidy.utils import jsonrpc +from mopidy.utils import encoding, jsonrpc logger = logging.getLogger(__name__) @@ -81,8 +81,9 @@ class WebSocketHandler(tornado.websocket.WebSocketHandler): try: client.write_message(msg) except Exception as e: + error_msg = encoding.locale_decode(e) logger.debug('Broadcast of WebSocket message to %s failed: %s', - client.request.remote_ip, e) + client.request.remote_ip, error_msg) # TODO: should this do the same cleanup as the on_message code? def initialize(self, core): @@ -121,7 +122,8 @@ class WebSocketHandler(tornado.websocket.WebSocketHandler): 'Sent WebSocket message to %s: %r', self.request.remote_ip, response) except Exception as e: - logger.error('WebSocket request error: %s', e) + error_msg = encoding.locale_decode(e) + logger.error('WebSocket request error: %s', error_msg) if self.ws_connection: # Tornado 3.2+ checks if self.ws_connection is None before # using it, but not older versions.