Pull request

User-visible changes:
  * The new qemu-trace-stap script makes it convenient to collect traces without
    writing SystemTap scripts.  See "man qemu-trace-stap" for details.
 -----BEGIN PGP SIGNATURE-----
 
 iQEcBAABAgAGBQJcURdlAAoJEJykq7OBq3PIPqAH/iSkYDDeWLQy4eqeTPpbsxd4
 U6mUYC/m2g1bevj1TxdFmr2g5LReGTd4w35w6/SUaLMHsu701T7gK+0z1gP2/N/D
 qzJiM9xxF6xYq1P4hWJGf+XsbJ0OVf7oRwn1j8qXVBxjIxERX98z0ZUtbk/aulGi
 wnNXycBufpKGk2PkQC+pBfhU2775dMqpUV49z9mqyVzsiZQlzbx8WMDQj1Ic1fbe
 ZcAvX5D350HJjB3Z+9wJ1V2pC9Gu+z3TIup+YR1Bkch0ywyTCVTqcepoOXwzQamm
 84bifPdObBm7SbbwtrwoVKYLrdIrbb3PTWaOlWVUKruKIIf8hzn5BxC3wChb2Qk=
 =bex6
 -----END PGP SIGNATURE-----

Merge remote-tracking branch 'remotes/stefanha/tags/tracing-pull-request' into staging

Pull request

User-visible changes:
 * The new qemu-trace-stap script makes it convenient to collect traces without
   writing SystemTap scripts.  See "man qemu-trace-stap" for details.

# gpg: Signature made Wed 30 Jan 2019 03:17:57 GMT
# gpg:                using RSA key 9CA4ABB381AB73C8
# gpg: Good signature from "Stefan Hajnoczi <stefanha@redhat.com>" [full]
# gpg:                 aka "Stefan Hajnoczi <stefanha@gmail.com>" [full]
# Primary key fingerprint: 8695 A8BF D3F9 7CDA AC35  775A 9CA4 ABB3 81AB 73C8

* remotes/stefanha/tags/tracing-pull-request:
  trace: rerun tracetool after ./configure changes
  trace: improve runstate tracing
  trace: add ability to do simple printf logging via systemtap
  trace: forbid use of %m in trace event format strings
  trace: enforce that every trace-events file has a final newline
  display: ensure qxl log_buf is a nul terminated string

Signed-off-by: Peter Maydell <peter.maydell@linaro.org>

MAINTAINERS

@@ -2011,6 +2011,7 @@ F: trace-events
 F: qemu-option-trace.texi
 F: scripts/tracetool.py
 F: scripts/tracetool/
+F: scripts/qemu-trace-stap*
 F: docs/devel/tracing.txt
 T: git https://github.com/stefanha/qemu.git tracing
 

Makefile

@@ -145,7 +145,7 @@ tracetool-y += $(shell find $(SRC_PATH)/scripts/tracetool -name "*.py")
 
 %/trace.h: %/trace.h-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-%/trace.h-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y)
+%/trace.h-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=$(call trace-group-name,$@) \
 		--format=h \
@@ -154,7 +154,7 @@ tracetool-y += $(shell find $(SRC_PATH)/scripts/tracetool -name "*.py")
 
 %/trace.c: %/trace.c-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-%/trace.c-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y)
+%/trace.c-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=$(call trace-group-name,$@) \
 		--format=c \
@@ -163,7 +163,7 @@ tracetool-y += $(shell find $(SRC_PATH)/scripts/tracetool -name "*.py")
 
 %/trace-ust.h: %/trace-ust.h-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-%/trace-ust.h-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y)
+%/trace-ust.h-timestamp: $(SRC_PATH)/%/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=$(call trace-group-name,$@) \
 		--format=ust-events-h \
@@ -187,7 +187,7 @@ tracetool-y += $(shell find $(SRC_PATH)/scripts/tracetool -name "*.py")
 
 trace-root.h: trace-root.h-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-trace-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
+trace-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=root \
 		--format=h \
@@ -196,7 +196,7 @@ trace-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
 
 trace-root.c: trace-root.c-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-trace-root.c-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
+trace-root.c-timestamp: $(SRC_PATH)/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=root \
 		--format=c \
@@ -205,7 +205,7 @@ trace-root.c-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
 
 trace-ust-root.h: trace-ust-root.h-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-trace-ust-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
+trace-ust-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=root \
 		--format=ust-events-h \
@@ -214,7 +214,7 @@ trace-ust-root.h-timestamp: $(SRC_PATH)/trace-events $(tracetool-y)
 
 trace-ust-all.h: trace-ust-all.h-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-trace-ust-all.h-timestamp: $(trace-events-files) $(tracetool-y)
+trace-ust-all.h-timestamp: $(trace-events-files) $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=all \
 		--format=ust-events-h \
@@ -223,7 +223,7 @@ trace-ust-all.h-timestamp: $(trace-events-files) $(tracetool-y)
 
 trace-ust-all.c: trace-ust-all.c-timestamp
 	@cmp $< $@ >/dev/null 2>&1 || cp $< $@
-trace-ust-all.c-timestamp: $(trace-events-files) $(tracetool-y)
+trace-ust-all.c-timestamp: $(trace-events-files) $(tracetool-y) $(BUILD_DIR)/config-host.mak
 	$(call quiet-command,$(TRACETOOL) \
 		--group=all \
 		--format=ust-events-c \
@@ -305,6 +305,9 @@ DOCS+=docs/qemu-cpu-models.7
 ifdef CONFIG_VIRTFS
 DOCS+=fsdev/virtfs-proxy-helper.1
 endif
+ifdef CONFIG_TRACE_SYSTEMTAP
+DOCS+=scripts/qemu-trace-stap.1
+endif
 else
 DOCS=
 endif
@@ -699,6 +702,9 @@ ifneq ($(TOOLS),)
 	$(INSTALL_DIR) "$(DESTDIR)$(mandir)/man8"
 	$(INSTALL_DATA) qemu-nbd.8 "$(DESTDIR)$(mandir)/man8"
 endif
+ifdef CONFIG_TRACE_SYSTEMTAP
+	$(INSTALL_DATA) scripts/qemu-trace-stap.1 "$(DESTDIR)$(mandir)/man1"
+endif
 ifneq (,$(findstring qemu-ga,$(TOOLS)))
 	$(INSTALL_DATA) qemu-ga.8 "$(DESTDIR)$(mandir)/man8"
 	$(INSTALL_DATA) docs/interop/qemu-ga-ref.html "$(DESTDIR)$(qemu_docdir)"
@@ -738,6 +744,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)"; \
@@ -852,6 +861,7 @@ qemu-nbd.8: qemu-nbd.texi qemu-option-trace.texi
 qemu-ga.8: qemu-ga.texi
 docs/qemu-block-drivers.7: docs/qemu-block-drivers.texi
 docs/qemu-cpu-models.7: docs/qemu-cpu-models.texi
+scripts/qemu-trace-stap.1: scripts/qemu-trace-stap.texi
 
 html: qemu-doc.html docs/interop/qemu-qmp-ref.html docs/interop/qemu-ga-ref.html
 info: qemu-doc.info docs/interop/qemu-qmp-ref.info docs/interop/qemu-ga-ref.info

Makefile.target

@@ -45,7 +45,7 @@ config-target.h: config-target.h-timestamp
 config-target.h-timestamp: config-target.mak
 
 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
 
 ifdef CONFIG_USER_ONLY
 TARGET_TYPE=user
@@ -84,6 +84,14 @@ $(QEMU_PROG)-simpletrace.stp: $(BUILD_DIR)/trace-events-all $(tracetool-y)
 		--probe-prefix=qemu.$(TARGET_TYPE).$(TARGET_NAME) \
 		$< > $@,"GEN","$(TARGET_DIR)$(QEMU_PROG)-simpletrace.stp")
 
+$(QEMU_PROG)-log.stp: $(BUILD_DIR)/trace-events-all $(tracetool-y)
+	$(call quiet-command,$(TRACETOOL) \
+		--group=all \
+		--format=log-stap \
+		--backends=$(TRACE_BACKENDS) \
+		--probe-prefix=qemu.$(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)/../systemtap/tapset/$(QEMU_PROG)-log.stp"
 endif
 
 GENERATED_FILES += config-target.h

docs/devel/tracing.txt

@@ -317,6 +317,10 @@ probes:
                          --target-name x86_64 \
                          <trace-events-all >qemu.stp
 
+To facilitate simple usage of systemtap where there merely needs to be printf
+logging of certain probes, a helper script "qemu-trace-stap" is provided.
+Consult its manual page for guidance on its usage.
+
 == Trace event properties ==
 
 Each event in the "trace-events-all" file can be prefixed with a space-separated

hw/display/qxl.c

@@ -1763,10 +1763,16 @@ async_common:
         qxl_set_mode(d, val, 0);
         break;
     case QXL_IO_LOG:
-        trace_qxl_io_log(d->id, d->ram->log_buf);
+        if (TRACE_QXL_IO_LOG_ENABLED || d->guestdebug) {
+            /* We cannot trust the guest to NUL terminate d->ram->log_buf */
+            char *log_buf = g_strndup((const char *)d->ram->log_buf,
+                                      sizeof(d->ram->log_buf));
+            trace_qxl_io_log(d->id, 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);
+                        qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL), log_buf);
+            }
+            g_free(log_buf);
         }
         break;
     case QXL_IO_RESET:

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=%d"
 qxl_interface_update_area_complete_schedule_bh(int qid, uint32_t num_dirty) "%d #dirty=%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 char *desc) "%d 0x%"PRIx64"=%"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=%"PRIu64 " (%s) val=%"PRIu64" size=%u async=%d"

hw/vfio/pci.c

@@ -2581,7 +2581,7 @@ static void vfio_populate_device(VFIOPCIDevice *vdev, Error **errp)
     ret = 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(strerror(errno));
     } else if (irq_info.count == 1) {
         vdev->pci_aer = true;
     } else {

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 reset: %s"
 vfio_populate_device_config(const char *name, unsigned long size, unsigned long offset, unsigned long flags) "Device %s config:\n  size: 0x%lx, offset: 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(const char *errstr) "VFIO_DEVICE_GET_IRQ_INFO failure: %s"
 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"

scripts/qemu-trace-stap

@@ -0,0 +1,175 @@
+#!/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; either version 2 of the License, or
+# (at your option) any later version.
+#
+# 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 <http://www.gnu.org/licenses/>.
+
+from __future__ import print_function
+
+import argparse
+import copy
+import os.path
+import re
+import subprocess
+import sys
+
+
+def probe_prefix(binary):
+    dirname, filename = 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 = os.path.split(binary)
+    if dirname == '':
+        thisfile = which(binary)
+    else:
+        thisfile = os.path.realpath(binary)
+        if not os.path.exists(thisfile):
+            print("Unable to find '%s'" % thisfile)
+            sys.exit(1)
+
+    basedir = os.path.split(thisfile)[0]
+    tapset = os.path.join(basedir, "..", "share", "systemtap", "tapset")
+    return os.path.realpath(tapset)
+
+
+def tapset_env(tapset_dir):
+    tenv = copy.copy(os.environ)
+    tenv["SYSTEMTAP_TAPSET"] = tapset_dir
+    return tenv
+
+def cmd_run(args):
+    prefix = probe_prefix(args.binary)
+    tapsets = tapset_dir(args.binary)
+
+    if args.verbose:
+        print("Using tapset dir '%s' for binary '%s'" % (tapsets, args.binary))
+
+    probes = []
+    for probe in args.probes:
+        probes.append("probe %s.%s {}" % (prefix, probe))
+    if len(probes) == 0:
+        print("At least one probe pattern must be specified")
+        sys.exit(1)
+
+    script = " ".join(probes)
+    if args.verbose:
+        print("Compiling script '%s'" % script)
+        script = """probe begin { print("Running script, <Ctrl>-c to quit\\n") } """ + script
+
+    # We request an 8MB buffer, since the stap default 1MB buffer
+    # can be easily overflowed by frequently firing QEMU traces
+    stapargs = ["stap", "-s", "8"]
+    if args.pid is not None:
+        stapargs.extend(["-x", args.pid])
+    stapargs.extend(["-e", script])
+    subprocess.call(stapargs, env=tapset_env(tapsets))
+
+
+def cmd_list(args):
+    tapsets = tapset_dir(args.binary)
+
+    if args.verbose:
+        print("Using tapset dir '%s' for binary '%s'" % (tapsets, args.binary))
+
+    def print_probes(verbose, name):
+        prefix = probe_prefix(args.binary)
+        offset = len(prefix) + 1
+        script = prefix + "." + name
+
+        if verbose:
+            print("Listing probes with name '%s'" % script)
+        proc = subprocess.Popen(["stap", "-l", script],
+                                stdout=subprocess.PIPE, env=tapset_env(tapsets))
+        out, err = proc.communicate()
+        if proc.returncode != 0:
+            print("No probes found, are the tapsets installed in %s" % tapset_dir(args.binary))
+            sys.exit(1)
+
+        for line in out.splitlines():
+            if line.startswith(prefix):
+                print("%s" % line[offset:])
+
+    if len(args.probes) == 0:
+        print_probes(args.verbose, "*")
+    else:
+        for probe in args.probes:
+            print_probes(args.verbose, probe)
+
+
+def main():
+    parser = argparse.ArgumentParser(description="QEMU SystemTap trace tool")
+    parser.add_argument("-v", "--verbose", help="Print verbose progress info",
+                        action='store_true')
+
+    subparser = parser.add_subparsers(help="commands")
+    subparser.required = True
+    subparser.dest = "command"
+
+    runparser = subparser.add_parser("run", help="Run a trace session",
+                                     formatter_class=argparse.RawDescriptionHelpFormatter,
+                                     epilog="""
+
+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=cmd_run)
+    runparser.add_argument("--pid", "-p", dest="pid",
+                           help="Restrict tracing to a specific process ID")
+    runparser.add_argument("binary", help="QEMU system or user emulator binary")
+    runparser.add_argument("probes", help="Probe names or wildcards",
+                           nargs=argparse.REMAINDER)
+
+    listparser = subparser.add_parser("list", help="List probe points",
+                                      formatter_class=argparse.RawDescriptionHelpFormatter,
+                                      epilog="""
+
+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=cmd_list)
+    listparser.add_argument("binary", help="QEMU system or user emulator binary")
+    listparser.add_argument("probes", help="Probe names or wildcards",
+                            nargs=argparse.REMAINDER)
+
+    args = parser.parse_args()
+
+    args.func(args)
+    sys.exit(0)
+
+if __name__ == '__main__':
+    main()

scripts/qemu-trace-stap.texi

@@ -0,0 +1,140 @@
+@example
+@c man begin SYNOPSIS
+@command{qemu-trace-stap} @var{GLOBAL-OPTIONS} @var{COMMAND} @var{COMMAND-OPTIONS} @var{ARGS...}
+@c man end
+@end example
+
+@c man begin DESCRIPTION
+
+The @command{qemu-trace-stap} program facilitates tracing of the execution
+of QEMU emulators using SystemTap.
+
+It is required to have the SystemTap runtime environment installed to use
+this program, since it is a wrapper around execution of the @command{stap}
+program.
+
+@c man end
+
+@c man begin OPTIONS
+
+The following global options may be used regardless of which command
+is executed:
+
+@table @option
+@item @var{--verbose}, @var{-v}
+
+Display verbose information about command execution.
+
+@end table
+
+The following commands are valid:
+
+@table @option
+
+@item @var{list} @var{BINARY} @var{PATTERN...}
+
+List all the probe names provided by @var{BINARY} that match
+@var{PATTERN}.
+
+If @var{BINARY} is not an absolute path, it will be located by searching
+the directories listed in the @code{$PATH} environment variable.
+
+@var{PATTERN} is a plain string that is used to filter the results of
+this command. It may optionally contain a @code{*} wildcard to facilitate
+matching multiple probes without listing each one explicitly. Multiple
+@var{PATTERN} arguments may be given, causing listing of probes that match
+any of the listed names. If no @var{PATTERN} is given, the all possible
+probes will be listed.
+
+For example, to list all probes available in the @command{qemu-system-x86_64}
+binary:
+
+@example
+$ qemu-trace-stap list qemu-system-x86_64
+@end example
+
+To filter the list to only cover probes related to QEMU's cryptographic
+subsystem, in a binary outside @code{$PATH}
+
+@example
+$ qemu-trace-stap list /opt/qemu/4.0.0/bin/qemu-system-x86_64 'qcrypto*'
+@end example
+
+
+@item @var{run} @var{OPTIONS} @var{BINARY} @var{PATTERN...}
+
+Run a trace session, printing formatted output any time a process that is
+executing @var{BINARY} triggers a probe matching @var{PATTERN}.
+
+If @var{BINARY} is not an absolute path, it will be located by searching
+the directories listed in the @code{$PATH} environment variable.
+
+@var{PATTERN} is a plain string that matches a probe name shown by the
+@var{list} command. It may optionally contain a @code{*} wildcard to
+facilitate matching multiple probes without listing each one explicitly.
+Multiple @var{PATTERN} arguments may be given, causing all matching probes
+to be monitored. At least one @var{PATTERN} is required, since stap is not
+capable of tracing all known QEMU probes concurrently without overflowing
+its trace buffer.
+
+Invocation of this command does not need to be synchronized with
+invocation of the QEMU process(es). It will match probes on all
+existing running processes and all future launched processes,
+unless told to only monitor a specific process.
+
+Valid command specific options are:
+
+@table @option
+@item @var{--pid=PID}, @var{-p PID}
+
+Restrict the tracing session so that it only triggers for the process
+identified by @code{PID}.
+
+@end table
+
+For example, to monitor all processes executing @command{qemu-system-x86_64}
+as found on $PATH, displaying all I/O related probes:
+
+@example
+$ qemu-trace-stap run qemu-system-x86_64 'qio*'
+@end example
+
+To monitor only the QEMU process with PID 1732
+
+@example
+$ qemu-trace-stap run --pid=1732 qemu-system-x86_64 'qio*'
+@end example
+
+To monitor QEMU processes running an alternative binary outside of
+@code{$PATH}, displaying verbose information about setup of the
+tracing environment:
+
+@example
+$ qemu-trace-stap -v run /opt/qemu/4.0.0/qemu-system-x86_64 'qio*'
+@end example
+
+@end table
+
+@c man end
+
+@ignore
+
+@setfilename qemu-trace-stap
+@settitle QEMU SystemTap trace tool
+
+@c man begin LICENSE
+
+Copyright (C) 2019 Red Hat, Inc.
+
+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; either version 2 of the License, or
+# (at your option) any later version.
+
+@c man end
+
+@c man begin SEEALSO
+qemu(1), stap(1)
+@c man end
+
+@end ignore

scripts/tracetool/__init__.py

@@ -274,6 +274,10 @@ class Event(object):
         props = groups["props"].split()
         fmt = groups["fmt"]
         fmt_trans = groups["fmt_trans"]
+        if fmt.find("%m") != -1 or fmt_trans.find("%m") != -1:
+            raise ValueError("Event format '%m' is forbidden, pass the error "
+                             "as an explicit trace argument")
+
         if len(fmt_trans) > 0:
             fmt = [fmt_trans, fmt]
         args = Arguments.build(groups["args"])
@@ -350,6 +354,8 @@ def read_events(fobj, fname):
 
     events = []
     for lineno, line in enumerate(fobj, 1):
+        if line[-1] != '\n':
+            raise ValueError("%s does not end with a new line" % fname)
         if not line.strip():
             continue
         if line.lstrip().startswith('#'):

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__     = "Daniel P. Berrange <berrange@redhat.com>"
+__copyright__  = "Copyright (C) 2014-2019, Red Hat, Inc."
+__license__    = "GPL version 2 or (at your option) any later version"
+
+__maintainer__ = "Daniel Berrange"
+__email__      = "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 = 0
+STATE_LITERAL = 1
+STATE_MACRO = 2
+
+def c_macro_to_format(macro):
+    if macro.startswith("PRI"):
+        return macro[3]
+
+    if macro == "TARGET_FMT_plx":
+        return "%016x"
+
+    raise Exception("Unhandled macro '%s'" % macro)
+
+def c_fmt_to_stap(fmt):
+    state = 0
+    bits = []
+    literal = ""
+    macro = ""
+    escape = 0;
+    for i in range(len(fmt)):
+        if fmt[i] == '\\':
+            if escape:
+                escape = 0
+            else:
+                escape = 1
+            if state != STATE_LITERAL:
+                raise Exception("Unexpected escape outside string literal")
+            literal = literal + fmt[i]
+        elif fmt[i] == '"' and not escape:
+            if state == STATE_LITERAL:
+                state = STATE_SKIP
+                bits.append(literal)
+                literal = ""
+            else:
+                if state == STATE_MACRO:
+                    bits.append(c_macro_to_format(macro))
+                state = STATE_LITERAL
+        elif fmt[i] == ' ' or fmt[i] == '\t':
+            if state == STATE_MACRO:
+                bits.append(c_macro_to_format(macro))
+                macro = ""
+                state = STATE_SKIP
+            elif state == STATE_LITERAL:
+                literal = literal + fmt[i]
+        else:
+            escape = 0
+            if state == STATE_SKIP:
+                state = STATE_MACRO
+
+            if state == STATE_LITERAL:
+                literal = literal + fmt[i]
+            else:
+                macro = macro + fmt[i]
+
+    if state == STATE_MACRO:
+        bits.append(c_macro_to_format(macro))
+    elif state == STATE_LITERAL:
+        bits.append(literal)
+
+    fmt = 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 = %(probeprefix)s.%(name)s ?',
+            '{',
+            probeprefix=probeprefix(),
+            name=e.name)
+
+        # Get references to userspace strings
+        for type_, name in e.args:
+            name = stap_escape(name)
+            if is_string(type_):
+                out('    try {',
+                    '        arg%(name)s_str = %(name)s ? ' +
+                    'user_string_n(%(name)s, 512) : "<null>"',
+                    '    } catch {}',
+                    name=name)
+
+        # Determine systemtap's view of variable names
+        fields = ["pid()", "gettimeofday_ns()"]
+        for type_, name in e.args:
+            name = 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 = ', '.join(arg for arg in fields)
+        fmt_str = "%d@%d " + e.name + " " + c_fmt_to_stap(e.fmt) + "\\n"
+        out('    printf("%(fmt_str)s", %(arg_str)s)',
+            fmt_str=fmt_str, arg_str=arg_str)
+
+        out('}')
+
+    out()

trace-events

@@ -34,9 +34,9 @@ cpu_out(unsigned int addr, char size, unsigned int val) "addr 0x%x(%c) value %u"
 balloon_event(void *opaque, unsigned long addr) "opaque %p addr %lu"
 
 # vl.c
-vm_state_notify(int running, int reason) "running %d reason %d"
+vm_state_notify(int running, int reason, const char *reason_str) "running %d reason %d (%s)"
 load_file(const char *name, const char *path) "name %s location %s"
-runstate_set(int new_state) "new state %d"
+runstate_set(int current_state, const char *current_state_str, int new_state, const char *new_state_str) "current_run_state %d (%s) new_state %d (%s)"
 system_wakeup_request(int reason) "reason=%d"
 qemu_system_shutdown_request(int reason) "reason=%d"
 qemu_system_powerdown_request(void) ""

vl.c

@@ -731,6 +731,9 @@ void runstate_set(RunState new_state)
 {
     assert(new_state < RUN_STATE__MAX);
 
+    trace_runstate_set(current_run_state, RunState_str(current_run_state),
+                       new_state, RunState_str(current_run_state));
+
     if (current_run_state == new_state) {
         return;
     }
@@ -741,7 +744,7 @@ void runstate_set(RunState new_state)
                      RunState_str(new_state));
         abort();
     }
-    trace_runstate_set(new_state);
+
     current_run_state = new_state;
 }
 
@@ -1554,7 +1557,7 @@ void vm_state_notify(int running, RunState state)
 {
     VMChangeStateEntry *e, *next;
 
-    trace_vm_state_notify(running, state);
+    trace_vm_state_notify(running, state, RunState_str(state));
 
     QLIST_FOREACH_SAFE(e, &vm_change_state_head, entries, next) {
         e->cb(e->opaque, running, state);