From nobody Fri Nov 7 08:54:58 2025 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (209.51.188.17 [209.51.188.17]) by mx.zohomail.com with SMTPS id 1547832819341976.0137835920082; Fri, 18 Jan 2019 09:33:39 -0800 (PST) Received: from localhost ([127.0.0.1]:44366 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkY1F-0003t4-IX for importer@patchew.org; Fri, 18 Jan 2019 12:33:25 -0500 Received: from eggs.gnu.org ([209.51.188.92]:58365) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkXzR-0002vD-Hy for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:34 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gkXzQ-0003Y5-E8 for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:33 -0500 Received: from mx1.redhat.com ([209.132.183.28]:55835) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gkXzQ-0003EF-29 for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:32 -0500 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id B421DB947 for ; Fri, 18 Jan 2019 17:31:17 +0000 (UTC) Received: from localhost.localdomain.com (unknown [10.42.22.189]) by smtp.corp.redhat.com (Postfix) with ESMTP id AF6E15D964; Fri, 18 Jan 2019 17:31:16 +0000 (UTC) From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= To: qemu-devel@nongnu.org Date: Fri, 18 Jan 2019 17:31:00 +0000 Message-Id: <20190118173103.4903-2-berrange@redhat.com> In-Reply-To: <20190118173103.4903-1-berrange@redhat.com> References: <20190118173103.4903-1-berrange@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.39]); Fri, 18 Jan 2019 17:31:17 +0000 (UTC) Content-Transfer-Encoding: quoted-printable X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 1/4] display: ensure qxl log_buf is a nul terminated string X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Alex Williamson , Gerd Hoffmann , Stefan Hajnoczi Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Type: text/plain; charset="utf-8" The QXL_IO_LOG command allows the guest to send log messages to the host via a buffer in the QXLRam struct. QEMU prints these to the console if the qxl 'guestdebug' option is set to non-zero. It will also feed them to the trace subsystem if any backends are built-in. In both cases the log_buf data will get treated as being as a nul terminated string, by the printf '%s' format specifier and / or other code reading the buffer. QEMU does nothing to guarantee that the log_buf really is nul terminated, so there is potential for out of bounds array access. This would affect any QEMU which has the log, syslog or ftrace trace backends built into QEMU. It can only be triggered if the 'qxl_io_log' trace event is enabled, however, so they are not vulnerable without specific administrative action to enable this. It would also affect QEMU if the 'guestdebug' parameter is set to a non-zero value, which again is not the default and requires explicit admin opt-in. Signed-off-by: Daniel P. Berrang=C3=A9 Reviewed-by: Eric Blake Reviewed-by: Gerd Hoffmann --- hw/display/qxl.c | 3 ++- hw/display/trace-events | 2 +- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/hw/display/qxl.c b/hw/display/qxl.c index 8e9a65e75b..eefdf4baac 100644 --- a/hw/display/qxl.c +++ b/hw/display/qxl.c @@ -1763,7 +1763,8 @@ async_common: qxl_set_mode(d, val, 0); break; case QXL_IO_LOG: - trace_qxl_io_log(d->id, d->ram->log_buf); + d->ram->log_buf[sizeof(d->ram->log_buf) - 1] =3D '\0'; + trace_qxl_io_log(d->id, (const char *)d->ram->log_buf); if (d->guestdebug) { fprintf(stderr, "qxl/guest-%d: %" PRId64 ": %s", d->id, qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL), d->ram->log_buf= ); diff --git a/hw/display/trace-events b/hw/display/trace-events index 5a48c6cb6a..387c6b8931 100644 --- a/hw/display/trace-events +++ b/hw/display/trace-events @@ -72,7 +72,7 @@ qxl_interface_update_area_complete_rest(int qid, uint32_t= num_updated_rects) "%d qxl_interface_update_area_complete_overflow(int qid, int max) "%d max=3D%d" qxl_interface_update_area_complete_schedule_bh(int qid, uint32_t num_dirty= ) "%d #dirty=3D%d" qxl_io_destroy_primary_ignored(int qid, const char *mode) "%d %s" -qxl_io_log(int qid, const uint8_t *log_buf) "%d %s" +qxl_io_log(int qid, const char *log_buf) "%d %s" qxl_io_read_unexpected(int qid) "%d" qxl_io_unexpected_vga_mode(int qid, uint64_t addr, uint64_t val, const cha= r *desc) "%d 0x%"PRIx64"=3D%"PRIu64" (%s)" qxl_io_write(int qid, const char *mode, uint64_t addr, const char *aname, = uint64_t val, unsigned size, int async) "%d %s addr=3D%"PRIu64 " (%s) val= =3D%"PRIu64" size=3D%u async=3D%d" --=20 2.20.1 From nobody Fri Nov 7 08:54:58 2025 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (209.51.188.17 [209.51.188.17]) by mx.zohomail.com with SMTPS id 1547832810354606.2078614127761; Fri, 18 Jan 2019 09:33:30 -0800 (PST) Received: from localhost ([127.0.0.1]:44364 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkY1D-0003sa-Mr for importer@patchew.org; Fri, 18 Jan 2019 12:33:23 -0500 Received: from eggs.gnu.org ([209.51.188.92]:58355) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkXzR-0002v8-3H for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:34 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gkXzQ-0003XX-5m for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:33 -0500 Received: from mx1.redhat.com ([209.132.183.28]:58740) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gkXzP-0003Ej-VD for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:32 -0500 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id ED8BA87642 for ; Fri, 18 Jan 2019 17:31:18 +0000 (UTC) Received: from localhost.localdomain.com (unknown [10.42.22.189]) by smtp.corp.redhat.com (Postfix) with ESMTP id E95785D964; Fri, 18 Jan 2019 17:31:17 +0000 (UTC) From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= To: qemu-devel@nongnu.org Date: Fri, 18 Jan 2019 17:31:01 +0000 Message-Id: <20190118173103.4903-3-berrange@redhat.com> In-Reply-To: <20190118173103.4903-1-berrange@redhat.com> References: <20190118173103.4903-1-berrange@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.26]); Fri, 18 Jan 2019 17:31:18 +0000 (UTC) Content-Transfer-Encoding: quoted-printable X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 2/4] trace: enforce that every trace-events file has a final newline X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Alex Williamson , Gerd Hoffmann , Stefan Hajnoczi Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Type: text/plain; charset="utf-8" When generating the trace-events-all file, the build system simply concatenates all the individual trace-events files. If any one of those files does not have a final newline, the printf format string will have the contents of the first line of the next file appended to it, which is usually a '#' comment. Signed-off-by: Daniel P. Berrang=C3=A9 Reviewed-by: Eric Blake Reviewed-by: Stefan Hajnoczi --- hw/gpio/trace-events | 2 +- scripts/tracetool/__init__.py | 2 ++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/hw/gpio/trace-events b/hw/gpio/trace-events index cb41a89756..5d4dd200c2 100644 --- a/hw/gpio/trace-events +++ b/hw/gpio/trace-events @@ -4,4 +4,4 @@ nrf51_gpio_read(uint64_t offset, uint64_t r) "offset 0x%" PRIx64 " value 0= x%" PRIx64 nrf51_gpio_write(uint64_t offset, uint64_t value) "offset 0x%" PRIx64 " va= lue 0x%" PRIx64 nrf51_gpio_set(int64_t line, int64_t value) "line %" PRIi64 " value %" PRI= i64 -nrf51_gpio_update_output_irq(int64_t line, int64_t value) "line %" PRIi64 = " value %" PRIi64 \ No newline at end of file +nrf51_gpio_update_output_irq(int64_t line, int64_t value) "line %" PRIi64 = " value %" PRIi64 diff --git a/scripts/tracetool/__init__.py b/scripts/tracetool/__init__.py index 0e3c9e146c..3478ac93ab 100644 --- a/scripts/tracetool/__init__.py +++ b/scripts/tracetool/__init__.py @@ -350,6 +350,8 @@ def read_events(fobj, fname): =20 events =3D [] for lineno, line in enumerate(fobj, 1): + if line[-1] !=3D '\n': + raise ValueError("%s does not end with a new line" % fname) if not line.strip(): continue if line.lstrip().startswith('#'): --=20 2.20.1 From nobody Fri Nov 7 08:54:58 2025 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) by mx.zohomail.com with SMTPS id 1547833128469484.4599121657243; Fri, 18 Jan 2019 09:38:48 -0800 (PST) Received: from localhost ([127.0.0.1]:44440 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkY6R-0000lw-G7 for importer@patchew.org; Fri, 18 Jan 2019 12:38:47 -0500 Received: from eggs.gnu.org ([209.51.188.92]:58370) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkXzR-0002vF-Kn for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:34 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gkXzQ-0003YC-FI for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:33 -0500 Received: from mx1.redhat.com ([209.132.183.28]:58764) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gkXzQ-0003Fs-2C for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:32 -0500 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 37E597E9E1 for ; Fri, 18 Jan 2019 17:31:20 +0000 (UTC) Received: from localhost.localdomain.com (unknown [10.42.22.189]) by smtp.corp.redhat.com (Postfix) with ESMTP id 30F5A5D964; Fri, 18 Jan 2019 17:31:19 +0000 (UTC) From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= To: qemu-devel@nongnu.org Date: Fri, 18 Jan 2019 17:31:02 +0000 Message-Id: <20190118173103.4903-4-berrange@redhat.com> In-Reply-To: <20190118173103.4903-1-berrange@redhat.com> References: <20190118173103.4903-1-berrange@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.26]); Fri, 18 Jan 2019 17:31:20 +0000 (UTC) Content-Transfer-Encoding: quoted-printable X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 3/4] trace: forbid use of %m in trace event format strings X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Alex Williamson , Gerd Hoffmann , Stefan Hajnoczi Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Type: text/plain; charset="utf-8" The '%m' format specifier instructs glibc's printf() implementation to insert the contents of strerror(errno). This is not something that should ever be used in trace-events files because several of the backends do not use the format string and so this error information is invisible to them. The errno value should be given as an explicit trace argument instead. Use of '%m' should also be avoided as it is not portable to all QEMU build targets. Signed-off-by: Daniel P. Berrang=C3=A9 --- hw/vfio/pci.c | 2 +- hw/vfio/trace-events | 2 +- scripts/tracetool/__init__.py | 4 ++++ 3 files changed, 6 insertions(+), 2 deletions(-) diff --git a/hw/vfio/pci.c b/hw/vfio/pci.c index c0cb1ec289..85f1908cfe 100644 --- a/hw/vfio/pci.c +++ b/hw/vfio/pci.c @@ -2581,7 +2581,7 @@ static void vfio_populate_device(VFIOPCIDevice *vdev,= Error **errp) ret =3D ioctl(vdev->vbasedev.fd, VFIO_DEVICE_GET_IRQ_INFO, &irq_info); if (ret) { /* This can fail for an old kernel or legacy PCI dev */ - trace_vfio_populate_device_get_irq_info_failure(); + trace_vfio_populate_device_get_irq_info_failure(errno); } else if (irq_info.count =3D=3D 1) { vdev->pci_aer =3D true; } else { diff --git a/hw/vfio/trace-events b/hw/vfio/trace-events index a85e8662ea..6d412afc83 100644 --- a/hw/vfio/trace-events +++ b/hw/vfio/trace-events @@ -37,7 +37,7 @@ vfio_pci_hot_reset_has_dep_devices(const char *name) "%s:= hot reset dependent de vfio_pci_hot_reset_dep_devices(int domain, int bus, int slot, int function= , int group_id) "\t%04x:%02x:%02x.%x group %d" vfio_pci_hot_reset_result(const char *name, const char *result) "%s hot re= set: %s" vfio_populate_device_config(const char *name, unsigned long size, unsigned= long offset, unsigned long flags) "Device %s config:\n size: 0x%lx, offse= t: 0x%lx, flags: 0x%lx" -vfio_populate_device_get_irq_info_failure(void) "VFIO_DEVICE_GET_IRQ_INFO = failure: %m" +vfio_populate_device_get_irq_info_failure(int err) "VFIO_DEVICE_GET_IRQ_IN= FO failure: %d" vfio_realize(const char *name, int group_id) " (%s) group %d" vfio_mdev(const char *name, bool is_mdev) " (%s) is_mdev %d" vfio_add_ext_cap_dropped(const char *name, uint16_t cap, uint16_t offset) = "%s 0x%x@0x%x" diff --git a/scripts/tracetool/__init__.py b/scripts/tracetool/__init__.py index 3478ac93ab..6fca674936 100644 --- a/scripts/tracetool/__init__.py +++ b/scripts/tracetool/__init__.py @@ -274,6 +274,10 @@ class Event(object): props =3D groups["props"].split() fmt =3D groups["fmt"] fmt_trans =3D groups["fmt_trans"] + if fmt.find("%m") !=3D -1 or fmt_trans.find("%m") !=3D -1: + raise ValueError("Event format '%m' is forbidden, pass the err= or " + "as an explicit trace argument") + if len(fmt_trans) > 0: fmt =3D [fmt_trans, fmt] args =3D Arguments.build(groups["args"]) --=20 2.20.1 From nobody Fri Nov 7 08:54:58 2025 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (209.51.188.17 [209.51.188.17]) by mx.zohomail.com with SMTPS id 1547832819418537.1428436984882; Fri, 18 Jan 2019 09:33:39 -0800 (PST) Received: from localhost ([127.0.0.1]:44368 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkY1I-0003wO-Ui for importer@patchew.org; Fri, 18 Jan 2019 12:33:29 -0500 Received: from eggs.gnu.org ([209.51.188.92]:58402) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gkXzT-0002vX-0K for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:37 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gkXzQ-0003YK-GU for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:34 -0500 Received: from mx1.redhat.com ([209.132.183.28]:34362) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gkXzQ-0003HK-4D for qemu-devel@nongnu.org; Fri, 18 Jan 2019 12:31:32 -0500 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 8D40DC05093A for ; Fri, 18 Jan 2019 17:31:21 +0000 (UTC) Received: from localhost.localdomain.com (unknown [10.42.22.189]) by smtp.corp.redhat.com (Postfix) with ESMTP id 6CA535D964; Fri, 18 Jan 2019 17:31:20 +0000 (UTC) From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= To: qemu-devel@nongnu.org Date: Fri, 18 Jan 2019 17:31:03 +0000 Message-Id: <20190118173103.4903-5-berrange@redhat.com> In-Reply-To: <20190118173103.4903-1-berrange@redhat.com> References: <20190118173103.4903-1-berrange@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.31]); Fri, 18 Jan 2019 17:31:21 +0000 (UTC) Content-Transfer-Encoding: quoted-printable X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 4/4] trace: add ability to do simple printf logging via systemtap X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Alex Williamson , Gerd Hoffmann , Stefan Hajnoczi Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Type: text/plain; charset="utf-8" The dtrace systemtap trace backend for QEMU is very powerful but it is also somewhat unfriendly to users who aren't familiar with systemtap, or who don't need its power right now. stap -e "....some strange script...." The 'log' backend for QEMU by comparison is very crude but incredibly easy to use: $ qemu -d trace:qio* ...some args... 23266@1547735759.137292:qio_channel_socket_new Socket new ioc=3D0x563a8a39= d400 23266@1547735759.137305:qio_task_new Task new task=3D0x563a891d0570 source= =3D0x563a8a39d400 func=3D0x563a86f1e6c0 opaque=3D0x563a89078000 23266@1547735759.137326:qio_task_thread_start Task thread start task=3D0x5= 63a891d0570 worker=3D0x563a86f1ce50 opaque=3D0x563a891d9d90 23273@1547735759.137491:qio_task_thread_run Task thread run task=3D0x563a8= 91d0570 23273@1547735759.137503:qio_channel_socket_connect_sync Socket connect syn= c ioc=3D0x563a8a39d400 addr=3D0x563a891d9d90 23273@1547735759.138108:qio_channel_socket_connect_fail Socket connect fai= l ioc=3D0x563a8a39d400 This commit introduces a way to do simple printf style logging of probe points using systemtap. In particular it creates another set of tapsets, one per emulator: /usr/share/systemtap/tapset/qemu-*-log.stp These pre-define probe functions which simply call printf() on their arguments. The printf() format string is taken from the normal trace-events files, with a little munging to the format specifiers to cope with systemtap's more restrictive syntax. With this you can now do $ stap -e 'probe qemu.system.x86_64.log.qio*{}' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=3D0x56135d= 1d7c00 22806@1547735341399862570 qio_task_new Task new task=3D0x56135cd66eb0 sour= ce=3D0x56135d1d7c00 func=3D0x56135af746c0 opaque=3D0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=3D0= x56135cd66eb0 worker=3D0x56135af72e50 opaque=3D0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=3D0x561= 35cd66eb0 We go one step further though and introduce a 'qemu-trace-stap' tool to make this even easier $ qemu-trace-stap run qemu-system-x86_64 qio* 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=3D0x56135d= 1d7c00 22806@1547735341399862570 qio_task_new Task new task=3D0x56135cd66eb0 sour= ce=3D0x56135d1d7c00 func=3D0x56135af746c0 opaque=3D0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=3D0= x56135cd66eb0 worker=3D0x56135af72e50 opaque=3D0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=3D0x561= 35cd66eb0 This tool is clever in that it will automatically change the SYSTEMTAP_TAPSET env variable to point to the directory containing the right set of probes for the QEMU binary path you give it. This is useful if you have QEMU installed in /usr but are trying to test and trace a binary in /home/berrange/usr/qemu-git. In that case you'd do $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 q= io* And it'll make sure /home/berrange/usr/qemu-git/share/systemtap/tapset is used for the trace session The 'qemu-trace-stap' script takes a verbose arg so you can understand what it is running $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 q= io* Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for = binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Compiling script 'probe qemu.system.x86_64.log.qio* {}' Running script, -c to quit ...trace output... It can enable multiple probes at once $ qemu-trace-stap run qemu-system-x86_64 qio* qcrypto* buffer* Finally if you can't remember what probes are valid it can tell you $ qemu-trace-stap list qemu-system-x86_64 ahci_check_irq ahci_cmd_done ahci_dma_prepare_buf ahci_dma_prepare_buf_fail ahci_dma_rw_buf ahci_irq_lower ...snip... Or list just those matching a prefix pattern $ qemu-trace-stap list -v qemu-system-x86_64 qio* Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for = binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Listing probes with name 'qemu.system.x86_64.log.qio*' qio_channel_command_abort qio_channel_command_new_pid qio_channel_command_new_spawn qio_channel_command_wait qio_channel_file_new_fd ...snip... Signed-off-by: Daniel P. Berrang=C3=A9 --- Makefile | 3 + Makefile.target | 11 +- docs/devel/tracing.txt | 32 +++++ scripts/qemu-trace-stap | 167 +++++++++++++++++++++++++++ scripts/tracetool/format/log_stap.py | 127 ++++++++++++++++++++ 5 files changed, 339 insertions(+), 1 deletion(-) create mode 100755 scripts/qemu-trace-stap create mode 100644 scripts/tracetool/format/log_stap.py diff --git a/Makefile b/Makefile index dccba1dca2..22e481e7ba 100644 --- a/Makefile +++ b/Makefile @@ -736,6 +736,9 @@ endif ifneq ($(HELPERS-y),) $(call install-prog,$(HELPERS-y),$(DESTDIR)$(libexecdir)) endif +ifdef CONFIG_TRACE_SYSTEMTAP + $(INSTALL_PROG) "scripts/qemu-trace-stap" $(DESTDIR)$(bindir) +endif ifneq ($(BLOBS),) set -e; for x in $(BLOBS); do \ $(INSTALL_DATA) $(SRC_PATH)/pc-bios/$$x "$(DESTDIR)$(qemu_datadir)"; \ diff --git a/Makefile.target b/Makefile.target index 39f72e81be..401dc1ea6f 100644 --- a/Makefile.target +++ b/Makefile.target @@ -45,7 +45,7 @@ config-target.h: config-target.h-timestamp config-target.h-timestamp: config-target.mak =20 ifdef CONFIG_TRACE_SYSTEMTAP -stap: $(QEMU_PROG).stp-installed $(QEMU_PROG).stp $(QEMU_PROG)-simpletrace= .stp +stap: $(QEMU_PROG).stp-installed $(QEMU_PROG).stp $(QEMU_PROG)-simpletrace= .stp $(QEMU_PROG)-log.stp =20 ifdef CONFIG_USER_ONLY TARGET_TYPE=3Duser @@ -84,6 +84,14 @@ $(QEMU_PROG)-simpletrace.stp: $(BUILD_DIR)/trace-events-= all $(tracetool-y) --probe-prefix=3Dqemu.$(TARGET_TYPE).$(TARGET_NAME) \ $< > $@,"GEN","$(TARGET_DIR)$(QEMU_PROG)-simpletrace.stp") =20 +$(QEMU_PROG)-log.stp: $(BUILD_DIR)/trace-events-all $(tracetool-y) + $(call quiet-command,$(TRACETOOL) \ + --group=3Dall \ + --format=3Dlog-stap \ + --backends=3D$(TRACE_BACKENDS) \ + --probe-prefix=3Dqemu.$(TARGET_TYPE).$(TARGET_NAME) \ + $< > $@,"GEN","$(TARGET_DIR)$(QEMU_PROG)-log.stp") + else stap: endif @@ -227,6 +235,7 @@ ifdef CONFIG_TRACE_SYSTEMTAP $(INSTALL_DIR) "$(DESTDIR)$(qemu_datadir)/../systemtap/tapset" $(INSTALL_DATA) $(QEMU_PROG).stp-installed "$(DESTDIR)$(qemu_datadir)/../= systemtap/tapset/$(QEMU_PROG).stp" $(INSTALL_DATA) $(QEMU_PROG)-simpletrace.stp "$(DESTDIR)$(qemu_datadir)/.= ./systemtap/tapset/$(QEMU_PROG)-simpletrace.stp" + $(INSTALL_DATA) $(QEMU_PROG)-log.stp "$(DESTDIR)$(qemu_datadir)/../system= tap/tapset/$(QEMU_PROG)-log.stp" endif =20 GENERATED_FILES +=3D config-target.h diff --git a/docs/devel/tracing.txt b/docs/devel/tracing.txt index bc52f12485..53327cd35b 100644 --- a/docs/devel/tracing.txt +++ b/docs/devel/tracing.txt @@ -317,6 +317,38 @@ probes: --target-name x86_64 \ qemu.stp =20 +To facilitate simple usage of systemtap where there merely needs to be pri= ntf +logging of certain probes, a helper script "qemu-trace-stap" is provided + +This can list all probes available for a given QEMU emulator binary: + + $ qemu-trace-stap list qemu-system-x86_64 + ahci_check_irq + ahci_cmd_done + ahci_dma_prepare_buf + ahci_dma_prepare_buf_fail + ahci_dma_rw_buf + ahci_irq_lower + ...snip... + +Optionally restricted to a pattern prefix: + + $ qemu-trace-stap list qemu-system-x86_64 qio* + qio_channel_command_abort + qio_channel_command_new_pid + qio_channel_command_new_spawn + qio_channel_command_wait + qio_channel_file_new_fd + ...snip... + +It can then run a simple systemtap script which prints each requested probe + + $ qemu-trace-stap run qemu-system-x86_64 qio* + 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=3D0x5= 6135d1d7c00 + 22806@1547735341399862570 qio_task_new Task new task=3D0x56135cd66eb0= source=3D0x56135d1d7c00 func=3D0x56135af746c0 opaque=3D0x56135bf06400 + 22806@1547735341399865943 qio_task_thread_start Task thread start tas= k=3D0x56135cd66eb0 worker=3D0x56135af72e50 opaque=3D0x56135c071d70 + 22806@1547735341399976816 qio_task_thread_run Task thread run task=3D= 0x56135cd66eb0 + =3D=3D Trace event properties =3D=3D =20 Each event in the "trace-events-all" file can be prefixed with a space-sep= arated diff --git a/scripts/qemu-trace-stap b/scripts/qemu-trace-stap new file mode 100755 index 0000000000..2db7b1470c --- /dev/null +++ b/scripts/qemu-trace-stap @@ -0,0 +1,167 @@ +#!/usr/bin/python +# -*- python -*- +# +# Copyright (C) 2019 Red Hat, Inc +# +# QEMU SystemTap Trace Tool +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; under version 2 of the License. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, see . + +from __future__ import print_function + +import argparse +import copy +import os.path +import re +import subprocess +import sys + + +def probe_prefix(binary): + dirname, filename =3D os.path.split(binary) + return re.sub("-", ".", filename) + ".log" + + +def which(binary): + for path in os.environ["PATH"].split(os.pathsep): + if os.path.exists(os.path.join(path, binary)): + return os.path.join(path, binary) + + print("Unable to find '%s' in $PATH" % binary) + sys.exit(1) + + +def tapset_dir(binary): + dirname, filename =3D os.path.split(binary) + if dirname =3D=3D '': + thisfile =3D which(binary) + else: + thisfile =3D os.path.realpath(binary) + if not os.path.exists(thisfile): + print("Unable to find '%s'" % thisfile) + sys.exit(1) + + basedir =3D os.path.split(thisfile)[0] + tapset =3D os.path.join(basedir, "..", "share", "systemtap", "tapset") + return os.path.realpath(tapset) + + +def tapset_env(tapset_dir): + tenv =3D copy.copy(os.environ) + tenv["SYSTEMTAP_TAPSET"] =3D tapset_dir + return tenv + +def cmd_run(args): + prefix =3D probe_prefix(args.binary) + tapsets =3D tapset_dir(args.binary) + + if args.verbose: + print("Using tapset dir '%s' for binary '%s'" % (tapsets, args.bin= ary)) + + probes =3D [] + for probe in args.probes: + probes.append("probe %s.%s {}" % (prefix, probe)) + if len(probes) =3D=3D 0: + probes.append("probe %s.* {}" % prefix) + + script =3D " ".join(probes) + if args.verbose: + print("Compiling script '%s'" % script) + script =3D """probe begin { print("Running script, -c to qui= t\\n") } """ + script + subprocess.call(["stap", "-e", script], + env=3Dtapset_env(tapsets)) + + +def cmd_list(args): + tapsets =3D tapset_dir(args.binary) + + if args.verbose: + print("Using tapset dir '%s' for binary '%s'" % (tapsets, args.bin= ary)) + + def print_probes(verbose, name): + prefix =3D probe_prefix(args.binary) + offset =3D len(prefix) + 1 + script =3D prefix + "." + name + + if verbose: + print("Listing probes with name '%s'" % script) + proc =3D subprocess.Popen(["stap", "-l", script], + stdout=3Dsubprocess.PIPE, env=3Dtapset_env= (tapsets)) + out, err =3D proc.communicate() + if proc.returncode !=3D 0: + print("No probes found, are the tapsets installed in %s" % tap= set_dir(args.binary)) + sys.exit(1) + + for line in out.splitlines(): + if line.startswith(prefix): + print("%s" % line[offset:]) + + if len(args.probes) =3D=3D 0: + print_probes(args.verbose, "*") + else: + for probe in args.probes: + print_probes(args.verbose, probe) + + +def main(): + parser =3D argparse.ArgumentParser(description=3D"QEMU SystemTap trace= tool") + + subparser =3D parser.add_subparsers(help=3D"commands") + subparser.required =3D True + subparser.dest =3D "command" + + runparser =3D subparser.add_parser("run", help=3D"Run a trace session", + formatter_class=3Dargparse.RawDescrip= tionHelpFormatter, + epilog=3D""" + +To watch all trace points on the qemu-system-x86_64 binary: + + %(argv0)s run qemu-system-x86_64 + +To only watch the trace points matching the qio* and qcrypto* patterns + + %(argv0)s run qemu-system-x86_64 qio* qcrypto* +""" % {"argv0": sys.argv[0]}) + runparser.set_defaults(func=3Dcmd_run) + runparser.add_argument("-v", "--verbose", help=3D"Print verbose progre= ss info", + action=3D'store_true') + runparser.add_argument("binary", help=3D"QEMU system or user emulator = binary") + runparser.add_argument("probes", help=3D"Probe names or wildcards", + nargs=3Dargparse.REMAINDER) + + listparser =3D subparser.add_parser("list", help=3D"List probe points", + formatter_class=3Dargparse.RawDescri= ptionHelpFormatter, + epilog=3D""" + +To list all trace points on the qemu-system-x86_64 binary: + + %(argv0)s list qemu-system-x86_64 + +To only list the trace points matching the qio* and qcrypto* patterns + + %(argv0)s list qemu-system-x86_64 qio* qcrypto* +""" % {"argv0": sys.argv[0]}) + listparser.set_defaults(func=3Dcmd_list) + listparser.add_argument("-v", "--verbose", help=3D"Print verbose progr= ess info", + action=3D'store_true') + listparser.add_argument("binary", help=3D"QEMU system or user emulator= binary") + listparser.add_argument("probes", help=3D"Probe names or wildcards", + nargs=3Dargparse.REMAINDER) + + args =3D parser.parse_args() + + args.func(args) + sys.exit(0) + +if __name__ =3D=3D '__main__': + main() diff --git a/scripts/tracetool/format/log_stap.py b/scripts/tracetool/forma= t/log_stap.py new file mode 100644 index 0000000000..3ccbc09d61 --- /dev/null +++ b/scripts/tracetool/format/log_stap.py @@ -0,0 +1,127 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- + +""" +Generate .stp file that printfs log messages (DTrace with SystemTAP only). +""" + +__author__ =3D "Daniel P. Berrange " +__copyright__ =3D "Copyright (C) 2014-2019, Red Hat, Inc." +__license__ =3D "GPL version 2 or (at your option) any later version" + +__maintainer__ =3D "Daniel Berrange" +__email__ =3D "berrange@redhat.com" + +import re + +from tracetool import out +from tracetool.backend.dtrace import binary, probeprefix +from tracetool.backend.simple import is_string +from tracetool.format.stap import stap_escape + +def global_var_name(name): + return probeprefix().replace(".", "_") + "_" + name + +STATE_SKIP =3D 0 +STATE_LITERAL =3D 1 +STATE_MACRO =3D 2 + +def c_macro_to_format(macro): + if macro.startswith("PRI"): + return macro[3] + + if macro =3D=3D "TARGET_FMT_plx": + return "%016x" + + raise Exception("Unhandled macro '%s'" % macro) + +def c_fmt_to_stap(fmt): + state =3D 0 + bits =3D [] + literal =3D "" + macro =3D "" + escape =3D 0; + for i in range(len(fmt)): + if fmt[i] =3D=3D '\\': + if escape: + escape =3D 0 + else: + escape =3D 1 + if state !=3D STATE_LITERAL: + raise Exception("Unexpected escape outside string literal") + literal =3D literal + fmt[i] + elif fmt[i] =3D=3D '"' and not escape: + if state =3D=3D STATE_LITERAL: + state =3D STATE_SKIP + bits.append(literal) + literal =3D "" + else: + if state =3D=3D STATE_MACRO: + bits.append(c_macro_to_format(macro)) + state =3D STATE_LITERAL + elif fmt[i] =3D=3D ' ' or fmt[i] =3D=3D '\t': + if state =3D=3D STATE_MACRO: + bits.append(c_macro_to_format(macro)) + macro =3D "" + state =3D STATE_SKIP + elif state =3D=3D STATE_LITERAL: + literal =3D literal + fmt[i] + else: + escape =3D 0 + if state =3D=3D STATE_SKIP: + state =3D STATE_MACRO + + if state =3D=3D STATE_LITERAL: + literal =3D literal + fmt[i] + else: + macro =3D macro + fmt[i] + + if state =3D=3D STATE_MACRO: + bits.append(c_macro_to_format(macro)) + elif state =3D=3D STATE_LITERAL: + bits.append(literal) + + fmt =3D re.sub("%(\d*)z(x|u|d)", "%\\1\\2", "".join(bits)) + return fmt + +def generate(events, backend, group): + out('/* This file is autogenerated by tracetool, do not edit. */', + '') + + for event_id, e in enumerate(events): + if 'disable' in e.properties: + continue + + out('probe %(probeprefix)s.log.%(name)s =3D %(probeprefix)s.%(name= )s ?', + '{', + probeprefix=3Dprobeprefix(), + name=3De.name) + + # Get references to userspace strings + for type_, name in e.args: + name =3D stap_escape(name) + if is_string(type_): + out(' try {', + ' arg%(name)s_str =3D %(name)s ? ' + + 'user_string_n(%(name)s, 512) : ""', + ' } catch {}', + name=3Dname) + + # Determine systemtap's view of variable names + fields =3D ["pid()", "gettimeofday_ns()"] + for type_, name in e.args: + name =3D stap_escape(name) + if is_string(type_): + fields.append("arg" + name + "_str") + else: + fields.append(name) + + # Emit the entire record in a single SystemTap printf() + arg_str =3D ', '.join(arg for arg in fields) + fmt_str =3D "%d@%d " + e.name + " " + c_fmt_to_stap(e.fmt) + "\\n" + out(' printf("%(fmt_str)s", %(arg_str)s)', + fmt_str=3Dfmt_str, arg_str=3Darg_str) + + out('}') + + out() --=20 2.20.1