Skip to content

Odd SocketIO Crash in Join #1447

Open
Open
@retu2libc

Description

@retu2libc

Describe the bug
New user joins the platform. Socket io messages don't seem to work properly despite connect returning True. The Join company data log line only shows up after the second join attempt which indicates to me that the user does not initially connect properly.

To Reproduce
User joins and then leaves company.

Expected behavior
The client receives a "join_company" event.

Logs

[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Received request to upgrade to websocket
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Upgrade to websocket successful
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Received packet MESSAGE data 0{"token":"redacted_auth_content_here"}
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Sending packet MESSAGE data 0{"sid":"N85lsv8EkOjX2p-BAAAB"}
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Received packet MESSAGE data 2["join_company",{"id":"9fe34a43-ae0b-424c-b409-9139cbb824a0","company_id":"41a218d0-0a5a-11f0-8fb8-4a05af380ba8"}]
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Received packet MESSAGE data 2["leave_company",{"id":"9fe34a43-ae0b-424c-b409-9139cbb824a0"}]
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Received packet MESSAGE data 2["join_company",{"id":"9fe34a43-ae0b-424c-b409-9139cbb824a0","company_id":"41a218d0-0a5a-11f0-8fb8-4a05af380ba8"}]
[2025-03-26 15:52:02 +0000] [67] [INFO] Join company data: {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': '41a218d0-0a5a-11f0-8fb8-4a05af380ba8'}
[2025-03-26 15:52:02 +0000] [67] [INFO] 0ICVWE80L6wIBdcpAAAA: Sending packet MESSAGE data 2["join_company",{"id":"9fe34a43-ae0b-424c-b409-9139cbb824a0","company_id":"41a218d0-0a5a-11f0-8fb8-4a05af380ba8"}]
Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 900, in gevent._gevent_cgreenlet.Greenlet.run
  File "/opt/venv/lib/python3.11/site-packages/socketio/server.py", line 591, in _handle_event_internal
    r = server._trigger_event(data[0], namespace, sid, *data[1:])
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/socketio/server.py", line 617, in _trigger_event
    return handler(*args)
           ^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/flask_socketio/__init__.py", line 292, in _handler
    return self._handle_event(handler, message, real_ns, sid,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/flask_socketio/__init__.py", line 797, in _handle_event
    environ = self.server.get_environ(sid, namespace=namespace)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/socketio/base_server.py", line 213, in get_environ
    eio_sid = self.manager.eio_sid_from_sid(sid, namespace or '/')
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/socketio/base_manager.py", line 72, in eio_sid_from_sid
    return self.rooms[namespace][None].get(sid)
           ~~~~~~~~~~~~~~~~~~~~~^^^^^^
KeyError: None
2025-03-26T15:52:02Z <Thread at 0x7fffc41af920: <bound method Server._handle_event_internal of <socketio.server.Server object at 0x7ffff18f2f50>>(<socketio.server.Server object at 0x7ffff18f2f50>, 'N85lsv8EkOjX2p-BAAAB', '0ICVWE80L6wIBdcpAAAA', ['join_company', {'id': '9fe34a43-ae0b-424c-b409-9, '/', None)> failed with KeyError

Additional context
This seems to only happen with new users but its hard to identify exactly why.

Activity

miguelgrinberg

miguelgrinberg commented on Mar 26, 2025

@miguelgrinberg
Owner

Can you provide the code that causes this crash?

retu2libc

retu2libc commented on Mar 26, 2025

@retu2libc
Author
@socketio.on("connect")
def handle_connect(auth):
    """Handle connect."""
    try:
        current_user = dict(
            flask_jwt_extended.decode_token(auth["token"])["sub"]
        )
    except (
        JWTDecodeError,
        InvalidHeaderError,
        NoAuthorizationError,
        RevokedTokenError,
        CSRFError,
        InvalidSignatureError,
        DecodeError,
        TypeError,
        ValueError,
    ):
        app.logger.exception("Token decode error")
        return False

    # Business logic

    db.session.commit()

    join_room(user.guid)  # this works
    return True

@socketio.on("join_company")
def company_join(data):
    """Join company."""
    app.logger.info("Join company data: %s", data)  # don't get here on the first join attempt?
    guid = data.get("id")
    company_id = data.get("company_id")

    # Business logic

    join_room(company_id)

    socketio.emit(
        "join_company", {"id": guid, "company_id": company_id}, to=company_id
    )
miguelgrinberg

miguelgrinberg commented on Mar 26, 2025

@miguelgrinberg
Owner

Why didn't the first join_company event sent by your client print any data to the log? Is this because you removed logs to simplify, or is this also part of the problem? And also, how much work does the section you called "business logic" do?

retu2libc

retu2libc commented on Mar 26, 2025

@retu2libc
Author

so upon further review it seems to be an issue with how we call the hook. since these are new customers we end up getting something like:

import io, { Socket } from 'socket.io-client';

const url = "http://localhost:5000";

const socket = io(url, {
    transports: ["websocket"],
});

socket.on('connect', () => {
    console.log('Connected to server');
});

socket.on('join_company', () => {
    console.log('Joined Company');
});

socket.emit('leave_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': undefined});

socket.emit('join_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': '41a218d0-0a5a-11f0-8fb8-4a05af380ba8'});

where the server would look like

import uuid
from flask import Flask, request
from flask_socketio import SocketIO, join_room, leave_room
import logging

app = Flask(__name__)
application = app


# Configure logging
logging.basicConfig(level=logging.INFO)

socketio = SocketIO(app, cors_allowed_origins="*", engineio_logger=app.logger)

@socketio.on("connect")
def handle_connect(auth):
    """Handle connect."""
    return True

@socketio.on("leave_company")
def company_leave(data):
    """Leave company."""
    app.logger.info("Leave company data: %s", data)
    guid = data.get("id")
    company_id = data.get("company_id")

    leave_room(company_id)

    socketio.emit(
        "leave_company", {"id": guid, "company_id": company_id}, to=company_id
    )

@socketio.on("join_company")
def company_join(data):
    """Join company."""
    app.logger.info("Join company data: %s", data)
    guid = data.get("id")
    company_id = data.get("company_id")

    join_room(company_id)

    socketio.emit(
        "join_company", {"id": guid, "company_id": company_id}, to=company_id
    )

if __name__ == "__main__":
    socketio.run(app, debug=True)

this directly leads to that logging statement not printing. I'm guessing the traceback is fallout from us trying to solve this with a reconnect. Ala

import io, { Socket } from 'socket.io-client';

const url = "http://localhost:5000";

let socket = io(url, {
    transports: ["websocket"],
});

socket.on('connect', () => {
    console.log('Connected to server');
});

socket.on('join_company', () => {
    console.log('Joined Company');
});

socket.emit('leave_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': undefined});

socket.emit('join_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': '41a218d0-0a5a-11f0-8fb8-4a05af380ba8'});

socket = io(url, {
    transports: ["websocket"],
});

socket.emit('join_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': '41a218d0-0a5a-11f0-8fb8-4a05af380ba8'});
socket.emit('leave_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': undefined});
socket.emit('join_company', {'id': '9fe34a43-ae0b-424c-b409-9139cbb824a0', 'company_id': '41a218d0-0a5a-11f0-8fb8-4a05af380ba8'});
retu2libc

retu2libc commented on Mar 26, 2025

@retu2libc
Author

So it seems the problem has to do with inadvertently calling leave_room(None). I can understand not wanting to support that, but it probably shouldn't break subsequent events. Ideally some warning or error would throw.

miguelgrinberg

miguelgrinberg commented on Mar 27, 2025

@miguelgrinberg
Owner

I agree, the internal data structures should not be corrupted, even if you send an argument that is invalid. Will add validation to prevent this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions

      Odd SocketIO Crash in Join · Issue #1447 · miguelgrinberg/python-socketio