Re: [pve-devel] [PATCH pve-qemu] fix: 3865: backup restore human readable output

[Thomas Lamprecht <t.lamprecht@proxmox.com>]

Thanks for the patch, some comments inline.

On 24.03.22 16:44, Daniel Tschlatscher wrote:
> The backup restore dialogue now displays size information and duration in a format more easily understandable for humans. The output was adapted to match the output of the backup restore dialogue where possible.

But this is the backup restore, so do you mean it was matched to how its
outputted for a special case there already or how its outputted for the backup
(i.e., the other direction) one?

> Added 2 helper methods for displaying bytes and time in human readable format.

please format the commit message according our submission rules:
https://pve.proxmox.com/wiki/Developer_Documentation#Commits_and_Commit_Messages

an output example (maybe even an before/after) excerpt would be nice to have here.

> 
> Signed-off-by: Daniel Tschlatscher <d.tschlatscher@proxmox.com>
> ---
>  ...VE-Backup-add-vma-backup-format-code.patch | 117 ++++++++++++++----
>  1 file changed, 96 insertions(+), 21 deletions(-)
> 
> diff --git a/debian/patches/pve/0026-PVE-Backup-add-vma-backup-format-code.patch b/debian/patches/pve/0026-PVE-Backup-add-vma-backup-format-code.patch
> index c4ed5bb..2dc1bd8 100644
> --- a/debian/patches/pve/0026-PVE-Backup-add-vma-backup-format-code.patch
> +++ b/debian/patches/pve/0026-PVE-Backup-add-vma-backup-format-code.patch
> @@ -9,11 +9,11 @@ Signed-off-by: Fabian Ebner <f.ebner@proxmox.com>
>  ---
>   block/meson.build |   2 +
>   meson.build       |   5 +
> - vma-reader.c      | 857 ++++++++++++++++++++++++++++++++++++++++++++++
> - vma-writer.c      | 790 ++++++++++++++++++++++++++++++++++++++++++
> - vma.c             | 851 +++++++++++++++++++++++++++++++++++++++++++++
> - vma.h             | 150 ++++++++
> - 6 files changed, 2655 insertions(+)
> + vma-reader.c      | 922 ++++++++++++++++++++++++++++++++++++++++++++++
> + vma-writer.c      | 790 +++++++++++++++++++++++++++++++++++++++
> + vma.c             | 857 ++++++++++++++++++++++++++++++++++++++++++
> + vma.h             | 153 ++++++++
> + 6 files changed, 2729 insertions(+)
>   create mode 100644 vma-reader.c
>   create mode 100644 vma-writer.c
>   create mode 100644 vma.c
> @@ -57,10 +57,10 @@ index 96de1a6ef9..54c23b9567 100644
>     subdir('contrib/elf2dmp')
>  diff --git a/vma-reader.c b/vma-reader.c
>  new file mode 100644
> -index 0000000000..2b1d1cdab3
> +index 0000000000..907759b295
>  --- /dev/null
>  +++ b/vma-reader.c
> -@@ -0,0 +1,857 @@
> +@@ -0,0 +1,922 @@
>  +/*
>  + * VMA: Virtual Machine Archive
>  + *
> @@ -77,6 +77,7 @@ index 0000000000..2b1d1cdab3
>  +#include "qemu/osdep.h"
>  +#include <glib.h>
>  +#include <uuid/uuid.h>
> ++#include <math.h>
>  +
>  +#include "qemu-common.h"
>  +#include "qemu/timer.h"
> @@ -87,6 +88,9 @@ index 0000000000..2b1d1cdab3
>  +
>  +static unsigned char zero_vma_block[VMA_BLOCK_SIZE];
>  +
> ++static time_t last_time = 0;
> ++static int64_t last_size = 0;
> ++
>  +typedef struct VmaRestoreState {
>  +    BlockBackend *target;
>  +    bool write_zeroes;
> @@ -649,13 +653,31 @@ index 0000000000..2b1d1cdab3
>  +
>  +        if (verbose) {
>  +            time_t duration = time(NULL) - vmar->start_time;

The resulting accuracy for time in seconds could be not that good, did you make any
thoughts or comparison regarding that.

> -+            int percent = (vmar->clusters_read*100)/vmar->cluster_count;
> -+            if (percent != vmar->clusters_read_per) {
> -+                printf("progress %d%% (read %zd bytes, duration %zd sec)\n",
> -+                       percent, vmar->clusters_read*VMA_CLUSTER_SIZE,
> -+                       duration);
> ++            int percent = (vmar->clusters_read*100) / vmar->cluster_count;

if we already touch this then please also add the missing spaces around `*`

> ++
> ++            /* Dont spam so many progress prints, but still show the 100% message*/
> ++            if ((duration - last_time) > 2 || percent == 100) {
> ++                int delta = duration - last_time;
> ++                int64_t bps = vmar->clusters_read*VMA_CLUSTER_SIZE - last_size;

missing spaces around `*`, shortening such units can be confusing, I'd rather suggest:
(may need be written more nicely if it fails the 100 characters width formatting rule)

int64_t byte_throughput = delta > 0 ? (vmar->clusters_read * VMA_CLUSTER_SIZE - last_size) / delta : 0;

> ++
> ++                if (delta != 0)
> ++                    bps /= delta;

currently, if delta would be null you'd print a size unit as throughput unit?

> ++
> ++                printf("Progress %d%% (", percent);
> ++                print_human_readable_byte_count(vmar->clusters_read*VMA_CLUSTER_SIZE);
> ++                printf(" of ");
> ++                print_human_readable_byte_count(vmar->devinfo[dev_id].size);
> ++                printf(") in ");
> ++                print_human_readable_time(duration);
> ++                printf(" - ");
> ++                print_human_readable_byte_count(bps);
> ++                printf("/s\n");
> ++
>  +                fflush(stdout);

would IMO be worth it to factor above lines out in a static local helper to avoid
crowding this function to much, e.g. (types may be adapted if reasonable):

print_restore_progress(uint64_t total_byte, uint64_t restored_byte, uint64_t duration_ms);

I would handle the last_X statics in there and also re-calculate the percentage as float
in there, so that we can print a similar amount of digits after the decimal place like
we do in backup.

> ++
>  +                vmar->clusters_read_per = percent;
> ++                last_time = duration;
> ++                last_size = vmar->clusters_read*VMA_CLUSTER_SIZE;
>  +            }
>  +        }
>  +
> @@ -881,11 +903,17 @@ index 0000000000..2b1d1cdab3
>  +
>  +    if (verbose) {
>  +        if (vmar->clusters_read) {
> -+            printf("total bytes read %zd, sparse bytes %zd (%.3g%%)\n",
> -+                   vmar->clusters_read*VMA_CLUSTER_SIZE,
> -+                   vmar->zero_cluster_data,
> -+                   (double)(100.0*vmar->zero_cluster_data)/
> -+                   (vmar->clusters_read*VMA_CLUSTER_SIZE));
> ++            double sparse_percent = (double)(100.0*vmar->zero_cluster_data) /
> ++                   (vmar->clusters_read*VMA_CLUSTER_SIZE);
> ++            time_t duration = time(NULL) - vmar->start_time;
> ++
> ++            printf("Finished restoring ");
> ++            print_human_readable_byte_count(vmar->clusters_read*VMA_CLUSTER_SIZE);
> ++            printf(" bytes in ");
> ++	    print_human_readable_time(duration);
> ++	    printf(" with ");
> ++	    print_human_readable_byte_count(vmar->zero_cluster_data);
> ++	    printf(" of sparse data. (%.3g%%)\n", sparse_percent);
>  +
>  +            int64_t datasize = vmar->clusters_read*VMA_CLUSTER_SIZE-vmar->zero_cluster_data;
>  +            if (datasize) { // this does not make sense for empty files
> @@ -918,6 +946,44 @@ index 0000000000..2b1d1cdab3
>  +    return vma_reader_restore_full(vmar, -1, verbose, true, errp);
>  +}
>  +
> ++void print_human_readable_time(int seconds) {
> ++	int days, hours, mins;
> ++
> ++	days = seconds / 86400;
> ++	seconds = seconds % 86400;

fwiw, modulo is always expensive, maybe try:

seconds -= days * 24 * 3600;


> ++
> ++	hours = seconds / 3600;
> ++	seconds = seconds % 3600;
> ++
> ++	mins = seconds / 60;
> ++	seconds = seconds % 60;
> ++
> ++	if (days)
> ++		printf("%d d ", days);
> ++	if (hours)
> ++		printf("%d h ", hours);
> ++	if (mins)> ++		printf("%d m ", mins);
> ++	printf("%d s", seconds);
> ++}
> ++
> ++/* This should correctly display values up to 9,2 Ebibytes*/
> ++void print_human_readable_byte_count(int64_t value) {
> ++	double calculated = (double)value;
> ++	const char* units = "KMGTPE";
> ++	char unit;
> ++
> ++	int maxUnit = 0;
> ++	if (value > 1023) {
> ++		maxUnit = (int)(log(value)/log(1024));

log is quite expensive, I'd rather go for a similar approach like we do in JS:

https://git.proxmox.com/?p=proxmox-widget-toolkit.git;a=blob;f=src/Utils.js;h=6a03057a704943539b90ed58dfb3d0b05ecf7883;hb=HEAD#l656

The units char array can stay, and if we just want base-2 units we can loop over
the value, shift it right by 10 each round until < 1024, then do a final /1024.0
division to float so that we get the digits after the decimal place.

> ++		calculated = value / pow(1024, maxUnit);
> ++		unit = units[maxUnit - 1];
> ++		printf("%.2f %ciB", calculated, unit);
> ++	} else {
> ++		printf("%zd B", (int64_t)calculated);
> ++	}
> ++}
> +\ No newline at end of file
>  diff --git a/vma-writer.c b/vma-writer.c
>  new file mode 100644
>  index 0000000000..11d8321ffd
> @@ -1716,10 +1782,10 @@ index 0000000000..11d8321ffd
>  +}
>  diff --git a/vma.c b/vma.c
>  new file mode 100644
> -index 0000000000..df542b7732
> +index 0000000000..781b5bf700
>  --- /dev/null
>  +++ b/vma.c
> -@@ -0,0 +1,851 @@
> +@@ -0,0 +1,857 @@
>  +/*
>  + * VMA: Virtual Machine Archive
>  + *
> @@ -1802,8 +1868,14 @@ index 0000000000..df542b7732
>  +            if (strcmp(di->devname, "vmstate") == 0) {
>  +                printf("VMSTATE: dev_id=%d memory: %zd\n", i, di->size);
>  +            } else {
> ++                /* Information that is needed in qemu-server (PVE::QemuServer.pm)
> ++                   Change only if you know what you are doing */
>  +                printf("DEV: dev_id=%d size: %zd devname: %s\n",
>  +                       i, di->size, di->devname);
> ++
> ++                printf("Info: dev_id=%d size: ", i);
> ++                print_human_readable_byte_count(di->size);
> ++                printf(" devname: %s\n", di->devname);

is this directly related to the swap restore-output to human readable?

>  +            }
>  +        }
>  +    }
> @@ -2573,10 +2645,10 @@ index 0000000000..df542b7732
>  +}
>  diff --git a/vma.h b/vma.h
>  new file mode 100644
> -index 0000000000..c895c97f6d
> +index 0000000000..c4867b8584
>  --- /dev/null
>  +++ b/vma.h
> -@@ -0,0 +1,150 @@
> +@@ -0,0 +1,153 @@
>  +/*
>  + * VMA: Virtual Machine Archive
>  + *
> @@ -2726,4 +2798,7 @@ index 0000000000..c895c97f6d
>  +                       Error **errp);
>  +int vma_reader_verify(VmaReader *vmar, bool verbose, Error **errp);
>  +
> ++void print_human_readable_time(int);
> ++void print_human_readable_byte_count(int64_t);
> ++
>  +#endif /* BACKUP_VMA_H */