bug: robot-server errors during shutdown if there's an active RPC connection

[SyntaxColoring]

Overview

The opentrons-robot-server service shows errors if it's shut down under certain circumstances, even though the shutdown is supposed to be graceful. This maybe suggests buggy handling of some resource lifetimes?

Steps to reproduce

1. SSH into a robot and run journalctl -f -u opentrons-robot-server.
2. Connect to the robot with the Opentrons App. Toggle the switch next to the robot's name to start an RPC connection over a WebSocket. (I think that's what that does, anyway?)
3. Run systemctl stop opentrons-robot-server over SSH.

Current behavior

These errors are printed:

Jul 22 18:27:11 red-dust opentrons-api[713]: While reading from socket:
                                             Traceback (most recent call last):
                                               File "usr/lib/python3.7/site-packages/robot_server/service/legacy/rpc/rpc.py", line 157, in handle_new_connection
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 98, in receive_json
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 80, in _raise_on_disconnect
                                             starlette.websockets.WebSocketDisconnect: 1012
Jul 22 18:27:11 red-dust opentrons-api[713]: Closing WebSocket 1900571920
Jul 22 18:27:11 red-dust opentrons-api[713]: Exception in ASGI application
                                             Traceback (most recent call last):
                                               File "usr/lib/python3.7/site-packages/uvicorn/protocols/websockets/wsproto_impl.py", line 209, in run_asgi
                                               File "usr/lib/python3.7/site-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
                                               File "usr/lib/python3.7/site-packages/fastapi/applications.py", line 149, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/applications.py", line 102, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/errors.py", line 146, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/base.py", line 21, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/cors.py", line 68, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/exceptions.py", line 58, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 550, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 283, in handle
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 57, in app
                                               File "usr/lib/python3.7/site-packages/fastapi/routing.py", line 242, in app
                                               File "usr/lib/python3.7/site-packages/robot_server/service/legacy/routers/rpc.py", line 15, in websocket_endpoint
                                               File "usr/lib/python3.7/site-packages/robot_server/service/legacy/rpc/rpc.py", line 165, in handle_new_connection
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 142, in close
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 68, in send
                                               File "usr/lib/python3.7/site-packages/uvicorn/protocols/websockets/wsproto_impl.py", line 281, in send
                                               File "usr/lib/python3.7/site-packages/wsproto/__init__.py", line 64, in send
                                               File "usr/lib/python3.7/site-packages/wsproto/connection.py", line 101, in send
                                             wsproto.utilities.LocalProtocolError: Connection cannot be closed in state ConnectionState.LOCAL_CLOSING

And this one, which is more concerning because it happens during the ASGI shutdown handler, which may prevent subsequent shutdown handlers from running and hide further errors.

Jul 22 18:27:11 red-dust opentrons-api[713]: Waiting for application shutdown.
Jul 22 18:27:11 red-dust opentrons-api[713]: Exception in 'lifespan' protocol
                                             Traceback (most recent call last):
                                               File "usr/lib/python3.7/site-packages/uvicorn/lifespan/on.py", line 48, in main
                                               File "usr/lib/python3.7/site-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
                                               File "usr/lib/python3.7/site-packages/fastapi/applications.py", line 149, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/applications.py", line 102, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/errors.py", line 146, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/base.py", line 21, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/middleware/cors.py", line 68, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/exceptions.py", line 58, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 539, in __call__
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 526, in lifespan
                                               File "usr/lib/python3.7/site-packages/starlette/routing.py", line 504, in shutdown
                                               File "usr/lib/python3.7/site-packages/robot_server/app.py", line 70, in on_shutdown
                                               File "usr/lib/python3.7/site-packages/robot_server/service/legacy/rpc/rpc.py", line 75, in on_shutdown
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 142, in close
                                               File "usr/lib/python3.7/site-packages/starlette/websockets.py", line 70, in send
                                             RuntimeError: Cannot call "send" once a close message has been sent.
Jul 22 18:27:11 red-dust opentrons-api[713]: Application shutdown complete.

Expected behavior

opentrons-robot-server should shut down cleanly.

[SyntaxColoring]

I believe this is moot with the merge of #8913, which removed this RPC endpoint entirely.

I don't know about the "Cannot call 'send' once a close message has been sent" error, but the "Connection cannot be closed in state ConnectionState.LOCAL_CLOSING" error looks to have been caused by this:

opentrons/robot-server/robot_server/service/legacy/rpc/rpc.py

Lines 67 to 76 in 92f7962

	async def on_shutdown(self):
	"""
	Graceful shutdown handler
	See https://docs.aiohttp.org/en/stable/web.html#graceful-shutdown
	"""
	for client_write_tasks in self.clients.copy():
	await client_write_tasks.socket.close(code=WS_1001_GOING_AWAY)
	self.shutdown()

Closing each open WebSocket on shutdown like this was apparently correct when robot-server was on aiohttp, but incorrect after we ported it to FastAPI. This is because FastAPI shutdown handlers run after all connections are already closed (I think), so closing them again here was redundant and an error.