From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <s.reiter@proxmox.com>
Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68])
 (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)
 key-exchange X25519 server-signature RSA-PSS (2048 bits))
 (No client certificate requested)
 by lists.proxmox.com (Postfix) with ESMTPS id F3AE960993
 for <pve-devel@lists.proxmox.com>; Thu, 13 Aug 2020 14:04:26 +0200 (CEST)
Received: from firstgate.proxmox.com (localhost [127.0.0.1])
 by firstgate.proxmox.com (Proxmox) with ESMTP id 9E11A19EBF
 for <pve-devel@lists.proxmox.com>; Thu, 13 Aug 2020 14:03:56 +0200 (CEST)
Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com
 [212.186.127.180])
 (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)
 key-exchange X25519 server-signature RSA-PSS (2048 bits))
 (No client certificate requested)
 by firstgate.proxmox.com (Proxmox) with ESMTPS id EFFCF19E65
 for <pve-devel@lists.proxmox.com>; Thu, 13 Aug 2020 14:03:53 +0200 (CEST)
Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1])
 by proxmox-new.maurer-it.com (Proxmox) with ESMTP id AF5BA445E8
 for <pve-devel@lists.proxmox.com>; Thu, 13 Aug 2020 14:03:53 +0200 (CEST)
From: Stefan Reiter <s.reiter@proxmox.com>
To: pve-devel@lists.proxmox.com
Date: Thu, 13 Aug 2020 14:03:32 +0200
Message-Id: <20200813120334.20928-3-s.reiter@proxmox.com>
X-Mailer: git-send-email 2.20.1
In-Reply-To: <20200813120334.20928-1-s.reiter@proxmox.com>
References: <20200813120334.20928-1-s.reiter@proxmox.com>
MIME-Version: 1.0
Content-Transfer-Encoding: 8bit
X-SPAM-LEVEL: Spam detection results:  0
 AWL -0.057 Adjusted score from AWL reputation of From: address
 KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment
 RCVD_IN_DNSWL_MED        -2.3 Sender listed at https://www.dnswl.org/,
 medium trust
 SPF_HELO_NONE           0.001 SPF: HELO does not publish an SPF Record
 SPF_PASS               -0.001 SPF: sender matches SPF record
Subject: [pve-devel] [PATCH qemu-server 2/4] vzdump: improve logging output
 with dirty bitmaps
X-BeenThere: pve-devel@lists.proxmox.com
X-Mailman-Version: 2.1.29
Precedence: list
List-Id: Proxmox VE development discussion <pve-devel.lists.proxmox.com>
List-Unsubscribe: <https://lists.proxmox.com/cgi-bin/mailman/options/pve-devel>, 
 <mailto:pve-devel-request@lists.proxmox.com?subject=unsubscribe>
List-Archive: <http://lists.proxmox.com/pipermail/pve-devel/>
List-Post: <mailto:pve-devel@lists.proxmox.com>
List-Help: <mailto:pve-devel-request@lists.proxmox.com?subject=help>
List-Subscribe: <https://lists.proxmox.com/cgi-bin/mailman/listinfo/pve-devel>, 
 <mailto:pve-devel-request@lists.proxmox.com?subject=subscribe>
X-List-Received-Date: Thu, 13 Aug 2020 12:04:27 -0000

Uses the new 'query-pbs-bitmap-info' QMP call to retrieve additional
information about each drive's dirty bitmap. Returned info is also used
to calculate $target by simply adding all the dirty values (dirty is
equal to size in case the entire drive will be backed up).

"Backup is sparse" message is suppressed for PBS, since it makes little
sense (if zero chunks appear in the clean area of a bitmap, they won't
be counted, and a user is probably more interested in the 'reused' data
anyway).

Also removes the need for the hacky $first_round query-backup handling.

Signed-off-by: Stefan Reiter <s.reiter@proxmox.com>
---
 PVE/VZDump/QemuServer.pm | 57 +++++++++++++++++++++++++++++++---------
 1 file changed, 45 insertions(+), 12 deletions(-)

diff --git a/PVE/VZDump/QemuServer.pm b/PVE/VZDump/QemuServer.pm
index 4614efc..6420bf4 100644
--- a/PVE/VZDump/QemuServer.pm
+++ b/PVE/VZDump/QemuServer.pm
@@ -275,14 +275,39 @@ sub bytes_to_human {
     return $num2str->($tb, $precission) . " TiB";
 };
 
+my $bitmap_action_to_human = sub {
+    my ($info) = @_;
+
+    my $action = $info->{action};
+
+    if ($action eq "not-used") {
+	return "disabled";
+    } elsif ($action eq "not-used-removed") {
+	return "disabled (old bitmap cleared)";
+    } elsif ($action eq "new") {
+	return "created new bitmap";
+    } elsif ($action eq "used") {
+	if ($info->{dirty} == 0) {
+	    return "OK, drive clean";
+	} else {
+	    my $size = bytes_to_human($info->{size});
+	    my $dirty = bytes_to_human($info->{dirty});
+	    return "OK, $dirty of $size dirty";
+	}
+    } elsif ($action eq "invalid") {
+	return "existing bitmap was invalid and has been cleared";
+    } else {
+	return "unknown";
+    }
+};
+
 my $query_backup_status_loop = sub {
-    my ($self, $vmid, $job_uuid) = @_;
+    my ($self, $vmid, $job_uuid, $pbs_features) = @_;
 
     my $starttime = time ();
     my $last_time = $starttime;
     my ($last_percent, $last_total, $last_target,  $last_zero, $last_transferred) = (-1, 0, 0, 0, 0);
     my ($transferred, $reused);
-    my $first_round = 1;
 
     my $get_mbps = sub {
 	my ($mb, $delta) = @_;
@@ -291,12 +316,26 @@ my $query_backup_status_loop = sub {
 	return bytes_to_human($bw) . "/s";
     };
 
+    my $target = 0;
+    my $has_query_bitmap = 0;
+    if (defined($pbs_features) && $pbs_features->{'query-bitmap-info'}) {
+	$has_query_bitmap = 1;
+	my $bitmap_info = mon_cmd($vmid, 'query-pbs-bitmap-info');
+	$self->loginfo("Fast incremental status:");
+	foreach my $info (@$bitmap_info) {
+	    my $text = $bitmap_action_to_human->($info);
+	    my $drive = $info->{drive};
+	    $drive =~ s/^drive-//; # for consistency
+	    $self->loginfo("$drive: $text");
+	    $target += $info->{dirty};
+	}
+    }
+
     while(1) {
 	my $status = mon_cmd($vmid, 'query-backup');
 
 	my $total = $status->{total} || 0;
-	my $dirty = $status->{dirty};
-	my $target = (defined($dirty) && $dirty < $total) ? $dirty : $total;
+	$target = $total if !$has_query_bitmap;
 	$transferred = $status->{transferred} || 0;
 	$reused = $status->{reused};
 	my $percent = $target ? int(($transferred * 100)/$target) : 0;
@@ -316,11 +355,6 @@ my $query_backup_status_loop = sub {
 	my $target_h = bytes_to_human($target);
 	my $transferred_h = bytes_to_human($transferred);
 
-	if ($first_round && $target != $total) {
-	    my $total_h = bytes_to_human($total);
-	    $self->loginfo("using fast incremental mode (dirty-bitmap), $target_h dirty of $total_h total");
-	}
-
 	my $statusline = "status: $percent% ($transferred_h of $target_h), duration $duration"
 	    .", read: $mbps_read, write: $mbps_write";
 
@@ -347,7 +381,6 @@ my $query_backup_status_loop = sub {
 	    $last_time = $ctime;
 	}
 	sleep(1);
-	$first_round = 0;
     }
 
     my $duration = time() - $starttime;
@@ -362,7 +395,7 @@ my $query_backup_status_loop = sub {
 	$self->loginfo("transferred $transferred_h in $duration seconds ($mbps)");
     }
 
-    if ($last_zero) {
+    if (!defined($pbs_features) && $last_zero) {
 	my $zero_per = $last_target ? int(($last_zero * 100)/$last_target) : 0;
 	my $zero_h = bytes_to_human($last_zero, 2);
 	$self->loginfo("Backup is sparse: ${zero_per}% ($zero_h) zero data");
@@ -490,7 +523,7 @@ sub archive_pbs {
 
 	$self->resume_vm_after_job_start($task, $vmid);
 
-	my $stat = $query_backup_status_loop->($self, $vmid, $backup_job_uuid);
+	my $stat = $query_backup_status_loop->($self, $vmid, $backup_job_uuid, $qemu_support);
 	$task->{size} = $stat->{total};
     };
     my $err = $@;
-- 
2.20.1