From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:33516) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X20Lx-0000hi-Qz for qemu-devel@nongnu.org; Tue, 01 Jul 2014 11:52:22 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1X20Lq-0001YU-E3 for qemu-devel@nongnu.org; Tue, 01 Jul 2014 11:52:17 -0400 Received: from zimbra3.corp.accelance.fr ([2001:4080:204::2:8]:40331) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X20Lq-0001Wo-4B for qemu-devel@nongnu.org; Tue, 01 Jul 2014 11:52:10 -0400 Date: Tue, 1 Jul 2014 17:52:03 +0200 (CEST) From: Sebastian Tanase Message-ID: <626925856.19196069.1404229922934.JavaMail.root@openwide.fr> In-Reply-To: <53B19A4D.1070203@redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Subject: Re: [Qemu-devel] [RFC PATCH V3 5/6] cpu_exec: Print to console if the guest is late List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Paolo Bonzini Cc: kwolf@redhat.com, peter maydell , aliguori@amazon.com, wenchaoqemu@gmail.com, quintela@redhat.com, qemu-devel@nongnu.org, mjt@tls.msk.ru, mst@redhat.com, stefanha@redhat.com, armbru@redhat.com, lcapitulino@redhat.com, michael@walle.cc, alex@alex.org.uk, crobinso@redhat.com, afaerber@suse.de, rth@twiddle.net ----- Mail original ----- > De: "Paolo Bonzini" > =C3=80: "Sebastian Tanase" , qemu-devel@non= gnu.org > Cc: aliguori@amazon.com, afaerber@suse.de, rth@twiddle.net, "peter maydel= l" , > michael@walle.cc, alex@alex.org.uk, stefanha@redhat.com, lcapitulino@redh= at.com, crobinso@redhat.com, > armbru@redhat.com, wenchaoqemu@gmail.com, quintela@redhat.com, kwolf@redh= at.com, mjt@tls.msk.ru, mst@redhat.com > Envoy=C3=A9: Lundi 30 Juin 2014 19:11:41 > Objet: Re: [RFC PATCH V3 5/6] cpu_exec: Print to console if the guest is = late >=20 > Il 30/06/2014 15:59, Sebastian Tanase ha scritto: > > 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=C3=A9gu=C3=A9 > > --- > > 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; > > +}; >=20 > I think these structs can be unified. >=20 > > #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 =3D -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 =3D qemu_clock_get_ns(QEMU_CLOCK_REALTIME); > > virtual_clock_value =3D qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL); > > if (clocks_offset =3D=3D -1) { > > clocks_offset =3D realtime_clock_value - > > virtual_clock_value; > > @@ -105,6 +124,47 @@ static void init_delay_params(SyncClocks *sc, > > sc->diff_clk =3D virtual_clock_value - realtime_clock_value + > > clocks_offset; > > sc->original_instr_counter =3D 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 > > + >=3D MAX_DELAY_PRINT_RATE && indl->nb_prints < > > MAX_NB_PRINTS) { > > + if (-diff_clk / (float)1000000000LL > threshold_delay) { > > + threshold_delay =3D (-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 =3D (-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 =3D indl->realtime_clock; > > + } > > +} > > + > > +static void init_inform(InformDelay *indl, int64_t > > realtime_clock_value) > > +{ > > + if (!icount_align_option) { > > + return; > > + } > > + indl->realtime_clock =3D realtime_clock_value; > > +} > > + > > +static void compute_value_of_rtc(int64_t *realtime_clock_value) > > +{ > > + if (!icount_align_option) { > > + return; > > + } > > + *realtime_clock_value =3D > > 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 =3D { > > .init_delay =3D init_delay_params, > > .perform_align =3D align_clocks > > }; > > + /* Print delay control */ > > + static InformDelay inform_delay =3D { > > + .init_inform_delay =3D init_inform, > > + .perform_print =3D print_delay > > + }; > > /* This must be volatile so it is not trashed by longjmp() */ > > volatile bool have_tb_lock =3D false; > > > > @@ -384,11 +462,19 @@ int cpu_exec(CPUArchState *env) > > #endif > > cpu->exception_index =3D -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); >=20 > Can this (and compute_clocks_offset) all remain part of > init_delay_params? >=20 > > /* 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); >=20 > This, too. >=20 > Paolo >=20 Unifying the 2 structs will certainly make this possible. Sebastian > > + > > /* prepare setjmp context for exception handling */ > > for(;;) { > > if (sigsetjmp(cpu->jmp_env, 0) =3D=3D 0) { > > >=20 >=20 >=20