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

@@ -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.

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"),
+        ])

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:

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 = """<node>
+  <network><name>lab</name><bridge name='virbr9'/>
+    <ip address='192.0.2.1' netmask='255.255.255.0'><dhcp><range start='192.0.2.10' end='192.0.2.20'/></dhcp></ip>
+  </network>
+</node>"""
+
+
+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="<network").exists())
+        self.assertEqual(set(Logs.objects.values_list("host", flat=True)), {"c1"})
+
+    def test_a_refused_network_stop(self):
+        error = "Requested operation is not valid: network is in use"
+        with patch("vrtManager.network.wvmNetwork.stop", side_effect=libvirt.libvirtError(error)):
+            response = self.post({"stop": ""})
+        self.assertIn(error, [str(m) for m in get_messages(response.wsgi_request)])
+        self.assertEqual(rows(), [(f"Network lab: stop: {error}", False)])
+
+    def test_network_create(self):
+        url = reverse("networks", args=[self.compute.id])
+        self.client.post(url, {"create": "", "name": "audit-net", "forward": "nat", "subnet": "198.51.100.0/24",
+                               "dhcp4": "on"})
+        self.client.post(url, {"create": "", "name": "bad name!", "forward": "nat"})  # invalid form
+        self.client.post(url, {"create": "", "name": "lab", "forward": "nat", "subnet": "203.0.113.0/24"})
+        [first, second] = rows()
+        self.assertEqual(first, ("Network audit-net: add", True))
+        self.assertFalse(second[1])
+        self.assertTrue(second[0].startswith("Network lab: add: "), second[0])

networks/views.py

@@ -6,6 +6,7 @@ from django.shortcuts import get_object_or_404, render
 from django.urls import reverse
 from django.utils.translation import gettext_lazy as _
 from libvirt import libvirtError
+from logs.audit import audit
 from vrtManager.network import network_size, wvmNetwork, wvmNetworks
 
 from networks.forms import AddNetPool
@@ -60,21 +61,22 @@ def networks(request, compute_id):
                             data["subnet6"], data["dhcp6"]
                         )
                     if not errors:
-                        conn.create_network(
-                            data["name"],
-                            data["forward"],
-                            ipv4,
-                            gateway4,
-                            netmask4,
-                            dhcp4,
-                            ipv6,
-                            gateway6,
-                            prefix6,
-                            dhcp6,
-                            data["bridge_name"],
-                            data["openvswitch"],
-                            data["fixed"],
-                        )
+                        with audit(request, compute, f"Network {data['name']}", "add"):
+                            conn.create_network(
+                                data["name"],
+                                data["forward"],
+                                ipv4,
+                                gateway4,
+                                netmask4,
+                                dhcp4,
+                                ipv6,
+                                gateway6,
+                                prefix6,
+                                dhcp6,
+                                data["bridge_name"],
+                                data["openvswitch"],
+                                data["fixed"],
+                            )
                         return HttpResponseRedirect(
                             reverse("network", args=[compute_id, data["name"]])
                         )
@@ -137,33 +139,39 @@ def network(request, compute_id, pool):
         return HttpResponseRedirect(reverse("networks", args=[compute_id]))
 
     if request.method == "POST":
+        subject = f"Network {pool}"
         if "start" in request.POST:
             try:
-                conn.start()
+                with audit(request, compute, subject, "start"):
+                    conn.start()
                 return HttpResponseRedirect(request.get_full_path())
             except libvirtError as lib_err:
                 messages.error(request, lib_err)
         if "stop" in request.POST:
             try:
-                conn.stop()
+                with audit(request, compute, subject, "stop"):
+                    conn.stop()
                 return HttpResponseRedirect(request.get_full_path())
             except libvirtError as lib_err:
                 messages.error(request, lib_err)
         if "delete" in request.POST:
             try:
-                conn.delete()
+                with audit(request, compute, subject, "delete"):
+                    conn.delete()
                 return HttpResponseRedirect(reverse("networks", args=[compute_id]))
             except libvirtError as lib_err:
                 messages.error(request, lib_err)
         if "set_autostart" in request.POST:
             try:
-                conn.set_autostart(1)
+                with audit(request, compute, subject, "autostart on"):
+                    conn.set_autostart(1)
                 return HttpResponseRedirect(request.get_full_path())
             except libvirtError as lib_err:
                 messages.error(request, lib_err)
         if "unset_autostart" in request.POST:
             try:
-                conn.set_autostart(0)
+                with audit(request, compute, subject, "autostart off"):
+                    conn.set_autostart(0)
                 return HttpResponseRedirect(request.get_full_path())
             except libvirtError as lib_err:
                 messages.error(request, lib_err)
@@ -178,7 +186,8 @@ def network(request, compute_id, pool):
                 mac_duid = request.POST.get("id", "")
 
             try:
-                ret_val = conn.modify_fixed_address(name, address, mac_duid, family)
+                with audit(request, compute, subject, f"set fixed address {address}"):
+                    conn.modify_fixed_address(name, address, mac_duid, family)
                 messages.success(
                     request,
                     _("Fixed address operation completed for %(family)s")
@@ -192,7 +201,8 @@ def network(request, compute_id, pool):
         if "delete_fixed_address" in request.POST:
             ip = request.POST.get("address", "")
             family = request.POST.get("family", "ipv4")
-            conn.delete_fixed_address(ip, family)
+            with audit(request, compute, subject, f"delete fixed address {ip}"):
+                conn.delete_fixed_address(ip, family)
             messages.success(
                 request,
                 _("%(family)s Fixed Address is Deleted.") % {"family": family.upper()},
@@ -203,7 +213,8 @@ def network(request, compute_id, pool):
             range_end = request.POST.get("range_end", "")
             family = request.POST.get("family", "ipv4")
             try:
-                conn.modify_dhcp_range(range_start, range_end, family)
+                with audit(request, compute, subject, f"set DHCP range {family.upper()}"):
+                    conn.modify_dhcp_range(range_start, range_end, family)
                 messages.success(
                     request,
                     _("%(family)s DHCP Range is Changed.") % {"family": family.upper()},
@@ -214,7 +225,8 @@ def network(request, compute_id, pool):
         if "edit_network" in request.POST:
             edit_xml = request.POST.get("edit_xml", "")
             if edit_xml:
-                conn.edit_network(edit_xml)
+                with audit(request, compute, subject, "change XML"):
+                    conn.edit_network(edit_xml)
                 if conn.is_active():
                     messages.success(
                         request,
@@ -233,7 +245,8 @@ def network(request, compute_id, pool):
             burst = request.POST.get("qos_burst") or 0
 
             try:
-                conn.set_qos(qos_dir, average, peak, burst)
+                with audit(request, compute, subject, f"set QoS {qos_dir}"):
+                    conn.set_qos(qos_dir, average, peak, burst)
                 if conn.is_active():
                     messages.success(
                         request,
@@ -253,7 +266,8 @@ def network(request, compute_id, pool):
         if "unset_qos" in request.POST:
             qos_dir = request.POST.get("qos_direction", "")
             try:
-                conn.unset_qos(qos_dir)
+                with audit(request, compute, subject, f"unset QoS {qos_dir}"):
+                    conn.unset_qos(qos_dir)
             except ValueError as err:
                 messages.error(request, err)
                 return HttpResponseRedirect(request.get_full_path())

nwfilters/tests/test_audit_rows.py

@@ -0,0 +1,105 @@
+"""Network filter changes write rows on the Logs page. libvirt's test driver
+has no filters, so the connection is a mock (as in test_redefine.py)."""
+
+from unittest.mock import patch
+
+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 libvirt import libvirtError
+
+from logs.models import Logs
+
+UUID = "6d1f7a10-0000-4000-8000-00000000c0de"
+XML = (f"<filter name='web' chain='root'><uuid>{UUID}</uuid><filterref filter='clean-traffic'/>"
+       "<rule action='drop' direction='in' priority='900'><all/></rule></filter>")
+NEW = "<filter name='f1' chain='root'><uuid>6d1f7a10-0000-4000-8000-0000000000f1</uuid></filter>"
+
+
+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": "<filter"})
+        self.assertEqual(response.status_code, 200)
+        [(message, success)] = rows()
+        self.assertFalse(success)
+        self.assertTrue(message.startswith("Network filter (no name): add: "), message)
+
+    @patch("nwfilters.views.wvmInstance")
+    @patch("nwfilters.views.wvmInstances")
+    def test_a_filter_in_use_is_not_deleted(self, instances, instance):
+        instances.return_value.get_instances.return_value = ["web-1"]
+        instance.return_value.get_filterrefs.return_value = ["web"]
+        self.client.post(self.list_url, {"del_nwfilter": "", "nwfiltername": "web"})
+        self.wvm.nwfilterLookupByName.return_value.undefine.assert_not_called()
+        self.assertEqual(rows(), [("Network filter web: delete: in use by web-1", False)])
+
+    def test_filter_page_actions(self):
+        self.client.post(self.url, {"edit_nwfilter": "", "edit_xml": XML})
+        self.client.post(self.url, {"add_nwfilter_rule": "",
+                                    "nwfilterrule_xml": "<rule action='accept' direction='in' priority='500'><all/></rule>"})
+        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": "<rule action='accept' direction='in' priority='500'><all/></rule>"})
+        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)

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()

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)

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']}")

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)

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:

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}
         )

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)])

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())