diff mbox series

[2/4] qtest: replace gettimeofday with GTimer

Message ID 20220304152704.3466036-3-marcandre.lureau@redhat.com
State Superseded
Headers show
Series RFC: remove qemu_gettimeofday() | expand

Commit Message

Marc-André Lureau March 4, 2022, 3:27 p.m. UTC
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(-)

Comments

Laurent Vivier March 4, 2022, 3:54 p.m. UTC | #1
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;
Laurent Vivier March 4, 2022, 3:55 p.m. UTC | #2
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>
diff mbox series

Patch

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;