iotests: port 141 to Python for reliable QMP testing

The common.qemu bash functions allow tests to interact with the QMP
monitor of a QEMU process. I spent two days trying to update 141 when
the order of the test output changed, but found it would still fail
occassionally because printf() and QMP events race with synchronous QMP
communication.

I gave up and ported 141 to the existing Python API for QMP tests. The
Python API is less affected by the order in which QEMU prints output
because it does not print all QMP traffic by default.

The next commit changes the order in which QMP messages are received.
Make 141 reliable first.

Cc: Hanna Czenczek <hreitz@redhat.com>
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Message-ID: <20240118144823.1497953-3-stefanha@redhat.com>
Reviewed-by: Kevin Wolf <kwolf@redhat.com>
Signed-off-by: Kevin Wolf <kwolf@redhat.com>
(cherry picked from commit 9ee2dd4c22)
Signed-off-by: Michael Tokarev <mjt@tls.msk.ru>
This commit is contained in:
Stefan Hajnoczi 2024-01-18 09:48:22 -05:00 committed by Michael Tokarev
parent d7a64c4517
commit 823892d19f
2 changed files with 154 additions and 309 deletions

View File

@ -1,9 +1,12 @@
#!/usr/bin/env bash #!/usr/bin/env python3
# group: rw auto quick # group: rw auto quick
# #
# Test case for ejecting BDSs with block jobs still running on them # Test case for ejecting BDSs with block jobs still running on them
# #
# Copyright (C) 2016 Red Hat, Inc. # Originally written in bash by Hanna Czenczek, ported to Python by Stefan
# Hajnoczi.
#
# Copyright Red Hat
# #
# This program is free software; you can redistribute it and/or modify # 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 # it under the terms of the GNU General Public License as published by
@ -19,177 +22,129 @@
# along with this program. If not, see <http://www.gnu.org/licenses/>. # along with this program. If not, see <http://www.gnu.org/licenses/>.
# #
# creator import iotests
owner=hreitz@redhat.com
seq="$(basename $0)" # Common filters to mask values that vary in the test output
echo "QA output created by $seq" QMP_FILTERS = [iotests.filter_qmp_testfiles, \
iotests.filter_qmp_imgfmt]
status=1 # failure is the default!
_cleanup()
{
_cleanup_qemu
_cleanup_test_img
for img in "$TEST_DIR"/{b,m,o}.$IMGFMT; do
_rm_test_img "$img"
done
}
trap "_cleanup; exit \$status" 0 1 2 3 15
# get standard environment, filters and checks
. ./common.rc
. ./common.filter
. ./common.qemu
# Needs backing file and backing format support
_supported_fmt qcow2 qed
_supported_proto file
_supported_os Linux
test_blockjob() class TestCase:
{ def __init__(self, name, vm, image_path, cancel_event):
_send_qemu_cmd $QEMU_HANDLE \ self.name = name
"{'execute': 'blockdev-add', self.vm = vm
'arguments': { self.image_path = image_path
'node-name': 'drv0', self.cancel_event = cancel_event
'driver': '$IMGFMT',
'file': {
'driver': 'file',
'filename': '$TEST_IMG'
}}}" \
'return'
# If "$2" is an event, we may or may not see it before the def __enter__(self):
# {"return": {}}. Therefore, filter the {"return": {}} out both iotests.log(f'=== Testing {self.name} ===')
# here and in the next command. (Naturally, if we do not see it self.vm.qmp_log('blockdev-add', \
# here, we will see it before the next command can be executed, node_name='drv0', \
# so it will appear in the next _send_qemu_cmd's output.) driver=iotests.imgfmt, \
_send_qemu_cmd $QEMU_HANDLE \ file={'driver': 'file', 'filename': self.image_path}, \
"$1" \ filters=QMP_FILTERS)
"$2" \
| _filter_img_create | _filter_qmp_empty_return
# We want this to return an error because the block job is still running def __exit__(self, *exc_details):
_send_qemu_cmd $QEMU_HANDLE \ # This is expected to fail because the job still exists
"{'execute': 'blockdev-del', self.vm.qmp_log('blockdev-del', node_name='drv0', \
'arguments': {'node-name': 'drv0'}}" \ filters=[iotests.filter_qmp_generated_node_ids])
'error' | _filter_generated_node_ids | _filter_qmp_empty_return
_send_qemu_cmd $QEMU_HANDLE \ self.vm.qmp_log('block-job-cancel', device='job0')
"{'execute': 'block-job-cancel', event = self.vm.event_wait(self.cancel_event)
'arguments': {'device': 'job0'}}" \ iotests.log(event, filters=[iotests.filter_qmp_event])
"$3"
_send_qemu_cmd $QEMU_HANDLE \ # This time it succeeds
"{'execute': 'blockdev-del', self.vm.qmp_log('blockdev-del', node_name='drv0')
'arguments': {'node-name': 'drv0'}}" \
'return' # Separate test cases in output
} iotests.log('')
TEST_IMG="$TEST_DIR/b.$IMGFMT" _make_test_img 1M def main() -> None:
TEST_IMG="$TEST_DIR/m.$IMGFMT" _make_test_img -b "$TEST_DIR/b.$IMGFMT" -F $IMGFMT 1M with iotests.FilePath('bottom', 'middle', 'top', 'target') as \
_make_test_img -b "$TEST_DIR/m.$IMGFMT" 1M -F $IMGFMT (bottom_path, middle_path, top_path, target_path), \
iotests.VM() as vm:
_launch_qemu -nodefaults iotests.log('Creating bottom <- middle <- top backing file chain...')
IMAGE_SIZE='1M'
iotests.qemu_img_create('-f', iotests.imgfmt, bottom_path, IMAGE_SIZE)
iotests.qemu_img_create('-f', iotests.imgfmt, \
'-F', iotests.imgfmt, \
'-b', bottom_path, \
middle_path, \
IMAGE_SIZE)
iotests.qemu_img_create('-f', iotests.imgfmt, \
'-F', iotests.imgfmt, \
'-b', middle_path, \
top_path, \
IMAGE_SIZE)
_send_qemu_cmd $QEMU_HANDLE \ iotests.log('Starting VM...')
"{'execute': 'qmp_capabilities'}" \ vm.add_args('-nodefaults')
'return' vm.launch()
echo # drive-backup will not send BLOCK_JOB_READY by itself, and cancelling
echo '=== Testing drive-backup ===' # the job will consequently result in BLOCK_JOB_CANCELLED being
echo # emitted.
with TestCase('drive-backup', vm, top_path, 'BLOCK_JOB_CANCELLED'):
vm.qmp_log('drive-backup', \
job_id='job0', \
device='drv0', \
target=target_path, \
format=iotests.imgfmt, \
sync='none', \
filters=QMP_FILTERS)
# drive-backup will not send BLOCK_JOB_READY by itself, and cancelling the job # drive-mirror will send BLOCK_JOB_READY basically immediately, and
# will consequently result in BLOCK_JOB_CANCELLED being emitted. # cancelling the job will consequently result in BLOCK_JOB_COMPLETED
# being emitted.
with TestCase('drive-mirror', vm, top_path, 'BLOCK_JOB_COMPLETED'):
vm.qmp_log('drive-mirror', \
job_id='job0', \
device='drv0', \
target=target_path, \
format=iotests.imgfmt, \
sync='none', \
filters=QMP_FILTERS)
event = vm.event_wait('BLOCK_JOB_READY')
assert event is not None # silence mypy
iotests.log(event, filters=[iotests.filter_qmp_event])
test_blockjob \ # An active block-commit will send BLOCK_JOB_READY basically
"{'execute': 'drive-backup', # immediately, and cancelling the job will consequently result in
'arguments': {'job-id': 'job0', # BLOCK_JOB_COMPLETED being emitted.
'device': 'drv0', with TestCase('active block-commit', vm, top_path, \
'target': '$TEST_DIR/o.$IMGFMT', 'BLOCK_JOB_COMPLETED'):
'format': '$IMGFMT', vm.qmp_log('block-commit', \
'sync': 'none'}}" \ job_id='job0', \
'return' \ device='drv0')
'"status": "null"' event = vm.event_wait('BLOCK_JOB_READY')
assert event is not None # silence mypy
iotests.log(event, filters=[iotests.filter_qmp_event])
echo # Give block-commit something to work on, otherwise it would be done
echo '=== Testing drive-mirror ===' # immediately, send a BLOCK_JOB_COMPLETED and ejecting the BDS would
echo # work just fine without the block job still running.
iotests.qemu_io(middle_path, '-c', f'write 0 {IMAGE_SIZE}')
with TestCase('non-active block-commit', vm, top_path, \
'BLOCK_JOB_CANCELLED'):
vm.qmp_log('block-commit', \
job_id='job0', \
device='drv0', \
top=middle_path, \
speed=1, \
filters=[iotests.filter_qmp_testfiles])
# drive-mirror will send BLOCK_JOB_READY basically immediately, and cancelling # Give block-stream something to work on, otherwise it would be done
# the job will consequently result in BLOCK_JOB_COMPLETED being emitted. # immediately, send a BLOCK_JOB_COMPLETED and ejecting the BDS would
# work just fine without the block job still running.
iotests.qemu_io(bottom_path, '-c', f'write 0 {IMAGE_SIZE}')
with TestCase('block-stream', vm, top_path, 'BLOCK_JOB_CANCELLED'):
vm.qmp_log('block-stream', \
job_id='job0', \
device='drv0', \
speed=1)
test_blockjob \ if __name__ == '__main__':
"{'execute': 'drive-mirror', iotests.script_main(main, supported_fmts=['qcow2', 'qed'],
'arguments': {'job-id': 'job0', supported_protocols=['file'])
'device': 'drv0',
'target': '$TEST_DIR/o.$IMGFMT',
'format': '$IMGFMT',
'sync': 'none'}}" \
'BLOCK_JOB_READY' \
'"status": "null"'
echo
echo '=== Testing active block-commit ==='
echo
# An active block-commit will send BLOCK_JOB_READY basically immediately, and
# cancelling the job will consequently result in BLOCK_JOB_COMPLETED being
# emitted.
test_blockjob \
"{'execute': 'block-commit',
'arguments': {'job-id': 'job0', 'device': 'drv0'}}" \
'BLOCK_JOB_READY' \
'"status": "null"'
echo
echo '=== Testing non-active block-commit ==='
echo
# Give block-commit something to work on, otherwise it would be done
# immediately, send a BLOCK_JOB_COMPLETED and ejecting the BDS would work just
# fine without the block job still running.
$QEMU_IO -c 'write 0 1M' "$TEST_DIR/m.$IMGFMT" | _filter_qemu_io
test_blockjob \
"{'execute': 'block-commit',
'arguments': {'job-id': 'job0',
'device': 'drv0',
'top': '$TEST_DIR/m.$IMGFMT',
'speed': 1}}" \
'return' \
'"status": "null"'
echo
echo '=== Testing block-stream ==='
echo
# Give block-stream something to work on, otherwise it would be done
# immediately, send a BLOCK_JOB_COMPLETED and ejecting the BDS would work just
# fine without the block job still running.
$QEMU_IO -c 'write 0 1M' "$TEST_DIR/b.$IMGFMT" | _filter_qemu_io
# With some data to stream (and @speed set to 1), block-stream will not complete
# until we send the block-job-cancel command.
test_blockjob \
"{'execute': 'block-stream',
'arguments': {'job-id': 'job0',
'device': 'drv0',
'speed': 1}}" \
'return' \
'"status": "null"'
_cleanup_qemu
# success, all done
echo "*** done"
rm -f $seq.full
status=0

View File

@ -1,179 +1,69 @@
QA output created by 141 Creating bottom <- middle <- top backing file chain...
Formatting 'TEST_DIR/b.IMGFMT', fmt=IMGFMT size=1048576 Starting VM...
Formatting 'TEST_DIR/m.IMGFMT', fmt=IMGFMT size=1048576 backing_file=TEST_DIR/b.IMGFMT backing_fmt=IMGFMT
Formatting 'TEST_DIR/t.IMGFMT', fmt=IMGFMT size=1048576 backing_file=TEST_DIR/m.IMGFMT backing_fmt=IMGFMT
{'execute': 'qmp_capabilities'}
{"return": {}}
=== Testing drive-backup === === Testing drive-backup ===
{"execute": "blockdev-add", "arguments": {"driver": "IMGFMT", "file": {"driver": "file", "filename": "TEST_DIR/PID-top"}, "node-name": "drv0"}}
{'execute': 'blockdev-add',
'arguments': {
'node-name': 'drv0',
'driver': 'IMGFMT',
'file': {
'driver': 'file',
'filename': 'TEST_DIR/t.IMGFMT'
}}}
{"return": {}} {"return": {}}
{'execute': 'drive-backup', {"execute": "drive-backup", "arguments": {"device": "drv0", "format": "IMGFMT", "job-id": "job0", "sync": "none", "target": "TEST_DIR/PID-target"}}
'arguments': {'job-id': 'job0', {"return": {}}
'device': 'drv0', {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
'target': 'TEST_DIR/o.IMGFMT',
'format': 'IMGFMT',
'sync': 'none'}}
Formatting 'TEST_DIR/o.IMGFMT', fmt=IMGFMT size=1048576 backing_file=TEST_DIR/t.IMGFMT backing_fmt=IMGFMT
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "paused", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: node is used as backing hd of 'NODE_NAME'"}} {"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: node is used as backing hd of 'NODE_NAME'"}}
{'execute': 'block-job-cancel', {"execute": "block-job-cancel", "arguments": {"device": "job0"}}
'arguments': {'device': 'job0'}}
{"return": {}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "job0"}} {"data": {"device": "job0", "len": 1048576, "offset": 0, "speed": 0, "type": "backup"}, "event": "BLOCK_JOB_CANCELLED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "job0", "len": 1048576, "offset": 0, "speed": 0, "type": "backup"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"return": {}} {"return": {}}
=== Testing drive-mirror === === Testing drive-mirror ===
{"execute": "blockdev-add", "arguments": {"driver": "IMGFMT", "file": {"driver": "file", "filename": "TEST_DIR/PID-top"}, "node-name": "drv0"}}
{'execute': 'blockdev-add',
'arguments': {
'node-name': 'drv0',
'driver': 'IMGFMT',
'file': {
'driver': 'file',
'filename': 'TEST_DIR/t.IMGFMT'
}}}
{"return": {}} {"return": {}}
{'execute': 'drive-mirror', {"execute": "drive-mirror", "arguments": {"device": "drv0", "format": "IMGFMT", "job-id": "job0", "sync": "none", "target": "TEST_DIR/PID-target"}}
'arguments': {'job-id': 'job0', {"return": {}}
'device': 'drv0', {"data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "mirror"}, "event": "BLOCK_JOB_READY", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
'target': 'TEST_DIR/o.IMGFMT', {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
'format': 'IMGFMT',
'sync': 'none'}}
Formatting 'TEST_DIR/o.IMGFMT', fmt=IMGFMT size=1048576 backing_file=TEST_DIR/t.IMGFMT backing_fmt=IMGFMT
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_READY", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "mirror"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: mirror"}} {"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: mirror"}}
{'execute': 'block-job-cancel', {"execute": "block-job-cancel", "arguments": {"device": "job0"}}
'arguments': {'device': 'job0'}}
{"return": {}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "job0"}} {"data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "mirror"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "job0"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "mirror"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"return": {}} {"return": {}}
=== Testing active block-commit === === Testing active block-commit ===
{"execute": "blockdev-add", "arguments": {"driver": "IMGFMT", "file": {"driver": "file", "filename": "TEST_DIR/PID-top"}, "node-name": "drv0"}}
{'execute': 'blockdev-add',
'arguments': {
'node-name': 'drv0',
'driver': 'IMGFMT',
'file': {
'driver': 'file',
'filename': 'TEST_DIR/t.IMGFMT'
}}}
{"return": {}} {"return": {}}
{'execute': 'block-commit', {"execute": "block-commit", "arguments": {"device": "drv0", "job-id": "job0"}}
'arguments': {'job-id': 'job0', 'device': 'drv0'}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job0"}} {"data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_READY", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_READY", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: commit"}} {"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: commit"}}
{'execute': 'block-job-cancel', {"execute": "block-job-cancel", "arguments": {"device": "job0"}}
'arguments': {'device': 'job0'}}
{"return": {}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "job0"}} {"data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "job0"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"return": {}} {"return": {}}
=== Testing non-active block-commit === === Testing non-active block-commit ===
{"execute": "blockdev-add", "arguments": {"driver": "IMGFMT", "file": {"driver": "file", "filename": "TEST_DIR/PID-top"}, "node-name": "drv0"}}
wrote 1048576/1048576 bytes at offset 0
1 MiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
{'execute': 'blockdev-add',
'arguments': {
'node-name': 'drv0',
'driver': 'IMGFMT',
'file': {
'driver': 'file',
'filename': 'TEST_DIR/t.IMGFMT'
}}}
{"return": {}} {"return": {}}
{'execute': 'block-commit', {"execute": "block-commit", "arguments": {"device": "drv0", "job-id": "job0", "speed": 1, "top": "TEST_DIR/PID-middle"}}
'arguments': {'job-id': 'job0', {"return": {}}
'device': 'drv0', {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
'top': 'TEST_DIR/m.IMGFMT',
'speed': 1}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: commit"}} {"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: commit"}}
{'execute': 'block-job-cancel', {"execute": "block-job-cancel", "arguments": {"device": "job0"}}
'arguments': {'device': 'job0'}}
{"return": {}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "job0"}} {"data": {"device": "job0", "len": 1048576, "offset": 524288, "speed": 1, "type": "commit"}, "event": "BLOCK_JOB_CANCELLED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "job0", "len": 1048576, "offset": 524288, "speed": 1, "type": "commit"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"return": {}} {"return": {}}
=== Testing block-stream === === Testing block-stream ===
{"execute": "blockdev-add", "arguments": {"driver": "IMGFMT", "file": {"driver": "file", "filename": "TEST_DIR/PID-top"}, "node-name": "drv0"}}
wrote 1048576/1048576 bytes at offset 0
1 MiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
{'execute': 'blockdev-add',
'arguments': {
'node-name': 'drv0',
'driver': 'IMGFMT',
'file': {
'driver': 'file',
'filename': 'TEST_DIR/t.IMGFMT'
}}}
{"return": {}} {"return": {}}
{'execute': 'block-stream', {"execute": "block-stream", "arguments": {"device": "drv0", "job-id": "job0", "speed": 1}}
'arguments': {'job-id': 'job0', {"return": {}}
'device': 'drv0', {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
'speed': 1}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: stream"}} {"error": {"class": "GenericError", "desc": "Node 'drv0' is busy: block device is in use by block job: stream"}}
{'execute': 'block-job-cancel', {"execute": "block-job-cancel", "arguments": {"device": "job0"}}
'arguments': {'device': 'job0'}}
{"return": {}} {"return": {}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "job0"}} {"data": {"device": "job0", "len": 1048576, "offset": 524288, "speed": 1, "type": "stream"}, "event": "BLOCK_JOB_CANCELLED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "job0", "len": 1048576, "offset": 524288, "speed": 1, "type": "stream"}} {"execute": "blockdev-del", "arguments": {"node-name": "drv0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job0"}}
{"timestamp": {"seconds": TIMESTAMP, "microseconds": TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job0"}}
{'execute': 'blockdev-del',
'arguments': {'node-name': 'drv0'}}
{"return": {}} {"return": {}}
*** done