Re: [Qemu-devel] [PATCH v4 01/21] iotests: Make 233 output more reliable

[Daniel P . Berrangé]

On Fri, Jan 18, 2019 at 08:28:21AM +0000, Vladimir Sementsov-Ogievskiy wrote:
> 17.01.2019 22:36, Eric Blake wrote:
> > We have a race between the nbd server and the client both trying
> > to report errors at once which can make the test sometimes fail
> > if the output lines swap order under load.  Break the race by
> > collecting server messages into a file and then replaying that
> > at the end of the test.
> > 
> > Signed-off-by: Eric Blake <address@hidden>
> > CC: Daniel P. Berrangé <address@hidden>
> > 
> > ---
> > An alternative solution might be to silence the message from the
> > server by default, and output it only when -v was passed
> > ---
> >   tests/qemu-iotests/233     | 11 ++++++++---
> >   tests/qemu-iotests/233.out |  4 +++-
> >   2 files changed, 11 insertions(+), 4 deletions(-)
> > 
> > diff --git a/tests/qemu-iotests/233 b/tests/qemu-iotests/233
> > index 1814efe3333..ab15c777370 100755
> > --- a/tests/qemu-iotests/233
> > +++ b/tests/qemu-iotests/233
> > @@ -2,7 +2,7 @@
> >   #
> >   # Test NBD TLS certificate / authorization integration
> >   #
> > -# Copyright (C) 2018 Red Hat, Inc.
> > +# Copyright (C) 2018-2019 Red Hat, Inc.
> >   #
> >   # This program is free software; you can redistribute it and/or modify
> >   # it under the terms of the GNU General Public License as published by
> > @@ -30,6 +30,7 @@ _cleanup()
> >   {
> >       nbd_server_stop
> >       _cleanup_test_img
> > +    rm -f "$TEST_DIR/server.log"
> >       tls_x509_cleanup
> >   }
> >   trap "_cleanup; exit \$status" 0 1 2 3 15
> > @@ -66,7 +67,7 @@ $QEMU_IO -c 'w -P 0x11 1m 1m' "$TEST_IMG" | 
> > _filter_qemu_io
> > 
> >   echo
> >   echo "== check TLS client to plain server fails =="
> > -nbd_server_start_tcp_socket -f $IMGFMT "$TEST_IMG"
> > +nbd_server_start_tcp_socket -f $IMGFMT "$TEST_IMG" 2> 
> > "$TEST_DIR/server.log"
> > 
> >   $QEMU_IMG info --image-opts \
> >       --object 
> > tls-creds-x509,dir=${tls_dir}/client1,endpoint=client,id=tls0 \
> > @@ -81,7 +82,7 @@ echo "== check plain client to TLS server fails =="
> >   nbd_server_start_tcp_socket \
> >       --object 
> > tls-creds-x509,dir=${tls_dir}/server1,endpoint=server,id=tls0,verify-peer=yes
> >  \
> >       --tls-creds tls0 \
> > -    -f $IMGFMT "$TEST_IMG"
> > +    -f $IMGFMT "$TEST_IMG" 2>> "$TEST_DIR/server.log"
> > 
> >   $QEMU_IMG info nbd://localhost:$nbd_tcp_port 2>&1 | sed 
> > "s/$nbd_tcp_port/PORT/g"
> > 
> > @@ -109,6 +110,10 @@ $QEMU_IO -c 'r -P 0x11 1m 1m' -c 'w -P 0x22 1m 1m' 
> > --image-opts \
> > 
> >   $QEMU_IO -f $IMGFMT -r -U -c 'r -P 0x22 1m 1m' "$TEST_IMG" | 
> > _filter_qemu_io
> > 
> > +echo
> > +echo "== final server log =="
> > +cat "$TEST_DIR/server.log"
> > +
> >   # success, all done
> >   echo "*** done"
> >   rm -f $seq.full
> > diff --git a/tests/qemu-iotests/233.out b/tests/qemu-iotests/233.out
> > index 5f416721b03..2199d8a8b32 100644
> > --- a/tests/qemu-iotests/233.out
> > +++ b/tests/qemu-iotests/233.out
> > @@ -27,7 +27,6 @@ virtual size: 64M (67108864 bytes)
> >   disk size: unavailable
> > 
> >   == check TLS with different CA fails ==
> > -qemu-nbd: option negotiation failed: Verify failed: No certificate was 
> > found.
> >   qemu-img: Could not open 
> > 'driver=nbd,host=127.0.0.1,port=PORT,tls-creds=tls0': The certificate 
> > hasn't got a known issuer
> > 
> >   == perform I/O over TLS ==
> > @@ -37,4 +36,7 @@ wrote 1048576/1048576 bytes at offset 1048576
> >   1 MiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
> >   read 1048576/1048576 bytes at offset 1048576
> >   1 MiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
> > +
> > +== final server log ==
> > +qemu-nbd: option negotiation failed: Verify failed: No certificate was 
> > found.
> >   *** done
> > 
> 
> The drawback of this way is that we lose captions of test cases, and will not 
> know, from which testcase is error output in "final server log".

That is true, but I don't think it is worth worrying about. It wouldn't
be very hard to identify which test was related to the server log messages,.

> 
> What about something like
> 
> prt() {
>    echo "$@" | tee "$SERVER_LOG"
> }
> 
> and then for captions:
> 
> - echo
> - echo "== check TLS works =="
> + prt
> + prt "== check TLS works =="

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|