| Message ID | 20220307070401.171986-3-marcandre.lureau@redhat.com |
|---|---|
| State | Handled Elsewhere |
| Headers | show |
| Series | Remove qemu_gettimeofday() | expand |
On 07/03/2022 08.03, marcandre.lureau@redhat.com wrote: > 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. [...] > @@ -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; The new timestamp here is quite unuseful now, of course ... could you replace it with g_get_current_time() instead? Thomas
Hi On Mon, Mar 7, 2022 at 11:46 AM Thomas Huth <thuth@redhat.com> wrote: > On 07/03/2022 08.03, marcandre.lureau@redhat.com wrote: > > 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. > [...] > > @@ -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; > > The new timestamp here is quite unuseful now, of course ... could you > replace it with g_get_current_time() instead? > Eventually, but I wonder why this (and only this) particular timestamp should be the current time.
On 07/03/2022 09.05, Marc-André Lureau wrote: > Hi > > On Mon, Mar 7, 2022 at 11:46 AM Thomas Huth <thuth@redhat.com > <mailto:thuth@redhat.com>> wrote: > > On 07/03/2022 08.03, marcandre.lureau@redhat.com > <mailto:marcandre.lureau@redhat.com> wrote: > > From: Marc-André Lureau <marcandre.lureau@redhat.com > <mailto: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. > [...] > > @@ -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; > > The new timestamp here is quite unuseful now, of course ... could you > replace it with g_get_current_time() instead? > > > Eventually, but I wonder why this (and only this) particular timestamp > should be the current time. I assume it was meant as a possibility to sync the times in this log with other things that are going on on the host system in parallel. If you only have the relative time stamps in the log here, you cannot compare the events to other logs anymore. (having said that, I wonder why it doesn't simply always use the current wall time and uses the relative time instead, but maybe there is also a reason for that...) Thomas
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;