Sporadic error in TestWebsocketSubscriptions.test_client_locking

[RobRuana]

I've only seen it happen in python 2.7, and it only happens sporadically. Usually goes away if you re-run the build.

py27 runtests: commands[0] | coverage run --source sideboard -m py.test
============================= test session starts ==============================
platform linux2 -- Python 2.7.12, pytest-3.0.7, py-1.4.33, pluggy-0.4.0
rootdir: /home/travis/build/magfest/sideboard, inifile: setup.cfg
collected 283 items 
sideboard/tests/test_configuration.py ..............................
sideboard/tests/test_imports.py .
sideboard/tests/test_jsonrpc.py ..........
sideboard/tests/test_lib.py .................................................
sideboard/tests/test_logging.py .
sideboard/tests/test_sa.py ..........s...........s...........................s...............................................
sideboard/tests/test_sep.py ....
sideboard/tests/test_server.py ....F..........................
sideboard/tests/test_websocket.py ..................
sideboard/tests/test_websocket_dispatcher.py .........................................
=================================== FAILURES ===================================
________________ TestWebsocketSubscriptions.test_client_locking ________________
self = <sideboard.tests.test_server.TestWebsocketSubscriptions testMethod=test_client_locking>
    def test_client_locking(self):
        self.ws._send(method='self.slow_echo', params=['foo'],
                          client=self.client, callback='cb1')
        sleep(1)
        self.ws._send(method='self.echo', params=['bar'],
                          client=self.client, callback='cb2')
>       self.assert_incoming(data='foo', timeout=2)
sideboard/tests/test_server.py:391: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <sideboard.tests.test_server.TestWebsocketSubscriptions testMethod=test_client_locking>
ws = None, client = None, timeout = 2, params = {'data': 'foo'}
data = {'_time': 1.0030920505523682, 'callback': 'cb2', 'client': 'test_client_locking', 'data': 'bar'}
@py_assert1 = False, @py_assert0 = None, @py_assert5 = None, @py_assert12 = None
@py_assert14 = None, @py_assert16 = None
    def assert_incoming(self, ws=None, client=None, timeout=1, **params):
        data = self.next(ws, timeout)
        assert (client or self.client) == data.get('client')
        for key, val in params.items():
>           assert val == data[key]
E           AssertionError: assert 'foo' == 'bar'
E             - foo
E             + bar
sideboard/tests/test_server.py:167: AssertionError
=============== 1 failed, 279 passed, 3 skipped in 79.70 seconds ===============
ERROR: InvocationError: '/home/travis/build/magfest/sideboard/.tox/py27/bin/coverage run --source sideboard -m py.test'
___________________________________ summary ____________________________________
ERROR:   py27: commands failed
The command "tox -e $TOX_ENV" exited with 1.
Done. Your build exited with 1.

[EliAndrewC]

Huh, that's a bad sign!

I definitely remember this being a thing in the past, but I thought it was fixed. I vaguely remember making a fix to client locking, which I remember being months ago. I'll double-check our local checkout of the repo at work tomorrow to make sure that there's not an un-pushed fix.

If this is happening in a sporadic manner, then that implies that there's a bug in our client locking code, e.g. perhaps we're not actually performing it correctly, and two methods can actually be executed in parallel with the same client id.

[EliAndrewC]

I'll double-check our local checkout of the repo at work tomorrow to make sure that there's not an un-pushed fix.

Just confirming that there aren't any unpushed fixes here :(