[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]

Re: [libvirt] [PATCH] Add a systemtap script for watching QEMU monitor interactions



On Mon, Oct 24, 2011 at 03:37:04PM +0100, Daniel P. Berrange wrote:
> From: "Daniel P. Berrange" <berrange 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 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 redhat com
> https://www.redhat.com/mailman/listinfo/libvir-list


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]