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

[Fam Zheng <famz@redhat.com>]

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
>