From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 From: Stefan Reiter Date: Wed, 27 May 2020 11:33:22 +0200 Subject: [PATCH] savevm-async: add debug timing prints Signed-off-by: Stefan Reiter [ Thomas: guard variable declaration by DEBUG #ifdef ] Signed-off-by: Thomas Lamprecht --- savevm-async.c | 22 ++++++++++++++++++++++ 1 file changed, 22 insertions(+) diff --git a/savevm-async.c b/savevm-async.c index 4ce83a0691..0388cebbe9 100644 --- a/savevm-async.c +++ b/savevm-async.c @@ -202,6 +202,10 @@ static void process_savevm_finalize(void *opaque) AioContext *iohandler_ctx = iohandler_get_aio_context(); MigrationState *ms = migrate_get_current(); +#ifdef DEBUG_SAVEVM_STATE + int64_t start_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); +#endif + qemu_bh_delete(snap_state.finalize_bh); snap_state.finalize_bh = NULL; snap_state.co = NULL; @@ -226,6 +230,8 @@ static void process_savevm_finalize(void *opaque) } DPRINTF("state saving complete\n"); + DPRINTF("timing: process_savevm_finalize (state saving) took %ld ms\n", + qemu_clock_get_ms(QEMU_CLOCK_REALTIME) - start_time); /* clear migration state */ migrate_set_state(&ms->state, MIGRATION_STATUS_SETUP, @@ -247,6 +253,9 @@ static void process_savevm_finalize(void *opaque) vm_start(); snap_state.saved_vm_running = false; } + + DPRINTF("timing: process_savevm_finalize (full) took %ld ms\n", + qemu_clock_get_ms(QEMU_CLOCK_REALTIME) - start_time); } static void coroutine_fn process_savevm_co(void *opaque) @@ -256,6 +265,10 @@ static void coroutine_fn process_savevm_co(void *opaque) BdrvNextIterator it; BlockDriverState *bs = NULL; +#ifdef DEBUG_SAVEVM_STATE + int64_t start_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); +#endif + ret = qemu_file_get_error(snap_state.file); if (ret < 0) { save_snapshot_error("qemu_savevm_state_setup failed"); @@ -290,6 +303,12 @@ static void coroutine_fn process_savevm_co(void *opaque) } } + DPRINTF("timing: process_savevm_co took %ld ms\n", + qemu_clock_get_ms(QEMU_CLOCK_REALTIME) - start_time); + +#ifdef DEBUG_SAVEVM_STATE + int64_t start_time_flush = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); +#endif /* If a drive runs in an IOThread we can flush it async, and only * need to sync-flush whatever IO happens between now and * vm_stop_force_state. bdrv_next can only be called from main AioContext, @@ -311,6 +330,9 @@ static void coroutine_fn process_savevm_co(void *opaque) } } + DPRINTF("timing: async flushing took %ld ms\n", + qemu_clock_get_ms(QEMU_CLOCK_REALTIME) - start_time_flush); + qemu_bh_schedule(snap_state.finalize_bh); }