public inbox for pve-devel@lists.proxmox.com
 help / color / mirror / Atom feed
* [pve-devel] [PATCH v2 storage] fix #3004: show progress of offline migration in task log
@ 2022-11-16 11:02 Leo Nunner
  2023-08-30  8:22 ` Fiona Ebner
  0 siblings, 1 reply; 3+ messages in thread
From: Leo Nunner @ 2022-11-16 11:02 UTC (permalink / raw)
  To: pve-devel

dd supports a 'status' flag, which enables it to show the copied bytes,
duration, and the transfer rate, which then get printed to stderr.

Signed-off-by: Leo Nunner <l.nunner@proxmox.com>
---
Changes from v1:
    - Add rate-limit for dd output with the intervals suggested by
      Thomas

 PVE/Storage.pm           | 23 ++++++++++++++++++-----
 PVE/Storage/LVMPlugin.pm |  2 +-
 PVE/Storage/Plugin.pm    |  4 ++--
 3 files changed, 21 insertions(+), 8 deletions(-)

diff --git a/PVE/Storage.pm b/PVE/Storage.pm
index c21b85e..dfceca9 100755
--- a/PVE/Storage.pm
+++ b/PVE/Storage.pm
@@ -821,12 +821,25 @@ sub storage_migrate {
 
     my $new_volid;
     my $pattern = volume_imported_message(undef, 1);
-    my $match_volid_and_log = sub {
+    # Matches new volid and rate-limits dd output
+    my $match_and_log = sub {
 	my $line = shift;
+	my $show = 1;
+
+	# rate-limit dd logs
+	if ($line =~ /(?:\d+ bytes)(?:.+?copied, )(\d+) s/) {
+	    if ($1 < 60) { # if < 60s, print every 3s
+		$show = !($1 % 3);
+	    } elsif($1 < 600) { # if < 10mins, print every 10s
+		$show = !($1 % 10);
+	    } else { # else, print every 30s
+		$show = !($1 % 30);
+	    }
+	}
 
 	$new_volid = $1 if ($line =~ $pattern);
 
-	if ($logfunc) {
+	if ($logfunc && $show) {
 	    chomp($line);
 	    $logfunc->($line);
 	}
@@ -855,7 +868,7 @@ sub storage_migrate {
 	    # we won't be reading from the socket
 	    shutdown($socket, 0);
 
-	    eval { run_command($cmds, output => '>&'.fileno($socket), errfunc => $logfunc); };
+	    eval { run_command($cmds, output => '>&'.fileno($socket), errfunc => $match_and_log); };
 	    my $send_error = $@;
 
 	    # don't close the connection entirely otherwise the receiving end
@@ -864,7 +877,7 @@ sub storage_migrate {
 
 	    # wait for the remote process to finish
 	    while (my $line = <$info>) {
-		$match_volid_and_log->("[$target_sshinfo->{name}] $line");
+		$match_and_log->("[$target_sshinfo->{name}] $line");
 	    }
 
 	    # now close the socket
@@ -877,7 +890,7 @@ sub storage_migrate {
 	    die $send_error if $send_error;
 	} else {
 	    push @$cmds, $recv;
-	    run_command($cmds, logfunc => $match_volid_and_log);
+	    run_command($cmds, logfunc => $match_and_log);
 	}
 
 	die "unable to get ID of the migrated volume\n"
diff --git a/PVE/Storage/LVMPlugin.pm b/PVE/Storage/LVMPlugin.pm
index a706e0c..4b951e7 100644
--- a/PVE/Storage/LVMPlugin.pm
+++ b/PVE/Storage/LVMPlugin.pm
@@ -645,7 +645,7 @@ sub volume_export {
 	$size = int($1);
     });
     PVE::Storage::Plugin::write_common_header($fh, $size);
-    run_command(['dd', "if=$file", "bs=64k"], output => '>&'.fileno($fh));
+    run_command(['dd', "if=$file", "bs=64k", "status=progress"], output => '>&'.fileno($fh));
 }
 
 sub volume_import_formats {
diff --git a/PVE/Storage/Plugin.pm b/PVE/Storage/Plugin.pm
index 8a41df1..e35fa97 100644
--- a/PVE/Storage/Plugin.pm
+++ b/PVE/Storage/Plugin.pm
@@ -1496,7 +1496,7 @@ sub volume_export {
 	    goto unsupported if $with_snapshots || $file_format eq 'subvol';
 	    write_common_header($fh, $size);
 	    if ($file_format eq 'raw') {
-		run_command(['dd', "if=$file", "bs=4k"], output => '>&'.fileno($fh));
+		run_command(['dd', "if=$file", "bs=4k", "status=progress"], output => '>&'.fileno($fh));
 	    } else {
 		run_command(['qemu-img', 'convert', '-f', $file_format, '-O', 'raw', $file, '/dev/stdout'],
 		            output => '>&'.fileno($fh));
@@ -1506,7 +1506,7 @@ sub volume_export {
 	    my $data_format = $1;
 	    goto unsupported if !$with_snapshots || $file_format ne $data_format;
 	    write_common_header($fh, $size);
-	    run_command(['dd', "if=$file", "bs=4k"], output => '>&'.fileno($fh));
+	    run_command(['dd', "if=$file", "bs=4k", "status=progress"], output => '>&'.fileno($fh));
 	    return;
 	} elsif ($format eq 'tar+size') {
 	    goto unsupported if $file_format ne 'subvol';
-- 
2.30.2





^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [pve-devel] [PATCH v2 storage] fix #3004: show progress of offline migration in task log
  2022-11-16 11:02 [pve-devel] [PATCH v2 storage] fix #3004: show progress of offline migration in task log Leo Nunner
@ 2023-08-30  8:22 ` Fiona Ebner
  2023-08-31  9:00   ` Leo Nunner
  0 siblings, 1 reply; 3+ messages in thread
From: Fiona Ebner @ 2023-08-30  8:22 UTC (permalink / raw)
  To: Proxmox VE development discussion, Leo Nunner

Sorry about the late review!

Am 16.11.22 um 12:02 schrieb Leo Nunner:
> --- a/PVE/Storage.pm
> +++ b/PVE/Storage.pm

Needs a rebase, because files got moved to src/

> @@ -821,12 +821,25 @@ sub storage_migrate {
>  
>      my $new_volid;
>      my $pattern = volume_imported_message(undef, 1);
> -    my $match_volid_and_log = sub {
> +    # Matches new volid and rate-limits dd output
> +    my $match_and_log = sub {

Why rename the function?

>  	my $line = shift;
> +	my $show = 1;
> +
> +	# rate-limit dd logs
> +	if ($line =~ /(?:\d+ bytes)(?:.+?copied, )(\d+) s/) {
> +	    if ($1 < 60) { # if < 60s, print every 3s
> +		$show = !($1 % 3);
> +	    } elsif($1 < 600) { # if < 10mins, print every 10s

Style nit: missing space after elsif

> +		$show = !($1 % 10);
> +	    } else { # else, print every 30s
> +		$show = !($1 % 30);
> +	    }
> +	}

Upon completion something strange happens: There's a duplicate final log
with fractional seconds and duplicate records in/out.

> 2023-08-30 09:57:05 Formatting '/mnt/pve/dir/images/105/vm-105-disk-0.raw', fmt=raw size=1073741824 preallocation=off
> 2023-08-30 09:57:08 1050218496 bytes (1.1 GB, 1002 MiB) copied, 3 s, 350 MB/s
> 2023-08-30 09:57:08 262144+0 records in
> 2023-08-30 09:57:08 262144+0 records out
> 2023-08-30 09:57:08 1073741824 bytes (1.1 GB, 1.0 GiB) copied, 3.06228 s, 351 MB/s
> 2023-08-30 09:57:08 10458+11861 records in
> 2023-08-30 09:57:08 10458+11861 records out
> 2023-08-30 09:57:08 1073741824 bytes (1.1 GB, 1.0 GiB) copied, 2.75082 s, 390 MB/s
> 2023-08-30 09:57:08 successfully imported 'dir:105/vm-105-disk-0.raw'

> 2023-08-30 10:00:38   Logical volume "vm-105-disk-0" created.
> 2023-08-30 10:00:42 873070592 bytes (873 MB, 833 MiB) copied, 3 s, 291 MB/s
> 2023-08-30 10:00:45 1944322048 bytes (1.9 GB, 1.8 GiB) copied, 6 s, 324 MB/s
> 2023-08-30 10:00:48 2976448512 bytes (3.0 GB, 2.8 GiB) copied, 9 s, 331 MB/s
> 2023-08-30 10:00:51 3998810112 bytes (4.0 GB, 3.7 GiB) copied, 12 s, 333 MB/s
> 2023-08-30 10:00:51 65536+0 records in
> 2023-08-30 10:00:51 65536+0 records out
> 2023-08-30 10:00:51 4294967296 bytes (4.3 GB, 4.0 GiB) copied, 13.1171 s, 327 MB/s
> 2023-08-30 10:00:53 44465+42142 records in
> 2023-08-30 10:00:53 44465+42142 records out
> 2023-08-30 10:00:53 4294967296 bytes (4.3 GB, 4.0 GiB) copied, 14.4084 s, 298 MB/s
> 2023-08-30 10:00:53 successfully imported 'lvmthin:vm-105-disk-0'
I think it's because we get it once from the source and once from the
target as better seen when using insecure migration:

> 2023-08-30 10:10:07 262144+0 records in
> 2023-08-30 10:10:07 262144+0 records out
> 2023-08-30 10:10:07 1073741824 bytes (1.1 GB, 1.0 GiB) copied, 1.43834 s, 747 MB/s
> 2023-08-30 10:10:07 [pve8a2] Formatting '/mnt/pve/dir/images/105/vm-105-disk-0.raw', fmt=raw size=1073741824 preallocation=off
> 2023-08-30 10:10:07 [pve8a2] 6997+25632 records in
> 2023-08-30 10:10:07 [pve8a2] 6997+25632 records out
> 2023-08-30 10:10:07 [pve8a2] 1073741824 bytes (1.1 GB, 1.0 GiB) copied, 1.41876 s, 757 MB/s
> 2023-08-30 10:10:07 [pve8a2] successfully imported 'dir:105/vm-105-disk-0.raw'
> 2023-08-30 10:10:07 volume 'dir:105/vm-105-disk-0.raw' is 'dir:105/vm-105-disk-0.raw' on the target

For insecure migration, we know which logs originate from source and
which from the target, so we could avoid the confusing duplicates. Maybe
there is a not too-involved way for secure migration too?




^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [pve-devel] [PATCH v2 storage] fix #3004: show progress of offline migration in task log
  2023-08-30  8:22 ` Fiona Ebner
@ 2023-08-31  9:00   ` Leo Nunner
  0 siblings, 0 replies; 3+ messages in thread
From: Leo Nunner @ 2023-08-31  9:00 UTC (permalink / raw)
  To: Proxmox VE development discussion

Thanks for the review!

On 2023-08-30 10:22, Fiona Ebner wrote:
> Sorry about the late review!
>
> Am 16.11.22 um 12:02 schrieb Leo Nunner:
>> --- a/PVE/Storage.pm
>> +++ b/PVE/Storage.pm
> Needs a rebase, because files got moved to src/
>
>> @@ -821,12 +821,25 @@ sub storage_migrate {
>>  
>>      my $new_volid;
>>      my $pattern = volume_imported_message(undef, 1);
>> -    my $match_volid_and_log = sub {
>> +    # Matches new volid and rate-limits dd output
>> +    my $match_and_log = sub {
> Why rename the function?
>
>>  	my $line = shift;
>> +	my $show = 1;
>> +
>> +	# rate-limit dd logs
>> +	if ($line =~ /(?:\d+ bytes)(?:.+?copied, )(\d+) s/) {
>> +	    if ($1 < 60) { # if < 60s, print every 3s
>> +		$show = !($1 % 3);
>> +	    } elsif($1 < 600) { # if < 10mins, print every 10s
> Style nit: missing space after elsif
>
>> +		$show = !($1 % 10);
>> +	    } else { # else, print every 30s
>> +		$show = !($1 % 30);
>> +	    }
>> +	}
ack, I'll fix those things in the v2.
> Upon completion something strange happens: There's a duplicate final log
> with fractional seconds and duplicate records in/out.

The duplicate logs seem to happen already without my patch:

> 2023-08-31 10:38:54 found local disk
> 'cluster-dir:100/vm-100-disk-0.raw' (attached)
> 2023-08-31 10:38:54 copying local disk images
> 2023-08-31 10:38:56 Formatting
> '/mnt/dir/images/100/vm-100-disk-0.raw', fmt=raw size=2147483648
> preallocation=off
> 2023-08-31 10:39:02 524288+0 records in
> 2023-08-31 10:39:02 524288+0 records out
> 2023-08-31 10:39:02 2147483648 bytes (2.1 GB, 2.0 GiB) copied, 6.52443
> s, 329 MB/s
> 2023-08-31 10:39:02 16749+32053 records in
> 2023-08-31 10:39:02 16749+32053 records out
> 2023-08-31 10:39:02 2147483648 bytes (2.1 GB, 2.0 GiB) copied, 6.22392
> s, 345 MB/s
> 2023-08-31 10:39:02 successfully imported
> 'cluster-dir:100/vm-100-disk-0.raw'
> 2023-08-31 10:39:02 volume 'cluster-dir:100/vm-100-disk-0.raw' is
> 'cluster-dir:100/vm-100-disk-0.raw' on the target
> 2023-08-31 10:39:03 migration finished successfully (duration 00:00:09)
> TASK OK

So this might be something that could be fixed in a separate, future patch.





^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2023-08-31  9:00 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-11-16 11:02 [pve-devel] [PATCH v2 storage] fix #3004: show progress of offline migration in task log Leo Nunner
2023-08-30  8:22 ` Fiona Ebner
2023-08-31  9:00   ` Leo Nunner

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
Service provided by Proxmox Server Solutions GmbH | Privacy | Legal