Re: [Qemu-devel] [PATCH v5 0/4] Use blkdebug to make test deterministic

[Fam Zheng]

On 2013年11月19日 23:31, Stefan Hajnoczi wrote:
> On Mon, Nov 18, 2013 at 03:01:47PM +0800, Fam Zheng wrote:
> > This adds "remove_break" command to block, which removes a break point defined
> > with "break". It is used in iotests.py to pause and resume drive in block job
> > cases to make the test deterministic.
> >
> > v5: Addressing Max's comments (thanks for reviewing)
> >      [02] Resume all the requests.
> >      [03] Fix event="" case. Change default value to None.
> >           Change resume to bool.
> >      [04] Change resume to bool
> >
> > v4: [01] Added.
> >      [03] Add common method pair "pause_drive" and "resume_drive".
> >      [04] Also fix 040, 055.
> >
> > Fam Zheng (4):
> >    qemu-iotests: Drop local version of cancel_and_wait from 040
> >    blkdebug: add "remove_break" command
> >    qemu-iotest: Add pause_drive and resume_drive methods
> >    qemu-iotests: Make test case 030, 040 and 055 deterministic
> >
> >   block.c                       | 13 +++++++++++++
> >   block/blkdebug.c              | 27 +++++++++++++++++++++++++++
> >   include/block/block.h         |  1 +
> >   include/block/block_int.h     |  2 ++
> >   qemu-io-cmds.c                | 22 ++++++++++++++++++++++
> >   tests/qemu-iotests/030        | 16 +++++++++++-----
> >   tests/qemu-iotests/040        | 19 +++----------------
> >   tests/qemu-iotests/055        | 15 +++++++++++----
> >   tests/qemu-iotests/iotests.py | 18 +++++++++++++++++-
> >   9 files changed, 107 insertions(+), 26 deletions(-)
>
> I get this failure after applying the patches onto my block-next tree:

Interesting. I guess this is what happens here:

 - Pause drive.
 - Start block job.
 - Block job send first IO request.
 - Request pended into blkdebug suspended request queue.
 - Block job pause.
 - Resume drive.
 - Query block job #1. The first IO is not completed (luckily): offset 
== 0.
 - Script sleep for 1 sec. The first IO request continues and 
completes, so the offset of block job becomes 65536.
 - Query block job #2. The offset == 65536. Asserssion failed.

This is what happened when I tested it before posting:

 - Pause drive.
 - Start block job.
 - "block-job-pause", before it even entering the IO loop.
 - Resume drive. But the block job is paused, no IO submitted.
 - Query block job #1. Offset is 0.
 - Sleep for 1 second.
 - Query block job #2. Offset is 0. (succeed by luck)
 - Block job resume, starts to IO.
 - Wait until completed
 - ...

Apparently, need some improvements to make this more deterministic. :)

Fam

> $ ./check -qcow2 055
> QEMU          -- /home/stefanha/qemu/tests/qemu-iotests/qemu
> QEMU_IMG      -- /home/stefanha/qemu/tests/qemu-iotests/qemu-img
> QEMU_IO       -- /home/stefanha/qemu/tests/qemu-iotests/qemu-io
> IMGFMT        -- qcow2 (compat=1.1)
> IMGPROTO      -- file
> PLATFORM      -- Linux/x86_64 stefanha-thinkpad 3.11.8-300.fc20.x86_64
> SOCKET_SCM_HELPER --
>
> 055 9s ... [failed, exit status 1] - output mismatch (see 055.out.bad)
> --- 055.out     2013-10-08 13:23:38.412934858 +0200
> +++ 055.out.bad 2013-11-19 16:30:31.100351135 +0100
> @@ -1,5 +1,15 @@
> -..............
> +.......F......
> +======================================================================
> +FAIL: test_pause (__main__.TestSingleDrive)
> +----------------------------------------------------------------------
> +Traceback (most recent call last):
> +  File "./055", line 80, in test_pause
> +    self.assert_qmp(result, 'return[0]/offset', offset)
> +  File "/home/stefanha/qemu/tests/qemu-iotests/iotests.py", line 232, in 
> assert_qmp
> +    self.assertEqual(result, value, 'values not equal "%s" and "%s"' % 
> (str(result), str(value)))
> +AssertionError: values not equal "65536" and "0"
> +
>   ----------------------------------------------------------------------
>   Ran 14 tests
>
> -OK
> +FAILED (failures=1)
> Failures: 055
> Failed 1 of 1 tests