Message ID | 1393767584-2141-1-git-send-email-aik@ozlabs.ru |
---|---|
State | New |
Headers | show |
I am glad to hear that you are also interested in migration. We will be pleasure if you find some bugs or suggestion and discuss them together with us. As I know, the qemu will print some log about the migration failure. It is same to your patch. > This adds more traces in the migration code. > > Signed-off-by: Alexey Kardashevskiy <aik@ozlabs.ru> > --- > > Debugging migration lately a lot and this patch helps quite a lot. > Would it make any use for anyone else? Thanks. > > > --- > migration.c | 34 +++++++++++----------------------- > savevm.c | 14 ++++++++------ > trace-events | 10 ++++++++-- > vmstate.c | 2 ++ > 4 files changed, 29 insertions(+), 31 deletions(-) > > diff --git a/migration.c b/migration.c > index 742dd5c..5455d2a 100644 > --- a/migration.c > +++ b/migration.c > @@ -26,16 +26,6 @@ > #include "qmp-commands.h" > #include "trace.h" > > -//#define DEBUG_MIGRATION > - > -#ifdef DEBUG_MIGRATION > -#define DPRINTF(fmt, ...) \ > - do { printf("migration: " fmt, ## __VA_ARGS__); } while (0) > -#else > -#define DPRINTF(fmt, ...) \ > - do { } while (0) > -#endif > - > enum { > MIG_STATE_ERROR = -1, > MIG_STATE_NONE, > @@ -111,7 +101,7 @@ static void process_incoming_migration_co(void *opaque) > exit(EXIT_FAILURE); > } > qemu_announce_self(); > - DPRINTF("successfully loaded vm state\n"); > + trace_migrate_event("successfully loaded vm state"); > > bdrv_clear_incoming_migration_all(); > /* Make sure all file formats flush their mutable metadata */ > @@ -300,7 +290,7 @@ static void migrate_fd_cleanup(void *opaque) > s->cleanup_bh = NULL; > > if (s->file) { > - DPRINTF("closing file\n"); > + trace_migrate_event("closing file"); > qemu_mutex_unlock_iothread(); > qemu_thread_join(&s->thread); > qemu_mutex_lock_iothread(); > @@ -323,7 +313,7 @@ static void migrate_fd_cleanup(void *opaque) > > void migrate_fd_error(MigrationState *s) > { > - DPRINTF("setting error state\n"); > + trace_migrate_event("setting error state"); > assert(s->file == NULL); > s->state = MIG_STATE_ERROR; > trace_migrate_set_state(MIG_STATE_ERROR); > @@ -333,7 +323,7 @@ void migrate_fd_error(MigrationState *s) > static void migrate_fd_cancel(MigrationState *s) > { > int old_state ; > - DPRINTF("cancelling migration\n"); > + trace_migrate_event("cancelling migration"); > > do { > old_state = s->state; > @@ -608,29 +598,28 @@ static void *migration_thread(void *opaque) > int64_t start_time = initial_time; > bool old_vm_running = false; > > - DPRINTF("beginning savevm\n"); > + trace_migrate_event("beginning savevm"); > qemu_savevm_state_begin(s->file, &s->params); > > s->setup_time = qemu_clock_get_ms(QEMU_CLOCK_HOST) - setup_start; > migrate_set_state(s, MIG_STATE_SETUP, MIG_STATE_ACTIVE); > > - DPRINTF("setup complete\n"); > + trace_migrate_event("setup complete"); > > while (s->state == MIG_STATE_ACTIVE) { > int64_t current_time; > uint64_t pending_size; > > if (!qemu_file_rate_limit(s->file)) { > - DPRINTF("iterate\n"); > + trace_migrate_event("iterate"); > pending_size = qemu_savevm_state_pending(s->file, max_size); > - DPRINTF("pending size %" PRIu64 " max %" PRIu64 "\n", > - pending_size, max_size); > + trace_migrate_pending(pending_size, max_size); > if (pending_size && pending_size >= max_size) { > qemu_savevm_state_iterate(s->file); > } else { > int ret; > > - DPRINTF("done iterating\n"); > + trace_migrate_event("done iterating"); > qemu_mutex_lock_iothread(); > start_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); > qemu_system_wakeup_request(QEMU_WAKEUP_REASON_OTHER); > @@ -669,9 +658,8 @@ static void *migration_thread(void *opaque) > s->mbps = time_spent ? (((double) transferred_bytes * 8.0) / > ((double) time_spent / 1000.0)) / 1000.0 / 1000.0 : -1; > > - DPRINTF("transferred %" PRIu64 " time_spent %" PRIu64 > - " bandwidth %g max_size %" PRId64 "\n", > - transferred_bytes, time_spent, bandwidth, max_size); > + trace_migrate_transferred(transferred_bytes, time_spent, > + bandwidth, max_size); > /* if we haven't sent anything, we don't want to recalculate > 10000 is a small enough number for our purposes */ > if (s->dirty_bytes_rate && transferred_bytes > 10000) { > diff --git a/savevm.c b/savevm.c > index 7329fc5..8e15b7e 100644 > --- a/savevm.c > +++ b/savevm.c > @@ -429,6 +429,7 @@ void vmstate_unregister(DeviceState *dev, const VMStateDescription *vmsd, > > static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) > { > + trace_vmstate_load(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); > if (!se->vmsd) { /* Old style */ > return se->ops->load_state(f, se->opaque, version_id); > } > @@ -437,6 +438,7 @@ static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) > > static void vmstate_save(QEMUFile *f, SaveStateEntry *se) > { > + trace_vmstate_save(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); > if (!se->vmsd) { /* Old style */ > se->ops->save_state(f, se->opaque); > return; > @@ -527,13 +529,13 @@ int qemu_savevm_state_iterate(QEMUFile *f) > if (qemu_file_rate_limit(f)) { > return 0; > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_PART); > qemu_put_be32(f, se->section_id); > > ret = se->ops->save_live_iterate(f, se->opaque); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); > > if (ret < 0) { > qemu_file_set_error(f, ret); > @@ -565,13 +567,13 @@ void qemu_savevm_state_complete(QEMUFile *f) > continue; > } > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_END); > qemu_put_be32(f, se->section_id); > > ret = se->ops->save_live_complete(f, se->opaque); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); > if (ret < 0) { > qemu_file_set_error(f, ret); > return; > @@ -584,7 +586,7 @@ void qemu_savevm_state_complete(QEMUFile *f) > if ((!se->ops || !se->ops->save_state) && !se->vmsd) { > continue; > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_FULL); > qemu_put_be32(f, se->section_id); > @@ -598,7 +600,7 @@ void qemu_savevm_state_complete(QEMUFile *f) > qemu_put_be32(f, se->version_id); > > vmstate_save(f, se); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); > } > > qemu_put_byte(f, QEMU_VM_EOF); > diff --git a/trace-events b/trace-events > index 3713063..525636c 100644 > --- a/trace-events > +++ b/trace-events > @@ -1030,8 +1030,11 @@ vmware_scratch_write(uint32_t index, uint32_t value) "index %d, value 0x%x" > vmware_setmode(uint32_t w, uint32_t h, uint32_t bpp) "%dx%d @ %d bpp" > > # savevm.c > -savevm_section_start(void) "" > -savevm_section_end(unsigned int section_id) "section_id %u" > +savevm_section_start(const char *id, unsigned int section_id) "%s, section_id %u" > +savevm_section_end(const char *id, unsigned int section_id) "%s, section_id %u" > +vmstate_save(const char *idstr, const char *vmsd_name) "%s, %s" > +vmstate_load(const char *idstr, const char *vmsd_name) "%s, %s" > +vmstate_load_field_error(const char *field, int ret) "field \"%s\" load failed, ret = %d" > > # arch_init.c > migration_bitmap_sync_start(void) "" > @@ -1164,6 +1167,9 @@ virtio_ccw_new_device(int cssid, int ssid, int schid, int devno, const char *dev > > # migration.c > migrate_set_state(int new_state) "new state %d" > +migrate_event(const char *str) "%s" > +migrate_pending(uint64_t size, uint64_t max) "pending size %" PRIu64 " max %" PRIu64 > +migrate_transferred(uint64_t tranferred, uint64_t time_spent, double bandwidth, uint64_t size) "transferred %" PRIu64 " time_spent %" PRIu64 " bandwidth %g max_size %" PRId64 > > # kvm-all.c > kvm_ioctl(int type, void *arg) "type 0x%x, arg %p" > diff --git a/vmstate.c b/vmstate.c > index d1f5eb0..b689f2f 100644 > --- a/vmstate.c > +++ b/vmstate.c > @@ -3,6 +3,7 @@ > #include "migration/qemu-file.h" > #include "migration/vmstate.h" > #include "qemu/bitops.h" > +#include "trace.h" > > static void vmstate_subsection_save(QEMUFile *f, const VMStateDescription *vmsd, > void *opaque); > @@ -73,6 +74,7 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd, > > } > if (ret < 0) { > + trace_vmstate_load_field_error(field->name, ret); > return ret; > } > } > -- > 1.8.4.rc4 > >
Good idea, but I dislike the generic trace_migrate_event tracepoint. Better add separate generic tracepoints, for example: > @@ -111,7 +101,7 @@ static void process_incoming_migration_co(void *opaque) > exit(EXIT_FAILURE); > } > qemu_announce_self(); > - DPRINTF("successfully loaded vm state\n"); > + trace_migrate_event("successfully loaded vm state"); qemu_fclose, qemu_announce_self_iter > > bdrv_clear_incoming_migration_all(); > /* Make sure all file formats flush their mutable metadata */ > @@ -300,7 +290,7 @@ static void migrate_fd_cleanup(void *opaque) > s->cleanup_bh = NULL; > > if (s->file) { > - DPRINTF("closing file\n"); > + trace_migrate_event("closing file"); migrate_fd_cleanup > qemu_mutex_unlock_iothread(); > qemu_thread_join(&s->thread); > qemu_mutex_lock_iothread(); > @@ -323,7 +313,7 @@ static void migrate_fd_cleanup(void *opaque) > > void migrate_fd_error(MigrationState *s) > { > - DPRINTF("setting error state\n"); > + trace_migrate_event("setting error state"); migrate_fd_error > assert(s->file == NULL); > s->state = MIG_STATE_ERROR; > trace_migrate_set_state(MIG_STATE_ERROR); > @@ -333,7 +323,7 @@ void migrate_fd_error(MigrationState *s) > static void migrate_fd_cancel(MigrationState *s) > { > int old_state ; > - DPRINTF("cancelling migration\n"); > + trace_migrate_event("cancelling migration"); migrate_fd_cancel > do { > old_state = s->state; > @@ -608,29 +598,28 @@ static void *migration_thread(void *opaque) > int64_t start_time = initial_time; > bool old_vm_running = false; > > - DPRINTF("beginning savevm\n"); > + trace_migrate_event("beginning savevm"); > qemu_savevm_state_begin(s->file, &s->params); qemu_savevm_state_begin/iterate/complete/cancel > > s->setup_time = qemu_clock_get_ms(QEMU_CLOCK_HOST) - setup_start; > migrate_set_state(s, MIG_STATE_SETUP, MIG_STATE_ACTIVE); > > - DPRINTF("setup complete\n"); > + trace_migrate_event("setup complete"); migrate_set_state > while (s->state == MIG_STATE_ACTIVE) { > int64_t current_time; > uint64_t pending_size; > > if (!qemu_file_rate_limit(s->file)) { > - DPRINTF("iterate\n"); > + trace_migrate_event("iterate"); Not needed. > pending_size = qemu_savevm_state_pending(s->file, max_size); > - DPRINTF("pending size %" PRIu64 " max %" PRIu64 "\n", > - pending_size, max_size); > + trace_migrate_pending(pending_size, max_size); Ack. > if (pending_size && pending_size >= max_size) { > qemu_savevm_state_iterate(s->file); See above. > } else { > int ret; > > - DPRINTF("done iterating\n"); > + trace_migrate_event("done iterating"); savevm_state_complete and, probably in a separate patch, qemu_system_wakeup_request. > qemu_mutex_lock_iothread(); > start_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); > qemu_system_wakeup_request(QEMU_WAKEUP_REASON_OTHER); > @@ -669,9 +658,8 @@ static void *migration_thread(void *opaque) > s->mbps = time_spent ? (((double) transferred_bytes * 8.0) / > ((double) time_spent / 1000.0)) / 1000.0 / 1000.0 : -1; > > - DPRINTF("transferred %" PRIu64 " time_spent %" PRIu64 > - " bandwidth %g max_size %" PRId64 "\n", > - transferred_bytes, time_spent, bandwidth, max_size); > + trace_migrate_transferred(transferred_bytes, time_spent, > + bandwidth, max_size); Ack. > /* if we haven't sent anything, we don't want to recalculate > 10000 is a small enough number for our purposes */ > if (s->dirty_bytes_rate && transferred_bytes > 10000) { > diff --git a/savevm.c b/savevm.c > index 7329fc5..8e15b7e 100644 > --- a/savevm.c > +++ b/savevm.c > @@ -429,6 +429,7 @@ void vmstate_unregister(DeviceState *dev, const VMStateDescription *vmsd, > > static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) > { > + trace_vmstate_load(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); Ack. > if (!se->vmsd) { /* Old style */ > return se->ops->load_state(f, se->opaque, version_id); > } > @@ -437,6 +438,7 @@ static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) > > static void vmstate_save(QEMUFile *f, SaveStateEntry *se) > { > + trace_vmstate_save(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); Ack. > if (!se->vmsd) { /* Old style */ > se->ops->save_state(f, se->opaque); > return; > @@ -527,13 +529,13 @@ int qemu_savevm_state_iterate(QEMUFile *f) > if (qemu_file_rate_limit(f)) { > return 0; > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); Ack, but modifying existing tracepoints should be a separate patch. > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_PART); > qemu_put_be32(f, se->section_id); > > ret = se->ops->save_live_iterate(f, se->opaque); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); Ack. > if (ret < 0) { > qemu_file_set_error(f, ret); > @@ -565,13 +567,13 @@ void qemu_savevm_state_complete(QEMUFile *f) > continue; > } > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_END); > qemu_put_be32(f, se->section_id); > > ret = se->ops->save_live_complete(f, se->opaque); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); > if (ret < 0) { > qemu_file_set_error(f, ret); > return; > @@ -584,7 +586,7 @@ void qemu_savevm_state_complete(QEMUFile *f) > if ((!se->ops || !se->ops->save_state) && !se->vmsd) { > continue; > } > - trace_savevm_section_start(); > + trace_savevm_section_start(se->idstr, se->section_id); > /* Section type */ > qemu_put_byte(f, QEMU_VM_SECTION_FULL); > qemu_put_be32(f, se->section_id); > @@ -598,7 +600,7 @@ void qemu_savevm_state_complete(QEMUFile *f) > qemu_put_be32(f, se->version_id); > > vmstate_save(f, se); > - trace_savevm_section_end(se->section_id); > + trace_savevm_section_end(se->idstr, se->section_id); > } > > qemu_put_byte(f, QEMU_VM_EOF); > diff --git a/trace-events b/trace-events > index 3713063..525636c 100644 > --- a/trace-events > +++ b/trace-events > @@ -1030,8 +1030,11 @@ vmware_scratch_write(uint32_t index, uint32_t value) "index %d, value 0x%x" > vmware_setmode(uint32_t w, uint32_t h, uint32_t bpp) "%dx%d @ %d bpp" > > # savevm.c > -savevm_section_start(void) "" > -savevm_section_end(unsigned int section_id) "section_id %u" > +savevm_section_start(const char *id, unsigned int section_id) "%s, section_id %u" > +savevm_section_end(const char *id, unsigned int section_id) "%s, section_id %u" > +vmstate_save(const char *idstr, const char *vmsd_name) "%s, %s" > +vmstate_load(const char *idstr, const char *vmsd_name) "%s, %s" > +vmstate_load_field_error(const char *field, int ret) "field \"%s\" load failed, ret = %d" > > # arch_init.c > migration_bitmap_sync_start(void) "" > @@ -1164,6 +1167,9 @@ virtio_ccw_new_device(int cssid, int ssid, int schid, int devno, const char *dev > > # migration.c > migrate_set_state(int new_state) "new state %d" > +migrate_event(const char *str) "%s" > +migrate_pending(uint64_t size, uint64_t max) "pending size %" PRIu64 " max %" PRIu64 > +migrate_transferred(uint64_t tranferred, uint64_t time_spent, double bandwidth, uint64_t size) "transferred %" PRIu64 " time_spent %" PRIu64 " bandwidth %g max_size %" PRId64 > > # kvm-all.c > kvm_ioctl(int type, void *arg) "type 0x%x, arg %p" > diff --git a/vmstate.c b/vmstate.c > index d1f5eb0..b689f2f 100644 > --- a/vmstate.c > +++ b/vmstate.c > @@ -3,6 +3,7 @@ > #include "migration/qemu-file.h" > #include "migration/vmstate.h" > #include "qemu/bitops.h" > +#include "trace.h" > > static void vmstate_subsection_save(QEMUFile *f, const VMStateDescription *vmsd, > void *opaque); > @@ -73,6 +74,7 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd, > > } > if (ret < 0) { > + trace_vmstate_load_field_error(field->name, ret); Ack. > return ret; > } > } >
diff --git a/migration.c b/migration.c index 742dd5c..5455d2a 100644 --- a/migration.c +++ b/migration.c @@ -26,16 +26,6 @@ #include "qmp-commands.h" #include "trace.h" -//#define DEBUG_MIGRATION - -#ifdef DEBUG_MIGRATION -#define DPRINTF(fmt, ...) \ - do { printf("migration: " fmt, ## __VA_ARGS__); } while (0) -#else -#define DPRINTF(fmt, ...) \ - do { } while (0) -#endif - enum { MIG_STATE_ERROR = -1, MIG_STATE_NONE, @@ -111,7 +101,7 @@ static void process_incoming_migration_co(void *opaque) exit(EXIT_FAILURE); } qemu_announce_self(); - DPRINTF("successfully loaded vm state\n"); + trace_migrate_event("successfully loaded vm state"); bdrv_clear_incoming_migration_all(); /* Make sure all file formats flush their mutable metadata */ @@ -300,7 +290,7 @@ static void migrate_fd_cleanup(void *opaque) s->cleanup_bh = NULL; if (s->file) { - DPRINTF("closing file\n"); + trace_migrate_event("closing file"); qemu_mutex_unlock_iothread(); qemu_thread_join(&s->thread); qemu_mutex_lock_iothread(); @@ -323,7 +313,7 @@ static void migrate_fd_cleanup(void *opaque) void migrate_fd_error(MigrationState *s) { - DPRINTF("setting error state\n"); + trace_migrate_event("setting error state"); assert(s->file == NULL); s->state = MIG_STATE_ERROR; trace_migrate_set_state(MIG_STATE_ERROR); @@ -333,7 +323,7 @@ void migrate_fd_error(MigrationState *s) static void migrate_fd_cancel(MigrationState *s) { int old_state ; - DPRINTF("cancelling migration\n"); + trace_migrate_event("cancelling migration"); do { old_state = s->state; @@ -608,29 +598,28 @@ static void *migration_thread(void *opaque) int64_t start_time = initial_time; bool old_vm_running = false; - DPRINTF("beginning savevm\n"); + trace_migrate_event("beginning savevm"); qemu_savevm_state_begin(s->file, &s->params); s->setup_time = qemu_clock_get_ms(QEMU_CLOCK_HOST) - setup_start; migrate_set_state(s, MIG_STATE_SETUP, MIG_STATE_ACTIVE); - DPRINTF("setup complete\n"); + trace_migrate_event("setup complete"); while (s->state == MIG_STATE_ACTIVE) { int64_t current_time; uint64_t pending_size; if (!qemu_file_rate_limit(s->file)) { - DPRINTF("iterate\n"); + trace_migrate_event("iterate"); pending_size = qemu_savevm_state_pending(s->file, max_size); - DPRINTF("pending size %" PRIu64 " max %" PRIu64 "\n", - pending_size, max_size); + trace_migrate_pending(pending_size, max_size); if (pending_size && pending_size >= max_size) { qemu_savevm_state_iterate(s->file); } else { int ret; - DPRINTF("done iterating\n"); + trace_migrate_event("done iterating"); qemu_mutex_lock_iothread(); start_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME); qemu_system_wakeup_request(QEMU_WAKEUP_REASON_OTHER); @@ -669,9 +658,8 @@ static void *migration_thread(void *opaque) s->mbps = time_spent ? (((double) transferred_bytes * 8.0) / ((double) time_spent / 1000.0)) / 1000.0 / 1000.0 : -1; - DPRINTF("transferred %" PRIu64 " time_spent %" PRIu64 - " bandwidth %g max_size %" PRId64 "\n", - transferred_bytes, time_spent, bandwidth, max_size); + trace_migrate_transferred(transferred_bytes, time_spent, + bandwidth, max_size); /* if we haven't sent anything, we don't want to recalculate 10000 is a small enough number for our purposes */ if (s->dirty_bytes_rate && transferred_bytes > 10000) { diff --git a/savevm.c b/savevm.c index 7329fc5..8e15b7e 100644 --- a/savevm.c +++ b/savevm.c @@ -429,6 +429,7 @@ void vmstate_unregister(DeviceState *dev, const VMStateDescription *vmsd, static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) { + trace_vmstate_load(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); if (!se->vmsd) { /* Old style */ return se->ops->load_state(f, se->opaque, version_id); } @@ -437,6 +438,7 @@ static int vmstate_load(QEMUFile *f, SaveStateEntry *se, int version_id) static void vmstate_save(QEMUFile *f, SaveStateEntry *se) { + trace_vmstate_save(se->idstr, se->vmsd ? se->vmsd->name : "(old)"); if (!se->vmsd) { /* Old style */ se->ops->save_state(f, se->opaque); return; @@ -527,13 +529,13 @@ int qemu_savevm_state_iterate(QEMUFile *f) if (qemu_file_rate_limit(f)) { return 0; } - trace_savevm_section_start(); + trace_savevm_section_start(se->idstr, se->section_id); /* Section type */ qemu_put_byte(f, QEMU_VM_SECTION_PART); qemu_put_be32(f, se->section_id); ret = se->ops->save_live_iterate(f, se->opaque); - trace_savevm_section_end(se->section_id); + trace_savevm_section_end(se->idstr, se->section_id); if (ret < 0) { qemu_file_set_error(f, ret); @@ -565,13 +567,13 @@ void qemu_savevm_state_complete(QEMUFile *f) continue; } } - trace_savevm_section_start(); + trace_savevm_section_start(se->idstr, se->section_id); /* Section type */ qemu_put_byte(f, QEMU_VM_SECTION_END); qemu_put_be32(f, se->section_id); ret = se->ops->save_live_complete(f, se->opaque); - trace_savevm_section_end(se->section_id); + trace_savevm_section_end(se->idstr, se->section_id); if (ret < 0) { qemu_file_set_error(f, ret); return; @@ -584,7 +586,7 @@ void qemu_savevm_state_complete(QEMUFile *f) if ((!se->ops || !se->ops->save_state) && !se->vmsd) { continue; } - trace_savevm_section_start(); + trace_savevm_section_start(se->idstr, se->section_id); /* Section type */ qemu_put_byte(f, QEMU_VM_SECTION_FULL); qemu_put_be32(f, se->section_id); @@ -598,7 +600,7 @@ void qemu_savevm_state_complete(QEMUFile *f) qemu_put_be32(f, se->version_id); vmstate_save(f, se); - trace_savevm_section_end(se->section_id); + trace_savevm_section_end(se->idstr, se->section_id); } qemu_put_byte(f, QEMU_VM_EOF); diff --git a/trace-events b/trace-events index 3713063..525636c 100644 --- a/trace-events +++ b/trace-events @@ -1030,8 +1030,11 @@ vmware_scratch_write(uint32_t index, uint32_t value) "index %d, value 0x%x" vmware_setmode(uint32_t w, uint32_t h, uint32_t bpp) "%dx%d @ %d bpp" # savevm.c -savevm_section_start(void) "" -savevm_section_end(unsigned int section_id) "section_id %u" +savevm_section_start(const char *id, unsigned int section_id) "%s, section_id %u" +savevm_section_end(const char *id, unsigned int section_id) "%s, section_id %u" +vmstate_save(const char *idstr, const char *vmsd_name) "%s, %s" +vmstate_load(const char *idstr, const char *vmsd_name) "%s, %s" +vmstate_load_field_error(const char *field, int ret) "field \"%s\" load failed, ret = %d" # arch_init.c migration_bitmap_sync_start(void) "" @@ -1164,6 +1167,9 @@ virtio_ccw_new_device(int cssid, int ssid, int schid, int devno, const char *dev # migration.c migrate_set_state(int new_state) "new state %d" +migrate_event(const char *str) "%s" +migrate_pending(uint64_t size, uint64_t max) "pending size %" PRIu64 " max %" PRIu64 +migrate_transferred(uint64_t tranferred, uint64_t time_spent, double bandwidth, uint64_t size) "transferred %" PRIu64 " time_spent %" PRIu64 " bandwidth %g max_size %" PRId64 # kvm-all.c kvm_ioctl(int type, void *arg) "type 0x%x, arg %p" diff --git a/vmstate.c b/vmstate.c index d1f5eb0..b689f2f 100644 --- a/vmstate.c +++ b/vmstate.c @@ -3,6 +3,7 @@ #include "migration/qemu-file.h" #include "migration/vmstate.h" #include "qemu/bitops.h" +#include "trace.h" static void vmstate_subsection_save(QEMUFile *f, const VMStateDescription *vmsd, void *opaque); @@ -73,6 +74,7 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd, } if (ret < 0) { + trace_vmstate_load_field_error(field->name, ret); return ret; } }
This adds more traces in the migration code. Signed-off-by: Alexey Kardashevskiy <aik@ozlabs.ru> --- Debugging migration lately a lot and this patch helps quite a lot. Would it make any use for anyone else? Thanks. --- migration.c | 34 +++++++++++----------------------- savevm.c | 14 ++++++++------ trace-events | 10 ++++++++-- vmstate.c | 2 ++ 4 files changed, 29 insertions(+), 31 deletions(-)