From: Marc-André Lureau <marcandre.lureau@redhat.com>
glib provides a convenience helper to measure elapsed time. It isn't
subject to wall-clock time changes.
Note that this changes the initial OPENED time, which used to print the
current time.
Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
---
softmmu/qtest.c | 39 ++++++++++-----------------------------
1 file changed, 10 insertions(+), 29 deletions(-)
diff --git a/softmmu/qtest.c b/softmmu/qtest.c
index 8b7cb6aa8e46..b2bb7777d17d 100644
--- a/softmmu/qtest.c
+++ b/softmmu/qtest.c
@@ -58,12 +58,12 @@ static FILE *qtest_log_fp;
static QTest *qtest;
static GString *inbuf;
static int irq_levels[MAX_IRQ];
-static qemu_timeval start_time;
+static GTimer *timer;
static bool qtest_opened;
static void (*qtest_server_send)(void*, const char*);
static void *qtest_server_send_opaque;
-#define FMT_timeval "%ld.%06ld"
+#define FMT_timeval "%.06f"
/**
* DOC: QTest Protocol
@@ -264,28 +264,13 @@ static int hex2nib(char ch)
}
}
-static void qtest_get_time(qemu_timeval *tv)
-{
- qemu_gettimeofday(tv);
- tv->tv_sec -= start_time.tv_sec;
- tv->tv_usec -= start_time.tv_usec;
- if (tv->tv_usec < 0) {
- tv->tv_usec += 1000000;
- tv->tv_sec -= 1;
- }
-}
-
static void qtest_send_prefix(CharBackend *chr)
{
- qemu_timeval tv;
-
if (!qtest_log_fp || !qtest_opened) {
return;
}
- qtest_get_time(&tv);
- fprintf(qtest_log_fp, "[S +" FMT_timeval "] ",
- (long) tv.tv_sec, (long) tv.tv_usec);
+ fprintf(qtest_log_fp, "[S +" FMT_timeval "] ", g_timer_elapsed(timer, NULL));
}
static void GCC_FMT_ATTR(1, 2) qtest_log_send(const char *fmt, ...)
@@ -386,12 +371,9 @@ static void qtest_process_command(CharBackend *chr, gchar **words)
command = words[0];
if (qtest_log_fp) {
- qemu_timeval tv;
int i;
- qtest_get_time(&tv);
- fprintf(qtest_log_fp, "[R +" FMT_timeval "]",
- (long) tv.tv_sec, (long) tv.tv_usec);
+ fprintf(qtest_log_fp, "[R +" FMT_timeval "]", g_timer_elapsed(timer, NULL));
for (i = 0; words[i]; i++) {
fprintf(qtest_log_fp, " %s", words[i]);
}
@@ -846,21 +828,20 @@ static void qtest_event(void *opaque, QEMUChrEvent event)
for (i = 0; i < ARRAY_SIZE(irq_levels); i++) {
irq_levels[i] = 0;
}
- qemu_gettimeofday(&start_time);
+
+ g_clear_pointer(&timer, g_timer_destroy);
+ timer = g_timer_new();
qtest_opened = true;
if (qtest_log_fp) {
- fprintf(qtest_log_fp, "[I " FMT_timeval "] OPENED\n",
- (long) start_time.tv_sec, (long) start_time.tv_usec);
+ fprintf(qtest_log_fp, "[I " FMT_timeval "] OPENED\n", g_timer_elapsed(timer, NULL));
}
break;
case CHR_EVENT_CLOSED:
qtest_opened = false;
if (qtest_log_fp) {
- qemu_timeval tv;
- qtest_get_time(&tv);
- fprintf(qtest_log_fp, "[I +" FMT_timeval "] CLOSED\n",
- (long) tv.tv_sec, (long) tv.tv_usec);
+ fprintf(qtest_log_fp, "[I +" FMT_timeval "] CLOSED\n", g_timer_elapsed(timer, NULL));
}
+ g_clear_pointer(&timer, g_timer_destroy);
break;
default:
break;
--
2.35.1.273.ge6ebfd0e8cbb
On 3/4/22 05:27, marcandre.lureau@redhat.com wrote:
> + g_clear_pointer(&timer, g_timer_destroy);
> + timer = g_timer_new();
Why not g_timer_{reset,start}, instead of destroying and recreating?
r~
Hi Richard
On Sat, Mar 5, 2022 at 12:50 AM Richard Henderson
<richard.henderson@linaro.org> wrote:
>
> On 3/4/22 05:27, marcandre.lureau@redhat.com wrote:
> > + g_clear_pointer(&timer, g_timer_destroy);
> > + timer = g_timer_new();
>
> Why not g_timer_{reset,start}, instead of destroying and recreating?
Well, that didn't seem much easier, as that opens the question where
to create/destroy. And we would potentially have a "running" timer at
creation time, which could be confusing.
(btw, just found that doc : "This function is useless; it's fine to
call g_timer_start() on an already-started timer to reset the start
time, so g_timer_reset() serves no purpose" ;)
thanks
Le 04/03/2022 à 16:27, marcandre.lureau@redhat.com a écrit :
> From: Marc-André Lureau <marcandre.lureau@redhat.com>
>
> glib provides a convenience helper to measure elapsed time. It isn't
> subject to wall-clock time changes.
>
> Note that this changes the initial OPENED time, which used to print the
> current time.
>
Time is printed using FMT_timeval ("%ld.%06ld"), but g_timer_elapsed() returns a gdouble.
Are you sure it works properly?
Laurent
> Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
> ---
> softmmu/qtest.c | 39 ++++++++++-----------------------------
> 1 file changed, 10 insertions(+), 29 deletions(-)
>
> diff --git a/softmmu/qtest.c b/softmmu/qtest.c
> index 8b7cb6aa8e46..b2bb7777d17d 100644
> --- a/softmmu/qtest.c
> +++ b/softmmu/qtest.c
> @@ -58,12 +58,12 @@ static FILE *qtest_log_fp;
> static QTest *qtest;
> static GString *inbuf;
> static int irq_levels[MAX_IRQ];
> -static qemu_timeval start_time;
> +static GTimer *timer;
> static bool qtest_opened;
> static void (*qtest_server_send)(void*, const char*);
> static void *qtest_server_send_opaque;
>
> -#define FMT_timeval "%ld.%06ld"
> +#define FMT_timeval "%.06f"
>
> /**
> * DOC: QTest Protocol
> @@ -264,28 +264,13 @@ static int hex2nib(char ch)
> }
> }
>
> -static void qtest_get_time(qemu_timeval *tv)
> -{
> - qemu_gettimeofday(tv);
> - tv->tv_sec -= start_time.tv_sec;
> - tv->tv_usec -= start_time.tv_usec;
> - if (tv->tv_usec < 0) {
> - tv->tv_usec += 1000000;
> - tv->tv_sec -= 1;
> - }
> -}
> -
> static void qtest_send_prefix(CharBackend *chr)
> {
> - qemu_timeval tv;
> -
> if (!qtest_log_fp || !qtest_opened) {
> return;
> }
>
> - qtest_get_time(&tv);
> - fprintf(qtest_log_fp, "[S +" FMT_timeval "] ",
> - (long) tv.tv_sec, (long) tv.tv_usec);
> + fprintf(qtest_log_fp, "[S +" FMT_timeval "] ", g_timer_elapsed(timer, NULL));
> }
>
> static void GCC_FMT_ATTR(1, 2) qtest_log_send(const char *fmt, ...)
> @@ -386,12 +371,9 @@ static void qtest_process_command(CharBackend *chr, gchar **words)
> command = words[0];
>
> if (qtest_log_fp) {
> - qemu_timeval tv;
> int i;
>
> - qtest_get_time(&tv);
> - fprintf(qtest_log_fp, "[R +" FMT_timeval "]",
> - (long) tv.tv_sec, (long) tv.tv_usec);
> + fprintf(qtest_log_fp, "[R +" FMT_timeval "]", g_timer_elapsed(timer, NULL));
> for (i = 0; words[i]; i++) {
> fprintf(qtest_log_fp, " %s", words[i]);
> }
> @@ -846,21 +828,20 @@ static void qtest_event(void *opaque, QEMUChrEvent event)
> for (i = 0; i < ARRAY_SIZE(irq_levels); i++) {
> irq_levels[i] = 0;
> }
> - qemu_gettimeofday(&start_time);
> +
> + g_clear_pointer(&timer, g_timer_destroy);
> + timer = g_timer_new();
> qtest_opened = true;
> if (qtest_log_fp) {
> - fprintf(qtest_log_fp, "[I " FMT_timeval "] OPENED\n",
> - (long) start_time.tv_sec, (long) start_time.tv_usec);
> + fprintf(qtest_log_fp, "[I " FMT_timeval "] OPENED\n", g_timer_elapsed(timer, NULL));
> }
> break;
> case CHR_EVENT_CLOSED:
> qtest_opened = false;
> if (qtest_log_fp) {
> - qemu_timeval tv;
> - qtest_get_time(&tv);
> - fprintf(qtest_log_fp, "[I +" FMT_timeval "] CLOSED\n",
> - (long) tv.tv_sec, (long) tv.tv_usec);
> + fprintf(qtest_log_fp, "[I +" FMT_timeval "] CLOSED\n", g_timer_elapsed(timer, NULL));
> }
> + g_clear_pointer(&timer, g_timer_destroy);
> break;
> default:
> break;
Le 04/03/2022 à 16:54, Laurent Vivier a écrit :
> Le 04/03/2022 à 16:27, marcandre.lureau@redhat.com a écrit :
>> From: Marc-André Lureau <marcandre.lureau@redhat.com>
>>
>> glib provides a convenience helper to measure elapsed time. It isn't
>> subject to wall-clock time changes.
>>
>> Note that this changes the initial OPENED time, which used to print the
>> current time.
>>
>
> Time is printed using FMT_timeval ("%ld.%06ld"), but g_timer_elapsed() returns a gdouble.
>
> Are you sure it works properly?
Sorry, I missed this part:
>> -#define FMT_timeval "%ld.%06ld"
>> +#define FMT_timeval "%.06f"
Reviewed-by: Laurent Vivier <laurent@vivier.eu>
© 2016 - 2026 Red Hat, Inc.