[libvirt] [PATCH] Add a systemtap script for watching QEMU monitor interactions
Alon Levy
alevy at redhat.com
Mon Oct 24 18:27:34 UTC 2011
On Mon, Oct 24, 2011 at 03:37:04PM +0100, Daniel P. Berrange wrote:
> From: "Daniel P. Berrange" <berrange at redhat.com>
>
> This change adds some systemtap/dtrace probes to the QEMU monitor
> client code. In particular it allows watching of all operations
> for a VM
>
> * examples/systemtap/qemu-monitor.stp: Watch all monitor commands
> * src/Makefile.am: Passing libdir/bindir/sbindir to dtrace2systemtap.pl
> * src/dtrace2systemtap.pl: Accept libdir/bindir/sbindir as args
> and look for '# binary:' comment to mark probes against libvirtd
> vs libvirt.so
> * src/qemu/qemu_monitor.c, src/qemu/qemu_monitor_json.c,
> src/qemu/qemu_monitor_text.c: Add probes for key functions
> ---
> examples/systemtap/qemu-monitor.stp | 81 +++++++++++++++++++++++++++++++++++
> src/Makefile.am | 2 +-
> src/dtrace2systemtap.pl | 15 ++++++-
> src/probes.d | 20 +++++++++
> src/qemu/qemu_monitor.c | 31 ++++++++++++-
> src/qemu/qemu_monitor_json.c | 4 ++
> src/qemu/qemu_monitor_text.c | 3 +
> 7 files changed, 150 insertions(+), 6 deletions(-)
> create mode 100644 examples/systemtap/qemu-monitor.stp
>
> diff --git a/examples/systemtap/qemu-monitor.stp b/examples/systemtap/qemu-monitor.stp
> new file mode 100644
> index 0000000..647eacc
> --- /dev/null
> +++ b/examples/systemtap/qemu-monitor.stp
> @@ -0,0 +1,81 @@
> +#!/usr/bin/stap
> +#
> +# Copyright (C) 2011 Red Hat, Inc.
> +#
> +# This library is free software; you can redistribute it and/or
> +# modify it under the terms of the GNU Lesser General Public
> +# License as published by the Free Software Foundation; either
> +# version 2.1 of the License, or (at your option) any later version.
> +#
> +# This library 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
> +# Lesser General Public License for more details.
> +#
> +# You should have received a copy of the GNU Lesser General Public
> +# License along with this library; if not, write to the Free Software
> +# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
> +#
> +# Author: Daniel P. Berrange <berrange at redhat.com>
> +#
> +# This script will monitor all messages sent/received between libvirt
> +# and the QEMU monitor
> +#
> +# stap qemu-monitor.stp
> +# 0.000 begin
> +# 3.848 ! 0x7f2dc00017b0 {"timestamp": {"seconds": 1319466931, "microseconds": 187755}, "event": "SHUTDOWN"}
> +# 5.773 > 0x7f2dc0007960 {"execute":"qmp_capabilities","id":"libvirt-1"}
> +# 5.774 < 0x7f2dc0007960 {"return": {}, "id": "libvirt-1"}
> +# 5.774 > 0x7f2dc0007960 {"execute":"query-commands","id":"libvirt-2"}
> +# 5.777 < 0x7f2dc0007960 {"return": [{"name": "quit"}, {"name": ....snip....
> +# 5.777 > 0x7f2dc0007960 {"execute":"query-chardev","id":"libvirt-3"}
> +# 5.778 < 0x7f2dc0007960 {"return": [{"filename": ....snip....
> +# 5.779 > 0x7f2dc0007960 {"execute":"query-cpus","id":"libvirt-4"}
> +# 5.780 < 0x7f2dc0007960 {"return": [{"current": true, "CPU": 0, "pc": 1048560, "halted": false, "thread_id": 13299}], "id": "libvirt-4"}
> +# 5.780 > 0x7f2dc0007960 {"execute":"set_password","arguments":{"protocol":"vnc","password":"123456","connected":"keep"},"id":"libvirt-5"}
> +# 5.782 < 0x7f2dc0007960 {"return": {}, "id": "libvirt-5"}
> +# 5.782 > 0x7f2dc0007960 {"execute":"expire_password","arguments":{"protocol":"vnc","time":"never"},"id":"libvirt-6"}
> +# 5.783 < 0x7f2dc0007960 {"return": {}, "id": "libvirt-6"}
> +# 5.783 > 0x7f2dc0007960 {"execute":"balloon","arguments":{"value":224395264},"id":"libvirt-7"}
> +# 5.785 < 0x7f2dc0007960 {"return": {}, "id": "libvirt-7"}
> +# 5.785 > 0x7f2dc0007960 {"execute":"cont","id":"libvirt-8"}
> +# 5.789 ! 0x7f2dc0007960 {"timestamp": {"seconds": 1319466933, "microseconds": 129980}, "event": "RESUME"}
> +# 5.789 < 0x7f2dc0007960 {"return": {}, "id": "libvirt-8"}
> +# 7.537 ! 0x7f2dc0007960 {"timestamp": {"seconds": 1319466934, "microseconds": 881214}, "event": "SHUTDOWN"}
> +#
> +
> +
> +global start
> +
> +# Print a string, with a timestamp relative to the start of the script
> +function print_ts(msg)
> +{
> + now = gettimeofday_ns() / (1000*1000)
> + delta = (now - start)
> +
> + printf("%3d.%03d %s\n", (delta / 1000), (delta % 1000), msg);
> +}
> +
> +
> +# Just so we know the script is now running
> +probe begin {
> + start = gettimeofday_ns() / (1000*1000)
> + print_ts("begin")
> +}
> +
> +probe libvirt.qemu.monitor_send_msg {
> + if (fd != -1) {
> + print_ts(sprintf("> %p %s (fd=%d)", mon, substr(msg, 0, strlen(msg)-2), fd));
> + } else {
> + print_ts(sprintf("> %p %s", mon, substr(msg, 0, strlen(msg)-2)));
> + }
> +}
> +
> +probe libvirt.qemu.monitor_recv_reply {
> + print_ts(sprintf("< %p %s", mon, reply));
> +}
> +
> +probe libvirt.qemu.monitor_recv_event {
> + print_ts(sprintf("! %p %s", mon, event));
> +}
> +
> diff --git a/src/Makefile.am b/src/Makefile.am
> index 2555f81..81ec730 100644
> --- a/src/Makefile.am
> +++ b/src/Makefile.am
> @@ -1288,7 +1288,7 @@ libvirt_functions.stp: $(RPC_PROBE_FILES) $(srcdir)/rpc/gensystemtap.pl
> $(AM_V_GEN)perl -w $(srcdir)/rpc/gensystemtap.pl $(RPC_PROBE_FILES) > $@
>
> libvirt_probes.stp: probes.d $(srcdir)/dtrace2systemtap.pl
> - $(AM_V_GEN)perl -w $(srcdir)/dtrace2systemtap.pl $< > $@
> + $(AM_V_GEN)perl -w $(srcdir)/dtrace2systemtap.pl $(bindir) $(sbindir) $(libdir) $< > $@
>
> CLEANFILES += probes.h probes.o libvirt_functions.stp libvirt_probes.stp
> endif
> diff --git a/src/dtrace2systemtap.pl b/src/dtrace2systemtap.pl
> index fab066b..b577eac 100755
> --- a/src/dtrace2systemtap.pl
> +++ b/src/dtrace2systemtap.pl
> @@ -31,6 +31,10 @@ my $file;
> my @files;
> my %files;
>
> +my $bindir = shift @ARGV;
> +my $sbindir = shift @ARGV;
> +my $libdir = shift @ARGV;
> +
> my $probe;
> my $args;
>
> @@ -47,6 +51,8 @@ while (<>) {
> $files{$file} = { prefix => undef, probes => [] };
> } elsif (m,^\s*\#\s*prefix:\s*(\S+)\s*$,) {
> $files{$file}->{prefix} = $1;
> + } elsif (m,^\s*\#\s*binary:\s*(\S+)\s*$,) {
> + $files{$file}->{binary} = $1;
> } else {
> if (m,\s*probe\s+([a-zA-Z0-9_]+)\((.*?)(\);)?$,) {
> $probe = $1;
> @@ -66,7 +72,7 @@ while (<>) {
> die "unexpected data $_ on line $.";
> }
> } else {
> - die "unexpected data $_ on line $.";
> + #die "unexpected data $_ on line $.";
Forgotten?
> }
> }
> }
> @@ -84,7 +90,12 @@ foreach my $file (@files) {
> my $pname = $name;
> $pname =~ s/${prefix}_/libvirt.$prefix./;
>
> - print "probe $pname = process(\"libvirt.so\").mark(\"$name\") {\n";
> + my $binary = "$libdir/libvirt.so";
> + if (exists $files{$file}->{binary}) {
> + $binary = $sbindir . "/" . $files{$file}->{binary};
> + }
> +
> + print "probe $pname = process(\"$binary\").mark(\"$name\") {\n";
>
> my @args = split /,/, $args;
> for (my $i = 0 ; $i <= $#args ; $i++) {
> diff --git a/src/probes.d b/src/probes.d
> index 6d95c84..7f66ac0 100644
> --- a/src/probes.d
> +++ b/src/probes.d
> @@ -69,4 +69,24 @@ provider libvirt {
> probe rpc_tls_session_handshake_pass(void *sess);
> probe rpc_tls_session_handshake_fail(void *sess);
>
> +
> + # file: src/qemu/qemu_monitor.c
> + # prefix: qemu
> + # binary: libvirtd
> + # Monitor lifecycle
> + probe qemu_monitor_new(void *mon, int refs, int fd);
> + probe qemu_monitor_ref(void *mon, int refs);
> + probe qemu_monitor_unref(void *mon, int refs);
> + probe qemu_monitor_close(void *monm, int refs);
> +
> + # High level monitor message processing
> + probe qemu_monitor_send_msg(void *mon, const char *msg, int fd);
> + probe qemu_monitor_recv_reply(void *mon, const char *reply);
> + probe qemu_monitor_recv_event(void *mon, const char *event);
> +
> + # Low level monitor I/O processing
> + probe qemu_monitor_io_process(void *mon, const char *buf, unsigned int len);
> + probe qemu_monitor_io_read(void *mon, const char *buf, unsigned int len, int ret, int errno);
> + probe qemu_monitor_io_write(void *mon, const char *buf, unsigned int len, int ret, int errno);
> + probe qemu_monitor_io_send_fd(void *mon, int fd, int ret, int errno);
> };
> diff --git a/src/qemu/qemu_monitor.c b/src/qemu/qemu_monitor.c
> index 182e63d..75429fa 100644
> --- a/src/qemu/qemu_monitor.c
> +++ b/src/qemu/qemu_monitor.c
> @@ -183,6 +183,8 @@ static void qemuMonitorFree(qemuMonitorPtr mon)
> int qemuMonitorRef(qemuMonitorPtr mon)
> {
> mon->refs++;
> + PROBE(QEMU_MONITOR_UNREF,
> + "mon=%p refs=%d", mon, mon->refs);
> return mon->refs;
> }
>
> @@ -190,6 +192,8 @@ int qemuMonitorUnref(qemuMonitorPtr mon)
> {
> mon->refs--;
>
> + PROBE(QEMU_MONITOR_UNREF,
> + "mon=%p refs=%d", mon, mon->refs);
> if (mon->refs == 0) {
> qemuMonitorUnlock(mon);
> qemuMonitorFree(mon);
> @@ -305,6 +309,9 @@ qemuMonitorIOProcess(qemuMonitorPtr mon)
> # endif
> #endif
>
> + PROBE(QEMU_MONITOR_IO_PROCESS,
> + "mon=%p buf=%s len=%zu", mon, mon->buffer, mon->bufferOffset);
> +
> if (mon->json)
> len = qemuMonitorJSONIOProcess(mon,
> mon->buffer, mon->bufferOffset,
> @@ -403,6 +410,18 @@ qemuMonitorIOWrite(qemuMonitorPtr mon)
> mon->msg->txLength - mon->msg->txOffset,
> mon->msg->txFD);
>
> + PROBE(QEMU_MONITOR_IO_WRITE,
> + "mon=%p buf=%s len=%d ret=%d errno=%d",
> + mon,
> + mon->msg->txBuffer + mon->msg->txOffset,
> + mon->msg->txLength - mon->msg->txOffset,
> + done, errno);
> +
> + if (mon->msg->txFD != -1)
> + PROBE(QEMU_MONITOR_IO_SEND_FD,
> + "mon=%p fd=%d ret=%d errno=%d",
> + mon, mon->msg->txFD, done, errno);
> +
> if (done < 0) {
> if (errno == EAGAIN)
> return 0;
> @@ -696,7 +715,9 @@ qemuMonitorOpen(virDomainObjPtr vm,
> }
> qemuMonitorRef(mon);
>
> - VIR_DEBUG("New mon %p fd =%d watch=%d", mon, mon->fd, mon->watch);
> + PROBE(QEMU_MONITOR_NEW,
> + "mon=%p refs=%d fd=%d",
> + mon, mon->refs, mon->fd);
> qemuMonitorUnlock(mon);
>
> return mon;
> @@ -719,9 +740,9 @@ void qemuMonitorClose(qemuMonitorPtr mon)
> if (!mon)
> return;
>
> - VIR_DEBUG("mon=%p", mon);
> -
> qemuMonitorLock(mon);
> + PROBE(QEMU_MONITOR_CLOSE,
> + "mon=%p refs=%d", mon, mon->refs);
>
> if (mon->fd >= 0) {
> if (mon->watch)
> @@ -762,6 +783,10 @@ int qemuMonitorSend(qemuMonitorPtr mon,
> mon->msg = msg;
> qemuMonitorUpdateWatch(mon);
>
> + PROBE(QEMU_MONITOR_SEND_MSG,
> + "mon=%p msg=%s fd=%d",
> + mon, mon->msg->txBuffer, mon->msg->txFD);
> +
> while (!mon->msg->finished) {
> if (virCondWait(&mon->notify, &mon->lock) < 0) {
> qemuReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> diff --git a/src/qemu/qemu_monitor_json.c b/src/qemu/qemu_monitor_json.c
> index cd8f1e5..2c4aee5 100644
> --- a/src/qemu/qemu_monitor_json.c
> +++ b/src/qemu/qemu_monitor_json.c
> @@ -126,9 +126,13 @@ qemuMonitorJSONIOProcessLine(qemuMonitorPtr mon,
> if (virJSONValueObjectHasKey(obj, "QMP") == 1) {
> ret = 0;
> } else if (virJSONValueObjectHasKey(obj, "event") == 1) {
> + PROBE(QEMU_MONITOR_RECV_EVENT,
> + "mon=%p event=%s", mon, line);
> ret = qemuMonitorJSONIOProcessEvent(mon, obj);
> } else if (virJSONValueObjectHasKey(obj, "error") == 1 ||
> virJSONValueObjectHasKey(obj, "return") == 1) {
> + PROBE(QEMU_MONITOR_RECV_REPLY,
> + "mon=%p reply=%s", mon, line);
> if (msg) {
> msg->rxObject = obj;
> msg->finished = 1;
> diff --git a/src/qemu/qemu_monitor_text.c b/src/qemu/qemu_monitor_text.c
> index 4774df9..c652321 100644
> --- a/src/qemu/qemu_monitor_text.c
> +++ b/src/qemu/qemu_monitor_text.c
> @@ -198,6 +198,9 @@ int qemuMonitorTextIOProcess(qemuMonitorPtr mon ATTRIBUTE_UNUSED,
> VIR_DEBUG("Finished 0 byte reply");
> #endif
> }
> + PROBE(QEMU_MONITOR_RECV_REPLY,
> + "mon=%p reply=%s",
> + mon, msg->rxBuffer);
> msg->finished = 1;
> used += end - (data + used);
> used += strlen(BASIC_PROMPT);
> --
> 1.7.6.4
>
> --
> libvir-list mailing list
> libvir-list at redhat.com
> https://www.redhat.com/mailman/listinfo/libvir-list
More information about the libvir-list
mailing list