Closed oberstet closed 2 years ago
=============================================================== FAILURES ================================================================
_________________________________________________ TestCookieStore.test_purge_on_startup _________________________________________________
self = <crossbar.router.test.test_cookiestore.TestCookieStore testMethod=test_purge_on_startup>
def test_purge_on_startup(self):
created_time = util.utcnow()
original = [{
"id": "thisIsAnID",
"created": created_time,
"max_age": 604800,
"authid": "example.authid",
"authrole": "example.authrole",
"authrealm": "example.authrealm",
"authmethod": "example.authmethod",
"authextra": {},
}, {
"id": "thisIsAnotherID",
"created": created_time,
"max_age": 604800,
"authid": "example.other.authid",
"authrole": "example.other.authrole",
"authrealm": "example.other.authrealm",
"authmethod": "example.other.authmethod",
"authextra": {
"a": "b"
},
}, {
"id": "thisIsAnID",
"modified": created_time,
"max_age": 604800,
"authid": "example.second.authid",
"authrole": "example.second.authrole",
"authrealm": "example.second.authrealm",
"authmethod": "example.second.authmethod",
"authextra": {},
}]
expected = [{
"id": "thisIsAnID",
"created": created_time,
"max_age": 604800,
"authid": "example.second.authid",
"authrole": "example.second.authrole",
"authrealm": "example.second.authrealm",
"authmethod": "example.second.authmethod",
"authextra": {},
}, {
"id": "thisIsAnotherID",
"created": created_time,
"max_age": 604800,
"authid": "example.other.authid",
"authrole": "example.other.authrole",
"authrealm": "example.other.authrealm",
"authmethod": "example.other.authmethod",
"authextra": {
"a": "b"
},
}]
with tempfile.NamedTemporaryFile() as fp:
self.write_cookies_to_file(original, fp)
config = {'store': {'type': 'file', 'filename': fp.name, 'purge_on_startup': True}}
> CookieStoreFileBacked(fp.name, config)
crossbar/router/test/test_cookiestore.py:84:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
crossbar/router/cookiestore.py:284: in __init__
self._init_store()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <crossbar.router.cookiestore.CookieStoreFileBacked object at 0x7fc321c35e50>
def _init_store(self):
n = 0
for cookie in self._iter_persisted():
> cbtid = cookie.pop('cbtid')
E KeyError: 'cbtid'
crossbar/router/cookiestore.py:321: KeyError
________________________________________ TestCookieStore.test_purge_on_startup_default_is_false _________________________________________
self = <crossbar.router.test.test_cookiestore.TestCookieStore testMethod=test_purge_on_startup_default_is_false>
def test_purge_on_startup_default_is_false(self):
original = [{
"id": "thisIsAnID",
"created": "2016-03-02T20:23:00.000Z",
"max_age": 604800,
"authid": "example.authid",
"authrole": "example.authrole",
"authrealm": "example.authrealm",
"authmethod": "example.authmethod",
"authextra": {},
}, {
"id": "thisIsAnID",
"modified": "2016-03-02T20:24:00.000Z",
"max_age": 604800,
"authid": "example.second.authid",
"authrole": "example.second.authrole",
"authrealm": "example.second.authrealm",
"authmethod": "example.second.authmethod",
"authextra": {},
}, {
"id": "thisIsAnotherID",
"created": "2016-03-02T20:23:30.000Z",
"max_age": 604800,
"authid": "example.other.authid",
"authrole": "example.other.authrole",
"authrealm": "example.other.authrealm",
"authmethod": "example.other.authmethod",
"authextra": {},
}]
with tempfile.NamedTemporaryFile() as fp:
self.write_cookies_to_file(original, fp)
config = {'store': {'type': 'file', 'filename': fp.name}}
> CookieStoreFileBacked(fp.name, config)
crossbar/router/test/test_cookiestore.py:125:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
crossbar/router/cookiestore.py:284: in __init__
self._init_store()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <crossbar.router.cookiestore.CookieStoreFileBacked object at 0x7fc321c44ac0>
def _init_store(self):
n = 0
for cookie in self._iter_persisted():
> cbtid = cookie.pop('cbtid')
E KeyError: 'cbtid'
crossbar/router/cookiestore.py:321: KeyError
_____________________________________ TestCookieStore.test_purge_on_startup_delete_expired_cookies ______________________________________
self = <crossbar.router.test.test_cookiestore.TestCookieStore testMethod=test_purge_on_startup_delete_expired_cookies>
def test_purge_on_startup_delete_expired_cookies(self):
max_age = 300
now = time.time()
valid_time = util.utcstr(datetime.fromtimestamp(now))
expired_time = util.utcstr(datetime.fromtimestamp(now - max_age - 10))
original = [{
"id": "thisIsAnID",
"created": expired_time,
"max_age": max_age,
"authid": "example.authid",
"authrole": "example.authrole",
"authrealm": "example.authrealm",
"authmethod": "example.authmethod",
"authextra": {},
}, {
"id": "thisIsAnotherID",
"created": valid_time,
"max_age": max_age,
"authid": "example.other.authid",
"authrole": "example.other.authrole",
"authrealm": "example.other.authrealm",
"authmethod": "example.other.authmethod",
"authextra": {},
}, {
"id": "thisIsAnID",
"modified": valid_time,
"max_age": max_age,
"authid": "example.second.authid",
"authrole": "example.second.authrole",
"authrealm": "example.second.authrealm",
"authmethod": "example.second.authmethod",
"authextra": {},
}]
expected = [
{
"id": "thisIsAnotherID",
"created": valid_time,
"max_age": max_age,
"authid": "example.other.authid",
"authrole": "example.other.authrole",
"authrealm": "example.other.authrealm",
"authmethod": "example.other.authmethod",
"authextra": {},
},
]
with tempfile.NamedTemporaryFile() as fp:
self.write_cookies_to_file(original, fp)
config = {'store': {'type': 'file', 'filename': fp.name, 'purge_on_startup': True}}
> CookieStoreFileBacked(fp.name, config)
crossbar/router/test/test_cookiestore.py:184:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
crossbar/router/cookiestore.py:284: in __init__
self._init_store()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <crossbar.router.cookiestore.CookieStoreFileBacked object at 0x7fc321bd54c0>
def _init_store(self):
n = 0
for cookie in self._iter_persisted():
> cbtid = cookie.pop('cbtid')
E KeyError: 'cbtid'
crossbar/router/cookiestore.py:321: KeyError
=========================================================== warnings summary ============================================================
crossbar/bridge/rest/test/test_caller.py:38
/home/oberstet/scm/crossbario/crossbar/crossbar/bridge/rest/test/test_caller.py:38: PytestWarning: cannot collect test class 'TestSession' because it has a __init__ constructor
class TestSession(ApplicationSession):
-- Docs: https://docs.pytest.org/en/latest/warnings.html
================================ 3 failed, 290 passed, 46 skipped, 3 xfailed, 1 warnings in 4.25 seconds ================================
ERROR: InvocationError for command /home/oberstet/scm/crossbario/crossbar/.tox/pytest/bin/pytest -sv crossbar (exited with code 1)
________________________________________________________________ summary ________________________________________________________________
ERROR: pytest: commands failed
(cpy39_1) (base) oberstet@intel-nuci7:~/scm/crossbario/crossbar$
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Controller 78400] <crossbar.node.node.Node.boot>::NODE_BOOT_COMPLETE[node_id="node1"]
2022-04-23T00:54:24+0200 Starting factory _HTTP11ClientFactory(<function HTTPConnectionPool._newConnection.<locals>.quiescentCallback at 0x7fd7f7ed0d30>, <HostnameEndpoint localhost:8443>)
2022-04-23T00:54:24+0200 Using default reactor
2022-04-23T00:54:24+0200 onConnect callback completed successfully with result=None
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419] Proxy frontend session connected from peer tcp4:127.0.0.1:51900 [<crossbar.worker.proxy.ProxyFrontendSession.onOpen>]
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419] <crossbar.worker.proxy.ProxyFrontendSession._process_Hello>: instantiating authenticator class <crossbar.router.auth.anonymous.PendingAuthAnonymous> for authmethod "anonymous"
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419] <crossbar.router.auth.anonymous.PendingAuthAnonymous.hello>(realm=foo, details.realm=foo, details.authid=None, details.authrole=quux) [config={'role': 'quux', 'type': 'static'}]
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419] Processed authmethod "anonymous" using <class 'crossbar.router.auth.anonymous.PendingAuthAnonymous'>: Accept(realm=<foo>, authid=<PJ6V-XQ73-V73X-VF56-9V6Q-5Q39>, authrole=<quux>, authmethod=anonymous, authprovider=static, authextra={}) [<crossbar.worker.proxy.ProxyFrontendSession._process_Hello>]
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419] Proxy frontend session accepted (Accept(realm=<foo>, authid=<PJ6V-XQ73-V73X-VF56-9V6Q-5Q39>, authrole=<quux>, authmethod=anonymous, authprovider=static, authextra={})) [<crossbar.worker.proxy.ProxyFrontendSession._accept>]
2022-04-23T00:54:24+0200 2022-04-23T00:54:24+0200 [Proxy 78419]
2022-04-23T00:54:24+0200 Traceback (most recent call last):
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/crossbar/worker/proxy.py", line 244, in onMessage
2022-04-23T00:54:24+0200 yield self._process_Hello(msg)
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/.tox/functests-cb/lib/python3.9/site-packages/twisted/internet/defer.py", line 1905, in unwindGenerator
2022-04-23T00:54:24+0200 return _cancellableInlineCallbacks(gen)
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/.tox/functests-cb/lib/python3.9/site-packages/twisted/internet/defer.py", line 1815, in _cancellableInlineCallbacks
2022-04-23T00:54:24+0200 _inlineCallbacks(None, gen, status)
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/.tox/functests-cb/lib/python3.9/site-packages/twisted/internet/defer.py", line 1660, in _inlineCallbacks
2022-04-23T00:54:24+0200 result = current_context.run(gen.send, result)
2022-04-23T00:54:24+0200 --- <exception caught here> ---
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/crossbar/worker/proxy.py", line 538, in _process_Hello
2022-04-23T00:54:24+0200 session = yield self._accept(hello_result)
2022-04-23T00:54:24+0200 File "/home/oberstet/scm/crossbario/crossbar/crossbar/worker/proxy.py", line 295, in _accept
2022-04-23T00:54:24+0200 self.transport.factory._cookiestore.setAuth(self.transport._cbtid, accept.authid, accept.authrole,
2022-04-23T00:54:24+0200 builtins.AttributeError: 'NoneType' object has no attribute 'setAuth'
2022-04-23T00:54:24+0200
2022-04-23T00:54:24+0200 session leaving 'wamp.error.authentication_failed'
2022-04-23T00:54:24+0200 wamp.error.authentication_failed: Frontend connection accept failed ('NoneType' object has no attribute 'setAuth')
________________________________________________________________ summary ________________________________________________________________
sphinx: commands succeeded
flake8: commands succeeded
mypy: commands succeeded
yapf: commands succeeded
bandit: commands succeeded
py39-pinned-trial: commands succeeded
py39-unpinned-trial: commands succeeded
py39-abtrunk-trial: commands succeeded
py39-examples: commands succeeded
pytest: commands succeeded
functests-cb: commands succeeded
functests-cfc: commands succeeded
py39-api-1: commands succeeded
py39-cli-0: commands succeeded
py39-cli-1: commands succeeded
py39-cli-2: commands succeeded
py39-cli-3: commands succeeded
congratulations :)
(cpy39_1) (base) oberstet@intel-nuci7:~/scm/crossbario/crossbar$ git log -1
commit c8595f55628f5a99848e79220abc8cd916ef6e8e (HEAD -> work-0420, origin/work-0420)
Author: Tobias Oberstein <tobias.oberstein@crossbario.com>
Date: Sat Apr 23 14:26:10 2022 +0200
sync
(cpy39_1) (base) oberstet@intel-nuci7:~/scm/crossbario/crossbar$
database backed cookie stores for WAMP-CRA+Cookie authentication in a 2x proxy 1x router configuration (that is, proxy workers sharing an embedded cookie store) works =)
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>(request={'extensions': [('permessage-deflate',
{'client_max_window_bits': [True],
'client_no_context_takeover': [True]})],
'headers': {'cache-control': 'no-cache',
'connection': 'Upgrade',
'host': 'localhost:8080',
'pragma': 'no-cache',
'sec-websocket-extensions': 'permessage-deflate; '
'client_no_context_takeover; '
'client_max_window_bits',
'sec-websocket-key': '9BMf0PQ3008yO0PK+0KzyA==',
'sec-websocket-protocol': 'wamp.2.cbor.batched,wamp.2.cbor,wamp.2.msgpack.batched,wamp.2.msgpack,wamp.2.ubjson.batched,wamp.2.ubjson,wamp.2.json.batched,wamp.2.json',
'sec-websocket-version': '13',
'upgrade': 'WebSocket',
'user-agent': 'AutobahnPython/22.4.1.dev5'},
'host': 'localhost',
'origin': '',
'params': {},
'path': '/ws',
'peer': 'tcp4:127.0.0.1:50460',
'protocols': ['wamp.2.cbor.batched',
'wamp.2.cbor',
'wamp.2.msgpack.batched',
'wamp.2.msgpack',
'wamp.2.ubjson.batched',
'wamp.2.ubjson',
'wamp.2.json.batched',
'wamp.2.json'],
'version': 13})
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: proceed with WebSocket opening handshake for WebSocket subprotocol "wamp.2.cbor.batched"
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: parsed cookie cbtid None from HTTP request headers
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.create> new cookie h0uGZUHoNgthk6uRpOjrMr3f stored in database
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: setting new cookie: cbtid=h0uGZUHoNgthk6uRpOjrMr3f;max-age=604800
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStore.addProto> adding proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7f9c2f564640> for cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.getAuth> cookie auth info for "h0uGZUHoNgthk6uRpOjrMr3f" retrieved: (None, None, None, None, {})
2022-04-23T20:16:03+0200 [Proxy 63924] Cookie-based authentication enabled, but cookie isn't authenticated yet on WebSocket connection <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7f9c2f564640>
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy frontend session connected from peer tcp4:127.0.0.1:50460 [<crossbar.worker.proxy.ProxyFrontendSession.onOpen>]
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.worker.proxy.ProxyFrontendSession._process_Hello>: instantiating authenticator class <crossbar.router.auth.wampcra.PendingAuthWampCra> for authmethod "wampcra"
2022-04-23T20:16:03+0200 [Proxy 63924] Processed authmethod "wampcra" using <class 'crossbar.router.auth.wampcra.PendingAuthWampCra'>: Challenge(method=wampcra, extra={'challenge': '{"authid": "client1", "authrole": "frontend", "authmethod": "wampcra", "authprovider": "static", "session": 7563551763702106, "nonce": "+B19Lefk3VSE7ml41rL+EezzxC3tqE0AT2NHw7MHMyxNaJTEb4Fbt1iar2MXtUoe", "timestamp": "2022-04-23T18:16:03.859Z"}'}) [<crossbar.worker.proxy.ProxyFrontendSession._process_Hello>]
2022-04-23T20:16:03+0200 [Proxy 63924] Processed pending authentication <crossbar.router.auth.wampcra.PendingAuthWampCra object at 0x7f9c2f4c84c0>: Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=static, authextra=None) [<crossbar.worker.proxy.ProxyFrontendSession._process_Authenticate>]
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy frontend session accepted (Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=static, authextra=None)) [<crossbar.worker.proxy.ProxyFrontendSession._accept>]
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.setAuth> cookie with cbtid="h0uGZUHoNgthk6uRpOjrMr3f" exists, and was updated (authid="client1", authrole="frontend", authmethod="wampcra", authrealm="realm1", authextra=None)
2022-04-23T20:16:03+0200 [Router 63915] Client session connected, - transport_info=
{'peer': 'unix', 'protocol': 'wamp.2.cbor', 'type': 'rawsocket'}
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy backend connection opened mapping frontend session to realm "realm1", authrole "frontend" [<crossbar.worker.proxy.ProxyController.map_backend>]
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy backend session authenticating (authmethods=['anonymous-proxy']) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected>]
2022-04-23T20:16:03+0200 [Router 63915] Router attached new session to realm "realm1" (session=4392839638386308, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.attach>
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy backend session joined (backend_session_id=4392839638386308) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected.<locals>._on_backend_joined>]
2022-04-23T20:16:03+0200 [Router 63915] add2() called with 23 and 666
2022-04-23T20:16:03+0200 [Router 63915] Router detached session from realm "realm1" (session=4392839638386308, detached_session_ids=1, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.detach>
2022-04-23T20:16:03+0200 [Proxy 63924] Proxy frontend session closed (wasClean=True) [<crossbar.worker.proxy.ProxyFrontendSession.onClose>]
2022-04-23T20:16:03+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStore.dropProto> removing proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7f9c2f564640> from cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>(request={'extensions': [('permessage-deflate',
{'client_max_window_bits': [True],
'client_no_context_takeover': [True]})],
'headers': {'cache-control': 'no-cache',
'connection': 'Upgrade',
'cookie': 'cbtid=h0uGZUHoNgthk6uRpOjrMr3f',
'host': 'localhost:8080',
'pragma': 'no-cache',
'sec-websocket-extensions': 'permessage-deflate; '
'client_no_context_takeover; '
'client_max_window_bits',
'sec-websocket-key': 'Si0uK0ilkNCo6zJB71IgWA==',
'sec-websocket-protocol': 'wamp.2.cbor.batched,wamp.2.cbor,wamp.2.msgpack.batched,wamp.2.msgpack,wamp.2.ubjson.batched,wamp.2.ubjson,wamp.2.json.batched,wamp.2.json',
'sec-websocket-version': '13',
'upgrade': 'WebSocket',
'user-agent': 'AutobahnPython/22.4.1.dev5'},
'host': 'localhost',
'origin': '',
'params': {},
'path': '/ws',
'peer': 'tcp4:127.0.0.1:50462',
'protocols': ['wamp.2.cbor.batched',
'wamp.2.cbor',
'wamp.2.msgpack.batched',
'wamp.2.msgpack',
'wamp.2.ubjson.batched',
'wamp.2.ubjson',
'wamp.2.json.batched',
'wamp.2.json'],
'version': 13})
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: proceed with WebSocket opening handshake for WebSocket subprotocol "wamp.2.cbor.batched"
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: parsed cookie cbtid h0uGZUHoNgthk6uRpOjrMr3f from HTTP request headers
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: cookie h0uGZUHoNgthk6uRpOjrMr3f already set and stored
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStore.addProto> adding proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7f9c2f36e670> for cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.getAuth> cookie auth info for "h0uGZUHoNgthk6uRpOjrMr3f" retrieved: ('client1', 'frontend', 'wampcra', 'realm1', {})
2022-04-23T20:16:06+0200 [Proxy 63924] Authenticated client via cookie cbtid=h0uGZUHoNgthk6uRpOjrMr3f as authid=client1, authrole=frontend, authmethod=wampcra, authrealm=realm1
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy frontend session connected from peer tcp4:127.0.0.1:50462 [<crossbar.worker.proxy.ProxyFrontendSession.onOpen>]
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.worker.proxy.ProxyFrontendSession._process_Hello>: authenticating client using cookie-authentication, hello_result=Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy frontend session accepted (Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})) [<crossbar.worker.proxy.ProxyFrontendSession._accept>]
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.setAuth> cookie with cbtid="h0uGZUHoNgthk6uRpOjrMr3f" exists, but needs no update
2022-04-23T20:16:06+0200 [Router 63915] Client session connected, - transport_info=
{'peer': 'unix', 'protocol': 'wamp.2.cbor', 'type': 'rawsocket'}
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy backend connection opened mapping frontend session to realm "realm1", authrole "frontend" [<crossbar.worker.proxy.ProxyController.map_backend>]
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy backend session authenticating (authmethods=['anonymous-proxy']) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected>]
2022-04-23T20:16:06+0200 [Router 63915] Router attached new session to realm "realm1" (session=2289996643949637, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.attach>
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy backend session joined (backend_session_id=2289996643949637) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected.<locals>._on_backend_joined>]
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy frontend session WELCOME: session_id=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7f9c2f36e760>, session=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7f9c2f36e760>, details="
SessionDetails(realm="realm1",
session=2289996643949637,
authid="client1",
authrole="frontend",
authmethod="anonymous-proxy",
authprovider="static",
authextra={'x_cb_node': 'intel-nuci7-63906', 'x_cb_worker': 'test_router1', 'x_cb_peer': 'unix', 'x_cb_pid': 63915},
serializer="cbor",
transport="rawsocket",
resumed=None,
resumable=None,
resume_token=None)" [<crossbar.worker.proxy.ProxyFrontendSession._process_Hello>]
2022-04-23T20:16:06+0200 [Router 63915] add2() called with 23 and 666
2022-04-23T20:16:06+0200 [Router 63915] Router detached session from realm "realm1" (session=2289996643949637, detached_session_ids=1, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.detach>
2022-04-23T20:16:06+0200 [Proxy 63924] Proxy frontend session closed (wasClean=True) [<crossbar.worker.proxy.ProxyFrontendSession.onClose>]
2022-04-23T20:16:06+0200 [Proxy 63924] <crossbar.router.cookiestore.CookieStore.dropProto> removing proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7f9c2f36e670> from cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>(request={'extensions': [('permessage-deflate',
{'client_max_window_bits': [True],
'client_no_context_takeover': [True]})],
'headers': {'cache-control': 'no-cache',
'connection': 'Upgrade',
'cookie': 'cbtid=h0uGZUHoNgthk6uRpOjrMr3f',
'host': 'localhost:8080',
'pragma': 'no-cache',
'sec-websocket-extensions': 'permessage-deflate; '
'client_no_context_takeover; '
'client_max_window_bits',
'sec-websocket-key': 'NquAaZ6XbKl73/S7oj1hoQ==',
'sec-websocket-protocol': 'wamp.2.cbor.batched,wamp.2.cbor,wamp.2.msgpack.batched,wamp.2.msgpack,wamp.2.ubjson.batched,wamp.2.ubjson,wamp.2.json.batched,wamp.2.json',
'sec-websocket-version': '13',
'upgrade': 'WebSocket',
'user-agent': 'AutobahnPython/22.4.1.dev5'},
'host': 'localhost',
'origin': '',
'params': {},
'path': '/ws',
'peer': 'tcp4:127.0.0.1:50464',
'protocols': ['wamp.2.cbor.batched',
'wamp.2.cbor',
'wamp.2.msgpack.batched',
'wamp.2.msgpack',
'wamp.2.ubjson.batched',
'wamp.2.ubjson',
'wamp.2.json.batched',
'wamp.2.json'],
'version': 13})
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: proceed with WebSocket opening handshake for WebSocket subprotocol "wamp.2.cbor.batched"
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: parsed cookie cbtid h0uGZUHoNgthk6uRpOjrMr3f from HTTP request headers
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: cookie h0uGZUHoNgthk6uRpOjrMr3f already set and stored
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStore.addProto> adding proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7fca1b0ef4f0> for cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.getAuth> cookie auth info for "h0uGZUHoNgthk6uRpOjrMr3f" retrieved: ('client1', 'frontend', 'wampcra', 'realm1', {})
2022-04-23T20:16:08+0200 [Proxy 63933] Authenticated client via cookie cbtid=h0uGZUHoNgthk6uRpOjrMr3f as authid=client1, authrole=frontend, authmethod=wampcra, authrealm=realm1
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy frontend session connected from peer tcp4:127.0.0.1:50464 [<crossbar.worker.proxy.ProxyFrontendSession.onOpen>]
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.worker.proxy.ProxyFrontendSession._process_Hello>: authenticating client using cookie-authentication, hello_result=Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy frontend session accepted (Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})) [<crossbar.worker.proxy.ProxyFrontendSession._accept>]
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.setAuth> cookie with cbtid="h0uGZUHoNgthk6uRpOjrMr3f" exists, but needs no update
2022-04-23T20:16:08+0200 [Router 63915] Client session connected, - transport_info=
{'peer': 'unix', 'protocol': 'wamp.2.cbor', 'type': 'rawsocket'}
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy backend connection opened mapping frontend session to realm "realm1", authrole "frontend" [<crossbar.worker.proxy.ProxyController.map_backend>]
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy backend session authenticating (authmethods=['anonymous-proxy']) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected>]
2022-04-23T20:16:08+0200 [Router 63915] Router attached new session to realm "realm1" (session=3650944109684768, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.attach>
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy backend session joined (backend_session_id=3650944109684768) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected.<locals>._on_backend_joined>]
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy frontend session WELCOME: session_id=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7fca1b0fbd90>, session=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7fca1b0fbd90>, details="
SessionDetails(realm="realm1",
session=3650944109684768,
authid="client1",
authrole="frontend",
authmethod="anonymous-proxy",
authprovider="static",
authextra={'x_cb_node': 'intel-nuci7-63906', 'x_cb_worker': 'test_router1', 'x_cb_peer': 'unix', 'x_cb_pid': 63915},
serializer="cbor",
transport="rawsocket",
resumed=None,
resumable=None,
resume_token=None)" [<crossbar.worker.proxy.ProxyFrontendSession._process_Hello>]
2022-04-23T20:16:08+0200 [Router 63915] add2() called with 23 and 666
2022-04-23T20:16:08+0200 [Router 63915] Router detached session from realm "realm1" (session=3650944109684768, detached_session_ids=1, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.detach>
2022-04-23T20:16:08+0200 [Proxy 63933] Proxy frontend session closed (wasClean=True) [<crossbar.worker.proxy.ProxyFrontendSession.onClose>]
2022-04-23T20:16:08+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStore.dropProto> removing proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7fca1b0ef4f0> from cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>(request={'extensions': [('permessage-deflate',
{'client_max_window_bits': [True],
'client_no_context_takeover': [True]})],
'headers': {'cache-control': 'no-cache',
'connection': 'Upgrade',
'cookie': 'cbtid=h0uGZUHoNgthk6uRpOjrMr3f',
'host': 'localhost:8080',
'pragma': 'no-cache',
'sec-websocket-extensions': 'permessage-deflate; '
'client_no_context_takeover; '
'client_max_window_bits',
'sec-websocket-key': '5pjZflx7vH5ITC8kzju9Fw==',
'sec-websocket-protocol': 'wamp.2.cbor.batched,wamp.2.cbor,wamp.2.msgpack.batched,wamp.2.msgpack,wamp.2.ubjson.batched,wamp.2.ubjson,wamp.2.json.batched,wamp.2.json',
'sec-websocket-version': '13',
'upgrade': 'WebSocket',
'user-agent': 'AutobahnPython/22.4.1.dev5'},
'host': 'localhost',
'origin': '',
'params': {},
'path': '/ws',
'peer': 'tcp4:127.0.0.1:50466',
'protocols': ['wamp.2.cbor.batched',
'wamp.2.cbor',
'wamp.2.msgpack.batched',
'wamp.2.msgpack',
'wamp.2.ubjson.batched',
'wamp.2.ubjson',
'wamp.2.json.batched',
'wamp.2.json'],
'version': 13})
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: proceed with WebSocket opening handshake for WebSocket subprotocol "wamp.2.cbor.batched"
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: parsed cookie cbtid h0uGZUHoNgthk6uRpOjrMr3f from HTTP request headers
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.protocol.WampWebSocketServerProtocol.onConnect>: cookie h0uGZUHoNgthk6uRpOjrMr3f already set and stored
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStore.addProto> adding proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7fca1afa4100> for cookie "h0uGZUHoNgthk6uRpOjrMr3f"
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.getAuth> cookie auth info for "h0uGZUHoNgthk6uRpOjrMr3f" retrieved: ('client1', 'frontend', 'wampcra', 'realm1', {})
2022-04-23T20:16:10+0200 [Proxy 63933] Authenticated client via cookie cbtid=h0uGZUHoNgthk6uRpOjrMr3f as authid=client1, authrole=frontend, authmethod=wampcra, authrealm=realm1
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy frontend session connected from peer tcp4:127.0.0.1:50466 [<crossbar.worker.proxy.ProxyFrontendSession.onOpen>]
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.worker.proxy.ProxyFrontendSession._process_Hello>: authenticating client using cookie-authentication, hello_result=Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy frontend session accepted (Accept(realm=<realm1>, authid=<client1>, authrole=<frontend>, authmethod=wampcra, authprovider=cookie, authextra={})) [<crossbar.worker.proxy.ProxyFrontendSession._accept>]
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStoreDatabaseBacked.setAuth> cookie with cbtid="h0uGZUHoNgthk6uRpOjrMr3f" exists, but needs no update
2022-04-23T20:16:10+0200 [Router 63915] Client session connected, - transport_info=
{'peer': 'unix', 'protocol': 'wamp.2.cbor', 'type': 'rawsocket'}
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy backend connection opened mapping frontend session to realm "realm1", authrole "frontend" [<crossbar.worker.proxy.ProxyController.map_backend>]
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy backend session authenticating (authmethods=['anonymous-proxy']) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected>]
2022-04-23T20:16:10+0200 [Router 63915] Router attached new session to realm "realm1" (session=7615959482044646, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.attach>
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy backend session joined (backend_session_id=7615959482044646) [<crossbar.worker.proxy.ProxyFrontendSession._accept.<locals>._backend_connected.<locals>._on_backend_joined>]
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy frontend session WELCOME: session_id=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7fca1afa42e0>, session=<crossbar.worker.proxy.ProxyFrontendSession object at 0x7fca1afa42e0>, details="
SessionDetails(realm="realm1",
session=7615959482044646,
authid="client1",
authrole="frontend",
authmethod="anonymous-proxy",
authprovider="static",
authextra={'x_cb_node': 'intel-nuci7-63906', 'x_cb_worker': 'test_router1', 'x_cb_peer': 'unix', 'x_cb_pid': 63915},
serializer="cbor",
transport="rawsocket",
resumed=None,
resumable=None,
resume_token=None)" [<crossbar.worker.proxy.ProxyFrontendSession._process_Hello>]
2022-04-23T20:16:10+0200 [Router 63915] add2() called with 23 and 666
2022-04-23T20:16:10+0200 [Router 63915] Router detached session from realm "realm1" (session=7615959482044646, detached_session_ids=1, authid="client1", authrole="frontend", authmethod="anonymous-proxy", authprovider="static") <crossbar.router.router.Router.detach>
2022-04-23T20:16:10+0200 [Proxy 63933] Proxy frontend session closed (wasClean=True) [<crossbar.worker.proxy.ProxyFrontendSession.onClose>]
2022-04-23T20:16:10+0200 [Proxy 63933] <crossbar.router.cookiestore.CookieStore.dropProto> removing proto <crossbar.router.protocol.WampWebSocketServerProtocol object at 0x7fca1afa4100> from cookie "h0uGZUHoNgthk6uRpOjrMr3f"
works locally ... not sure (again) why it (sometimes) fails on GH CI