This is for debugging?
Why not trace events?
Regards,
Orit
On 01/18/2013 01:53 PM, Juan Quintela wrote:
> Signed-off-by: Juan Quintela <quint...@redhat.com>
> ---
> block.c | 6 ++++++
> cpus.c | 17 +++++++++++++++++
> migration.c | 13 +++++++++++++
> savevm.c | 13 +++++++++++++
> 4 files changed, 49 insertions(+)
>
> diff --git a/block.c b/block.c
> index 6fa7c90..c121db3 100644
> --- a/block.c
> +++ b/block.c
> @@ -2693,9 +2693,15 @@ int bdrv_get_flags(BlockDriverState *bs)
> void bdrv_flush_all(void)
> {
> BlockDriverState *bs;
> + int64_t start_time, end_time;
> +
> + start_time = qemu_get_clock_ms(rt_clock);
>
> QTAILQ_FOREACH(bs, &bdrv_states, list) {
> bdrv_flush(bs);
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time flush device %s: %ld\n", bs->filename,
> + end_time - start_time);
> }
> }
>
> diff --git a/cpus.c b/cpus.c
> index a4390c3..15534ba 100644
> --- a/cpus.c
> +++ b/cpus.c
> @@ -439,14 +439,31 @@ bool cpu_is_stopped(CPUState *cpu)
>
> static void do_vm_stop(RunState state)
> {
> + int64_t start_time, end_time;
> +
> if (runstate_is_running()) {
> + start_time = qemu_get_clock_ms(rt_clock);
> cpu_disable_ticks();
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time cpu_disable_ticks %ld\n", end_time - start_time);
> pause_all_vcpus();
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time pause_all_vcpus %ld\n", end_time - start_time);
> runstate_set(state);
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time runstate_set %ld\n", end_time - start_time);
> vm_state_notify(0, state);
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time vmstate_notify %ld\n", end_time - start_time);
> bdrv_drain_all();
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time bdrv_drain_all %ld\n", end_time - start_time);
> bdrv_flush_all();
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time bdrv_flush_all %ld\n", end_time - start_time);
> monitor_protocol_event(QEVENT_STOP, NULL);
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("time monitor_protocol_event %ld\n", end_time - start_time);
> }
> }
>
> diff --git a/migration.c b/migration.c
> index de665f7..5e965cc 100644
> --- a/migration.c
> +++ b/migration.c
> @@ -712,12 +712,17 @@ static void *buffered_file_thread(void *opaque)
> DPRINTF("done iterating\n");
> start_time = qemu_get_clock_ms(rt_clock);
> qemu_system_wakeup_request(QEMU_WAKEUP_REASON_OTHER);
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("wakeup_request %ld\n", end_time - start_time);
> if (old_vm_running) {
> vm_stop(RUN_STATE_FINISH_MIGRATE);
> } else {
> vm_stop_force_state(RUN_STATE_FINISH_MIGRATE);
> }
>
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("vm_stop %ld\n", end_time - start_time);
> +
> /* 8 is the size of an end of section mark, so empty section
> */
> while ((ret = qemu_savevm_state_iterate(s->file, free_space))
> > 8) {
> @@ -728,15 +733,21 @@ static void *buffered_file_thread(void *opaque)
> }
> free_space = s->buffer_capacity - s->buffer_size;
> }
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("iterate phase %ld\n", end_time - start_time);
>
> ret = qemu_savevm_state_complete(s->file);
> if (ret < 0) {
> qemu_mutex_unlock_iothread();
> break;
> } else {
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("complete without error 3a %ld\n",
> + end_time - start_time);
> migrate_fd_completed(s);
> }
> end_time = qemu_get_clock_ms(rt_clock);
> + printf("completed %ld\n", end_time - start_time);
> s->total_time = end_time - s->total_time;
> s->downtime = end_time - start_time;
> if (s->state != MIG_STATE_COMPLETED) {
> @@ -744,6 +755,8 @@ static void *buffered_file_thread(void *opaque)
> vm_start();
> }
> }
> + end_time = qemu_get_clock_ms(rt_clock);
> + printf("end completed stage %ld\n", end_time - start_time);
> last_round = true;
> }
> }
> diff --git a/savevm.c b/savevm.c
> index 3447f91..113c1dd 100644
> --- a/savevm.c
> +++ b/savevm.c
> @@ -1660,9 +1660,14 @@ int qemu_savevm_state_complete(QEMUFile *f)
> {
> SaveStateEntry *se;
> int ret;
> + int64_t t1;
> + int64_t t0 = qemu_get_clock_ms(rt_clock);
>
> cpu_synchronize_all_states();
> + t1 = qemu_get_clock_ms(rt_clock);
> + printf("synchronize_all_states %ld\n", t1 - t0);
>
> + t0 = t1;
> QTAILQ_FOREACH(se, &savevm_handlers, entry) {
> if (!se->ops || !se->ops->save_live_complete) {
> continue;
> @@ -1683,6 +1688,11 @@ int qemu_savevm_state_complete(QEMUFile *f)
> return ret;
> }
> }
> + t1 = qemu_get_clock_ms(rt_clock);
> +
> + printf("migrate save live complete %ld\n", t1 - t0);
> +
> + t0 = t1;
>
> QTAILQ_FOREACH(se, &savevm_handlers, entry) {
> int len;
> @@ -1707,6 +1717,9 @@ int qemu_savevm_state_complete(QEMUFile *f)
> trace_savevm_section_end(se->section_id);
> }
>
> + t1 = qemu_get_clock_ms(rt_clock);
> +
> + printf("migrate rest devices %ld\n", t1 - t0);
> qemu_put_byte(f, QEMU_VM_EOF);
>
> return qemu_file_get_error(f);
>
