Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug] nodes do not reconnect properly when the server is rebooted #840

Closed
frankcorneliusmartin opened this issue Sep 13, 2023 · 1 comment · Fixed by #866
Closed

[Bug] nodes do not reconnect properly when the server is rebooted #840

frankcorneliusmartin opened this issue Sep 13, 2023 · 1 comment · Fixed by #866
Labels
bug Something isn't working

Comments

@frankcorneliusmartin
Copy link
Contributor

Describe the bug
I observed that nodes did not reconnect their websocket channel on a lost connection event.

In the node logs:

2023-09-13 14:02:05 - socket         - INFO     - Disconnected from the server
2023-09-13 14:02:05 - urllib3.connectionpool - DEBUG    - Resetting dropped connection: host.docker.internal
2023-09-13 14:02:09 - urllib3.connectionpool - DEBUG    - Starting new HTTP connection (2): host.docker.internal:5000
2023-09-13 14:02:15 - urllib3.connectionpool - DEBUG    - Starting new HTTP connection (3): host.docker.internal:5000
2023-09-13 14:02:21 - urllib3.connectionpool - DEBUG    - Starting new HTTP connection (4): host.docker.internal:5000
2023-09-13 14:02:22 - urllib3.connectionpool - DEBUG    - http://host.docker.internal:5000 "GET /socket.io/?transport=polling&EIO=4&t=1694613741.986876 HTTP/1.1" 200 None
2023-09-13 14:02:28 - urllib3.connectionpool - DEBUG    - Resetting dropped connection: host.docker.internal
2023-09-13 14:02:28 - urllib3.connectionpool - DEBUG    - http://host.docker.internal:5000 "GET /socket.io/?transport=polling&EIO=4&t=1694613748.5010855 HTTP/1.1" 200 None
2023-09-13 14:02:34 - urllib3.connectionpool - DEBUG    - Resetting dropped connection: host.docker.internal
2023-09-13 14:02:34 - urllib3.connectionpool - DEBUG    - http://host.docker.internal:5000 "GET /socket.io/?transport=polling&EIO=4&t=1694613754.1009824 HTTP/1.1" 200 None

in the server logs:

2023-09-13 14:03:05 - websockets     - INFO     - Client connected: "3t6ZJ2v8n1OkKnPgAAAv"
2023-09-13 14:03:05 - websockets     - ERROR    - Couldn't connect client! No or Invalid JWT token?
2023-09-13 14:03:05 - websockets     - ERROR    - Signature verification failed
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/__init__.py", line 824, in _handle_event
    ret = handler(auth)
TypeError: DefaultSocketNamespace.on_connect() takes 1 positional argument but 2 were given

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 53, in on_connect
    verify_jwt_in_request()
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 89, in verify_jwt_in_request
    jwt_data, jwt_header, jwt_location = _decode_jwt_from_request(
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 323, in _decode_jwt_from_request
    decoded_token = decode_token(encoded_token, csrf_token)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/utils.py", line 127, in decode_token
    return jwt_manager._decode_jwt_from_config(encoded_token, csrf_value, allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/jwt_manager.py", line 553, in _decode_jwt_from_config
    return _decode_jwt(**kwargs, allow_expired=allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/tokens.py", line 94, in _decode_jwt
    decoded_token = jwt.decode(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 168, in decode
    decoded = self.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 120, in decode_complete
    decoded = api_jws.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 202, in decode_complete
    self._verify_signature(signing_input, header, signature, key, algorithms)
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 301, in _verify_signature
    raise InvalidSignatureError("Signature verification failed")
jwt.exceptions.InvalidSignatureError: Signature verification failed
message handler error
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/__init__.py", line 824, in _handle_event
    ret = handler(auth)
TypeError: DefaultSocketNamespace.on_connect() takes 1 positional argument but 2 were given

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 53, in on_connect
    verify_jwt_in_request()
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 89, in verify_jwt_in_request
    jwt_data, jwt_header, jwt_location = _decode_jwt_from_request(
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 323, in _decode_jwt_from_request
    decoded_token = decode_token(encoded_token, csrf_token)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/utils.py", line 127, in decode_token
    return jwt_manager._decode_jwt_from_config(encoded_token, csrf_value, allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/jwt_manager.py", line 553, in _decode_jwt_from_config
    return _decode_jwt(**kwargs, allow_expired=allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/tokens.py", line 94, in _decode_jwt
    decoded_token = jwt.decode(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 168, in decode
    decoded = self.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 120, in decode_complete
    decoded = api_jws.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 202, in decode_complete
    self._verify_signature(signing_input, header, signature, key, algorithms)
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 301, in _verify_signature
    raise InvalidSignatureError("Signature verification failed")
jwt.exceptions.InvalidSignatureError: Signature verification failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/engineio/server.py", line 622, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 789, in _handle_eio_message
    self._handle_connect(eio_sid, pkt.namespace, pkt.data)
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 679, in _handle_connect
    success = self._trigger_event(
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 765, in _trigger_event
    return self.namespace_handlers[namespace].trigger_event(
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/namespace.py", line 25, in trigger_event
    return self.socketio._handle_event(handler, event, self.namespace,
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/__init__.py", line 826, in _handle_event
    ret = handler()
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 64, in on_connect
    self.__join_room_and_notify(request.sid)
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 343, in __join_room_and_notify
    msg = f'{session.type.title()} <{session.name}> joined room <{room}>'
AttributeError: '_ManagedSession' object has no attribute 'type'
2023-09-13 14:03:05 - engineio.server - ERROR    - message handler error
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/__init__.py", line 824, in _handle_event
    ret = handler(auth)
TypeError: DefaultSocketNamespace.on_connect() takes 1 positional argument but 2 were given

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 53, in on_connect
    verify_jwt_in_request()
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 89, in verify_jwt_in_request
    jwt_data, jwt_header, jwt_location = _decode_jwt_from_request(
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/view_decorators.py", line 323, in _decode_jwt_from_request
    decoded_token = decode_token(encoded_token, csrf_token)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/utils.py", line 127, in decode_token
    return jwt_manager._decode_jwt_from_config(encoded_token, csrf_value, allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/jwt_manager.py", line 553, in _decode_jwt_from_config
    return _decode_jwt(**kwargs, allow_expired=allow_expired)
  File "/usr/local/lib/python3.10/site-packages/flask_jwt_extended/tokens.py", line 94, in _decode_jwt
    decoded_token = jwt.decode(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 168, in decode
    decoded = self.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jwt.py", line 120, in decode_complete
    decoded = api_jws.decode_complete(
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 202, in decode_complete
    self._verify_signature(signing_input, header, signature, key, algorithms)
  File "/usr/local/lib/python3.10/site-packages/jwt/api_jws.py", line 301, in _verify_signature
    raise InvalidSignatureError("Signature verification failed")
jwt.exceptions.InvalidSignatureError: Signature verification failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/engineio/server.py", line 622, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 789, in _handle_eio_message
    self._handle_connect(eio_sid, pkt.namespace, pkt.data)
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 679, in _handle_connect
    success = self._trigger_event(
  File "/usr/local/lib/python3.10/site-packages/socketio/server.py", line 765, in _trigger_event
    return self.namespace_handlers[namespace].trigger_event(
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/namespace.py", line 25, in trigger_event
    return self.socketio._handle_event(handler, event, self.namespace,
  File "/usr/local/lib/python3.10/site-packages/flask_socketio/__init__.py", line 826, in _handle_event
    ret = handler()
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 64, in on_connect
    self.__join_room_and_notify(request.sid)
  File "/vantage6/vantage6-server/vantage6/server/websockets.py", line 343, in __join_room_and_notify
    msg = f'{session.type.title()} <{session.name}> joined room <{room}>'
AttributeError: '_ManagedSession' object has no attribute 'type'
2023-09-13 14:03:05 - websockets     - DEBUG    - Client disconnected before identification
[uwsgi-http key: host.docker.internal:5000 client_addr: 192.168.224.1 client_port: 1260] hr_instance_read(): Connection reset by peer [plugins/http/http.c line 647]
2023-09-13 14:03:05 - websockets     - DEBUG    - Client disconnected before identification
2023-09-13 14:03:06 - websockets     - DEBUG    - Client disconnected before identification

To Reproduce
Steps to reproduce the behavior:

  1. Create new network and start it: vdev start-demo-network, vdev create-demo-network
  2. Attach one of the node logs vnode atttach
  3. Stop the server vserver stop
  4. Start the server and observe the logs files vserver start, vserver attach

Details

  • Version 4.0.0a8
@frankcorneliusmartin frankcorneliusmartin added the bug Something isn't working label Sep 13, 2023
@github-actions github-actions bot added the New label Sep 13, 2023
@bartvanb bartvanb mentioned this issue Sep 14, 2023
Merged
@frankcorneliusmartin
Copy link
Contributor Author

When the server restarts, a new JWT secret is issued. Thereby invalidating all issued access tokens. The socketio client is therefore rejected. This could be temporary fixed by setting a constant JWT secret, however this is not desirable in a production case.

Thus the server needs to send an event to the client that it should reauthenticate to obtain a new token and setup a new socketio channel

@bartvanb bartvanb mentioned this issue Sep 22, 2023
Merged
@bartvanb bartvanb closed this as completed Oct 5, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix connection issues of node when server is restarted without consta… vantage6/vantage6
2 participants
@bartvanb @frankcorneliusmartin