On 12/18/2015 03:46 PM, Eric Blake wrote:
> On 12/11/2015 06:23 PM, John Snow wrote:
>>
>
> ping
>
>>
>> On 12/10/2015 10:27 PM, Eric Blake wrote:
>>> On my machine, './check -qcow2 028' was failing about 80% of the
>>> time, due to a race in how many times the repeated attempts
>>> to run 'info block-jobs' could occur before the job was done,
>>> showing up as a failure of fewer '(qemu) ' prompts than in the
>>> expected output. Silence the output during the repetitions, then
>>> add a final clean command to keep the expected output useful;
>>> once patched, I was finally able to run the test 20 times in a
>>> row with no failures.
>>>
>>
>> Son of a gun:
>>
>> 028 4s ... - output mismatch (see 028.out.bad)
>> --- /home/bos/jsnow/src/q3mu/tests/qemu-iotests/028.out 2015-10-09
>> 13:33:06.823758271 -0400
>> +++ 028.out.bad 2015-12-11 20:12:23.688952510 -0500
>> @@ -470,7 +470,7 @@
>>
>> Formatting 'TEST_DIR/t.IMGFMT.copy', fmt=IMGFMT size=4294968832
>> backing_file=TEST_DIR/t.IMGFMT.base backing_fmt=IMGFMT
>> (qemu)
>> -(qemu) info block-jobs
>> +info block-jobs
>> Type backup, device disk: Completed 0 of 4294968832 bytes, speed limit
>> 0 bytes/s
>> info block-jobs
>> No active jobs
>>
>>
>> Something must have changed to make it more prone to races, somehow.
>> Venus... Swamp gas...
>
> Now that 2.6 is open, is my approach right, or do we need a more robust
> solution?
>
>>
>>> Signed-off-by: Eric Blake <ebl...@redhat.com>
>>> ---
>>>
>>> Not sure if this is the best fix, or if it is even appropriate
>>> for inclusion in 2.5 this late in the game.
>>>
>>> tests/qemu-iotests/028 | 6 ++++--
>>> tests/qemu-iotests/028.out | 3 ---
>>> 2 files changed, 4 insertions(+), 5 deletions(-)
>>>
>>> diff --git a/tests/qemu-iotests/028 b/tests/qemu-iotests/028
>>> index a1f4423..756c335 100755
>>> --- a/tests/qemu-iotests/028
>>> +++ b/tests/qemu-iotests/028
>>> @@ -111,10 +111,12 @@ h=$QEMU_HANDLE
>>> QEMU_COMM_TIMEOUT=1
>>>
>>> # Silence output since it contains the disk image path and QEMU's readline
>>> -# character echoing makes it very hard to filter the output
>>> +# character echoing makes it very hard to filter the output. Plus, there
>>> +# is no telling how many times the command will repeat before succeeding.
>>> _send_qemu_cmd $h "drive_backup disk ${TEST_IMG}.copy" "(qemu)" >/dev/null
>>> _send_qemu_cmd $h "" "Formatting" | _filter_img_create
>>> -qemu_cmd_repeat=20 _send_qemu_cmd $h "info block-jobs" "No active jobs"
>>> +qemu_cmd_repeat=20 _send_qemu_cmd $h "info block-jobs" "No active jobs"
>>> >/dev/null
>>> +_send_qemu_cmd $h "info block-jobs" "No active jobs"
>>> _send_qemu_cmd $h 'quit' ""
>>>
>>> # Base image sectors
>>> diff --git a/tests/qemu-iotests/028.out b/tests/qemu-iotests/028.out
>>> index 29c9972..e03452d 100644
>>> --- a/tests/qemu-iotests/028.out
>>> +++ b/tests/qemu-iotests/028.out
>>> @@ -469,10 +469,7 @@ No errors were found on the image.
>>> block-backup
>>>
>>> Formatting 'TEST_DIR/t.IMGFMT.copy', fmt=IMGFMT size=4294968832
>>> backing_file=TEST_DIR/t.IMGFMT.base backing_fmt=IMGFMT
>>> -(qemu)
>>> (qemu) i[K[Din[K[D[Dinf[K[D[D[Dinfo[K[D[D[D[Dinfo
>>> [K[D[D[D[D[Dinfo b[K[D[D[D[D[D[Dinfo
>>> bl[K[D[D[D[D[D[D[Dinfo blo[K[D[D[D[D[D[D[D[Dinfo
>>> bloc[K[D[D[D[D[D[D[D[D[Dinfo
>>> block[K[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-[K[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-j[K[D[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-jo[K[D[D[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-job[K[D[D[D[D[D[D[D[D[D[D[D[D[D[Dinfo block-jobs[K
>>> -Type backup, device disk: Completed 0 of 4294968832 bytes, speed limit 0
>>> bytes/s
>>> -i[K[Din[K[D[Dinf[K[D[D[Dinfo[K[D[D[D[Dinfo
>>> [K[D[D[D[D[Dinfo b[K[D[D[D[D[D[Dinfo
>>> bl[K[D[D[D[D[D[D[Dinfo blo[K[D[D[D[D[D[D[D[Dinfo
>>> bloc[K[D[D[D[D[D[D[D[D[Dinfo
>>> block[K[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-[K[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-j[K[D[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-jo[K[D[D[D[D[D[D[D[D[D[D[D[D[Dinfo
>>> block-job[K[D[D[D[D[D[D[D[D[D[D[D[D[D[Dinfo block-jobs[K
>>> No active jobs
>>> === IO: pattern 195
>>> read 512/512 bytes at offset 3221194240
>>>
>>
>
It looks sane to me, because you are deleting the insane portion of the
expected output. The final "info block" command serves as an assertion
that the loop polled successfully.
Reviewed-by: John Snow <js...@redhat.com>
