Add an option to disable printing the timestamp in the reply. This may help tests that want to compare the output between runs. It's not use by this series after all, it could be excluded.
Signed-off-by: Marc-André Lureau <[email protected]> --- qapi/qom.json | 5 ++- include/system/qtest.h | 3 +- system/qtest.c | 61 ++++++++++++++++++++++----- system/vl.c | 7 ++- qemu-options.hx | 1 + tests/qemu-iotests/iotests.py | 4 +- tests/qemu-iotests/tests/copy-before-write | 4 +- tests/qemu-iotests/tests/migrate-bitmaps-test | 4 +- 8 files changed, 70 insertions(+), 19 deletions(-) diff --git a/qapi/qom.json b/qapi/qom.json index dd45ac1087c..c7b6c64d157 100644 --- a/qapi/qom.json +++ b/qapi/qom.json @@ -834,11 +834,14 @@ # # @log: the path to a log file # +# @ts: if true, print timestamps in the log. Default true. +# # Since: 6.0 ## { 'struct': 'QtestProperties', 'data': { 'chardev': 'str', - '*log': 'str' } } + '*log': 'str', + '*ts': 'bool' } } ## # @RemoteObjectProperties: diff --git a/include/system/qtest.h b/include/system/qtest.h index 7f6dc01d147..2fa06409a84 100644 --- a/include/system/qtest.h +++ b/include/system/qtest.h @@ -27,7 +27,8 @@ void G_GNUC_PRINTF(2, 3) qtest_sendf(CharFrontend *chr, const char *fmt, ...); void qtest_set_command_cb(bool (*pc_cb)(CharFrontend *chr, gchar **words)); bool qtest_driver(void); -void qtest_server_init(const char *qtest_chrdev, const char *qtest_log, Error **errp); +void qtest_server_init(const char *qtest_chrdev, const char *qtest_log, + bool qtest_no_ts, Error **errp); void qtest_server_set_send_handler(void (*send)(void *, const char *), void *opaque); diff --git a/system/qtest.c b/system/qtest.c index a79d10d1361..1fb35ae36bc 100644 --- a/system/qtest.c +++ b/system/qtest.c @@ -42,6 +42,7 @@ struct QTest { Object parent; bool has_machine_link; + bool ts; char *chr_name; Chardev *chr; CharFrontend qtest_chr; @@ -57,6 +58,7 @@ static GString *inbuf; static int irq_levels[MAX_IRQ]; static GTimer *timer; static bool qtest_opened; +static bool qtest_ts = true; static void (*qtest_server_send)(void*, const char*); static void *qtest_server_send_opaque; @@ -270,13 +272,17 @@ static int hex2nib(char ch) } } -static void qtest_log_timestamp(void) +static void qtest_log_timestamp(const char c) { if (!qtest_log_fp || !qtest_opened) { return; } - fprintf(qtest_log_fp, "[S +" FMT_timeval "] ", g_timer_elapsed(timer, NULL)); + fprintf(qtest_log_fp, "[%c", c); + if (qtest_ts) { + fprintf(qtest_log_fp, " +" FMT_timeval, g_timer_elapsed(timer, NULL)); + } + fprintf(qtest_log_fp, "]"); } static void G_GNUC_PRINTF(1, 2) qtest_log_send(const char *fmt, ...) @@ -287,8 +293,8 @@ static void G_GNUC_PRINTF(1, 2) qtest_log_send(const char *fmt, ...) return; } - qtest_log_timestamp(); - + qtest_log_timestamp('S'); + fprintf(qtest_log_fp, " "); va_start(ap, fmt); vfprintf(qtest_log_fp, fmt, ap); va_end(ap); @@ -306,7 +312,10 @@ static void qtest_server_char_be_send(void *opaque, const char *str) static void qtest_send(CharFrontend *chr, const char *str) { - qtest_log_timestamp(); + if (qtest_log_fp) { + qtest_log_timestamp('S'); + fprintf(qtest_log_fp, " "); + } qtest_server_send(qtest_server_send_opaque, str); } @@ -364,7 +373,7 @@ static void qtest_process_command(CharFrontend *chr, gchar **words) if (qtest_log_fp) { int i; - fprintf(qtest_log_fp, "[R +" FMT_timeval "]", g_timer_elapsed(timer, NULL)); + qtest_log_timestamp('R'); for (i = 0; words[i]; i++) { fprintf(qtest_log_fp, " %s", words[i]); } @@ -812,7 +821,8 @@ static void qtest_event(void *opaque, QEMUChrEvent event) timer = g_timer_new(); qtest_opened = true; if (qtest_log_fp) { - fprintf(qtest_log_fp, "[I " FMT_timeval "] OPENED\n", g_timer_elapsed(timer, NULL)); + qtest_log_timestamp('I'); + fprintf(qtest_log_fp, " OPENED\n"); } break; case CHR_EVENT_CLOSED: @@ -820,10 +830,11 @@ static void qtest_event(void *opaque, QEMUChrEvent event) /* Ignore CLOSED events if we have already closed the log */ break; } - qtest_opened = false; if (qtest_log_fp) { - fprintf(qtest_log_fp, "[I +" FMT_timeval "] CLOSED\n", g_timer_elapsed(timer, NULL)); + qtest_log_timestamp('I'); + fprintf(qtest_log_fp, " CLOSED\n"); } + qtest_opened = false; g_clear_pointer(&timer, g_timer_destroy); break; default: @@ -831,7 +842,8 @@ static void qtest_event(void *opaque, QEMUChrEvent event) } } -void qtest_server_init(const char *qtest_chrdev, const char *qtest_log, Error **errp) +void qtest_server_init(const char *qtest_chrdev, const char *qtest_log, + bool no_ts, Error **errp) { ERRP_GUARD(); Chardev *chr; @@ -849,6 +861,9 @@ void qtest_server_init(const char *qtest_chrdev, const char *qtest_log, Error ** if (qtest_log) { object_property_set_str(qobj, "log", qtest_log, &error_abort); } + if (no_ts) { + object_property_set_bool(qobj, "ts", false, &error_abort); + } object_property_add_child(qdev_get_machine(), "qtest", qobj); user_creatable_complete(USER_CREATABLE(qobj), errp); if (*errp) { @@ -871,6 +886,8 @@ static bool qtest_server_start(QTest *q, Error **errp) qtest_log_fp = stderr; } + qtest_ts = q->ts; + if (!qemu_chr_fe_init(&q->qtest_chr, chr, errp)) { return false; } @@ -974,6 +991,20 @@ static char *qtest_get_log(Object *obj, Error **errp) return g_strdup(q->log); } +static bool qtest_get_ts(Object *obj, Error **errp) +{ + QTest *q = QTEST(obj); + + return q->ts; +} + +static void qtest_set_ts(Object *obj, bool value, Error **errp) +{ + QTest *q = QTEST(obj); + + q->ts = value; +} + static void qtest_set_chardev(Object *obj, const char *value, Error **errp) { QTest *q = QTEST(obj); @@ -1018,6 +1049,8 @@ static void qtest_class_init(ObjectClass *oc, const void *data) qtest_get_chardev, qtest_set_chardev); object_class_property_add_str(oc, "log", qtest_get_log, qtest_set_log); + object_class_property_add_bool(oc, "ts", + qtest_get_ts, qtest_set_ts); } static void qtest_finalize(Object *obj) @@ -1029,10 +1062,18 @@ static void qtest_finalize(Object *obj) object_unref(q->chr); } +static void qtest_init(Object *obj) +{ + QTest *q = QTEST(obj); + + q->ts = true; +} + static const TypeInfo qtest_info = { .name = TYPE_QTEST, .parent = TYPE_OBJECT, .class_init = qtest_class_init, + .instance_init = qtest_init, .instance_finalize = qtest_finalize, .instance_size = sizeof(QTest), .interfaces = (const InterfaceInfo[]) { diff --git a/system/vl.c b/system/vl.c index f4d55f0addd..4797700abd5 100644 --- a/system/vl.c +++ b/system/vl.c @@ -193,6 +193,7 @@ static const char *log_file; static bool list_data_dirs; static const char *qtest_chrdev; static const char *qtest_log; +static bool qtest_no_ts; static int has_defaults = 1; static int default_audio = 1; @@ -2092,7 +2093,8 @@ static bool object_create_late(const char *type) static void qemu_create_late_backends(void) { if (qtest_chrdev) { - qtest_server_init(qtest_chrdev, qtest_log, &error_fatal); + qtest_server_init(qtest_chrdev, qtest_log, qtest_no_ts, + &error_fatal); } net_init_clients(); @@ -3596,6 +3598,9 @@ void qemu_init(int argc, char **argv) case QEMU_OPTION_qtest_log: qtest_log = optarg; break; + case QEMU_OPTION_qtest_no_ts: + qtest_no_ts = true; + break; case QEMU_OPTION_sandbox: olist = qemu_find_opts("sandbox"); if (!olist) { diff --git a/qemu-options.hx b/qemu-options.hx index 96ae41f787b..4c1b32713e0 100644 --- a/qemu-options.hx +++ b/qemu-options.hx @@ -5584,6 +5584,7 @@ ERST HXCOMM Internal use DEF("qtest", HAS_ARG, QEMU_OPTION_qtest, "", QEMU_ARCH_ALL) DEF("qtest-log", HAS_ARG, QEMU_OPTION_qtest_log, "", QEMU_ARCH_ALL) +DEF("qtest-no-ts", 0, QEMU_OPTION_qtest_no_ts, "", QEMU_ARCH_ALL) #if defined(CONFIG_POSIX) && !defined(EMSCRIPTEN) DEF("run-with", HAS_ARG, QEMU_OPTION_run_with, diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py index 05274772ce4..5a4d843886d 100644 --- a/tests/qemu-iotests/iotests.py +++ b/tests/qemu-iotests/iotests.py @@ -712,8 +712,8 @@ def filter_nbd_exports(output: str) -> str: return re.sub(r'((min|opt|max) block): [0-9]+', r'\1: XXX', output) def filter_qtest(output: str) -> str: - output = re.sub(r'^\[I \d+\.\d+\] OPENED\n', '', output) - output = re.sub(r'\n?\[I \+\d+\.\d+\] CLOSED\n?$', '', output) + output = re.sub(r'^\[I \+?\d+\.\d+\] OPENED\n', '', output) + output = re.sub(r'\n?\[I \+?\d+\.\d+\] CLOSED\n?$', '', output) return output Msg = TypeVar('Msg', Dict[str, Any], List[Any], str) diff --git a/tests/qemu-iotests/tests/copy-before-write b/tests/qemu-iotests/tests/copy-before-write index 236cb8ac374..f86032b1167 100755 --- a/tests/qemu-iotests/tests/copy-before-write +++ b/tests/qemu-iotests/tests/copy-before-write @@ -273,8 +273,8 @@ read 1048576/1048576 bytes at offset 0 self.vm.shutdown() log = self.vm.get_log() - log = re.sub(r'^\[I \d+\.\d+\] OPENED\n', '', log) - log = re.sub(r'\[I \+\d+\.\d+\] CLOSED\n?$', '', log) + log = re.sub(r'^\[I \+?\d+\.\d+\] OPENED\n', '', log) + log = re.sub(r'\[I \+?\d+\.\d+\] CLOSED\n?$', '', log) log = iotests.filter_qemu_io(log) return log diff --git a/tests/qemu-iotests/tests/migrate-bitmaps-test b/tests/qemu-iotests/tests/migrate-bitmaps-test index 8fb4099201d..eec110757a6 100755 --- a/tests/qemu-iotests/tests/migrate-bitmaps-test +++ b/tests/qemu-iotests/tests/migrate-bitmaps-test @@ -195,8 +195,8 @@ class TestDirtyBitmapMigration(iotests.QMPTestCase): # catch 'Could not reopen qcow2 layer: Bitmap already exists' # possible error log = self.vm_b.get_log() - log = re.sub(r'^\[I \d+\.\d+\] OPENED\n', '', log) - log = re.sub(r'\[I \+\d+\.\d+\] CLOSED\n?$', '', log) + log = re.sub(r'^\[I \+?\d+\.\d+\] OPENED\n', '', log) + log = re.sub(r'\[I \+?\d+\.\d+\] CLOSED\n?$', '', log) self.assertEqual(log, '') # recreate vm_b, as we don't want -incoming option (this will lead -- 2.54.0
