On 7/28/20 1:10 PM, Max Reitz wrote: > On 28.07.20 01:09, Bruce Rogers wrote: >> 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 <vsement...@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. > > Thanks for both your investigation. Does the attached patch help? > > Max >
Hello Max, yes, this solves the problem everywhere (on s390, on X86, based on all the reproducers so far). Thanks a lot for the help! Claudio
