iotests: 077: Filter out 'resume' lines

In the "Overlapping multiple requests" cases, the 3rd reqs (the break
point B) doesn't wait for the 2nd, and once resumed the I/O will just
continue.  This is because the 2nd is already waiting for the 1st, and
in wait_serialising_requests() there is:

    /* If the request is already (indirectly) waiting for us, or
     * will wait for us as soon as it wakes up, then just go on
     * (instead of producing a deadlock in the former case). */
    if (!req->waiting_for) {
        /* actually break */
        ...
    }

Consequently, the following "sleep 100; resume A" command races with the
completion of that request, and sometimes results in an unexpected
order of output:

> @@ -56,9 +56,9 @@
>  wrote XXX/XXX bytes at offset XXX
>  XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
>  blkdebug: Resuming request 'B'
> +blkdebug: Resuming request 'A'
>  wrote XXX/XXX bytes at offset XXX
>  XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
> -blkdebug: Resuming request 'A'
>  wrote XXX/XXX bytes at offset XXX
>  XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
>  wrote XXX/XXX bytes at offset XXX

Filter out the "Resuming request" lines to make the output
deterministic.

Reported-by: Patchew <no-reply@patchew.org>
Signed-off-by: Fam Zheng <famz@redhat.com>
Message-id: 20171113150026.4743-1-famz@redhat.com
Reviewed-by: Eric Blake <eblake@redhat.com>
Signed-off-by: Max Reitz <mreitz@redhat.com>
This commit is contained in:
Fam Zheng 2017-11-13 23:00:26 +08:00 committed by Max Reitz
parent 04dec3c3ae
commit d04c155503
2 changed files with 18 additions and 33 deletions

View File

@ -188,7 +188,8 @@ EOF
test_io | $QEMU_IO | _filter_qemu_io | \
sed -e 's,[0-9/]* bytes at offset [0-9]*,XXX/XXX bytes at offset XXX,g' \
-e 's/^[0-9]* \(bytes\|KiB\)/XXX bytes/' \
-e '/Suspended/d'
-e '/Suspended/d' \
-e '/blkdebug: Resuming request/d'
echo
echo "== Verify image content =="

View File

@ -4,17 +4,6 @@ Formatting 'TEST_DIR/t.IMGFMT', fmt=IMGFMT size=134217728
== Some concurrent requests involving RMW ==
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
@ -31,51 +20,46 @@ wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'B'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'B'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'B'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'B'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
blkdebug: Resuming request 'C'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'B'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
blkdebug: Resuming request 'A'
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX
XXX bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
wrote XXX/XXX bytes at offset XXX