Re: migration: broken snapshot saves appear on s390 when small fields in migration stream removed

[Bruce Rogers]

On Tue, 2020-07-21 at 10:22 +0200, Claudio Fontana wrote:
> On 7/20/20 8:24 PM, Claudio Fontana wrote:
> > I have now been able to reproduce this on X86 as well.
> > 
> > It happens much more rarely, about once every 10 times.
> > 
> > I will sort out the data and try to make it even more reproducible,
> > then post my findings in detail.
> > 
> > Overall I proceeded as follows:
> > 
> > 1) hooked the savevm code to skip all fields with the exception of
> > "s390-skeys". So only s390-skeys are actually saved.
> > 
> > 2) reimplemented "s390-skeys" in a common implementation in cpus.c,
> > used on both x86 and s390, modeling the behaviour of save/load from
> > hw/s390
> > 
> > 3) ran ./check -qcow2 267 on both x86 and s390.
> > 
> > In the case of s390, failure seems to be reproducible 100% of the
> > times.
> > On X86, it is as mentioned failing about 10% of the times.
> > 
> > Ciao,
> > 
> > Claudio
> 
> And here is a small series of two patches that can be used to
> reproduce the problem.
> 
> Clearly, this is not directly related to s390 or to skeys or to
> icount in particular, it is just an issue that happened to be more
> visible there.
> 
> If you could help with this, please apply the attached patches.
> 
> Patch 1 just adds a new "300" iotest. It is way easier to extract the
> relevant part out of test 267, which does a bit too much in the same
> file.
> Also this allows easier use of valgrind, since it does not "require"
> anything.
> 
> Patch 2 hooks the savevm code to skip all fields during the snapshot
> with the exception of "s390-skeys", a new artificial field
> implemented to
> model what the real s390-skeys is doing.
> 
> After applying patch 1 and patch 2, you can test (also on X86), with:
> 
> ./check -qcow2 300
> 
> On X86 many runs will be successful, but a certain % of them will
> instead fail like this:
> 
> 
> claudio@linux-ch70:~/git/qemu-pristine/qemu-build/tests/qemu-iotests> 
> ./check -qcow2 300
> QEMU          -- "/home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/../../x86_64-softmmu/qemu-system-x86_64"
> -nodefaults -display none -accel qtest
> QEMU_IMG      -- "/home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/../../qemu-img" 
> QEMU_IO       -- "/home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/../../qemu-io"  --cache writeback --aio
> threads -f qcow2
> QEMU_NBD      -- "/home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/../../qemu-nbd" 
> IMGFMT        -- qcow2 (compat=1.1)
> IMGPROTO      -- file
> PLATFORM      -- Linux/x86_64 linux-ch70 4.12.14-lp151.28.36-default
> TEST_DIR      -- /home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/scratch
> SOCK_DIR      -- /tmp/tmp.gdcUu3l0SM
> SOCKET_SCM_HELPER -- /home/claudio/git/qemu-pristine/qemu-
> build/tests/qemu-iotests/socket_scm_helper
> 
> 300      fail       [10:14:05] [10:14:06]      (last: 0s)    output
> mismatch (see 300.out.bad)
> --- /home/claudio/git/qemu-pristine/qemu/tests/qemu-
> iotests/300.out     2020-07-21 10:03:54.468104764 +0200
> +++ /home/claudio/git/qemu-pristine/qemu-build/tests/qemu-
> iotests/300.out.bad   2020-07-21 10:14:06.098090543 +0200
> @@ -12,6 +12,9 @@
>  ID        TAG                 VM SIZE                DATE       VM
> CLOCK
>  --        snap0                  SIZE yyyy-mm-dd
> hh:mm:ss   00:00:00.000
>  (qemu) loadvm snap0
> +Unexpected storage key data: 0
> +error while loading state for instance 0x0 of device 's390-skeys'
> +Error: Error -22 while loading VM state
>  (qemu) quit
>  
>  *** done
> Failures: 300
> Failed 1 of 1 iotests
> 
> 
> At this point somebody more knowledgeable about QCOW2, coroutines and
> backing files could chime in?
> 
<trim>

I used the reproducer you provide here to do a git bisect as I assume
whatever is now broken wasn't always broken, and it pointed to the
following commit:

commit df893d25ceea3c0dcbe6d6b425309317fab6b22e (refs/bisect/bad)
Author: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Date:   Tue Jun 4 19:15:13 2019 +0300

    block/qcow2: implement .bdrv_co_preadv_part

Indeed, I am currently able to reliable reproduce the issue with this
commit applied, and not reproduce it without it.

That said, I've not been able to identify exactly what is going wrong.
I'm fairly confident the savevm data is correctly written out, but on
the loadvm side, somehow the last part of the s390 data is not
correctly read in the data (it's in the second pass through the while
loop in qcow2_co_preadv_part() where that happens.)

If anyone familiar with this code can have a look or provide some
pointers, it would be much appreciated.

Adding commit author to CC.

Thanks,

Bruce