Libguestfs - Feb 2021 - [PATCH libnbd 1/2] copy: Add temporary debugging messages

Trying to play with --sparse= I found that we abort when converting standard
images (.e.g fedora-32 image created with virt-builder). Add temporary
debugging logs to diagnose the issue (should not be merged
as is) and fix the issue.

Nir Soffer (2):
  copy: Add temporary debugging messages
  copy: Fix sparsifying if start is not aligned

 copy/multi-thread-copying.c | 22 +++++++++++++++++++++-
 1 file changed, 21 insertions(+), 1 deletion(-)

-- 
2.26.2

To help diagnose the abort during sparsify. We probably need to have
similar messages when using --verbose.
---
 copy/multi-thread-copying.c | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

diff --git a/copy/multi-thread-copying.c b/copy/multi-thread-copying.c
index c36a165..a1f4b19 100644
--- a/copy/multi-thread-copying.c
+++ b/copy/multi-thread-copying.c
@@ -393,12 +393,16 @@ finished_read (void *vp, int *error)
     uint64_t i;
     struct command *newcommand;
 
+    fprintf(stderr, "sparsifying range start=%ld end=%ld len=%ld\n",
+            start, end, end - start);
+
     /* Iterate over whole blocks in the command, starting on a block
      * boundary.
      */
     for (i = ROUND_UP (start, sparse_size);
          i + sparse_size <= end;
          i += sparse_size) {
+
       if (is_zero (slice_ptr (command->slice) + i-start, sparse_size)) {
         /* It's a hole.  If the last was a hole too then we do nothing
          * here which coalesces.  Otherwise write the last data and
@@ -407,6 +411,8 @@ finished_read (void *vp, int *error)
         if (!last_is_hole) {
           /* Write the last data (if any). */
           if (i - last_offset > 0) {
+            fprintf(stderr, "write last data start=%ld end=%ld
len=%ld\n",
+                    last_offset, i, i - last_offset);
             newcommand = copy_subcommand (command,
                                           last_offset, i - last_offset,
                                           false);
@@ -429,6 +435,8 @@ finished_read (void *vp, int *error)
         if (last_is_hole) {
           /* Write the last hole (if any). */
           if (i - last_offset > 0) {
+            fprintf(stderr, "write last hole start=%ld end=%ld
len=%ld\n",
+                    last_offset, i, i - last_offset);
             newcommand = copy_subcommand (command,
                                           last_offset, i - last_offset,
                                           true);
@@ -444,6 +452,8 @@ finished_read (void *vp, int *error)
     /* Write the last_offset up to i. */
     if (i - last_offset > 0) {
       if (!last_is_hole) {
+        fprintf(stderr, "write last data start=%ld end=%ld
len=%ld\n",
+                last_offset, i, i - last_offset);
         newcommand = copy_subcommand (command,
                                       last_offset, i - last_offset,
                                       false);
@@ -454,6 +464,8 @@ finished_read (void *vp, int *error)
                                 });
       }
       else {
+        fprintf(stderr, "write last hole start=%ld end=%ld
len=%ld\n",
+                last_offset, i, i - last_offset);
         newcommand = copy_subcommand (command,
                                       last_offset, i - last_offset,
                                       true);
@@ -463,6 +475,8 @@ finished_read (void *vp, int *error)
 
     /* There may be an unaligned tail, so write that. */
     if (end - i > 0) {
+      fprintf(stderr, "write unaligned tail offset=%ld end=%ld
len=%ld\n",
+              i, end, end - i);
       newcommand = copy_subcommand (command, i, end - i, false);
       dst->ops->asynch_write (dst, newcommand,
                               (nbd_completion_callback) {
-- 
2.26.2

When using --sparse=, we may have a case when command start is not
aligned to sparse_size and command length is smaller than sparse_size.
In this case we advance i after the end of the command, and abort when
we try to write after end.

To reproduce this issue (with temporary debug logs):

$ ./nbdcopy --sparse=$((64*1024)) --threads=1 --requests=1
nbd+unix:///?socket=/tmp/src.sock null:
sparsifying range start=0 end=4096 len=4096
write unaligned tail offset=0 end=4096 len=4096
sparsifying range start=1048576 end=1114112 len=65536
write last data start=1048576 end=1114112 len=65536
sparsifying range start=2097152 end=2121728 len=24576
write unaligned tail offset=2097152 end=2121728 len=24576
sparsifying range start=2138112 end=2146304 len=8192
write last data start=2138112 end=2162688 len=24576
lt-nbdcopy: multi-thread-copying.c:351: copy_subcommand: Assertion `offset + len
<= end' failed.
Aborted (core dumped)

Fixed by clipping initial value of i to end of the image.
---
 copy/multi-thread-copying.c | 8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/copy/multi-thread-copying.c b/copy/multi-thread-copying.c
index a1f4b19..ac917e9 100644
--- a/copy/multi-thread-copying.c
+++ b/copy/multi-thread-copying.c
@@ -367,6 +367,12 @@ copy_subcommand (struct command *command, uint64_t offset,
size_t len,
   return newcommand;
 }
 
+static inline uint64_t
+min(uint64_t a, uint64_t b)
+{
+    return a < b ? a : b;
+}
+
 /* Callback called when src has finished one read command.  This
  * initiates a write.
  */
@@ -399,7 +405,7 @@ finished_read (void *vp, int *error)
     /* Iterate over whole blocks in the command, starting on a block
      * boundary.
      */
-    for (i = ROUND_UP (start, sparse_size);
+    for (i = min (ROUND_UP (start, sparse_size), end);
          i + sparse_size <= end;
          i += sparse_size) {
 
-- 
2.26.2