[PATCH pve-firewall v6 04/28] firewall: references: log the references an object update touched

[Arthur Bied-Charreton <a.bied-charreton@proxmox.com>]

Make update_refs() log each reference once the config holding it was
saved, so a run that dies halfway through the cluster still shows what
it managed to update and does not count failed attempts:

    firewall: ipset 'set' renamed to 'set2':
      cluster: rules: rule 6: '+set' renamed to '+set2'
      cluster: group 'fixgrp': rule 1: '+set' renamed to '+set2'
    firewall: 2 references updated

The footer only counts what was actually updated, so it is logged even
if the walk did not run to the end. Errors are still raised.

The lines go to stdout in a worker, and to the syslog otherwise. Also
take an optional log sink coderef to allow a caller to collect logs
instead.

Signed-off-by: Arthur Bied-Charreton <a.bied-charreton@proxmox.com>
---
 src/PVE/Firewall/References.pm | 124 +++++++++++++++++++++++++++++----
 1 file changed, 111 insertions(+), 13 deletions(-)

diff --git a/src/PVE/Firewall/References.pm b/src/PVE/Firewall/References.pm
index 9eb5bc8..6ea39cb 100644
--- a/src/PVE/Firewall/References.pm
+++ b/src/PVE/Firewall/References.pm
@@ -5,6 +5,8 @@ use warnings;
 
 use PVE::Cluster;
 use PVE::Firewall;
+use PVE::RESTEnvironment;
+use PVE::SafeSyslog qw(syslog);
 
 use base 'Exporter';
 our @EXPORT_OK = qw(
@@ -66,27 +68,38 @@ sub rewrite_refs_in_env {
 
     my $changes = [];
 
+    # a change is only reported after successful save
+    my $emit = sub {
+        my ($conf_changes) = @_;
+        for my $change ($conf_changes->@*) {
+            push $changes->@*, $change;
+            $op->{on_change}->($change) if $op->{on_change};
+        }
+    };
+
     my $visit = sub {
         my ($fw_conf, $env, $is_guest, $scope) = @_;
 
         my $conf_changes = rewrite_refs_in_conf($fw_conf, $op, $env, $is_guest);
-        push $changes->@*, map { { $_->%*, scope => $scope } } $conf_changes->@*;
-
-        return scalar($conf_changes->@*);
+        return [map { { $_->%*, scope => $scope } } $conf_changes->@*];
     };
 
     my $self_scope = 'cluster';
     if ($rule_env ne 'cluster' && $rule_env ne 'sdn') {
         $self_scope = defined($conf->{vmid}) ? "$rule_env/$conf->{vmid}" : $rule_env;
     }
-    $visit->($conf, $rule_env, 0, $self_scope);
+    my $self_changes = $visit->($conf, $rule_env, 0, $self_scope);
 
-    return $changes if $rule_env ne 'cluster' && $rule_env ne 'sdn';
+    if ($rule_env ne 'cluster' && $rule_env ne 'sdn') {
+        $emit->($self_changes);
+        return $changes;
+    }
 
     # on renames, the configs below are rewritten to reference the object under its new name. during
     # this process, the object has to be resolvable under both names, otherwise concurrent firewall
     # compilations will choke on unresolvable objects.
     $op->{save}->($conf) if $op->{save};
+    $emit->($self_changes) if $op->{save};
 
     my $vmlist = PVE::Cluster::get_vmlist();
     my $vmids = ($vmlist // {})->{ids} // {};
@@ -97,8 +110,10 @@ sub rewrite_refs_in_env {
             sub {
                 my $guest_env = $vmlist->{ids}->{$vmid}->{type} eq 'lxc' ? 'ct' : 'vm';
                 my $guest_conf = PVE::Firewall::load_vmfw_conf($conf, $guest_env, $vmid);
-                if ($visit->($guest_conf, $rule_env, 1, "$guest_env/$vmid")) {
+                my $guest_changes = $visit->($guest_conf, $rule_env, 1, "$guest_env/$vmid");
+                if ($guest_changes->@*) {
                     PVE::Firewall::save_vmfw_conf($vmid, $guest_conf);
+                    $emit->($guest_changes);
                 }
             },
         );
@@ -111,8 +126,10 @@ sub rewrite_refs_in_env {
             10,
             sub {
                 my $host_conf = PVE::Firewall::load_hostfw_conf($conf, $host_conf_path);
-                if ($visit->($host_conf, $rule_env, 0, "host/$node")) {
+                my $host_changes = $visit->($host_conf, $rule_env, 0, "host/$node");
+                if ($host_changes->@*) {
                     PVE::Firewall::save_hostfw_conf($host_conf, $host_conf_path);
+                    $emit->($host_changes);
                 }
             },
         );
@@ -124,13 +141,18 @@ sub rewrite_refs_in_env {
             10,
             sub {
                 my $vnet_conf = PVE::Firewall::load_vnetfw_conf($conf, 'vnet', $vnet);
-                if ($visit->($vnet_conf, $rule_env, 0, "vnet/$vnet")) {
+                my $vnet_changes = $visit->($vnet_conf, $rule_env, 0, "vnet/$vnet");
+                if ($vnet_changes->@*) {
                     PVE::Firewall::save_vnetfw_conf($vnet, $vnet_conf);
+                    $emit->($vnet_changes);
                 }
             },
         );
     }
 
+    # without a save callback, the caller saves $conf once we return
+    $emit->($self_changes) if !$op->{save};
+
     return $changes;
 }
 
@@ -319,9 +341,17 @@ sub rewrite_refs_in_conf {
     return $ctx->{changes};
 }
 
+my $ref_change_verbs = {
+    rename => 'updated',
+    disable => 'disabled',
+    drop => 'dropped',
+};
+
 =head3 update_refs($opts)
 
-Rename, disable or drop all references to a firewall object across the environment.
+Rename, disable or drop all references to a firewall object across the environment, logging each
+one once the config holding it was saved. Without C<save>, the changes to C<conf> are logged last,
+as the caller saves it after this returns.
 
 References are matched in rules, security groups and IPSet members. Matching is case-insensitive
 and renames are written back lowercased.
@@ -335,6 +365,10 @@ C<$opts> holds:
     env      # 'cluster', 'sdn', or 'vm'/'ct' for a guest-defined object
     action   # 'rename', 'disable' or 'drop', or undef to leave the references alone
     save     # persists C<conf>, required for a cluster-wide rename
+    subject  # header for the task log
+    log      # optional log sink coderef, by default logs go to task log if in worker, otherwise syslog
+
+The caller is responsible for locking and saving C<conf> itself.
 
 IPSet members have no disabled state, so C<disable> removes them as well.
 
@@ -344,7 +378,8 @@ C<conf> itself have been rewritten and before any downstream config : downstream
 rewritten to reference the object under its new name, and a concurrent compilation parsing the
 cluster config would fail to resolve that name until it has been written.
 
-The caller is responsible for locking and saving C<conf> itself.
+If the logs cannot be written as we go (SDN apply is an example, since the conf update is done
+before forking a worker and logs would go to syslog), pass C<log> with custom collection logic.
 
 Return the number of references changed.
 
@@ -353,9 +388,15 @@ Return the number of references changed.
 sub update_refs {
     my ($opts) = @_;
 
-    my ($conf, $kind, $old, $new, $env, $action) = $opts->@{qw(conf kind old new env action)};
+    my ($conf, $kind, $old, $new, $env, $action, $subject) =
+        $opts->@{qw(conf kind old new env action subject)};
 
-    return 0 if !defined($action);
+    my $log = $opts->{log} // \&log_ref_line;
+
+    if (!defined($action)) {
+        $log->("firewall: $subject: references left as they are");
+        return 0;
+    }
 
     die "invalid action '$action'" if $action !~ m/^(rename|disable|drop)$/;
     die "\$new must be set if \$action is 'rename'" if $action eq 'rename' && !defined($new);
@@ -367,6 +408,10 @@ sub update_refs {
     die "cannot rename more than one object at once\n"
         if $action eq 'rename' && scalar($lc_old->@*) != 1;
 
+    $log->("firewall: $subject:");
+
+    my $count = 0;
+
     my $op = {
         kind => $kind,
         old => $lc_old,
@@ -374,9 +419,62 @@ sub update_refs {
         action => $action,
         cluster_conf => $conf,
         save => $opts->{save},
+        on_change => sub {
+            $count++;
+            $log->('  ' . format_ref_change($_[0]));
+        },
     };
 
-    return scalar(rewrite_refs_in_env($conf, $env, $op)->@*);
+    eval { rewrite_refs_in_env($conf, $env, $op) };
+    my $err = $@;
+
+    # if the walk died before incrementing $count there is nothing to log
+    if ($count) {
+        my $noun = $count == 1 ? 'reference' : 'references';
+        $log->("firewall: $count $noun $ref_change_verbs->{$action}");
+    } elsif (!$err) {
+        $log->("firewall: no references found");
+    }
+
+    die $err if $err;
+
+    return $count;
+}
+
+=head3 format_ref_change($change)
+
+Format one recorded config change as a single line, e.g.
+
+    "cluster: rules: rule 6: '+ipset' renamed to '+ipset1'"
+
+=cut
+
+sub format_ref_change {
+    my ($change) = @_;
+
+    my $section = $change->{section};
+    my $where = $section eq 'rules' ? 'rules' : "$section '$change->{name}'";
+    my $item = $section eq 'ipset' ? 'member' : 'rule';
+
+    my $what = "$change->{scope}: $where: $item $change->{pos}: '$change->{ref}'";
+
+    return "$what renamed to '$change->{new}'" if $change->{action} eq 'rename';
+    return "$what dropped" if $change->{action} eq 'drop';
+
+    # an IPSet member has no disabled state, so disabling it removed it
+    return "$what " . ($section eq 'ipset' ? 'removed' : 'disabled');
+}
+
+sub log_ref_line {
+    my ($line) = @_;
+
+    if (PVE::RESTEnvironment::is_worker()) {
+        print("$line\n");
+    } else {
+        syslog('info', '%s', $line);
+    }
+
+    return;
 }
 
 1;
-- 
2.47.3