Python-socketio: SIGINT handler does not disconnect client

Created on 19 Jul 2020  路  14Comments  路  Source: miguelgrinberg/python-socketio

When attempting to disconnect client, it only disconnects once, but then reconnects.

Connection log:

DEBUG:asyncio:Using selector: KqueueSelector
INFO:engineio.client:Attempting WebSocket connection to wss://myproject.com/api/ws/?transport=websocket&EIO=3
INFO:engineio.client:WebSocket connection accepted with {'sid': '7a2f537ad5cc49e79c5f05fa3644c923', 'upgrades': [], 'pingTimeout': 60000, 'pingInterval': 25000}
INFO:socketio.client:Engine.IO connection established
INFO:engineio.client:Sending packet PING data None
INFO:engineio.client:Received packet MESSAGE data 0
INFO:socketio.client:Namespace / is connected
INFO:engineio.client:Received packet PONG data None

After sending SIGINT:

INFO:engineio.client:Sending packet PING data None
ERROR:engineio.client:packet queue is empty, aborting
INFO:engineio.client:Exiting write loop task
INFO:engineio.client:Unexpected error receiving packet: "", aborting
INFO:engineio.client:Waiting for write loop task to end
INFO:engineio.client:Waiting for ping loop task to end
INFO:engineio.client:PONG response has not been received, aborting
INFO:engineio.client:Exiting ping task
INFO:socketio.client:Engine.IO connection dropped
WARNING:project:Disconnected
INFO:engineio.client:Exiting read loop task
INFO:socketio.client:Connection failed, new attempt in 0.91 seconds
INFO:engineio.client:Attempting WebSocket connection to wss://myproject.com/api/ws/?transport=websocket&EIO=3
INFO:engineio.client:WebSocket connection accepted with {'sid': '3c5ebff507024dadbb293e9d1adfcad7', 'upgrades': [], 'pingTimeout': 60000, 'pingInterval': 25000}
INFO:socketio.client:Engine.IO connection established
INFO:socketio.client:Reconnection successful
INFO:engineio.client:Sending packet PING data None
INFO:engineio.client:Received packet MESSAGE data 0
INFO:socketio.client:Namespace / is connected
INFO:engineio.client:Received packet PONG data None

After another SIGINT:

^CERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<AsyncClient.disconnect() running at /Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/asyncio_client.py:106>>
/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py:604: RuntimeWarning: coroutine 'AsyncClient.disconnect' was never awaited
  self._ready.clear()
RuntimeWarning: Enable tracemalloc to get the object allocation traceback
Traceback (most recent call last):
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 566, in run_until_complete
    self.run_forever()
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 534, in run_forever
    self._run_once()
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 1735, in _run_once
    event_list = self._selector.select(timeout)
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/selectors.py", line 558, in select
    kev_list = self._selector.control(None, max_ev, timeout)
  File "/Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/client.py", line 43, in signal_handler
    return original_signal_handler(sig, frame)
  File "/Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/socketio/client.py", line 26, in signal_handler
    return original_signal_handler(sig, frame)
KeyboardInterrupt

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/Users/asnelzin/dev/project/project/__main__.py", line 93, in <module>
    asyncio.run(main(sys.argv[1:]))
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/runners.py", line 46, in run
    _cancel_all_tasks(loop)
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/runners.py", line 62, in _cancel_all_tasks
    tasks.gather(*to_cancel, loop=loop, return_exceptions=True))
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 566, in run_until_complete
    self.run_forever()
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 534, in run_forever
    self._run_once()
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 1735, in _run_once
    event_list = self._selector.select(timeout)
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/selectors.py", line 558, in select
    kev_list = self._selector.control(None, max_ev, timeout)
  File "/Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/client.py", line 43, in signal_handler
    return original_signal_handler(sig, frame)
  File "/Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/socketio/client.py", line 26, in signal_handler
    return original_signal_handler(sig, frame)
KeyboardInterrupt
ERROR:asyncio:Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x10c7e0310>
ERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<AsyncClient._ping_loop() running at /Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/asyncio_client.py:446> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x10c7ed790>()]>>
ERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<AsyncClient._write_loop() running at /Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/asyncio_client.py:551> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x10c7eda50>()]>>
ERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<AsyncClient._read_loop_websocket() running at /Users/asnelzin/dev/project/venv/lib/python3.7/site-packages/engineio/asyncio_client.py:500> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x10c0af5d0>()]> cb=[<TaskWakeupMethWrapper object at 0x10c7ed9d0>()]>
ERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<Queue.get() running at /Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/queues.py:159> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x10c7ed2d0>()]> cb=[_release_waiter(<Future pendi...10c7eda50>()]>)() at /Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/tasks.py:392]>
Exception ignored in: <coroutine object Queue.get at 0x10c806710>
Traceback (most recent call last):
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/queues.py", line 161, in get
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 683, in call_soon
  File "/Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/base_events.py", line 475, in _check_closed
RuntimeError: Event loop is closed
ERROR:asyncio:Task was destroyed but it is pending!
task: <Task pending coro=<Event.wait() running at /Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/locks.py:293> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x10c7ed7d0>()]> cb=[_release_waiter(<Future pendi...10c7ed790>()]>)() at /Users/asnelzin/.pyenv/versions/3.7.4/lib/python3.7/asyncio/tasks.py:392]>
bug

All 14 comments

I also noticed this in my project.

Tried fixing it using some process managers, supervisord / monit / circusd. It took 9 weeks of after work time and I finally realised my bug was a little more trouble then your report might seem..

I immediately started using the atexit.register builtin for Client.disconnect and forgot all this time I introduced it "after" noticing the bug!

Long story short; this library is not _signal aware_ and it is incompatible with the atexit python builtin (doing this actually turns your process into a zombie).

You need to do 2 things;

1) Add some signal handlers;

import socketio
from retry.api import retry

@retry((Exception), tries=15, delay=1.5, backoff=3)
def close_socket():
    sio.disconnect()

sio = socketio.Client()
def signal_handler(signum, **_):
    message = f'Signal handler called with signal {signum}'
    log.warning(message)
    # do things
    close_socket()
    sys.exit(0)

if __name__ == "__main__":
    signal.signal(signal.SIGQUIT, signal_handler)
    signal.signal(signal.SIGTERM, signal_handler)
    signal.signal(signal.SIGTSTP, signal_handler) # ctrl+z
    signal.signal(signal.SIGINT, signal_handler) # ctrl+c
    # do things
    close_socket()
    sys.exit(0)

2) Make sure _every single possible_ exit location calls close_socket (because atexit will zombie this library)

Hope that helps you too

Maintainers
You should consider fixing your incompatibility with python atexit builtin, being a zombie is not a good look.. or document the atexit limitation (and how to disconnect safely) in the getting started guide.

@chrisdlangton the client in this library installs a signal handler and disconnects any active connections. I'm trying to understand why it did not work in your case.

There are actually two signal handlers, one in python-engineio and one in this project.

The sigint handler in python-engineio will disconnect any active connections, while the handler in this project will stop any ongoing reconnection attempts. Both handlers call other registered handlers. The OP reported a bug in this logic that I need to investigate and fix. Just wanted to mention that your statement that this library is not signal aware is incorrect.

Would you send me a complete example with atexit that shows the zombie problem?

Zombie maker;

import atexit
import logging
import json
import socketio


log = logging.getLogger(__name__)
sio = socketio.Client()
atexit.register(sio.disconnect)

@sio.event
def connect():
    log.info("connected")

@sio.event
def connect_error():
    log.info("connection failed")

@sio.event
def disconnect():
    log.info("disconnected")

def not_the_real_send_event(event: str, data: dict, host: str):
    if not sio.connected:
        sio.connect(host)
    sio.emit(event, json.dumps(data, sort_keys=True, default=str))

if __name__ == "__main__":
    # Do stuff that will use not_the_real_send_event()
    log.info(f'Finished')
    sys.exit(0)

This caused output of connected and expected script outputs, finally i get a Finished which should be the end - however the process remains active. You can force external connectivity to be lost (by cycling the socket server or taking down the interface) which causes the zombie to produce output disconnected followed by connected when a connectivity is re-established. these occur after the exit;

connected
# do stuff that has outputs
Finished
disconnected
connected
disconnected

The fix was simply removing atexit

import logging
import json
import socketio
import signal


log = logging.getLogger(__name__)
sio = socketio.Client()

@sio.event
def connect():
    log.info("connected")

@sio.event
def connect_error():
    log.info("connection failed")

@sio.event
def disconnect():
    log.info("disconnected")

def not_the_real_send_event(event: str, data: dict, host: str):
    if not sio.connected:
        sio.connect(host)
    sio.emit(event, json.dumps(data, sort_keys=True, default=str))

def signal_handler(signum, stack_frame):
    message = f'Signal handler called with signal {signum}'
    log.warning(message)
    log.debug(stack_frame)
    sio.disconnect()
    sys.exit(0)

signal.signal(signal.SIGQUIT, signal_handler)
signal.signal(signal.SIGTERM, signal_handler)
signal.signal(signal.SIGTSTP, signal_handler) # ctrl+z
signal.signal(signal.SIGINT, signal_handler) # ctrl+c

if __name__ == "__main__":
    # Do stuff that will use not_the_real_send_event()
    sio.disconnect()
    log.info(f'Finished')
    sys.exit(0)

However if there is an unhanded signal, and no sio.disconnect() call, we are a zombie again.

@asnelzin Can I ask you to install the python-engineio package from the git master branch and check if your problem is addressed?

@chrisdlangton your test is incorrect in that you are not waiting after connecting and emitting. So the function that you registered with atexit is running concurrently with the asynchronous parts of the connect and emit. If you want a quick & dirty alternative to your test that is valid, add a sio.sleep(2) after the emit, to give time to all these background tasks to complete before you exit.

@miguelgrinberg have tried, but no luck. Still the same behavior

@asnelzin And you are positive you have installed the python-engineio package from its master branch and not from pypi? Can you show me the output of pip freeze to confirm?

@miguelgrinberg yep, pretty sure.

It's says: python-socketio==4.6.1.dev0

I ran: pip install git+https://github.com/miguelgrinberg/python-socketio.git@master

@asnelzin the package that have the fix is python-engineio. Try with that one installed from master.

@miguelgrinberg yes that helps, now it is working as expected. Thanks, I will be using this version from now.

How long it will take to release current master to pypi?

@asnelzin version 3.13.2 is now out with this fix.

The following code is not finishing the program, even setting atexit to finish it.

import socketio
import atexit
import sys

class SocketIOTest:
    def __init__(self):
        self.sio = socketio.Client()

        self.sio.connect('http://localhost:8080')
        self.sio.emit('init', 'message')
        atexit.register(self.atexitFinish)

        @self.sio.event
        def connect():
            print("I'm connected!")

        @self.sio.event
        def connect_error():
            print("The connection failed!")

        @self.sio.event
        def disconnect():
            print("I'm disconnected!")

    def atexitFinish(self):
        self.sio.sleep(2)
        self.sio.disconnect()

s = SocketIOTest()
atexit.register(s.atexitFinish)
print('exiting...')
sys.exit(0)

output:

$ python teste.py
exiting...

And never exits. It hangs the application running

versions:

'python-engineio==3.13.2',
'python-socketio[client]==4.6.1'

Am I doing something wrong? I just want the client to disconnect when my application and I didn't opened another issue because I think this thread is 100% related

@LeonardoRick the order in which things are destroyed/stopped during shutdown of the Python process is really unpredictable, so it is not possible to have a reliable shutdown procedure so late in the life of the process. Here is an alternative that works well:

import socketio
import atexit
import sys

class SocketIOTest:
    def __init__(self):
        self.sio = socketio.Client()

        self.sio.connect('http://localhost:5000')
        self.sio.emit('init', 'message')

        @self.sio.event
        def connect():
            print("I'm connected!")

        @self.sio.event
        def connect_error():
            print("The connection failed!")

        @self.sio.event
        def disconnect():
            print("I'm disconnected!")

    def finish(self):
        self.sio.sleep(2)
        self.sio.disconnect()
        self.sio.wait()

s = SocketIOTest()
print('exiting...')
s.finish()
sys.exit(0)

@miguelgrinberg thanks for answering! This solution is kind of bad for me because I use sys.exit() in a lot of places and I don't want to call s.finish() all the times. Is that possible to use s.finish inside a atexit register?

Anyway, I changed somethings and chose to use the AsyncClient and now I'm disconnected! is printed everytime I sys.exit(), so I guess it's working ok

@LeonardoRick with the standard client it is very difficult to do an orderly exit inside atexit. Asyncio termination is cleaner, for that reason I believe it works better for you.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

kamranhossain picture kamranhossain  路  7Comments

LilyHolms picture LilyHolms  路  4Comments

cetteup picture cetteup  路  6Comments

alcupe picture alcupe  路  5Comments

feikiss picture feikiss  路  3Comments