From 3bd9fe63e5eb317211547ee32363e6fa5fc1fc5d Mon Sep 17 00:00:00 2001 From: catborise Date: Mon, 26 Oct 2026 20:45:27 +0300 Subject: [PATCH] fix(console): the console daemons log where the operator looks - novncd and socketiod log to stderr: the journal on hosts, docker logs in the container (runit no longer sends them to unrotated files under /var/log). Django's settings gave them the panel's own log file, which every process rotated on its own, and made novncd's -v and -d have no effect; both work again. - A refused console says why in the log: novncd's denials are warnings (they were shown only with -v), socketiod logs each refusal and who opened which VM's serial console. - The README's serial console notes say what #228 changed (access re-checked, superuser takeover, reasons) and where the logs are. --- README.md | 5 ++-- conf/runit/novncd.sh | 3 ++- conf/runit/socketiod.sh | 3 ++- console/novncd | 46 ++++++++++++++------------------- console/socketiod | 21 ++++++++++++--- console/tests/test_socketiod.py | 4 ++- console/tests/test_views.py | 7 ++--- 7 files changed, 51 insertions(+), 38 deletions(-) diff --git a/README.md b/README.md index ba3e6faa..86c0db3e 100644 --- a/README.md +++ b/README.md @@ -412,8 +412,9 @@ A VM without graphics (no `` device, a ``) opens a - The VM page's Settings → Console switches a shut-off VM between VNC and serial (Console type). A new VNC console takes the form's other fields; on a TCP or TLS compute it needs Listen on: All interfaces (only SSH computes reach a localhost console). - The guest must use its serial port: a login prompt needs `systemctl enable --now serial-getty@ttyS0`, boot messages need the kernel parameter `console=ttyS0,115200`. The console shows only what the guest writes after it opens; press Enter for a new prompt. - socketiod listens on 127.0.0.1:6081; the page reaches it through nginx's `/socket.io/` location on the panel's own address. -- It accepts the console page's signed token, as noVNC does: whoever gets that token within 120 s gets the console, and an open console stays open after its user loses access to the VM. -- One console per VM, at most 20 at a time; a second one shows "refused". +- It accepts the console page's signed token, as noVNC does: whoever gets that token within 120 s gets the console. An open console closes within 10 s once its user loses access to the VM. +- One console per VM, at most 20 at a time; a second one is refused with the reason, except a superuser's, which takes the console over. +- novncd and socketiod log to the journal (`journalctl -u webvirt-novncd -u webvirt-socketiod`) or, in Docker, to `docker logs`: a console that was refused or could not connect says why there. ## Updating diff --git a/conf/runit/novncd.sh b/conf/runit/novncd.sh index 38c02628..7e0c62f3 100755 --- a/conf/runit/novncd.sh +++ b/conf/runit/novncd.sh @@ -1,4 +1,5 @@ #!/bin/sh cd /srv/webvirtcloud || exit 1 -exec /sbin/setuser www-data /srv/webvirtcloud/venv/bin/python3 /srv/webvirtcloud/console/novncd >> /var/log/novncd.log 2>&1 +# its log goes to the container's output (docker logs) +exec /sbin/setuser www-data /srv/webvirtcloud/venv/bin/python3 /srv/webvirtcloud/console/novncd 2>&1 diff --git a/conf/runit/socketiod.sh b/conf/runit/socketiod.sh index ff77d8e5..9c203d0c 100755 --- a/conf/runit/socketiod.sh +++ b/conf/runit/socketiod.sh @@ -2,4 +2,5 @@ # The serial console daemon; it refuses connections while SERIAL_CONSOLE_ENABLED is off. cd /srv/webvirtcloud || exit 1 -exec /sbin/setuser www-data /srv/webvirtcloud/venv/bin/python3 /srv/webvirtcloud/console/socketiod >> /var/log/socketiod.log 2>&1 +# its log goes to the container's output (docker logs) +exec /sbin/setuser www-data /srv/webvirtcloud/venv/bin/python3 /srv/webvirtcloud/console/socketiod 2>&1 diff --git a/console/novncd b/console/novncd index 750b41a1..0be60ccd 100755 --- a/console/novncd +++ b/console/novncd @@ -58,22 +58,18 @@ def get_connection_infos(token): from console.tokens import authorize from vrtManager.instance import wvmInstance - try: - instance, _user = authorize(token) - conn = wvmInstance( - instance.compute.hostname, - instance.compute.login, - instance.compute.password, - instance.compute.type, - instance.name, - uuid=instance.uuid, # the VM access was checked for, whatever its name now - ) - console_host = conn.get_console_listener_addr() - console_port = conn.get_console_port() - console_socket = conn.get_console_socket() - except Exception as e: - logging.error("Fail to retrieve console connection infos: %s", e) - raise + instance, _user = authorize(token) + conn = wvmInstance( + instance.compute.hostname, + instance.compute.login, + instance.compute.password, + instance.compute.type, + instance.name, + uuid=instance.uuid, # the VM access was checked for, whatever its name now + ) + console_host = conn.get_console_listener_addr() + console_port = conn.get_console_port() + console_socket = conn.get_console_socket() compute = instance.compute return compute.hostname, compute.login, compute.type, console_host, console_port, console_socket @@ -98,13 +94,13 @@ class ConsoleClient: # is shared by the browser's tabs and would name the last console opened token = parse_qs(urlparse(self.path).query).get("token", [None])[0] if not token: - self.msg("No console token in the websocket URL") + logging.warning("Console connection without a token in its websocket URL") return try: connhost, connuser, conntype, console_host, console_port, console_socket = get_connection_infos(token) except Exception as e: - self.msg("Console connection denied: %s" % e) + logging.warning("Console connection denied: %s", e) return logging.debug( "Console of %s@%s (type %s): %s:%s, socket %s", @@ -160,14 +156,12 @@ class ConsoleProxyHandler(ProxyRequestHandler, ConsoleClient): if __name__ == "__main__": options = get_parser().parse_args() - FORMAT = "%(asctime)s - %(name)s - %(levelname)s : %(message)s" - if options.debug: - logging.basicConfig(level=logging.DEBUG, format=FORMAT) - options.verbose = True - elif options.verbose: - logging.basicConfig(level=logging.INFO, format=FORMAT) - else: - logging.basicConfig(level=logging.WARNING, format=FORMAT) + # to stderr (the journal, docker logs), not the panel's own log file: + # each process rotating that file would lose lines. force: Django's + # settings already gave the root logger that file. + level = logging.DEBUG if options.debug else logging.INFO if options.verbose else logging.WARNING + logging.basicConfig(level=level, format="%(levelname)s %(name)s: %(message)s", force=True) + options.verbose = options.verbose or options.debug # nginx ends TLS: novncd speaks plain websockets on the loopback WebSocketProxy( diff --git a/console/socketiod b/console/socketiod index 83cf014e..707b81ca 100755 --- a/console/socketiod +++ b/console/socketiod @@ -7,6 +7,7 @@ import argparse import codecs import fcntl +import logging import os import pty import select @@ -34,6 +35,7 @@ from console.tokens import authorize # noqa: E402 CONSOLECALLBACK = os.path.join(ROOT_PATH, "conf", "daemon", "consolecallback") MAX_SESSIONS = 20 +logger = logging.getLogger("socketiod") sio = socketio.Server(async_mode="threading") # the same origin only # Handlers run on their own threads. sessions (sid -> {"pid", "fd", "vm", # "lock", "open"}) changes only under sessions_lock; a session's fd is used @@ -43,24 +45,30 @@ sessions = {} sessions_lock = threading.Lock() +def refused(reason): + """The refusal the page shows; it is logged too.""" + logger.info("serial console refused: %s", reason) + return socketio.exceptions.ConnectionRefusedError(reason) + + @sio.event def connect(sid, environ, auth): # the page shows the reason if not settings.SERIAL_CONSOLE_ENABLED: - raise socketio.exceptions.ConnectionRefusedError("The serial console is turned off on this server") + raise refused("The serial console is turned off on this server") try: instance, user = authorize((auth or {}).get("token")) except PermissionError: - raise socketio.exceptions.ConnectionRefusedError("The console link has expired: reload the page") + raise refused("The console link has expired: reload the page") finally: db.close_old_connections() taken = None with sessions_lock: open_sid = next((s for s, session in sessions.items() if session["vm"] == instance.pk), None) if open_sid is not None and not user.is_superuser: - raise socketio.exceptions.ConnectionRefusedError("The console of this VM is open in another window") + raise refused("The console of this VM is open in another window") if open_sid is None and len(sessions) >= MAX_SESSIONS: - raise socketio.exceptions.ConnectionRefusedError("Too many consoles are open on this server: try again later") + raise refused("Too many consoles are open on this server: try again later") if open_sid is not None: # a superuser takes over a console left open taken = open_sid, sessions.pop(open_sid) pid, fd = pty.fork() @@ -73,6 +81,8 @@ def connect(sid, environ, auth): finally: os._exit(1) sessions[sid] = session = {"pid": pid, "fd": fd, "vm": instance.pk, "lock": threading.Lock(), "open": True} + logger.info("serial console of VM %s opened by %s%s", instance.name, user.username, + " (taken over)" if taken else "") if taken: old_sid, old_session = taken sio.emit("pty_output", {"output": "\r\n[An administrator opened this console]\r\n"}, to=old_sid) @@ -183,4 +193,7 @@ if __name__ == "__main__": parser.add_argument("-H", "--host", default=settings.SOCKETIO_HOST, help="Listen host") parser.add_argument("-p", "--port", type=int, default=settings.SOCKETIO_PORT, help="Listen port") options = parser.parse_args() + # to stderr (the journal, docker logs), not the panel's own log file: + # each process rotating that file would lose lines + logging.basicConfig(level=logging.INFO, format="%(levelname)s %(name)s: %(message)s", force=True) Server(options.host, options.port).run() diff --git a/console/tests/test_socketiod.py b/console/tests/test_socketiod.py index 274c09f9..4957b851 100644 --- a/console/tests/test_socketiod.py +++ b/console/tests/test_socketiod.py @@ -91,8 +91,10 @@ class SocketiodTestCase(Base): self.assertEqual(self.started[0][0], self.d.forward) def refused(self, sid, auth): - with self.assertRaises(self.d.socketio.exceptions.ConnectionRefusedError) as refusal: + with self.assertRaises(self.d.socketio.exceptions.ConnectionRefusedError) as refusal, \ + self.assertLogs("socketiod", level="INFO") as log: # the reason is logged too self.d.connect(sid, {}, auth) + self.assertIn(refusal.exception.error_args["message"], log.output[0]) return refusal.exception.error_args["message"] def test_refused_connections_start_nothing_and_say_why(self): diff --git a/console/tests/test_views.py b/console/tests/test_views.py index b319caa1..41741bf9 100644 --- a/console/tests/test_views.py +++ b/console/tests/test_views.py @@ -577,12 +577,13 @@ class NovncdDaemonLogicTestCase(TestCase): handler.msg = MagicMock() socket_factory = MagicMock() - # Should cleanly exit and log message without raising UnboundLocalError - handler._new_client(socket_factory=socket_factory) + # a refusal is a warning: it shows in the log without -v + with self.assertLogs(level="WARNING") as log: + handler._new_client(socket_factory=socket_factory) mock_get_info.assert_not_called() socket_factory.assert_not_called() - handler.msg.assert_called_with("No console token in the websocket URL") + self.assertIn("without a token", log.output[0]) @patch("console.tokens.authorize") @patch("vrtManager.instance.wvmInstance")