Test delay-alert-ms via HMP qemu-io (break, aio_read/write, resume) on a null node (with blkdebug).
Signed-off-by: Hanna Czenczek <[email protected]> --- tests/qemu-iotests/tests/delay-alert | 136 +++++++++++++++++++++++ tests/qemu-iotests/tests/delay-alert.out | 46 ++++++++ 2 files changed, 182 insertions(+) create mode 100755 tests/qemu-iotests/tests/delay-alert create mode 100644 tests/qemu-iotests/tests/delay-alert.out diff --git a/tests/qemu-iotests/tests/delay-alert b/tests/qemu-iotests/tests/delay-alert new file mode 100755 index 00000000000..d98f537e802 --- /dev/null +++ b/tests/qemu-iotests/tests/delay-alert @@ -0,0 +1,136 @@ +#!/usr/bin/env python3 +# group: rw +# +# Test the I/O delay QMP event. +# +# Copyright (C) 2026 Red Hat, Inc. +# +# SPDX-License-Identifier: GPL-2.0-or-later +# +# Creator/Owner: Hanna Czenczek <[email protected]> + +import asyncio +import iotests +from iotests import filter_qmp_event, log + +DELAY_ALERT_MS = 5000 # ms +EPSILON_MS = 50 # ms -- small delta that can safely be added/subtracted +NS_PER_MS = 1000 * 1000 + +qtest_clock = 0 # ms + +iotests.script_initialize() + +def vm_qemu_io(qvm, virtio_blk_id, cmd): + log(f'[HMP] qemu-io to {virtio_blk_id}: {cmd}') + cmd = f'qemu-io -d {virtio_blk_id}/virtio-backend "{cmd}"' + log(qvm.qmp('human-monitor-command', command_line=cmd)) + +def advance_clock_to(qvm, clock_ms): + # Retain the current absolute clock time so we can step *to* a specific + # time via `clock_step`. pylint does not like global much, but this is a + # test script, and not using global would just make this more complicated. + global qtest_clock # pylint: disable=global-statement + + msecs = clock_ms - qtest_clock + log(f'[qtest] clock_step {msecs}ms to {clock_ms}ms') + qvm.qtest(f'clock_step {msecs * NS_PER_MS}') + qtest_clock += msecs + +def assert_no_event(qvm, event_name): + try: + evt = qvm.event_wait(event_name, timeout=0.1) + assert evt is None, f'Unexpected {event_name} event: {evt}' + except asyncio.TimeoutError: + pass + log(f'(No {event_name} event)') + +with iotests.VM() as vm: + # Cannot use null-co.latency-ns, as that uses realtime (not qtest time) + # Need to use raw to get the read_aio event working + vm.add_blockdev(vm.qmp_to_opts({ + 'driver': 'raw', + 'node-name': 'test-node', + 'file': { + 'driver': 'blkdebug', + 'image': { + 'driver': 'null-co', + }, + }, + })) + + vm.launch() + + log(f'[QMP] device_add id=vblk delay-alert-ms={DELAY_ALERT_MS}') + log(vm.qmp('device_add', { + 'driver': 'virtio-blk', + 'id': 'vblk', + 'drive': 'test-node', + 'delay-alert-ms': DELAY_ALERT_MS, + })) + + try: + # Test different operation types. Flushing and discarding would also be + # nice but `aio_flush` does not actually execute a flush, and there is + # no blkdebug event for discarding. + + vm_qemu_io(vm, 'vblk', 'break read_aio read_0') + vm_qemu_io(vm, 'vblk', 'aio_read 0k 4k') + vm_qemu_io(vm, 'vblk', 'wait_break read_0') + + vm_qemu_io(vm, 'vblk', 'break write_aio write_0') + vm_qemu_io(vm, 'vblk', 'aio_write 4k 4k') + vm_qemu_io(vm, 'vblk', 'wait_break write_0') + + vm_qemu_io(vm, 'vblk', 'break read_aio read_1') + vm_qemu_io(vm, 'vblk', 'aio_read 8k 4k') + vm_qemu_io(vm, 'vblk', 'wait_break read_1') + + vm_qemu_io(vm, 'vblk', 'break write_aio write_1') + vm_qemu_io(vm, 'vblk', 'aio_write 12k 4k') + vm_qemu_io(vm, 'vblk', 'wait_break write_1') + + # Assert there is no event before the step + advance_clock_to(vm, DELAY_ALERT_MS - EPSILON_MS) + assert_no_event(vm, 'BLOCK_IO_DELAY') + + # Even when a request finishes here + vm_qemu_io(vm, 'vblk', 'resume read_0') + assert_no_event(vm, 'BLOCK_IO_DELAY') + + # Crossing the threshold alone does not cause an event to fire + advance_clock_to(vm, DELAY_ALERT_MS + EPSILON_MS) + assert_no_event(vm, 'BLOCK_IO_DELAY') + + # Only when the request finishes past the threshold do we see one + vm_qemu_io(vm, 'vblk', 'resume write_0') + event = vm.event_wait('BLOCK_IO_DELAY') + assert event is not None + log(event, filters=[filter_qmp_event]) + assert_no_event(vm, 'BLOCK_IO_DELAY') + + # Check that we get the event immediately on completion + vm_qemu_io(vm, 'vblk', 'resume read_1') + event = vm.event_wait('BLOCK_IO_DELAY') + assert event is not None + log(event, filters=[filter_qmp_event]) + assert_no_event(vm, 'BLOCK_IO_DELAY') + + # And the same for the final request, but add another bit of delay + advance_clock_to(vm, DELAY_ALERT_MS + 2 * EPSILON_MS) + vm_qemu_io(vm, 'vblk', 'resume write_1') + event = vm.event_wait('BLOCK_IO_DELAY') + assert event is not None + log(event, filters=[filter_qmp_event]) + assert_no_event(vm, 'BLOCK_IO_DELAY') + except Exception as exc: + # The VM will not be able to quit without these requests + # finished, which (without this block) would make the test + # hang instead of exit if something unexpected goes wrong + vm_qemu_io(vm, 'vblk', 'resume read_0') + vm_qemu_io(vm, 'vblk', 'resume write_0') + vm_qemu_io(vm, 'vblk', 'resume read_1') + vm_qemu_io(vm, 'vblk', 'resume write_1') + raise exc + + vm.shutdown() diff --git a/tests/qemu-iotests/tests/delay-alert.out b/tests/qemu-iotests/tests/delay-alert.out new file mode 100644 index 00000000000..fe6cd71c6b1 --- /dev/null +++ b/tests/qemu-iotests/tests/delay-alert.out @@ -0,0 +1,46 @@ +[QMP] device_add id=vblk delay-alert-ms=5000 +{"return": {}} +[HMP] qemu-io to vblk: break read_aio read_0 +{"return": ""} +[HMP] qemu-io to vblk: aio_read 0k 4k +{"return": ""} +[HMP] qemu-io to vblk: wait_break read_0 +{"return": ""} +[HMP] qemu-io to vblk: break write_aio write_0 +{"return": ""} +[HMP] qemu-io to vblk: aio_write 4k 4k +{"return": ""} +[HMP] qemu-io to vblk: wait_break write_0 +{"return": ""} +[HMP] qemu-io to vblk: break read_aio read_1 +{"return": ""} +[HMP] qemu-io to vblk: aio_read 8k 4k +{"return": ""} +[HMP] qemu-io to vblk: wait_break read_1 +{"return": ""} +[HMP] qemu-io to vblk: break write_aio write_1 +{"return": ""} +[HMP] qemu-io to vblk: aio_write 12k 4k +{"return": ""} +[HMP] qemu-io to vblk: wait_break write_1 +{"return": ""} +[qtest] clock_step 4950ms to 4950ms +(No BLOCK_IO_DELAY event) +[HMP] qemu-io to vblk: resume read_0 +{"return": ""} +(No BLOCK_IO_DELAY event) +[qtest] clock_step 100ms to 5050ms +(No BLOCK_IO_DELAY event) +[HMP] qemu-io to vblk: resume write_0 +{"return": ""} +{"data": {"bytes": 4096, "duration": 5.05, "offset": 4096, "operation": "write", "qom-path": "/machine/peripheral/vblk/virtio-backend"}, "event": "BLOCK_IO_DELAY", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +(No BLOCK_IO_DELAY event) +[HMP] qemu-io to vblk: resume read_1 +{"return": ""} +{"data": {"bytes": 4096, "duration": 5.05, "offset": 8192, "operation": "read", "qom-path": "/machine/peripheral/vblk/virtio-backend"}, "event": "BLOCK_IO_DELAY", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +(No BLOCK_IO_DELAY event) +[qtest] clock_step 50ms to 5100ms +[HMP] qemu-io to vblk: resume write_1 +{"return": ""} +{"data": {"bytes": 4096, "duration": 5.1, "offset": 12288, "operation": "write", "qom-path": "/machine/peripheral/vblk/virtio-backend"}, "event": "BLOCK_IO_DELAY", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +(No BLOCK_IO_DELAY event) -- 2.55.0
