From 9402df2bdd66c8442988a54d0814ecc54d3cd3fc Mon Sep 17 00:00:00 2001 From: Markus Hilger Date: Fri, 14 Aug 2026 01:18:47 +0200 Subject: [PATCH] Stop a websocket console spinning once its peer is gone The receive loop treated only WSMsgType.CLOSE as the end of a session, but aiohttp reports a peer that has gone away as CLOSED, and it does so immediately and for every subsequent call. Everything that was not CLOSE fell to an else branch that printed a line and went round again, so a console whose bmc restarted became a full speed loop writing one line per iteration: measured at 2.7 million iterations a second, and observed filling 15 GB of log in a quarter of an hour while the daemon stopped answering requests. Treat every message that is not data as the end of the session, clear the connected flag and report the disconnect once. A session that ended any other way than a clean close is recorded in the trace log, unbuffered so that it survives a daemon that does not, rather than printed. Both websocket console plugins carried the same loop. While here, give the openbmc one the parts tsmsol already had: text frames are data rather than a surprise, and the client session is closed when the upgrade fails and when the console does, instead of being leaked. --- .../confluent/plugins/console/openbmc.py | 60 ++++++++++++++++--- .../confluent/plugins/console/tsmsol.py | 44 +++++++++++--- 2 files changed, 88 insertions(+), 16 deletions(-) diff --git a/confluent_server/confluent/plugins/console/openbmc.py b/confluent_server/confluent/plugins/console/openbmc.py index 2d71acb4..02f05126 100644 --- a/confluent_server/confluent/plugins/console/openbmc.py +++ b/confluent_server/confluent/plugins/console/openbmc.py @@ -20,14 +20,34 @@ # to use this. import asyncio +import traceback import confluent.exceptions as cexc import confluent.interface.console as conapi +import confluent.log as log import confluent.tasks as tasks import confluent.util as util import aiohmi.exceptions as pygexc import aiohmi.util.webclient as webclient import aiohttp +_tracelog = None + + +def _trace(text, event=log.Events.stacktrace): + """Record a console problem where an operator can find it. + + A daemon has nowhere useful to print to, and printing once per message + received is how a websocket that had already gone away managed to write + gigabytes of a single line. + """ + global _tracelog + if _tracelog is None: + # Unbuffered: this records a console that has just gone away, and + # the daemon may not survive long enough to flush a buffered write. + _tracelog = log.Logger('trace', buffered=False) + _tracelog.log(text, ltype=log.DataTypes.event, event=event) + + class CustomVerifier(aiohttp.Fingerprint): def __init__(self, verifycallback): self._certverify = verifycallback @@ -83,6 +103,7 @@ class OpenBmcConsole(conapi.Console): self.nodeconfig = config self.connected = False self.recvr = None + self.clisess = None async def recvdata(self): @@ -92,11 +113,23 @@ class OpenBmcConsole(conapi.Console): if pendingdata.type == aiohttp.WSMsgType.BINARY: await self.datacallback(pendingdata.data) continue - elif pendingdata.type == aiohttp.WSMsgType.CLOSE: - await self.datacallback(conapi.ConsoleEvent.Disconnect) - return - else: - print("Unknown response in WSConsoleHandler") + elif pendingdata.type == aiohttp.WSMsgType.TEXT: + await self.datacallback(pendingdata.data.encode()) + continue + # Every other message type means the socket is finished. Once + # the peer is gone receive() answers CLOSED straight away and + # keeps doing so, so looping here would spin rather than wait. + if pendingdata.type != aiohttp.WSMsgType.CLOSE: + _trace( + 'Console websocket for {0} ended with {1}{2}'.format( + self.node, pendingdata.type.name, + ': {0}'.format(pendingdata.data) + if pendingdata.type == aiohttp.WSMsgType.ERROR + else ''), + event=log.Events.consoledisconnect) + self.connected = False + await self.datacallback(conapi.ConsoleEvent.Disconnect) + return except asyncio.CancelledError: pass @@ -118,8 +151,12 @@ class OpenBmcConsole(conapi.Console): for ck in wc.cookies: if ck.key == 'XSRF-TOKEN': protos = [ck.value] - self.ws = await self.clisess.ws_connect('wss://{0}/console0'.format(self.bmc), protocols=protos, ssl=self.ssl) - #self.ws.connect('wss://{0}/console0'.format(self.bmc), host=bmc, cookie='XSRF-TOKEN={0}; SESSION={1}'.format(wc.cookies['XSRF-TOKEN'], wc.cookies['SESSION']), subprotocols=[wc.cookies['XSRF-TOKEN']]) + try: + self.ws = await self.clisess.ws_connect('wss://{0}/console0'.format(self.bmc), protocols=protos, ssl=self.ssl) + except Exception: + await self.clisess.close() + self.clisess = None + raise self.connected = True self.recvr = tasks.spawn_task(self.recvdata()) return @@ -127,8 +164,9 @@ class OpenBmcConsole(conapi.Console): async def write(self, data): try: await self.ws.send_str(data.decode()) - except Exception as e: - print(repr(e)) + except Exception: + _trace('Console websocket write for {0} failed:\n{1}'.format( + self.node, traceback.format_exc())) await self.datacallback(conapi.ConsoleEvent.Disconnect) async def close(self): @@ -137,6 +175,10 @@ class OpenBmcConsole(conapi.Console): self.recvr = None if self.ws: await self.ws.close() + self.ws = None + if self.clisess: + await self.clisess.close() + self.clisess = None self.connected = False self.datacallback = None diff --git a/confluent_server/confluent/plugins/console/tsmsol.py b/confluent_server/confluent/plugins/console/tsmsol.py index 8c5b00a4..4abdf485 100644 --- a/confluent_server/confluent/plugins/console/tsmsol.py +++ b/confluent_server/confluent/plugins/console/tsmsol.py @@ -20,14 +20,34 @@ # to use this. import asyncio +import traceback import confluent.exceptions as cexc import confluent.interface.console as conapi +import confluent.log as log import confluent.tasks as tasks import confluent.util as util import aiohmi.exceptions as pygexc import aiohmi.redfish.command as rcmd import aiohttp +_tracelog = None + + +def _trace(text, event=log.Events.stacktrace): + """Record a console problem where an operator can find it. + + A daemon has nowhere useful to print to, and printing once per message + received is how a websocket that had already gone away managed to write + gigabytes of a single line. + """ + global _tracelog + if _tracelog is None: + # Unbuffered: this records a console that has just gone away, and + # the daemon may not survive long enough to flush a buffered write. + _tracelog = log.Logger('trace', buffered=False) + _tracelog.log(text, ltype=log.DataTypes.event, event=event) + + class CustomVerifier(aiohttp.Fingerprint): def __init__(self, verifycallback): self._certverify = verifycallback @@ -96,11 +116,20 @@ class TsmConsole(conapi.Console): elif pendingdata.type == aiohttp.WSMsgType.TEXT: await self.datacallback(pendingdata.data.encode()) continue - elif pendingdata.type == aiohttp.WSMsgType.CLOSE: - await self.datacallback(conapi.ConsoleEvent.Disconnect) - return - else: - print("Unknown response in WSConsoleHandler") + # Every other message type means the socket is finished. Once + # the peer is gone receive() answers CLOSED straight away and + # keeps doing so, so looping here would spin rather than wait. + if pendingdata.type != aiohttp.WSMsgType.CLOSE: + _trace( + 'Console websocket for {0} ended with {1}{2}'.format( + self.node, pendingdata.type.name, + ': {0}'.format(pendingdata.data) + if pendingdata.type == aiohttp.WSMsgType.ERROR + else ''), + event=log.Events.consoledisconnect) + self.connected = False + await self.datacallback(conapi.ConsoleEvent.Disconnect) + return except asyncio.CancelledError: pass @@ -133,8 +162,9 @@ class TsmConsole(conapi.Console): async def write(self, data): try: await self.ws.send_str(data.decode()) - except Exception as e: - print(repr(e)) + except Exception: + _trace('Console websocket write for {0} failed:\n{1}'.format( + self.node, traceback.format_exc())) await self.datacallback(conapi.ConsoleEvent.Disconnect) async def close(self):