On 7/13/20 1:39 PM, Claudio Fontana wrote: > Hello, > > On 7/13/20 1:03 PM, Dr. David Alan Gilbert wrote: >> * Claudio Fontana (cfont...@suse.de) wrote: >>> Hello all, >>> >>> during unrelated work for splitting QTest from the TCG instruction counting >>> module, >>> >>> I encountered what seems to be a migration stream issue, which is apparent >>> only on s390, and only shows in block test 267. >>> >>> ./check -qcow2 267 >>> >>> when it comes to snapshot save and load using backing file. >>> >>> Here is a minimal reproducer patch that causes the issue on s390 only. >>> >>> --------------------------------------------cut------------------------------------------- >>> diff --git a/cpus.c b/cpus.c >>> index 41d1c5099f..443b88697a 100644 >>> --- a/cpus.c >>> +++ b/cpus.c >>> @@ -643,7 +643,7 @@ static void qemu_account_warp_timer(void) >>> >>> static bool icount_state_needed(void *opaque) >>> { >>> - return use_icount; >>> + return 0; >>> } >> >> That's weird; I mean that's just turning a subsection on and off; >> so you'd hope if this is a test that generates it's own snapshot and >> then uses it then it should be consistent. > > Indeed. > >> >>> static bool warp_timer_state_needed(void *opaque) >>> --------------------------------------------cut------------------------------------------- >>> >>> config.status configure line: >>> exec '/home/cfontana/qemu-build/../qemu/configure' '--enable-tcg' >>> '--disable-kvm' '--disable-hax' '--target-list=s390x-softmmu' >>> '--enable-debug' >>> >>> $ make check-block >>> >>> TEST iotest-qcow2: 267 [fail] >>> QEMU -- >>> "/home/cfontana/qemu-build/tests/qemu-iotests/../../s390x-softmmu/qemu-system-s390x" >>> -nodefaults -display none -accel qtest >>> QEMU_IMG -- >>> "/home/cfontana/qemu-build/tests/qemu-iotests/../../qemu-img" >>> QEMU_IO -- >>> "/home/cfontana/qemu-build/tests/qemu-iotests/../../qemu-io" --cache >>> writeback --aio threads -f qcow2 >>> QEMU_NBD -- >>> "/home/cfontana/qemu-build/tests/qemu-iotests/../../qemu-nbd" >>> IMGFMT -- qcow2 (compat=1.1) >>> IMGPROTO -- file >>> PLATFORM -- Linux/s390x s390zp13 5.3.18-21-default >>> TEST_DIR -- /home/cfontana/qemu-build/tests/qemu-iotests/scratch >>> SOCK_DIR -- /tmp/tmp.bLJcJVtzk5 >>> SOCKET_SCM_HELPER -- >>> /home/cfontana/qemu-build/tests/qemu-iotests/socket_scm_helper >>> >>> --- /home/cfontana/qemu/tests/qemu-iotests/267.out 2020-07-12 >>> 05:10:07.948262675 -0400 >>> +++ /home/cfontana/qemu-build/tests/qemu-iotests/267.out.bad >>> 2020-07-12 05:27:03.358362781 -0400 >>> @@ -137,6 +137,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 flag data: 0 >>> +error while loading state for instance 0x0 of device 's390-skeys' >>> +Error: Error -22 while loading VM state >>> (qemu) quit >>> >>> >>> ----------- >>> >>> >>> Not run: 172 186 192 259 287 >>> Failures: 267 >>> Failed 1 of 115 iotests >>> make: *** [/home/cfontana/qemu/tests/Makefile.include:880: >>> check-tests/check-block.sh] Error 1 >>> >>> ----------- >>> >>> Note: only the === -blockdev with a backing file === part of test 267 >>> fails. -blockdev with NBD is ok, like all the rest. >>> >>> >>> Interesting facts about s390 in particular: its save/load code includes the >>> transfer of "storage keys", >>> which include a buffer of 32768 bytes of keydata in the stream. >>> >>> The code (hw/s390x/s390-skeys.c), >>> is modeled similarly to RAM transfer (like in migration/ram.c), with an EOS >>> (end of stream) marker. >>> >>> Countrary to RAM transfer code though, after qemu_put_be64(f, EOS), the >>> s390 code does not qemu_fflush(f). >>> >>> ---------- >>> Observation: the migration/qemu-file.c shows an IO_BUF_SIZE of 32768. >>> >>> -- >>> >>> The following workarounds hide the problem (make the test pass): >>> >>> 1) always including the icount field in the (unrelated) timers field that >>> are sent before in the migration stream (ie not applying the reproducer >>> patch). >>> >>> 2) increasing the IO_BUF_SIZE also hides the problem: >>> >>> ----------------------cut-------------------------- >>> diff --git a/migration/qemu-file.c b/migration/qemu-file.c >>> index be21518c57..f81d1272eb 100644 >>> --- a/migration/qemu-file.c >>> +++ b/migration/qemu-file.c >>> @@ -30,7 +30,7 @@ >>> #include "trace.h" >>> #include "qapi/error.h" >>> >>> -#define IO_BUF_SIZE 32768 >>> +#define IO_BUF_SIZE 65536 >>> #define MAX_IOV_SIZE MIN_CONST(IOV_MAX, 64) >>> >>> struct QEMUFile { >>> ----------------------cut-------------------------- >>> >>> 3) adding a qemu_fflush in hw/s390x/s390-skeys.c after EOS also "fixes" the >>> problem: >>> >>> ----------------------cut-------------------------- >>> diff --git a/hw/s390x/s390-skeys.c b/hw/s390x/s390-skeys.c >>> index 1e036cc602..47c9a015af 100644 >>> --- a/hw/s390x/s390-skeys.c >>> +++ b/hw/s390x/s390-skeys.c >>> @@ -252,6 +252,8 @@ static const TypeInfo qemu_s390_skeys_info = { >>> .class_size = sizeof(S390SKeysClass), >>> }; >>> >>> +extern void qemu_fflush(QEMUFile *f); >>> + >>> static void s390_storage_keys_save(QEMUFile *f, void *opaque) >>> { >>> S390SKeysState *ss = S390_SKEYS(opaque); >>> @@ -302,6 +304,7 @@ static void s390_storage_keys_save(QEMUFile *f, void >>> *opaque) >>> g_free(buf); >>> end_stream: >>> qemu_put_be64(f, eos); >>> + qemu_fflush(f); >>> } >>> >>> static int s390_storage_keys_load(QEMUFile *f, void *opaque, int >>> version_id) >>> ----------------------cut-------------------------- >>> >>> Do any of you with better understanding of migration/, block and s390 have >>> a suggestion on what could be the issue here, >>> and what could be the next step in the investigation? >>> >>> Is the fact that migration/ram.c always does fflush after writing the EOS >>> have any relevance here? why does it do it, >>> and should s390 code also follow the same pattern? >> >> I didn't think it was required. >> And qemu_put_buffer loops if needed and calls qemu_fflush internally. > > This detail probably does not help in this case, because the buffer itself is > fine (32678 zero bytes is actually correct). > > The End Of Stream marker written just after with qemu_put_be64 is not ok, > and anything past that point is just a whole bunch of zeroes in the stream > when we hookup the calls to > > qcow2_co_pwritev_task and qcow2_co_preadv_task > > (see my response to Paolo in this thread). > > >> It's possible here that the storage key code is just the canary - the >> first thing that detects that the stream is invalid after it all goes >> wrong. > > Seems the exact opposite to me, ie, the stream seems just fine up to the > point where the EOS marker after the keydata in "s390-skeys" should be.
Ah I might have misunderstood what you wrote there, you mean that the stream became invalid, and this just happened in the context of s390-skeys right.. To me it also looks like an underlying issue, not really related to skeys in particular, just that they exercise the underlying machinery is a very peculiar way, in terms or field positions, sizes etc. Ciao, Claudio > > Thanks! > > Claudio > >> >> Dave >> >> >>> Thanks, >>> >>> Claudio >>> >>> >>> -- >>> Claudio Fontana >>> Engineering Manager Virtualization, SUSE Labs Core >>> >>> SUSE Software Solutions Italy Srl >>> >> -- >> Dr. David Alan Gilbert / dgilb...@redhat.com / Manchester, UK >> >> > >