Close sync ServerConnection before reading all data gives hanging threads

[mandermo]

Closing sync ServerConnection from server side, before consuming all data results in deadlocked threads started by websockets, preventing the program from exiting. I have attached (main.py.txt) a minimal example with a client and a server that consistently results in the problem. It is stuck on self.messages_fetched.wait() in Assembler.put() and on self.recv_events_thread.join() in Connection.send_context().

It also provides a switch to use the asyncio based websockets server instead, which doesn't suffer from the issue. Here is a run on latest main with hash bb17be2.

This is the threads from websockets at the end of the execution, also printed by the script:

Thread 0x00007f3cecabb640 (most recent call first):
  File "/usr/lib/python3.10/threading.py", line 320 in wait
  File "/usr/lib/python3.10/threading.py", line 607 in wait
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/messages.py", line 245 in put
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/connection.py", line 485 in process_event
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/server.py", line 160 in process_event
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/connection.py", line 579 in recv_events
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/server.py", line 168 in recv_events
  File "/usr/lib/python3.10/threading.py", line 953 in run
  File "/usr/lib/python3.10/threading.py", line 1016 in _bootstrap_inner
  File "/usr/lib/python3.10/threading.py", line 973 in _bootstrap

Thread 0x00007f3ced2bc640 (most recent call first):
  File "/usr/lib/python3.10/threading.py", line 1116 in _wait_for_tstate_lock
  File "/usr/lib/python3.10/threading.py", line 1096 in join
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/connection.py", line 712 in send_context
  File "/usr/lib/python3.10/contextlib.py", line 142 in __exit__
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/connection.py", line 399 in close
  File "/home/mandermo/develop/bsh/websockets/src/websockets/sync/server.py", line 498 in conn_handler
  File "/usr/lib/python3.10/threading.py", line 953 in run
  File "/usr/lib/python3.10/threading.py", line 1016 in _bootstrap_inner
  File "/usr/lib/python3.10/threading.py", line 973 in _bootstrap

[aaugustin]

Thank for you the bug report. I'll look into it.

[aaugustin]

TIL about faulthandler 🤩

Here's a reproduction that doesn't involve threads outside of those created by websockets itself and produces the same deadlock.

Server

#!/usr/bin/env python

import faulthandler
import os
import time

from websockets.sync.server import serve

faulthandler.enable()
print(f"When stuck, dump stack trace with:")
print(f"kill -ABRT {os.getpid()}")

def handler(websocket):
    time.sleep(1)
    print("closing...")
    t0 = time.time()
    websocket.close()
    t1 = time.time()
    print(f"closed in {t1 - t0:.1f}s")

with serve(handler, "localhost", 8765, close_timeout=2) as server:
    server.serve_forever()

Client

#!/usr/bin/env python

from websockets.sync.client import connect

with connect("ws://localhost:8765", close_timeout=1) as websocket:
    websocket.send("message")
    for msg in websocket:
        raise AssertionError("no message expected")

Deadlock

Fatal Python error: Aborted

Thread 0x000000016f79f000 (most recent call first):
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 320 in wait
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 622 in wait
  File "/Users/myk/dev/websockets/src/websockets/sync/messages.py", line 245 in put
  File "/Users/myk/dev/websockets/src/websockets/sync/connection.py", line 485 in process_event
  File "/Users/myk/dev/websockets/src/websockets/sync/server.py", line 160 in process_event
  File "/Users/myk/dev/websockets/src/websockets/sync/connection.py", line 579 in recv_events
  File "/Users/myk/dev/websockets/src/websockets/sync/server.py", line 168 in recv_events
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 975 in run
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 1038 in _bootstrap_inner
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 995 in _bootstrap

Thread 0x000000016e793000 (most recent call first):
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 1132 in _wait_for_tstate_lock
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 1112 in join
  File "/Users/myk/dev/websockets/src/websockets/sync/connection.py", line 710 in send_context
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/contextlib.py", line 144 in __exit__
  File "/Users/myk/dev/websockets/src/websockets/sync/connection.py", line 399 in close
  File "/Users/myk/dev/websockets/issue-1336-server.py", line 17 in handler
  File "/Users/myk/dev/websockets/src/websockets/sync/server.py", line 493 in conn_handler
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 975 in run
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 1038 in _bootstrap_inner
  File "/Users/myk/.pyenv/versions/3.11.2/lib/python3.11/threading.py", line 995 in _bootstrap

Current thread 0x00000001ebbc5b40 (most recent call first):
  File "/Users/myk/dev/websockets/src/websockets/sync/server.py", line 222 in serve_forever
  File "/Users/myk/dev/websockets/issue-1336-server.py", line 22 in <module>

Extension modules: websockets.speedups (total: 1)

[mandermo]

Thanks for looking into it, keep up the great work. Yeah, faulthandler can be pretty handy :) FYI, can sometimes be used without special code in the monitored program also https://docs.python.org/3/using/cmdline.html#envvar-PYTHONFAULTHANDLER and triggered with pkill -ABRT -f 'python3 server.py'.

[aaugustin]

After checking other places where the same issue may occur, I'll make a more thorough fix. Also, I'll add tests. Right now CI is failing because the new code isn't covered by tests and release the fix.