From patchwork Mon Jun 30 13:59:08 2014 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Sebastian Tanase X-Patchwork-Id: 365632 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from lists.gnu.org (lists.gnu.org [IPv6:2001:4830:134:3::11]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 482EE1400EE for ; Tue, 1 Jul 2014 00:00:22 +1000 (EST) Received: from localhost ([::1]:34541 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X1c84-0000ja-9D for incoming@patchwork.ozlabs.org; Mon, 30 Jun 2014 10:00:20 -0400 Received: from eggs.gnu.org ([2001:4830:134:3::10]:33794) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X1c7L-0007oq-Tv for qemu-devel@nongnu.org; Mon, 30 Jun 2014 09:59:41 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1X1c7E-0006Pp-IH for qemu-devel@nongnu.org; Mon, 30 Jun 2014 09:59:35 -0400 Received: from zimbra3.corp.accelance.fr ([2001:4080:204::2:8]:46889) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X1c7E-0006Pc-7b for qemu-devel@nongnu.org; Mon, 30 Jun 2014 09:59:28 -0400 Received: from localhost (localhost [127.0.0.1]) by zimbra3.corp.accelance.fr (Postfix) with ESMTP id 8A3BF72C58; Mon, 30 Jun 2014 15:59:27 +0200 (CEST) X-Virus-Scanned: amavisd-new at zimbra3.corp.accelance.fr Received: from zimbra3.corp.accelance.fr ([127.0.0.1]) by localhost (zimbra3.corp.accelance.fr [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id zgWqiPBbah75; Mon, 30 Jun 2014 15:59:23 +0200 (CEST) Received: from debian-seb.daviel.openwide.fr. (unknown [193.56.60.160]) by zimbra3.corp.accelance.fr (Postfix) with ESMTPSA id 4CF8B72C5E; Mon, 30 Jun 2014 15:59:20 +0200 (CEST) From: Sebastian Tanase To: qemu-devel@nongnu.org Date: Mon, 30 Jun 2014 15:59:08 +0200 Message-Id: <1404136749-523-6-git-send-email-sebastian.tanase@openwide.fr> X-Mailer: git-send-email 2.0.0.rc2 In-Reply-To: <1404136749-523-1-git-send-email-sebastian.tanase@openwide.fr> References: <1404136749-523-1-git-send-email-sebastian.tanase@openwide.fr> MIME-Version: 1.0 X-detected-operating-system: by eggs.gnu.org: Error: Malformed IPv6 address (bad octet value). X-Received-From: 2001:4080:204::2:8 Cc: kwolf@redhat.com, peter.maydell@linaro.org, alex@alex.org.uk, wenchaoqemu@gmail.com, quintela@redhat.com, mjt@tls.msk.ru, mst@redhat.com, stefanha@redhat.com, armbru@redhat.com, lcapitulino@redhat.com, michael@walle.cc, aliguori@amazon.com, crobinso@redhat.com, pbonzini@redhat.com, Sebastian Tanase , afaerber@suse.de, rth@twiddle.net Subject: [Qemu-devel] [RFC PATCH V3 5/6] cpu_exec: Print to console if the guest is late X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Sender: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org If the align option is enabled, we print to the user whenever the guest clock is behind the host clock in order for he/she to have a hint about the actual performance. The maximum print interval is 2s and we limit the number of messages to 100. If desired, this can be changed in cpu-exec.c Signed-off-by: Sebastian Tanase Tested-by: Camille Bégué --- cpu-exec.c | 94 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 90 insertions(+), 4 deletions(-) diff --git a/cpu-exec.c b/cpu-exec.c index ac741b7..4a4533d 100644 --- a/cpu-exec.c +++ b/cpu-exec.c @@ -24,12 +24,21 @@ #include "sysemu/qtest.h" #include "qemu/timer.h" -/* Structs and function pointers for delaying the host */ +/* Structs and function pointers for delaying the host + and printing the clock difference between the guest + and the host. */ typedef struct SyncClocks SyncClocks; +typedef struct InformDelay InformDelay; typedef void (*init_delay_func)(SyncClocks *sc, + int64_t realtime_clock_value, const CPUState *cpu); typedef void (*perform_align_func)(SyncClocks *sc, const CPUState *cpu); +typedef void (*init_inform_delay_func)(InformDelay *indl, + int64_t realtime_clock_value); +typedef void (*perform_print_func)(InformDelay *indl, + int64_t diff_clk); + struct SyncClocks { int64_t diff_clk; int64_t original_instr_counter; @@ -37,12 +46,22 @@ struct SyncClocks { perform_align_func perform_align; }; +struct InformDelay { + int64_t realtime_clock; + unsigned int nb_prints; + init_inform_delay_func init_inform_delay; + perform_print_func perform_print; +}; + #if !defined(CONFIG_USER_ONLY) /* Allow the guest to have a max 3ms advance. * The difference between the 2 clocks could therefore * oscillate around 0. */ #define VM_CLOCK_ADVANCE 3000000 +#define THRESHOLD_REDUCE 1.5 +#define MAX_DELAY_PRINT_RATE 2 +#define MAX_NB_PRINTS 100 static int64_t delay_host(int64_t diff_clk) { @@ -82,10 +101,11 @@ static void align_clocks(SyncClocks *sc, const CPUState *cpu) } static void init_delay_params(SyncClocks *sc, + int64_t realtime_clock_value, const CPUState *cpu) { static int64_t clocks_offset = -1; - int64_t realtime_clock_value, virtual_clock_value; + int64_t virtual_clock_value; if (!icount_align_option) { return; } @@ -97,7 +117,6 @@ static void init_delay_params(SyncClocks *sc, Therefore we impose that the first time we run the cpu the host and virtual clocks should be aligned; we don't alter any of the clocks, we just calculate the difference between them. */ - realtime_clock_value = qemu_clock_get_ns(QEMU_CLOCK_REALTIME); virtual_clock_value = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL); if (clocks_offset == -1) { clocks_offset = realtime_clock_value - virtual_clock_value; @@ -105,6 +124,47 @@ static void init_delay_params(SyncClocks *sc, sc->diff_clk = virtual_clock_value - realtime_clock_value + clocks_offset; sc->original_instr_counter = cpu->icount_extra + cpu->icount_decr.u16.low; } +static void print_delay(InformDelay *indl, int64_t diff_clk) +{ + static float threshold_delay; + static int64_t last_realtime_clock; + if (icount_align_option && + (indl->realtime_clock - last_realtime_clock) / 1000000000LL + >= MAX_DELAY_PRINT_RATE && indl->nb_prints < MAX_NB_PRINTS) { + if (-diff_clk / (float)1000000000LL > threshold_delay) { + threshold_delay = (-diff_clk / 1000000000LL) + 1; + printf("Warning: The guest is late by %.1f to %.1f seconds\n", + threshold_delay - 1, + threshold_delay); + indl->nb_prints++; + } else if (-diff_clk / (float)1000000000LL < + (threshold_delay - THRESHOLD_REDUCE)) { + threshold_delay = (-diff_clk / 1000000000LL) + 1; + printf("Warning: The guest has reduced the delay and is now " + "late by %.1f to %.1f seconds\n", + threshold_delay - 1, + threshold_delay); + indl->nb_prints++; + } + last_realtime_clock = indl->realtime_clock; + } +} + +static void init_inform(InformDelay *indl, int64_t realtime_clock_value) +{ + if (!icount_align_option) { + return; + } + indl->realtime_clock = realtime_clock_value; +} + +static void compute_value_of_rtc(int64_t *realtime_clock_value) +{ + if (!icount_align_option) { + return; + } + *realtime_clock_value = qemu_clock_get_ns(QEMU_CLOCK_REALTIME); +} #else /* We don't use the align feature for User emulation thus we add empty functions which shall be ignored @@ -114,9 +174,21 @@ static void align_clocks(SyncClocks *sc, const CPUState *cpu) } static void init_delay_params(SyncClocks *sc, + int64_t realtime_clock_value, const CPUState *cpu) { } +static void print_delay(InformDelay *indl, int64_t diff_clk) +{ +} + +static void init_inform(InformDelay *indl, int64_t realtime_clock_value) +{ +} + +static void compute_value_of_rtc(int64_t *realtime_clock_value) +{ +} #endif /* CONFIG USER ONLY */ void cpu_loop_exit(CPUState *cpu) @@ -324,10 +396,16 @@ int cpu_exec(CPUArchState *env) uint8_t *tc_ptr; uintptr_t next_tb; /* Delay algorithm */ + int64_t realtime_clock_value; static SyncClocks sc = { .init_delay = init_delay_params, .perform_align = align_clocks }; + /* Print delay control */ + static InformDelay inform_delay = { + .init_inform_delay = init_inform, + .perform_print = print_delay + }; /* This must be volatile so it is not trashed by longjmp() */ volatile bool have_tb_lock = false; @@ -384,11 +462,19 @@ int cpu_exec(CPUArchState *env) #endif cpu->exception_index = -1; + /* Calculating the realtime is expensive so we do it once here + and then pass this value around. */ + compute_value_of_rtc(&realtime_clock_value); /* Calculate difference between guest clock and host clock. This delay includes the delay of the last cycle, so what we have to do is sleep until it is 0. As for the advance/delay we gain here, we try to fix it next time. */ - sc.init_delay(&sc, cpu); + inform_delay.init_inform_delay(&inform_delay, realtime_clock_value); + sc.init_delay(&sc, realtime_clock_value, cpu); + /* Print every 2s max if the guest is late. We limit the number + of printed messages to NB_PRINT_MAX(currently 100) */ + inform_delay.perform_print(&inform_delay, sc.diff_clk); + /* prepare setjmp context for exception handling */ for(;;) { if (sigsetjmp(cpu->jmp_env, 0) == 0) {