From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([208.118.235.92]:42258) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TxESl-0006HT-2z for qemu-devel@nongnu.org; Mon, 21 Jan 2013 05:18:48 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1TxESi-0003iE-7j for qemu-devel@nongnu.org; Mon, 21 Jan 2013 05:18:47 -0500 Received: from mx1.redhat.com ([209.132.183.28]:49202) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TxESi-0003hM-0Q for qemu-devel@nongnu.org; Mon, 21 Jan 2013 05:18:44 -0500 Received: from int-mx02.intmail.prod.int.phx2.redhat.com (int-mx02.intmail.prod.int.phx2.redhat.com [10.5.11.12]) by mx1.redhat.com (8.14.4/8.14.4) with ESMTP id r0LAIhEQ028200 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK) for ; Mon, 21 Jan 2013 05:18:43 -0500 Message-ID: <50FD164C.1070504@redhat.com> Date: Mon, 21 Jan 2013 12:19:56 +0200 From: Orit Wasserman MIME-Version: 1.0 References: <1358510033-17268-1-git-send-email-quintela@redhat.com> <1358510033-17268-5-git-send-email-quintela@redhat.com> In-Reply-To: <1358510033-17268-5-git-send-email-quintela@redhat.com> Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] [PATCH 4/4] migration: print times for end phase List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Juan Quintela Cc: qemu-devel@nongnu.org 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 > --- > 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); >