Description
The RFC says:
The underlying TCP connection, in most normal cases, SHOULD be closed
first by the server, so that it holds the TIME_WAIT state and not the
client (as this would prevent it from re-opening the connection for 2
maximum segment lifetimes (2MSL), while there is no corresponding
server impact as a TIME_WAIT connection is immediately reopened upon
a new SYN with a higher seq number). In abnormal cases (such as not
having received a TCP Close from the server after a reasonable amount
of time) a client MAY initiate the TCP Close. As such, when a server
is instructed to Close the WebSocket Connection it SHOULD initiate
a TCP Close immediately, and when a client is instructed to do the
same, it SHOULD wait for a TCP Close from the server.
This doesn't always happen. I noticed this while testing a trio-websocket server with an asyncio websockets client. After doing the WebSocket closing handshake, the client times out after 10 seconds waiting for the server to close the connection.
The server code:
import logging
import trio
from trio_websocket import open_websocket_url, serve_websocket, ConnectionClosed
logging.basicConfig(level=logging.DEBUG)
async def handler(request):
conn = await request.accept()
try:
while True:
message = await conn.get_message()
await conn.send_message(message)
except ConnectionClosed:
pass
await conn.aclose()
async def main():
logging.info('Listening on ws://127.0.0.1:8000')
try:
await serve_websocket(handler, '127.0.0.1', 8000, ssl_context=None)
except KeyboardInterrupt:
logging.warning('Received interrupt: aborting')
trio.run(main, restrict_keyboard_interrupt_to_checkpoints=True)The client code:
import asyncio
import logging
import websockets
logging.basicConfig(level=logging.DEBUG)
async def main():
url = 'ws://localhost:8000'
logging.info('Connecting to %s', url)
async with websockets.connect(url) as conn:
await conn.send('this is a test message')
response = await conn.recv()
logging.info('Got response: %s', response)
asyncio.get_event_loop().run_until_complete(main())And a relevant section of the client's logs:
DEBUG:websockets.protocol:client - state = CLOSING
DEBUG:websockets.protocol:client > Frame(fin=True, opcode=8, data=b'\x03\xe8', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=8, data=b'\x03\xe8', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client ! timed out waiting for TCP close
DEBUG:websockets.protocol:client x half-closing TCP connection
DEBUG:websockets.protocol:client - event = eof_received()
DEBUG:websockets.protocol:client - event = connection_lost(None)
DEBUG:websockets.protocol:client - state = CLOSED
DEBUG:websockets.protocol:client x code = 1000, reason = [no reason]
This is tangled up with #90 a bit but is a bit more urgent for me personally because I'm now using a trio websocket server with an asyncio client.