From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: 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) server-digest SHA256) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id 3787061D7A for ; Wed, 19 Aug 2020 17:02:33 +0200 (CEST) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id 1F48325D0C for ; Wed, 19 Aug 2020 17:02:33 +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 696BD25CE9 for ; Wed, 19 Aug 2020 17:02:31 +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 3374C44700 for ; Wed, 19 Aug 2020 17:02:31 +0200 (CEST) From: Stefan Reiter To: pve-devel@lists.proxmox.com Date: Wed, 19 Aug 2020 17:02:01 +0200 Message-Id: <20200819150204.9178-3-s.reiter@proxmox.com> X-Mailer: git-send-email 2.20.1 In-Reply-To: <20200819150204.9178-1-s.reiter@proxmox.com> References: <20200819150204.9178-1-s.reiter@proxmox.com> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-SPAM-LEVEL: Spam detection results: 0 AWL -0.053 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 URIBL_BLOCKED 0.001 ADMINISTRATOR NOTICE: The query to URIBL was blocked. See http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block for more information. [qemuserver.pm] Subject: [pve-devel] [PATCH v2 qemu-server 2/5] 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 List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 19 Aug 2020 15:02:33 -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 --- 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