Long-Polling SID from ping/disconnect and connect are not the same

[killjourdain]

Hello,

I got an AsyncServer hosted on a uvicorn web server.

On my AsyncClient, after it is connected to my AsyncServer, i emit him a custom event with some data that i will store in a database. So in my server i send data to an API and i also send the sid from the event at same time so i can send custom event to this client from a web interface.

When a disconnect event is handled, i send the sid of the event to my api to set client offline in my database.

I have seen that when the disconnect event is handled :

• If transport is long polling, the sid is not the previously stored sid so i can't set my client offline in my database from sid.
• If transport is websockets, the sid is the same and it will successfully be disconnected in my database.

I have also seen that my server, when it pings clients with long polling, it pings SIDs stored in sio.eio.socket.keys() and my SIDs from connect event are not in there so i don't know how it works but this how i found that the SID from disconnect and connect events are not the same in long polling transport.

With websockets only, it works perfectly.

So i you have more informations about how i can solve this and if you can tell me if this is a bug or my fault.

I got socketio, engineio and uvicorn last versions.

[miguelgrinberg]

It would be useful to see some of your code, specifically how you determine the sid in the client and the server.

[killjourdain]

Server.py

sio = socketio.AsyncServer(async_mode='asgi', cors_allowed_origins='*', ping_timeout=30, ping_interval=60, monitor_clients=True, logger=mylogger_socketio, engineio_logger=mylogger_socketio)

app = socketio.ASGIApp(sio, other_asgi_app=sanic_app)

Connect event

@sio.on('connect')
async def on_connect(sid, environ):
    mylogger.debug(f"New client connected (SID:{sid})")

Event emitted by client after he is connected to server

@sio.event
async def client_details(sid, data):

    mylogger.debug(f"new event client_details received (SID:{sid})")

    serial_number = data.get('serial_number')
    logon_details = data.get('logon_details')
    computer_name = data.get('computer_name')
    software_version = data.get('software_version')

    url = f'{api_url}/register_endpoint'
    data = {
        'serial_number': serial_number,
        'logon_details': logon_details,
        'computer_name': computer_name,
        'sid': sid,
        'online': True,
        'software_version': software_version,
    }
    
   Then, Sending async request to an api to store data and sid in database

Disconnect event

async def on_disconnect(sid):
        mylogger.info(f"Client disconnected (SID:{sid})")
        
        url = f'{api_url}/set_endpoint_offline'
        data = {
            'sid': sid
        }
        
        Then, Sending async request to set endpoint related to sid offline in database

    Actually with this code, the client first connect with long polling and then try to upgrade to websocket.
    
    If the client stay in long polling, the server will keep pinging the client with different sid from the sid stored in database, so if there is a timeout, the disconnected event will be handled with a different sid.
           
   If i set transports="websocket" in my .connect(), it. will works.
   If i set default transport in .connect() and allow_upgrades=False in AsyncServer(), the disconnect handler will works but my client will still appears online in my database cause of different sid.

[killjourdain]

Indeed, there was some confusion on my part regarding the SIDs, but I am almost sure that the SID of the disconnection event was not the same as the connection one.

I tried to recreate a minimalist version of my server in order to avoid any problems.

With the code below, I see that if I close my client or it no longer has access to the internet, my server will try to ping it but after the ping_timeout it will not emit the disconnect event, it is like this it had not detected the timeout, which could also be the cause of my initial problem.

Server.py

import socketio
import requests

from sanic import Sanic
import logging
import uvicorn

mylogger = logging.getLogger('MyLogs')
mylogger_socketio = logging.getLogger('SocketioLogs')


mylogger.setLevel(logging.DEBUG)
mylogger_socketio.setLevel(logging.DEBUG)

formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s')

console_handler = logging.StreamHandler()
console_handler.setFormatter(formatter)
mylogger.addHandler(console_handler)
mylogger_socketio.addHandler(console_handler)

sio = socketio.AsyncServer(async_mode='asgi', cors_allowed_origins='*', ping_interval=30, ping_timeout=10, logger=mylogger_socketio, engineio_logger=mylogger_socketio, allow_upgrades=False)

sanic_app = Sanic(__name__)
sanic_app.static('/static', './static')
app = socketio.ASGIApp(sio, other_asgi_app=sanic_app)

@sio.on('connect')
async def on_connect(sid, environ):

    mylogger.debug(f"Connect event (SID:{sid})")   

@sio.on('disconnect')
async def on_disconnect(sid):

    mylogger.info(f"Disconnect event (SID:{sid})")

@sio.on('client_details')
async def client_details(sid, data):

    mylogger.debug(f"Event client_details received from SID {sid}")
    

if __name__ == '__main__':

    uvicorn.run(app, host="0.0.0.0", port=8142, log_level="debug")

Client.py

import socketio
import requests

class MyClient:
    def __init__(self):

        print("Starting client...")

        self.sio = socketio.Client(handle_sigint=True, logger=True, engineio_logger=True, ssl_verify=False, request_timeout=20)

        @self.sio.on('connect')
        def on_connect():
            print(f"Connected with sid {self.sio.get_sid()}") 

            self.sio.emit('client_details', {
                'serial_number':'TEST_SERIALNUMBER',
                'computer_name':'TEST_COMPUTERNAME'
                })           
        
        @self.sio.on('disconnect')
        def on_disconnect():
            print("Disconnected")
            
        server_address = 'http://localhost:8142'

        self.sio.connect(server_address, wait_timeout=10)
        self.sio.wait()
        
if __name__ == "__main__":
    myClient = MyClient()

[miguelgrinberg]

Are you running your client on a mobile platform by any chance? Phones work in strange ways with socket connections, they sometimes delay or suppress notifications of disconnections because they are designed for networks that come and go as the person moves.

[killjourdain]

On the last test, my server was running on a Windows computer, my client was running on a Windows computer.

Usually my clients are computers running Windows 10 and 11, my server runs on a Debian server under Docker in production.

[killjourdain]

It seems that it works in version 4.5.1 of the python-engineio module, I think the problem comes from the modification of the _service_task function in the commit below.

miguelgrinberg/python-engineio@87f6003?diff=split&w=0

[miguelgrinberg]

First of all, testing with your code I do see the disconnects when the client goes away. But also looking at the change you highlighted, it is about a server shutdown, it has nothing to do with what you are doing, right? Or am I missing something?

[killjourdain]

Good morning,

For information, I had tested on different operating systems and different web servers and the problem was the same.

Maybe I expressed myself wrongly, if I run the server and the client on the same computer, I would see the disconnection. I don't see the disconnection when I have a server and a client on two separate computers and I cut the client's wifi or ethernet.

In my server log I see a "service task canceled" log and that's what makes me think that the commit could be the cause of my problem, quite simply because I think that "raise KeyboardInterrupt()" line (which is not present in version 4.5.1) break the loop. Maybe I'm wrong.

And otherwise the commit does not only modify the shutdown, if you go down further you will see that the _service_task function is also modified, this function is called when a client connects in the code below:

        """Handle a client connection request."""
        if self.start_service_task:
            # start the service task to monitor connected clients
            self.start_service_task = False
            self.service_task_handle = self.start_background_task(
                self._service_task)```
                
                

[miguelgrinberg]

Okay, now I understand! Sorry it took me so long to catch up.

I do see a problem in the async version of the service task. The logic to exit this task is inverted. The sync version on which it was based is correct, but I made a mistake when I created the async one. Fixed in miguelgrinberg/python-engineio#354.

May I ask you to install the main branch of python-engineio and retest on your side? Let me know if there are any remaining problems.

[killjourdain]

I downloaded the main branch and put it in the folder that contains the modules, and after my tests I confirm that it now works. 👍

[miguelgrinberg]

The fix is released in python-engineio 4.9.1.