From 5b8793ad4cf6d2dc66c0b72c4731b8ab55f06306 Mon Sep 17 00:00:00 2001 From: catborise Date: Fri, 23 Oct 2026 11:24:24 +0300 Subject: [PATCH] feat(logs): changes to networks, storage, interfaces, secrets and filters are logged The Logs page now records every change an admin makes to a compute's libvirt objects, with the compute's name in the host column: - networks: add, start, stop, delete, autostart, DHCP range, fixed addresses, QoS and XML edits; - storage pools: add, start, stop, delete, autostart, from web and API; volumes: add and delete (web and API), clone and ISO upload; - host interfaces: add, start, stop, delete; - secrets: add, set value (never the value), delete; - network filters: add, clone, delete, XML edits, rules and references. A refused or failed change is a failed row with its reason (libvirt text through safe_text). The volume clone and upload jobs write their row when they end; a refused submission is a failed row at once. A volume row names the volume libvirt created (a dir pool adds .qcow2 or .img). Volume create or delete through the API on an inactive pool (409) is a failed row. Network filters: the rows read "Network filter f1: add" instead of "f1 network filter is created", and their host is the compute's name instead of its hostname. A duplicate name or UUID no longer raises a bare exception, and a filter XML that cannot be parsed no longer ends in UnboundLocalError. --- README.md | 2 +- interfaces/tests/test_audit_rows.py | 38 +++++ interfaces/views.py | 39 +++-- networks/tests/test_audit_rows.py | 93 +++++++++++ networks/views.py | 66 ++++---- nwfilters/tests/test_audit_rows.py | 105 +++++++++++++ nwfilters/views.py | 68 ++++---- storages/api/viewsets.py | 31 ++-- storages/jobs.py | 12 ++ storages/tests/test_audit_rows.py | 225 +++++++++++++++++++++++++++ storages/upload.py | 11 +- storages/views.py | 96 +++++++----- virtsecrets/tests/test_audit_rows.py | 57 +++++++ virtsecrets/views.py | 20 ++- 14 files changed, 716 insertions(+), 147 deletions(-) create mode 100644 interfaces/tests/test_audit_rows.py create mode 100644 networks/tests/test_audit_rows.py create mode 100644 nwfilters/tests/test_audit_rows.py create mode 100644 storages/tests/test_audit_rows.py create mode 100644 virtsecrets/tests/test_audit_rows.py diff --git a/README.md b/README.md index 1ee61495..695b805f 100644 --- a/README.md +++ b/README.md @@ -583,7 +583,7 @@ A version from before v3.0.0 has no worker: `systemctl disable --now webvirt-wor - A disk can be grown while its VM runs or is paused, not only when it is shut off. A disk on an LVM pool cannot be grown (libvirt cannot resize its volumes): the resize says so instead of failing, and the VM's other disks still grow. - Enabling vCPU hot plug keeps the VM's current vCPU count (it enabled all of them up to the maximum). - A host's CPU graph shows the average since its previous point (normally 5 s) instead of a 1 s sample taken while a worker waits. -- The Logs page records who added, changed or deleted a compute, user, group (with its members and permissions), VM owner, flavor, setting, removed-VM record or SSH key, who mailed an OTP QR code, and every login, failed login, lockout and logout, with the address it came from and whether it worked (Result: Done, Failed, Unknown for older rows); a compute's VMs leaving the panel get a row each. Changes of networks, storage and other host objects follow. +- The Logs page records who added, changed or deleted a compute, user, group (with its members and permissions), VM owner, flavor, setting, removed-VM record or SSH key, who mailed an OTP QR code, and every login, failed login, lockout and logout, with the address it came from and whether it worked (Result: Done, Failed, Unknown for older rows); a compute's VMs leaving the panel get a row each. On each compute it records changes to networks, storage pools, volumes (including clones and ISO uploads), host interfaces, secrets (never their values) and network filters. - The CPU usage in the new-VM dialog is the current load (over 1 s), read when the dialog opens; it was the average since the host booted. - A VM's stats are polled every 5 s like the host graph, the first point as soon as the tab opens; each point is the average since the previous one, disk rates in MB/s (they were MiB/s labelled Mb/s); a counter the host does not report shows a gap instead of 0. - An ISO uploads to an SSH compute about 3.5 times faster (SFTP writes no longer wait for each 32 KiB); a failed write still fails the upload. diff --git a/interfaces/tests/test_audit_rows.py b/interfaces/tests/test_audit_rows.py new file mode 100644 index 00000000..5a428695 --- /dev/null +++ b/interfaces/tests/test_audit_rows.py @@ -0,0 +1,38 @@ +"""Host interface changes write rows on the Logs page.""" + +from unittest.mock import patch + +from computes.models import Compute +from django.contrib.auth import get_user_model +from django.test import TestCase +from django.urls import reverse + +from logs.models import Logs + + +class InterfaceRowTests(TestCase): + def setUp(self): + self.compute = Compute.objects.create(name="c1", hostname="localhost", login="", password="", type=4) + self.client.force_login(get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw")) + Logs.objects.all().delete() # the login's row + + @patch("interfaces.views.wvmInterface") + @patch("interfaces.views.wvmInterfaces") + def test_interface_actions(self, ifaces, iface): + ifaces.return_value.can_change_interfaces.return_value = True + ifaces.return_value.get_net_devices.return_value = ["eth0"] + ifaces.return_value.get_ifaces.return_value = [] + iface.return_value.can_change_interfaces.return_value = True + self.client.post(reverse("interfaces", args=[self.compute.id]), { + "create": "", "name": "br1", "itype": "bridge", "start_mode": "onboot", "netdev": "eth0", + "ipv4_type": "dhcp", "ipv6_type": "none", "stp": "on", "delay": "0"}) + ifaces.return_value.create_iface.assert_called_once() + url = reverse("interface", args=[self.compute.id, "br1"]) + for action in ("start", "stop", "delete"): + self.client.post(url, {action: ""}) + self.assertEqual(list(Logs.objects.order_by("id").values_list("message", "success", "host")), [ + ("Interface br1: add", True, "c1"), + ("Interface br1: start", True, "c1"), + ("Interface br1: stop", True, "c1"), + ("Interface br1: delete", True, "c1"), + ]) diff --git a/interfaces/views.py b/interfaces/views.py index 9397d99a..78d74e64 100644 --- a/interfaces/views.py +++ b/interfaces/views.py @@ -6,6 +6,7 @@ from django.utils.translation import gettext_lazy as _ from libvirt import libvirtError from computes.models import Compute from interfaces.forms import AddInterface +from logs.audit import audit from vrtManager.interface import wvmInterface, wvmInterfaces from admin.decorators import superuser_only @@ -57,20 +58,21 @@ def interfaces(request, compute_id): form = AddInterface(request.POST, netdevs=netdevs) if form.is_valid(): data = form.cleaned_data - conn.create_iface( - data["name"], - data["itype"], - data["start_mode"], - data["netdev"], - data["ipv4_type"], - data["ipv4_addr"], - data["ipv4_gw"], - data["ipv6_type"], - data["ipv6_addr"], - data["ipv6_gw"], - data["stp"], - data["delay"], - ) + with audit(request, compute, f"Interface {data['name']}", "add"): + conn.create_iface( + data["name"], + data["itype"], + data["start_mode"], + data["netdev"], + data["ipv4_type"], + data["ipv4_addr"], + data["ipv4_gw"], + data["ipv6_type"], + data["ipv6_addr"], + data["ipv6_gw"], + data["stp"], + data["delay"], + ) return HttpResponseRedirect(request.get_full_path()) else: for msg_err in form.errors.values(): @@ -117,13 +119,16 @@ def interface(request, compute_id, iface): # the page says why nothing is done on a host that cannot change interfaces if request.method == "POST" and changeable: if "stop" in request.POST: - conn.stop_iface() + with audit(request, compute, f"Interface {iface}", "stop"): + conn.stop_iface() return HttpResponseRedirect(request.get_full_path()) if "start" in request.POST: - conn.start_iface() + with audit(request, compute, f"Interface {iface}", "start"): + conn.start_iface() return HttpResponseRedirect(request.get_full_path()) if "delete" in request.POST: - conn.delete_iface() + with audit(request, compute, f"Interface {iface}", "delete"): + conn.delete_iface() return HttpResponseRedirect(reverse("interfaces", args=[compute_id])) conn.close() except libvirtError as lib_err: diff --git a/networks/tests/test_audit_rows.py b/networks/tests/test_audit_rows.py new file mode 100644 index 00000000..ef133e61 --- /dev/null +++ b/networks/tests/test_audit_rows.py @@ -0,0 +1,93 @@ +"""Network changes write rows on the Logs page. Runs on a private libvirt test driver.""" + +import tempfile +from unittest.mock import patch + +import libvirt +from computes.models import Compute +from django.contrib.auth import get_user_model +from django.contrib.messages import get_messages +from django.test import TestCase +from django.urls import reverse + +from logs.models import Logs + +NODE = """ + lab + + +""" + + +def rows(): + return list(Logs.objects.order_by("id").values_list("message", "success")) + + +class NetworkRowTests(TestCase): + def setUp(self): + node = tempfile.NamedTemporaryFile("w", suffix=".xml") + self.addCleanup(node.close) + node.write(NODE) + node.flush() + self.conn = libvirt.open(f"test://{node.name}") + self.addCleanup(self.conn.close) + patcher = patch("vrtManager.connection.connection_manager.get_connection", return_value=self.conn) + patcher.start() + self.addCleanup(patcher.stop) + self.compute = Compute.objects.create(name="c1", hostname="localhost", login="", password="", type=4) + self.client.force_login(get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw")) + Logs.objects.all().delete() # the login's row + self.url = reverse("network", args=[self.compute.id, "lab"]) + + def post(self, data): + return self.client.post(self.url, data) + + def test_network_actions(self): + xml = self.conn.networkLookupByName("lab").XMLDesc(0) + self.post({"stop": ""}) + self.post({"modify_dhcp_range": "", "range_start": "192.0.2.30", "range_end": "192.0.2.40", "family": "ipv4"}) + self.post({"start": ""}) + self.post({"set_autostart": ""}) + self.post({"unset_autostart": ""}) + self.post({"modify_fixed_address": "", "name": "web-1", "address": "192.0.2.31", + "mac": "52:54:00:00:00:31", "family": "ipv4"}) + self.post({"delete_fixed_address": "", "address": "192.0.2.31", "family": "ipv4"}) + self.post({"set_qos": "", "qos_direction": "inbound", "qos_average": "100"}) + self.post({"unset_qos": "", "qos_direction": "inbound"}) + self.post({"edit_network": "", "edit_xml": xml}) + self.post({"stop": ""}) + self.post({"delete": ""}) + self.assertEqual(rows(), [ + ("Network lab: stop", True), + ("Network lab: set DHCP range IPV4", True), + ("Network lab: start", True), + ("Network lab: autostart on", True), + ("Network lab: autostart off", True), + ("Network lab: set fixed address 192.0.2.31", True), + ("Network lab: delete fixed address 192.0.2.31", True), + ("Network lab: set QoS inbound", True), + ("Network lab: unset QoS inbound", True), + ("Network lab: change XML", True), + ("Network lab: stop", True), + ("Network lab: delete", True), + ]) + self.assertFalse(Logs.objects.filter(message__contains="{UUID}" + "") +NEW = "6d1f7a10-0000-4000-8000-0000000000f1" + + +def rows(): + return list(Logs.objects.order_by("id").values_list("message", "success")) + + +class FilterRowTests(TestCase): + def setUp(self): + patcher = patch("vrtManager.connection.connection_manager.get_connection") + self.wvm = patcher.start().return_value + self.addCleanup(patcher.stop) + nwfilter = self.wvm.nwfilterLookupByName.return_value + nwfilter.XMLDesc.return_value = XML + nwfilter.name.return_value = "web" + nwfilter.UUIDString.return_value = UUID + self.wvm.listNWFilters.return_value = ["web"] + self.compute = Compute.objects.create(name="c1", hostname="localhost", login="", password="", type=4) + self.client.force_login(get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw")) + Logs.objects.all().delete() # the login's row + self.list_url = reverse("nwfilters", args=[self.compute.id]) + self.url = reverse("nwfilter", args=[self.compute.id, "web"]) + + @patch("nwfilters.views.wvmInstances") + def test_filter_list_actions(self, instances): + instances.return_value.get_instances.return_value = [] + self.client.post(self.list_url, {"create_nwfilter": "", "nwfilter_xml": NEW}) + self.client.post(self.list_url, {"cln_nwfilter": "", "nwfiltername": "web", "cln_name": "web-copy"}) + self.client.post(self.list_url, {"del_nwfilter": "", "nwfiltername": "web"}) + self.assertEqual(rows(), [ + ("Network filter f1: add", True), + ("Network filter web: clone as web-copy", True), + ("Network filter web: delete", True), + ]) + self.assertEqual(set(Logs.objects.values_list("host", flat=True)), {"c1"}) + + def test_a_duplicate_filter_is_a_failed_row(self): + response = self.client.post(self.list_url, {"create_nwfilter": "", "nwfilter_xml": XML}) + self.assertIn("A network filter with this name already exists", + [str(m) for m in get_messages(response.wsgi_request)]) + other = XML.replace("name='web'", "name='other'") + self.client.post(self.list_url, {"create_nwfilter": "", "nwfilter_xml": other}) + self.wvm.nwfilterDefineXML.assert_not_called() + self.assertEqual(rows(), [ + ("Network filter web: add: name already in use", False), + ("Network filter other: add: UUID already in use", False), + ]) + + def test_an_unparsable_filter(self): + self.wvm.nwfilterDefineXML.side_effect = libvirtError("XML error") + response = self.client.post(self.list_url, {"create_nwfilter": "", "nwfilter_xml": ""}) + self.client.post(self.url, {"del_nwfilter_rule": "", "action": "drop", "direction": "in", "priority": "900"}) + self.client.post(self.url, {"add_nwfilter_ref": "", "nwfilters_select": "no-spoofing"}) + self.client.post(self.url, {"del_nwfilter_ref": "", "ref": "clean-traffic"}) + self.assertEqual(rows(), [ + ("Network filter web: change XML", True), + ("Network filter web: add rule", True), + ("Network filter web: delete rule", True), + ("Network filter web: add reference no-spoofing", True), + ("Network filter web: delete reference clean-traffic", True), + ]) + self.assertFalse(Logs.objects.filter(message__contains="<").exists()) + + def test_a_failing_rule_add(self): + self.wvm.nwfilterDefineXML.side_effect = libvirtError("refused") + response = self.client.post(self.url, {"add_nwfilter_rule": "", "nwfilterrule_xml": ""}) + self.assertIn("refused", " ".join(str(m) for m in get_messages(response.wsgi_request))) + [(message, success)] = rows() + self.assertFalse(success) + self.assertTrue(message.startswith("Network filter web: add rule: "), message) diff --git a/nwfilters/views.py b/nwfilters/views.py index 8560ba13..bc2d247d 100644 --- a/nwfilters/views.py +++ b/nwfilters/views.py @@ -5,7 +5,7 @@ from django.http import HttpResponseRedirect from django.shortcuts import get_object_or_404, render from django.utils.translation import gettext_noop as _ from libvirt import libvirtError -from logs.views import addlogmsg +from logs.audit import audit, failed from vrtManager import util from vrtManager.instance import wvmInstance, wvmInstances from vrtManager.nwfilters import wvmNWFilter, wvmNWFilters @@ -37,40 +37,33 @@ def nwfilters(request, compute_id): if "create_nwfilter" in request.POST: xml = request.POST.get("nwfilter_xml", "") if xml: + name = uuid = None try: util.etree.fromstring(xml) name = util.get_xml_path(xml, "/filter/@name") uuid = util.get_xml_path(xml, "/filter/uuid") except util.etree.ParseError: - name = None + pass + subject = f"Network filter {name or '(no name)'}" for nwf in nwfilters_all: if name == nwf["name"]: - error_msg = _( - "A network filter with this name already exists" - ) - raise Exception(error_msg) + failed(request, compute, subject, "add", "name already in use") + messages.error(request, _("A network filter with this name already exists")) + break if uuid == nwf["uuid"]: - error_msg = _( - "A network filter with this UUID already exists" - ) - raise Exception(error_msg) + failed(request, compute, subject, "add", "UUID already in use") + messages.error(request, _("A network filter with this UUID already exists")) + break else: try: - msg = _("%(filter)s network filter is created") % { - "filter": name - } - conn.create_nwfilter(xml) - addlogmsg(request.user.username, compute.hostname, "", msg) + with audit(request, compute, subject, "add"): + conn.create_nwfilter(xml) except libvirtError as lib_err: messages.error(request, lib_err) - addlogmsg( - request.user.username, compute.hostname, "", lib_err - ) if "del_nwfilter" in request.POST: name = request.POST.get("nwfiltername", "") - msg = _("%(filter)s network filter is deleted") % {"filter": name} in_use = False nwfilter = conn.get_nwfilter(name) nwfilter_info = conn.get_nwfilter_info(name) @@ -98,36 +91,29 @@ def nwfilters(request, compute_id): "NWFilter is in use by %(instance)s. Cannot be deleted." ) % {"instance": inst} messages.error(request, msg) - addlogmsg(request.user.username, compute.hostname, "", msg) + failed(request, compute, f"Network filter {name}", "delete", f"in use by {inst}") i_conn.close() break is_conn.close() if nwfilter and not in_use: - nwfilter.undefine() + with audit(request, compute, f"Network filter {name}", "delete"): + nwfilter.undefine() nwfilters_all.remove(nwfilter_info) - addlogmsg(request.user.username, compute.hostname, "", msg) if "cln_nwfilter" in request.POST: name = request.POST.get("nwfiltername", "") cln_name = request.POST.get("cln_name", name + "-clone") - conn.clone_nwfilter(name, cln_name) + with audit(request, compute, f"Network filter {name}", f"clone as {cln_name}"): + conn.clone_nwfilter(name, cln_name) nwfilters_all.append(conn.get_nwfilter_info(cln_name)) - msg = _("Cloning NWFilter %(name)s as %(clone)s") % { - "name": name, - "clone": cln_name, - } - addlogmsg(request.user.username, compute.hostname, "", msg) - conn.close() except libvirtError as lib_err: messages.error(request, lib_err) - addlogmsg(request.user.username, compute.hostname, "", lib_err) except Exception as err: messages.error(request, err) - addlogmsg(request.user.username, compute.hostname, "", err) return render( request, @@ -176,38 +162,40 @@ def nwfilter(request, compute_id, nwfltr): if request.method == "POST": + subject = f"Network filter {name}" if "edit_nwfilter" in request.POST: new_xml = request.POST.get("edit_xml", "") if new_xml: - conn.create_nwfilter(new_xml) + with audit(request, compute, subject, "change XML"): + conn.create_nwfilter(new_xml) if "del_nwfilter_rule" in request.POST: action = request.POST.get("action", "") direction = request.POST.get("direction", "") priority = request.POST.get("priority", "") - new_xml = nwfilter.delete_rule(action, direction, priority) - conn.create_nwfilter(new_xml) + with audit(request, compute, subject, "delete rule"): + conn.create_nwfilter(nwfilter.delete_rule(action, direction, priority)) if "del_nwfilter_ref" in request.POST: ref_name = request.POST.get("ref") - new_xml = nwfilter.delete_ref(ref_name) - conn.create_nwfilter(new_xml) + with audit(request, compute, subject, f"delete reference {ref_name}"): + conn.create_nwfilter(nwfilter.delete_ref(ref_name)) if "add_nwfilter_rule" in request.POST: rule_xml = request.POST.get("nwfilterrule_xml", "") if not rule_xml: return HttpResponseRedirect(request.get_full_path()) - new_xml = nwfilter.add_rule(rule_xml) - conn.create_nwfilter(new_xml) + with audit(request, compute, subject, "add rule"): + conn.create_nwfilter(nwfilter.add_rule(rule_xml)) if "add_nwfilter_ref" in request.POST: ref_name = request.POST.get("nwfilters_select", "") if not ref_name: return HttpResponseRedirect(request.get_full_path()) - new_xml = nwfilter.add_ref(ref_name) - conn.create_nwfilter(new_xml) + with audit(request, compute, subject, f"add reference {ref_name}"): + conn.create_nwfilter(nwfilter.add_ref(ref_name)) return HttpResponseRedirect(request.get_full_path()) conn.close() diff --git a/storages/api/viewsets.py b/storages/api/viewsets.py index 714f0b28..3af5d0c6 100644 --- a/storages/api/viewsets.py +++ b/storages/api/viewsets.py @@ -4,6 +4,7 @@ from computes.models import Compute from computes.utils import libvirt_compute_lock from django.shortcuts import get_object_or_404 from drf_spectacular.utils import extend_schema, inline_serializer +from logs.audit import audit, failed from rest_framework import serializers, status, viewsets from rest_framework.decorators import action from rest_framework.response import Response @@ -69,7 +70,8 @@ class StorageViewSet(viewsets.ViewSet): conn = wvmStorage( compute.hostname, compute.login, compute.password, compute.type, pk ) - ret = conn.start() + with audit(request, compute, f"Storage pool {pk}", "start"): + ret = conn.start() conn.close() return Response({"status": "Pool start command send: " + str(ret)}) @@ -81,7 +83,8 @@ class StorageViewSet(viewsets.ViewSet): conn = wvmStorage( compute.hostname, compute.login, compute.password, compute.type, pk ) - ret = conn.stop() + with audit(request, compute, f"Storage pool {pk}", "stop"): + ret = conn.stop() conn.close() return Response({"status": "Pool stop command send: " + str(ret)}) @@ -170,20 +173,24 @@ class VolumeViewSet(viewsets.ViewSet): serializer = VolumeSerializer(data=request.data) if serializer.is_valid(): + subject, action = f"Storage pool {storage_pk}", f"add volume {serializer.validated_data['name']}" state = conn.is_active() if state: conn.refresh() - ret = conn.create_volume( - serializer.validated_data["name"], - serializer.validated_data["size"], - serializer.validated_data["type"], - serializer.validated_data["meta_prealloc"], - int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_UID), - int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_GID), - ) + with audit(request, compute, subject, action) as entry: + ret = conn.create_volume( + serializer.validated_data["name"], + serializer.validated_data["size"], + serializer.validated_data["type"], + serializer.validated_data["meta_prealloc"], + int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_UID), + int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_GID), + ) + entry.action = f"add volume {ret}" conn.close() return Response({"status": "Volume: " + ret + " is created"}) else: + failed(request, compute, subject, action, "pool is not active") return Response({"status": "Pool is not active"}, status=status.HTTP_409_CONFLICT) else: return Response(serializer.errors, status=status.HTTP_400_BAD_REQUEST) @@ -196,11 +203,13 @@ class VolumeViewSet(viewsets.ViewSet): compute.hostname, compute.login, compute.password, compute.type, storage_pk ) + subject, action = f"Storage pool {storage_pk}", f"delete volume {pk}" if conn.is_active(): # no VM operation attaches it between the check and the delete - with libvirt_compute_lock(compute): + with audit(request, compute, subject, action), libvirt_compute_lock(compute): conn.del_volume(pk) conn.close() return Response({"status": "Volume: " + pk + " is deleted"}) else: + failed(request, compute, subject, action, "pool is not active") return Response({"status": "Pool is not active"}, status=status.HTTP_409_CONFLICT) diff --git a/storages/jobs.py b/storages/jobs.py index 32c03089..caec999a 100644 --- a/storages/jobs.py +++ b/storages/jobs.py @@ -18,6 +18,12 @@ from storages import upload logger = logging.getLogger(__name__) +def _log(op, state, action): + compute, _sep, pool = op.resource_label.rpartition("/") # a pool name has no "/" + message = f"Storage pool {pool}: {action}" + return compute, "", message if state == Operation.SUCCEEDED else f"{message} ({state})" + + def _storage(params): c = Compute.objects.get(pk=params["compute"]) return c, wvmStorage(c.hostname, c.login, c.password, c.type, params["pool"]) @@ -69,6 +75,9 @@ class CloneVolume(Kind): "check it, then resolve this job.") return Outcome(Operation.FAILED, error="The copy was not made") + def log_entry(self, op, state): + return _log(op, state, f"clone volume {op.params['image']} as {op.intent['target']}") + @register class UploadVolume(Kind): @@ -116,3 +125,6 @@ class UploadVolume(Kind): def expire(self, op): upload.end(op, Operation.FAILED, upload.IDLE) + + def log_entry(self, op, state): + return _log(op, state, f"upload volume {op.params['name']}") diff --git a/storages/tests/test_audit_rows.py b/storages/tests/test_audit_rows.py new file mode 100644 index 00000000..7bb1e8b2 --- /dev/null +++ b/storages/tests/test_audit_rows.py @@ -0,0 +1,225 @@ +"""Changes to storage pools and volumes, and the volume jobs, write rows on the Logs page.""" + +from types import SimpleNamespace +from unittest.mock import patch + +from django.contrib.auth import get_user_model +from django.contrib.sessions.middleware import SessionMiddleware +from django.core.files.uploadedfile import SimpleUploadedFile +from django.test import RequestFactory, TransactionTestCase +from django.urls import reverse + +from computes.models import Compute +from logs.models import Logs +from operations import claims, jobs +from operations.jobs import Context, Outcome +from operations.models import Claim, Operation, acquire +from storages.jobs import CloneVolume +from storages.tests import test_upload_job as upload_tests +from storages.upload import write_chunk + + +def rows(): + return list(Logs.objects.order_by("id").values_list("message", "success")) + + +class CloneRowTests(TransactionTestCase): + def setUp(self): + self.compute = Compute.objects.create(name="c1", hostname="192.0.2.20", login="root", password="", type=1) + self.admin = get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw") + self.client.force_login(self.admin) + Logs.objects.all().delete() # the login's row + patcher = patch("storages.jobs.wvmStorage") + self.stg = patcher.start().return_value + self.addCleanup(patcher.stop) + self.stg.get_volumes.return_value = ["base.qcow2"] + self.stg.get_volume_format_type.return_value = "qcow2" + self.stg.clone_name.return_value = "copy.qcow2" + self.stg.clone_volume.return_value = "copy.qcow2" + page = patch("storages.views.wvmStorage") + conn = page.start().return_value + conn.is_active.return_value = False + conn.get_size.return_value = (1, 1) + self.addCleanup(page.stop) + self.url = reverse("storage", args=[self.compute.pk, "default"]) + + def submit(self, key): + self.client.post(self.url, {"cln_volume": "1", "image": "base.qcow2", "name": "copy", "submission_key": key}) + return Operation.objects.get(submission_key=key) + + def run_and_finish(self, op, outcome): + acquire("wvc-test:1:a", "wvc-test") + Operation.objects.filter(pk=op.pk).update(state=Operation.RUNNING, worker="wvc-test:1:a") + op.refresh_from_db() + CloneVolume().run(op, Context(op, SimpleNamespace(identity="wvc-test:1:a"))) + jobs.finish(op, outcome) + + def test_a_clone_writes_its_row_when_it_ends(self): + op = self.submit("key-vol00001") + self.assertEqual(rows(), []) + self.run_and_finish(op, Outcome(Operation.SUCCEEDED)) + self.assertEqual(rows(), [("Storage pool default: clone volume base.qcow2 as copy.qcow2", True)]) + self.assertEqual(Logs.objects.get().host, "c1") + + self.run_and_finish(self.submit("key-vol00002"), Outcome(Operation.FAILED, error="disk full")) + jobs.cancel(self.submit("key-vol00003").pk, self.admin) + self.assertEqual(rows()[1:], [ + ("Storage pool default: clone volume base.qcow2 as copy.qcow2 (failed)", False), + ("Storage pool default: clone volume base.qcow2 as copy.qcow2 (cancelled)", None), + ]) + + def test_a_refused_clone_is_a_failed_row(self): + self.stg.get_volumes.return_value = ["base.qcow2", "copy.qcow2"] + self.client.post(self.url, {"cln_volume": "1", "image": "base.qcow2", "name": "copy", + "submission_key": "key-vol00004"}) + self.assertFalse(Operation.objects.exists()) + self.assertEqual(rows(), [ + ("Storage pool default: clone volume base.qcow2 as copy: Name of volume already in use", False)]) + + def test_a_busy_pool_refuses_the_clone(self): + self.stg.get_volumes.return_value = ["base.qcow2"] + claims.admit({claims.pool_key(self.compute.pk, "default"): Claim.EXCLUSIVE}, holder="192.0.2.30:1:1") + self.client.post(self.url, {"cln_volume": "1", "image": "base.qcow2", "name": "copy", + "submission_key": "key-vol00005"}) + [(message, success)] = rows() + self.assertFalse(success) + self.assertTrue(message.startswith("Storage pool default: clone volume base.qcow2 as copy: "), message) + + +class UploadRowTests(upload_tests.LocalPool, upload_tests.UploadTestCase): + def request(self): + request = RequestFactory().post("/") + request.user = self.admin + SessionMiddleware(lambda r: None).process_request(request) + return request + + def chunk(self, index, data, name=" disk.iso", total=2, size=6): + return write_chunk(self.admin, self.conn, self.compute, "default", upload_tests.KEY, + {"name": name, "size": size, "chunks": total}, index, SimpleUploadedFile("chunk", data), + request=self.request()) + + def test_an_upload_writes_one_row(self): + self.chunk(0, b"abc") + self.chunk(0, b"abc") # a retried first chunk + self.assertEqual(rows(), []) + self.chunk(1, b"def") + self.chunk(1, b"def") # the answer to the last chunk was lost + self.assertEqual(rows(), [("Storage pool default: upload volume disk.iso", True)]) + self.assertEqual(Logs.objects.get().host, "up-c") + + def test_a_refused_upload_is_a_failed_row(self): + open(self.path(), "wb").close() + with self.assertRaises(FileExistsError): + self.chunk(0, b"abc") + self.assertEqual(rows(), [("Storage pool default: upload volume disk.iso: FileExistsError", False)]) + + +class PoolAndVolumeRowTests(TransactionTestCase): + def setUp(self): + self.compute = Compute.objects.create(name="c1", hostname="192.0.2.21", login="root", password="", type=1) + self.admin = get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw") + self.client.force_login(self.admin) + Logs.objects.all().delete() # the login's row + for name, target in (("pool", "storages.views.wvmStorage"), ("pools", "storages.views.wvmStorages"), + ("api_pool", "storages.api.viewsets.wvmStorage")): + patcher = patch(target) + conn = patcher.start().return_value + self.addCleanup(patcher.stop) + conn.is_active.return_value = True + conn.get_size.return_value = (1, 1) + conn.get_storages_info.return_value = [] + conn.get_storages.return_value = ["default"] + conn.get_secrets.return_value = [] + conn.update_volumes.return_value = [] + conn.create_volume.return_value = "disk1.qcow2" + setattr(self, name, conn) + self.url = reverse("storage", args=[self.compute.pk, "default"]) + self.api = f"/api/v1/computes/{self.compute.pk}/storages/default/" + + def test_pool_actions(self): + for action in ("start", "stop", "set_autostart", "unset_autostart", "delete"): + self.client.post(self.url, {action: "1"}) + self.assertEqual(rows(), [ + ("Storage pool default: start", True), + ("Storage pool default: stop", True), + ("Storage pool default: autostart on", True), + ("Storage pool default: autostart off", True), + ("Storage pool default: delete", True), + ]) + self.assertEqual(set(Logs.objects.values_list("host", flat=True)), {"c1"}) + + def test_a_refused_pool_stop(self): + from vrtManager.util import OperationError + + reason = "Pool default is in use by the running VMs web-1" + self.pool.stop.side_effect = OperationError(reason) + response = self.client.post(self.url, {"stop": "1"}, follow=True) + self.assertIn(reason, [str(m) for m in response.context["messages"]]) + self.assertEqual(rows(), [(f"Storage pool default: stop: {reason}", False)]) + + def test_pool_create_and_a_duplicate_name(self): + url = reverse("storages", args=[self.compute.pk]) + self.client.post(url, {"create": "1", "name": "audit-pool", "stg_type": "dir", "target": "/srv/audit-pool"}) + self.client.post(url, {"create": "1", "name": "bad name!", "stg_type": "dir", "target": "/srv/x"}) # invalid + from libvirt import libvirtError + + # libvirt refuses a name in use (the page's own name check compares names with dicts) + self.pools.create_storage.side_effect = libvirtError("pool 'default' already exists") + self.client.post(url, {"create": "1", "name": "default", "stg_type": "dir", "target": "/srv/default"}) + self.assertEqual(rows(), [ + ("Storage pool audit-pool: add", True), + ("Storage pool default: add: pool 'default' already exists", False), + ]) + + def test_volume_add_and_delete(self): + self.client.post(reverse("create_volume", args=[self.compute.pk, "default"]), + {"name": "disk1", "format": "qcow2", "size": 1}) + self.client.post(self.url, {"del_volume": "1", "volname": "disk1.qcow2"}) + with patch("storages.views.libvirt_compute_lock", side_effect=claims.Busy("compute:1")): + self.client.post(self.url, {"del_volume": "1", "volname": "disk1.qcow2"}) + self.assertEqual(rows()[:2], [ + ("Storage pool default: add volume disk1.qcow2", True), + ("Storage pool default: delete volume disk1.qcow2", True), + ]) + message, success = rows()[2] + self.assertFalse(success) + self.assertTrue(message.startswith("Storage pool default: delete volume disk1.qcow2: "), message) + + def test_the_api_writes_the_same_rows(self): + self.client.post(self.api + "start/") + self.client.post(self.api + "stop/") + self.client.post(self.api + "refresh/") + self.client.post(self.api + "volumes/", {"name": "disk1", "type": "qcow2", "size": 1, "meta_prealloc": False}, + content_type="application/json") + self.client.delete(self.api + "volumes/disk1.qcow2/") + self.assertEqual(rows(), [ + ("Storage pool default: start", True), + ("Storage pool default: stop", True), + ("Storage pool default: add volume disk1.qcow2", True), + ("Storage pool default: delete volume disk1.qcow2", True), + ]) + + def test_an_inactive_pool_refuses_api_volume_changes(self): + self.api_pool.is_active.return_value = False + response = self.client.post(self.api + "volumes/", {"name": "disk2", "type": "qcow2", "size": 1, + "meta_prealloc": False}, content_type="application/json") + self.assertEqual(response.status_code, 409) + self.assertEqual(self.client.delete(self.api + "volumes/disk2/").status_code, 409) + self.assertEqual(rows(), [ + ("Storage pool default: add volume disk2: pool is not active", False), + ("Storage pool default: delete volume disk2: pool is not active", False), + ]) + + def test_the_row_has_actor_ip_and_no_instance(self): + self.client.post(self.url, {"start": "1"}, REMOTE_ADDR="192.0.2.9") + row = Logs.objects.get() + self.assertEqual((row.user, row.host, row.instance, row.ip), ("audit-admin", "c1", "", "192.0.2.9")) + + def test_a_libvirt_reason_is_redacted(self): + from libvirt import libvirtError + + self.pool.start.side_effect = libvirtError("cannot connect to qemu+tcp://admin:s3cret@192.0.2.5/system") + self.client.post(self.url, {"start": "1"}) # the middleware answers it + [(message, success)] = rows() + self.assertFalse(success) + self.assertNotIn("s3cret", message) diff --git a/storages/upload.py b/storages/upload.py index aa8ef184..71695324 100644 --- a/storages/upload.py +++ b/storages/upload.py @@ -16,6 +16,7 @@ from django.utils.translation import gettext_lazy as _ from libvirt import VIR_ERR_NO_STORAGE_VOL, libvirtError from computes.models import Compute +from logs.audit import audit from operations import claims, jobs from operations.models import Claim, Operation from vrtManager.connection import CONN_SSH, CONN_SOCKET, CONN_TCP, CONN_TLS @@ -502,10 +503,14 @@ def write_chunk(user, conn, compute, pool, upload_id, raw, chunk_index, chunk, r key) and commit it on the job; the last chunk renames the image.""" kind = jobs.get_kind("volume.upload") raw = {**raw, "compute": compute.pk, "pool": pool} - if chunk_index == 0: + if chunk_index == 0 and request is not None: + name = os.path.basename(str(raw["name"])).strip() + with audit(request, compute, f"Storage pool {pool}", f"upload volume {name}") as entry: + op = jobs.submit(kind.name, user, raw, upload_id) + entry.skip = True # the job writes its row when it ends + jobs.remember_job(request, op) + elif chunk_index == 0: op = jobs.submit(kind.name, user, raw, upload_id) - if request is not None: - jobs.remember_job(request, op) else: op = Operation.objects.filter(user=user, submission_key=upload_id).first() if op is None: diff --git a/storages/views.py b/storages/views.py index c6957bfa..20e49ef3 100644 --- a/storages/views.py +++ b/storages/views.py @@ -12,6 +12,7 @@ from django.utils.translation import gettext_lazy as _ from libvirt import libvirtError from operations import claims, jobs from operations.utils import busy_message +from logs.audit import audit from vrtManager.util import OperationError from vrtManager.storage import wvmStorage, wvmStorages @@ -97,31 +98,32 @@ def storages(request, compute_id): messages.error(request, msg) errors = True if not errors: - if data["stg_type"] == "rbd": - conn.create_storage_ceph( - data["stg_type"], - data["name"], - data["ceph_pool"], - data["ceph_host"], - data["ceph_user"], - data["secret"], - ) - elif data["stg_type"] == "netfs": - conn.create_storage_netfs( - data["stg_type"], - data["name"], - data["netfs_host"], - data["source"], - data["source_format"], - data["target"], - ) - else: - conn.create_storage( - data["stg_type"], - data["name"], - data["source"], - data["target"], - ) + with audit(request, compute, f"Storage pool {data['name']}", "add"): + if data["stg_type"] == "rbd": + conn.create_storage_ceph( + data["stg_type"], + data["name"], + data["ceph_pool"], + data["ceph_host"], + data["ceph_user"], + data["secret"], + ) + elif data["stg_type"] == "netfs": + conn.create_storage_netfs( + data["stg_type"], + data["name"], + data["netfs_host"], + data["source"], + data["source_format"], + data["target"], + ) + else: + conn.create_storage( + data["stg_type"], + data["name"], + data["source"], + data["target"], + ) return HttpResponseRedirect( reverse("storage", args=[compute_id, data["name"]]) ) @@ -181,33 +183,39 @@ def storage(request, compute_id, pool): volumes = None if request.method == "POST": + subject = f"Storage pool {pool}" if "start" in request.POST: - conn.start() + with audit(request, compute, subject, "start"): + conn.start() return HttpResponseRedirect(request.get_full_path()) if "stop" in request.POST: try: - conn.stop() + with audit(request, compute, subject, "stop"): + conn.stop() except OperationError as err: # a running VM's disk is in it messages.error(request, str(err)) return HttpResponseRedirect(request.get_full_path()) if "delete" in request.POST: try: - conn.delete() + with audit(request, compute, subject, "delete"): + conn.delete() except OperationError as err: # a VM names it for a disk messages.error(request, str(err)) return HttpResponseRedirect(request.get_full_path()) return HttpResponseRedirect(reverse("storages", args=[compute_id])) if "set_autostart" in request.POST: - conn.set_autostart(1) + with audit(request, compute, subject, "autostart on"): + conn.set_autostart(1) return HttpResponseRedirect(request.get_full_path()) if "unset_autostart" in request.POST: - conn.set_autostart(0) + with audit(request, compute, subject, "autostart off"): + conn.set_autostart(0) return HttpResponseRedirect(request.get_full_path()) if "del_volume" in request.POST: volname = request.POST.get("volname", "") try: # no VM operation attaches it between the check and the delete - with libvirt_compute_lock(compute): + with audit(request, compute, subject, f"delete volume {volname}"), libvirt_compute_lock(compute): conn.del_volume(volname) except OperationError as err: messages.error(request, str(err)) @@ -222,9 +230,13 @@ def storage(request, compute_id, pool): if "cln_volume" in request.POST: form = CloneImage(request.POST) if form.is_valid(): + data = form.cleaned_data try: - op = jobs.submit("volume.clone", request.user, {"compute": compute.id, "pool": pool, - **form.cleaned_data}, request.POST.get("submission_key", "")) + with audit(request, compute, f"Storage pool {pool}", + f"clone volume {data['image']} as {data['name']}") as entry: + op = jobs.submit("volume.clone", request.user, {"compute": compute.id, "pool": pool, **data}, + request.POST.get("submission_key", "")) + entry.skip = True # the job writes its row when it ends except claims.Busy as busy: messages.error(request, busy_message(busy, request.user)) except (jobs.SubmissionConflict, libvirtError) as err: @@ -267,14 +279,16 @@ def create_volume(request, compute_id, pool): disk_owner_uid = int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_UID) disk_owner_gid = int(app_settings.INSTANCE_VOLUME_DEFAULT_OWNER_GID) - name = conn.create_volume( - data["name"], - data["size"], - data["format"], - meta_prealloc, - disk_owner_uid, - disk_owner_gid, - ) + with audit(request, compute, f"Storage pool {pool}", f"add volume {data['name']}") as entry: + name = conn.create_volume( + data["name"], + data["size"], + data["format"], + meta_prealloc, + disk_owner_uid, + disk_owner_gid, + ) + entry.action = f"add volume {name}" messages.success( request, _("Image file %(name)s is created successfully") % {"name": name} ) diff --git a/virtsecrets/tests/test_audit_rows.py b/virtsecrets/tests/test_audit_rows.py new file mode 100644 index 00000000..4727dab1 --- /dev/null +++ b/virtsecrets/tests/test_audit_rows.py @@ -0,0 +1,57 @@ +"""Secret changes write rows on the Logs page; a secret's value never does.""" + +from unittest.mock import patch + +from computes.models import Compute +from django.contrib.auth import get_user_model +from django.test import TestCase +from django.urls import reverse +from vrtManager.util import OperationError + +from logs.models import Logs + +UUID = "8f2c0000-0000-4000-8000-000000000009" +VALUE = "s3cr3t-value" + + +def rows(): + return list(Logs.objects.order_by("id").values_list("message", "success")) + + +class SecretRowTests(TestCase): + def setUp(self): + self.compute = Compute.objects.create(name="c1", hostname="localhost", login="", password="", type=4) + self.client.force_login(get_user_model().objects.create_superuser("audit-admin", "a@example.com", "pw")) + Logs.objects.all().delete() # the login's row + self.url = reverse("virtsecrets", args=[self.compute.id]) + patcher = patch("virtsecrets.views.wvmSecrets") + self.conn = patcher.start().return_value + self.addCleanup(patcher.stop) + self.conn.get_secrets.return_value = [] + + def test_secret_actions(self): + self.client.post(self.url, {"create": "", "ephemeral": "no", "private": "yes", "usage_type": "ceph", + "data": "client.admin"}) + self.client.post(self.url, {"set_value": "", "uuid": UUID, "value": VALUE}) + self.client.post(self.url, {"delete": "", "uuid": UUID}) + self.assertEqual(rows(), [ + ("Secret ceph client.admin: add", True), + (f"Secret {UUID}: set value", True), + (f"Secret {UUID}: delete", True), + ]) + self.assertEqual(set(Logs.objects.values_list("host", flat=True)), {"c1"}) + + def test_a_secret_value_is_never_logged(self): + self.conn.set_secret_value.side_effect = ValueError(f"bad value {VALUE}") + self.client.post(self.url, {"set_value": "", "uuid": UUID, "value": VALUE}) + self.assertEqual(rows(), [(f"Secret {UUID}: set value: ValueError", False)]) + with patch.object(Logs.objects, "create", side_effect=RuntimeError("db down")), \ + self.assertLogs("logs.audit", "WARNING") as logged: + self.client.post(self.url, {"set_value": "", "uuid": UUID, "value": VALUE}) + self.assertNotIn(VALUE, "\n".join(logged.output)) + self.assertIn(f"Secret {UUID}: set value", "\n".join(logged.output)) + + def test_a_refused_secret_delete(self): + self.conn.delete_secret.side_effect = OperationError(f"Secret {UUID} is used by VMs db-2") + self.client.post(self.url, {"delete": "", "uuid": UUID}) + self.assertEqual(rows(), [(f"Secret {UUID}: delete: Secret {UUID} is used by VMs db-2", False)]) diff --git a/virtsecrets/views.py b/virtsecrets/views.py index 3eeece37..e8c59395 100644 --- a/virtsecrets/views.py +++ b/virtsecrets/views.py @@ -11,6 +11,7 @@ from libvirt import ( VIR_SECRET_USAGE_TYPE_VOLUME, libvirtError, ) +from logs.audit import audit from vrtManager.util import OperationError from vrtManager.virtsecrets import wvmSecrets @@ -57,12 +58,13 @@ def secrets(request, compute_id): form = AddSecret(request.POST) if form.is_valid(): data = form.cleaned_data - conn.create_secret( - data["ephemeral"], - data["private"], - data["usage_type"], - data["data"], - ) + with audit(request, compute, f"Secret {data['usage_type']} {data['data']}", "add"): + conn.create_secret( + data["ephemeral"], + data["private"], + data["usage_type"], + data["data"], + ) return HttpResponseRedirect(request.get_full_path()) else: for msg_err in form.errors.values(): @@ -70,7 +72,8 @@ def secrets(request, compute_id): if "delete" in request.POST: uuid = request.POST.get("uuid", "") try: - conn.delete_secret(uuid) + with audit(request, compute, f"Secret {uuid}", "delete"): + conn.delete_secret(uuid) except OperationError as err: # a VM disk or a pool needs it messages.error(request, str(err)) return HttpResponseRedirect(request.get_full_path()) @@ -78,7 +81,8 @@ def secrets(request, compute_id): uuid = request.POST.get("uuid", "") value = request.POST.get("value", "") try: - conn.set_secret_value(uuid, value) + with audit(request, compute, f"Secret {uuid}", "set value"): + conn.set_secret_value(uuid, value) except Exception as err: messages.error(request, err) return HttpResponseRedirect(request.get_full_path())