From: "Daniel P. Berrange" <berrange@redhat.com> To avoid static linking libvirtd to the RPC server code, which then prevents sane introduction of DTrace probes, put it all in the libvirt.so, and export it * daemon/Makefile.am: Don't link to RPC libraries * src/Makefile.am: Link all RPC libraries to libvirt.so * src/libvirt_private.syms: Export all RPC functions --- daemon/Makefile.am | 2 - src/Makefile.am | 5 ++- src/libvirt_private.syms | 95 ++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 99 insertions(+), 3 deletions(-) diff --git a/daemon/Makefile.am b/daemon/Makefile.am index 1cf2b73..ce15cbb 100644 --- a/daemon/Makefile.am +++ b/daemon/Makefile.am @@ -111,8 +111,6 @@ libvirtd_LDADD = \ $(POLKIT_LIBS) libvirtd_LDADD += \ - ../src/libvirt-net-rpc-server.la \ - ../src/libvirt-net-rpc.la \ ../src/libvirt-qemu.la if ! WITH_DRIVER_MODULES diff --git a/src/Makefile.am b/src/Makefile.am index 9650139..7f2f5e5 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -610,7 +610,10 @@ libvirt_driver_remote_la_CFLAGS = \ -I@top_srcdir@/src/rpc \ $(AM_CFLAGS) libvirt_driver_remote_la_LDFLAGS = $(AM_LDFLAGS) -libvirt_driver_remote_la_LIBADD = $(GNUTLS_LIBS) libvirt-net-rpc-client.la libvirt-net-rpc.la +libvirt_driver_remote_la_LIBADD = $(GNUTLS_LIBS) \ + libvirt-net-rpc-client.la \ + libvirt-net-rpc-server.la \ + libvirt-net-rpc.la if WITH_DRIVER_MODULES libvirt_driver_remote_la_LIBADD += ../gnulib/lib/libgnu.la libvirt_driver_remote_la_LDFLAGS += -module -avoid-version diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms index 1ac486f..59e301c 100644 --- a/src/libvirt_private.syms +++ b/src/libvirt_private.syms @@ -1165,6 +1165,101 @@ virFileFclose; virFileFdopen; +# virnetmessage.h +virNetMessageClear; +virNetMessageEncodeHeader; +virNetMessageEncodePayload; +virNetMessageFree; +virNetMessageNew; +virNetMessageQueuePush; +virNetMessageQueueServe; +virNetMessageSaveError; + + +# virnetsaslcontext.h +virNetSASLContextCheckIdentity; +virNetSASLContextNewServer; +virNetSASLSessionExtKeySize; +virNetSASLSessionFree; +virNetSASLSessionGetIdentity; +virNetSASLSessionGetKeySize; +virNetSASLSessionListMechanisms; +virNetSASLSessionNewServer; +virNetSASLSessionSecProps; +virNetSASLSessionServerStart; +virNetSASLSessionServerStep; + + +# virnetserver.h +virNetServerAddProgram; +virNetServerAddService; +virNetServerAddSignalHandler; +virNetServerAutoShutdown; +virNetServerClose; +virNetServerFree; +virNetServerIsPrivileged; +virNetServerNew; +virNetServerQuit; +virNetServerRef; +virNetServerRun; +virNetServerServiceFree; +virNetServerServiceNewTCP; +virNetServerServiceNewUNIX; +virNetServerUpdateServices; + + +# virnetserverclient.h +virNetServerClientAddFilter; +virNetServerClientClose; +virNetServerClientDelayedClose; +virNetServerClientFree; +virNetServerClientGetAuth; +virNetServerClientGetFD; +virNetServerClientGetLocalIdentity; +virNetServerClientGetPrivateData; +virNetServerClientGetReadonly; +virNetServerClientGetTLSKeySize; +virNetServerClientHasTLSSession; +virNetServerClientImmediateClose; +virNetServerClientIsSecure; +virNetServerClientLocalAddrString; +virNetServerClientRef; +virNetServerClientRemoteAddrString; +virNetServerClientRemoveFilter; +virNetServerClientSendMessage; +virNetServerClientSetCloseHook; +virNetServerClientSetIdentity; +virNetServerClientSetPrivateData; +virNetServerClientSetSASLSession; + + +# virnetserverprogram.h +virNetServerProgramFree; +virNetServerProgramGetID; +virNetServerProgramGetVersion; +virNetServerProgramMatches; +virNetServerProgramNew; +virNetServerProgramRef; +virNetServerProgramSendReplyError; +virNetServerProgramSendStreamData; +virNetServerProgramSendStreamError; + + +# virnetsocket.h +virNetSocketDupFD; +virNetSocketFree; +virNetSocketGetFD; +virNetSocketListen; +virNetSocketNewConnectTCP; +virNetSocketNewListenUNIX; + + +# virnettlscontext.h +virNetTLSContextFree; +virNetTLSContextNewServer; +virNetTLSContextNewServerPath; + + # virpidfile.h virPidFileAcquire; virPidFileAcquirePath; -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> If we receive an error on the stream, set the EOF marker so that any further (bogus) incoming data is dropped. * src/rpc/virnetclientstream.c: Set EOF on stream --- src/rpc/virnetclientstream.c | 3 +++ 1 files changed, 3 insertions(+), 0 deletions(-) diff --git a/src/rpc/virnetclientstream.c b/src/rpc/virnetclientstream.c index 4cd0295..7e2d9ae 100644 --- a/src/rpc/virnetclientstream.c +++ b/src/rpc/virnetclientstream.c @@ -268,6 +268,9 @@ int virNetClientStreamSetError(virNetClientStreamPtr st, st->err.int1 = err.int1; st->err.int2 = err.int2; + st->incomingEOF = true; + virNetClientStreamEventTimerUpdate(st); + ret = 0; cleanup: -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> Instead of directly manipulating sock->refs, add a virSocketRef API * src/rpc/virnetsocket.c, src/rpc/virnetsocket.h: Add virSocketRef --- src/rpc/virnetsocket.c | 13 +++++++++++-- src/rpc/virnetsocket.h | 1 + 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/src/rpc/virnetsocket.c b/src/rpc/virnetsocket.c index 88dc2a4..93e062a 100644 --- a/src/rpc/virnetsocket.c +++ b/src/rpc/virnetsocket.c @@ -655,6 +655,14 @@ int virNetSocketNewConnectExternal(const char **cmdargv, } +void virNetSocketRef(virNetSocketPtr sock) +{ + virMutexLock(&sock->lock); + sock->refs++; + virMutexUnlock(&sock->lock); +} + + void virNetSocketFree(virNetSocketPtr sock) { if (!sock) @@ -1187,20 +1195,19 @@ int virNetSocketAddIOCallback(virNetSocketPtr sock, { int ret = -1; + virNetSocketRef(sock); virMutexLock(&sock->lock); if (sock->watch > 0) { VIR_DEBUG("Watch already registered on socket %p", sock); goto cleanup; } - sock->refs++; if ((sock->watch = virEventAddHandle(sock->fd, events, virNetSocketEventHandle, sock, virNetSocketEventFree)) < 0) { VIR_DEBUG("Failed to register watch on socket %p", sock); - sock->refs--; goto cleanup; } sock->func = func; @@ -1211,6 +1218,8 @@ int virNetSocketAddIOCallback(virNetSocketPtr sock, cleanup: virMutexUnlock(&sock->lock); + if (ret != 0) + virNetSocketFree(sock); return ret; } diff --git a/src/rpc/virnetsocket.h b/src/rpc/virnetsocket.h index f7e5ebb..9c4f112 100644 --- a/src/rpc/virnetsocket.h +++ b/src/rpc/virnetsocket.h @@ -101,6 +101,7 @@ void virNetSocketSetSASLSession(virNetSocketPtr sock, virNetSASLSessionPtr sess); # endif bool virNetSocketHasCachedData(virNetSocketPtr sock); +void virNetSocketRef(virNetSocketPtr sock); void virNetSocketFree(virNetSocketPtr sock); const char *virNetSocketLocalAddrString(virNetSocketPtr sock); -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> Pull the call to gnutls_x509_crt_get_dn up into a higher function so that the 'dname' variable will be available for probe points * src/rpc/virnettlscontext.c: Pull gnutls_x509_crt_get_dn up one level --- src/rpc/virnettlscontext.c | 34 +++++++++++++++++----------------- 1 files changed, 17 insertions(+), 17 deletions(-) diff --git a/src/rpc/virnettlscontext.c b/src/rpc/virnettlscontext.c index 971fb80..58accaf 100644 --- a/src/rpc/virnettlscontext.c +++ b/src/rpc/virnettlscontext.c @@ -383,24 +383,11 @@ static int virNetTLSContextCheckCertDN(gnutls_x509_crt_t cert, const char *certFile, const char *hostname, + const char *dname, const char *const* whitelist) { - int ret; - char name[256]; - size_t namesize = sizeof name; - - memset(name, 0, namesize); - - ret = gnutls_x509_crt_get_dn(cert, name, &namesize); - if (ret != 0) { - virNetError(VIR_ERR_SYSTEM_ERROR, - _("Failed to get certificate %s distinguished name: %s"), - certFile, gnutls_strerror(ret)); - return -1; - } - VIR_DEBUG("Peer DN is %s", name); - if (whitelist && - virNetTLSContextCheckCertDNWhitelist(name, whitelist) <= 0) + if (whitelist && dname && + virNetTLSContextCheckCertDNWhitelist(dname, whitelist) <= 0) return -1; if (hostname && @@ -955,6 +942,10 @@ static int virNetTLSContextValidCertificate(virNetTLSContextPtr ctxt, unsigned int status; const gnutls_datum_t *certs; unsigned int nCerts, i; + char dname[256]; + size_t dnamesize = sizeof(dname); + + memset(dname, 0, dnamesize); if ((ret = gnutls_certificate_verify_peers2(sess->session, &status)) < 0){ virNetError(VIR_ERR_SYSTEM_ERROR, @@ -1021,7 +1012,16 @@ static int virNetTLSContextValidCertificate(virNetTLSContextPtr ctxt, } if (i == 0) { - if (virNetTLSContextCheckCertDN(cert, "[session]", sess->hostname, + ret = gnutls_x509_crt_get_dn(cert, dname, &dnamesize); + if (ret != 0) { + virNetError(VIR_ERR_SYSTEM_ERROR, + _("Failed to get certificate %s distinguished name: %s"), + "[session]", gnutls_strerror(ret)); + goto authfail; + } + VIR_DEBUG("Peer DN is %s", dname); + + if (virNetTLSContextCheckCertDN(cert, "[session]", sess->hostname, dname, ctxt->x509dnWhitelist) < 0) { gnutls_x509_crt_deinit(cert); goto authdeny; -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> The virNetTLSContextRef API forgot to acquire/release the lock while changing ctxt->refs * src/rpc/virnettlscontext.c: Add lock calls --- src/rpc/virnettlscontext.c | 2 ++ 1 files changed, 2 insertions(+), 0 deletions(-) diff --git a/src/rpc/virnettlscontext.c b/src/rpc/virnettlscontext.c index 58accaf..f3cc769 100644 --- a/src/rpc/virnettlscontext.c +++ b/src/rpc/virnettlscontext.c @@ -931,7 +931,9 @@ virNetTLSContextPtr virNetTLSContextNewClient(const char *cacert, void virNetTLSContextRef(virNetTLSContextPtr ctxt) { + virMutexLock(&ctxt->lock); ctxt->refs++; + virMutexUnlock(&ctxt->lock); } -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> The libvirtd daemon had a few crude system tap probes. Some of these were broken during the RPC rewrite. The new modular RPC code is structured in a way that allows much more effective tracing. Instead of trying to hook up the original probes, define a new set of probes for the RPC and event code. The master probes file is now src/probes.d. This contains probes for virNetServerClientPtr, virNetClientPtr, virSocketPtr virNetTLSContextPtr and virNetTLSSessionPtr modules. Also add probes for the poll event loop. The src/dtrace2systemtap.pl script can convert the probes.d file into a libvirt_probes.stp file to make use from systemtap much simpler. The src/rpc/gensystemtap.pl script can generate a set of systemtap functions for translating RPC enum values into printable strings. This works for all RPC header enums (program, type, status, procedure) and also the authentication enum The PROBE macro will automatically generate a VIR_DEBUG statement, so any place with a PROBE can remove any existing manual DEBUG statements. * daemon/libvirtd.stp, daemon/probes.d: Remove obsolete probing * daemon/libvirtd.h: Remove probe macros * daemon/Makefile.am: Remove all probe buildings/install * daemon/remote.c: Update authentication probes * src/dtrace2systemtap.pl, src/rpc/gensystemtap.pl: Scripts to generate STP files * src/internal.h: Add probe macros * src/probes.d: Master list of probes * src/rpc/virnetclient.c, src/rpc/virnetserverclient.c, src/rpc/virnetsocket.c, src/rpc/virnettlscontext.c, src/util/event_poll.c: Insert probe points, removing any DEBUG statements that duplicate the info --- daemon/Makefile.am | 26 +----- daemon/libvirtd.h | 47 ---------- daemon/libvirtd.stp | 65 -------------- daemon/probes.d | 12 --- daemon/remote.c | 60 ++++++++----- src/.gitignore | 4 + src/Makefile.am | 39 ++++++++- src/dtrace2systemtap.pl | 104 ++++++++++++++++++++++ src/internal.h | 73 ++++++++++++++++ src/probes.d | 72 ++++++++++++++++ src/rpc/gensystemtap.pl | 195 ++++++++++++++++++++++++++++++++++++++++++ src/rpc/virnetclient.c | 28 +++++-- src/rpc/virnetserverclient.c | 23 +++++- src/rpc/virnetsocket.c | 13 +++- src/rpc/virnettlscontext.c | 47 +++++++--- src/util/event_poll.c | 47 ++++++++--- 16 files changed, 644 insertions(+), 211 deletions(-) delete mode 100644 daemon/libvirtd.stp delete mode 100644 daemon/probes.d create mode 100644 src/dtrace2systemtap.pl create mode 100644 src/probes.d create mode 100644 src/rpc/gensystemtap.pl diff --git a/daemon/Makefile.am b/daemon/Makefile.am index ce15cbb..e7821b2 100644 --- a/daemon/Makefile.am +++ b/daemon/Makefile.am @@ -48,7 +48,6 @@ EXTRA_DIST = \ THREADS.txt \ libvirtd.pod.in \ libvirtd.8.in \ - libvirtd.stp \ $(DAEMON_SOURCES) BUILT_SOURCES = @@ -110,6 +109,10 @@ libvirtd_LDADD = \ $(SASL_LIBS) \ $(POLKIT_LIBS) +if WITH_DTRACE +libvirtd_LDADD += ../src/probes.o +endif + libvirtd_LDADD += \ ../src/libvirt-qemu.la @@ -167,24 +170,6 @@ policyfile = libvirtd.policy-1 endif endif -if WITH_DTRACE -libvirtd_LDADD += probes.o -nodist_libvirtd_SOURCES = probes.h - -BUILT_SOURCES += probes.h - -tapsetdir = $(datadir)/systemtap/tapset -tapset_DATA = libvirtd.stp - -probes.h: probes.d - $(AM_V_GEN)$(DTRACE) -o $@ -h -s $< - -probes.o: probes.d - $(AM_V_GEN)$(DTRACE) -o $@ -G -s $< - -CLEANFILES += probes.h probes.o -endif - install-data-local: install-init install-data-sasl install-data-polkit \ install-logrotate mkdir -p $(DESTDIR)$(localstatedir)/log/libvirt @@ -299,9 +284,6 @@ install-data-local: install-data-sasl uninstall-local:: uninstall-data-sasl endif # WITH_LIBVIRTD -# This is needed for 'make dist' too, so can't wrap in WITH_LIBVIRTD. -EXTRA_DIST += probes.d libvirtd.stp - POD2MAN = pod2man -c "Virtualization Support" \ -r "$(PACKAGE)-$(VERSION)" -s 8 diff --git a/daemon/libvirtd.h b/daemon/libvirtd.h index 6d6460e..ecb7374 100644 --- a/daemon/libvirtd.h +++ b/daemon/libvirtd.h @@ -39,53 +39,6 @@ # endif # include "virnetserverprogram.h" -# if WITH_DTRACE -# ifndef LIBVIRTD_PROBES_H -# define LIBVIRTD_PROBES_H -# include "probes.h" -# endif /* LIBVIRTD_PROBES_H */ - -/* Systemtap 1.2 headers have a bug where they cannot handle a - * variable declared with array type. Work around this by casting all - * arguments. This is some gross use of the preprocessor because - * PROBE is a var-arg macro, but it is better than the alternative of - * making all callers to PROBE have to be aware of the issues. And - * hopefully, if we ever add a call to PROBE with other than 2 or 3 - * end arguments, you can figure out the pattern to extend this hack. - */ -# define VIR_COUNT_ARGS(...) VIR_ARG5(__VA_ARGS__, 4, 3, 2, 1) -# define VIR_ARG5(_1, _2, _3, _4, _5, ...) _5 -# define VIR_ADD_CAST_EXPAND(a, b, ...) VIR_ADD_CAST_PASTE(a, b, __VA_ARGS__) -# define VIR_ADD_CAST_PASTE(a, b, ...) a##b(__VA_ARGS__) - -/* The double cast is necessary to silence gcc warnings; any pointer - * can safely go to intptr_t and back to void *, which collapses - * arrays into pointers; while any integer can be widened to intptr_t - * then cast to void *. */ -# define VIR_ADD_CAST(a) ((void *)(intptr_t)(a)) -# define VIR_ADD_CAST2(a, b) \ - VIR_ADD_CAST(a), VIR_ADD_CAST(b) -# define VIR_ADD_CAST3(a, b, c) \ - VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c) - -# define VIR_ADD_CASTS(...) \ - VIR_ADD_CAST_EXPAND(VIR_ADD_CAST, VIR_COUNT_ARGS(__VA_ARGS__), \ - __VA_ARGS__) - -# define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) -# define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ - #NAME ": " FMT, __VA_ARGS__); \ - if (LIBVIRTD_ ## NAME ## _ENABLED()) { \ - PROBE_EXPAND(LIBVIRTD_ ## NAME, \ - VIR_ADD_CASTS(__VA_ARGS__)); \ - } -# else -# define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__, __func__, __LINE__, \ - #NAME ": " FMT, __VA_ARGS__); -# endif - typedef struct daemonClientStream daemonClientStream; typedef daemonClientStream *daemonClientStreamPtr; typedef struct daemonClientPrivate daemonClientPrivate; diff --git a/daemon/libvirtd.stp b/daemon/libvirtd.stp deleted file mode 100644 index 7406eeb..0000000 --- a/daemon/libvirtd.stp +++ /dev/null @@ -1,65 +0,0 @@ -probe libvirt.daemon.client.connect = process("libvirtd").mark("client_connect") -{ - fd = $arg1; - readonly = $arg2; - localAddr = user_string($arg3); - remoteAddr = user_string($arg4); -} - -probe libvirt.daemon.client.disconnect = process("libvirtd").mark("client_disconnect") -{ - fd = $arg1; -} - - -probe libvirt.daemon.client.tls_allow = process("libvirtd").mark("client_tls_allow") -{ - fd = $arg1; - x509dname = user_string($arg2); -} - -probe libvirt.daemon.client.tls_deny = process("libvirtd").mark("client_tls_deny") -{ - fd = $arg1; - x509dname = user_string($arg2); -} - -probe libvirt.daemon.client.tls_fail = process("libvirtd").mark("client_tls_fail") -{ - fd = $arg1; -} - - -function authtype_to_string(authtype) { - if (authtype == 0) - return "none" - if (authtype == 1) - return "sasl" - if (authtype == 2) - return "polkit" - return "unknown" -} - - -probe libvirt.daemon.client.auth_allow = process("libvirtd").mark("client_auth_allow") -{ - fd = $arg1; - authtype = $arg2; - authname = authtype_to_string($arg2); - identity = user_string($arg3); -} - -probe libvirt.daemon.client.auth_deny = process("libvirtd").mark("client_auth_deny") -{ - fd = $arg1; - authtype = $arg2; - authname = authtype_to_string($arg2); - identity = user_string($arg3); -} - -probe libvirt.daemon.client.auth_fail = process("libvirtd").mark("client_auth_fail") -{ - fd = $arg1; - authtype = $arg2; - authname = authtype_to_string($arg2); -} diff --git a/daemon/probes.d b/daemon/probes.d deleted file mode 100644 index d1050c0..0000000 --- a/daemon/probes.d +++ /dev/null @@ -1,12 +0,0 @@ -provider libvirtd { - probe client_connect(int fd, int readonly, const char *localAddr, const char *remoteAddr); - probe client_disconnect(int fd); - - probe client_auth_allow(int fd, int authtype, const char *identity); - probe client_auth_deny(int fd, int authtype, const char *identity); - probe client_auth_fail(int fd, int authtype); - - probe client_tls_allow(int fd, const char *x509dname); - probe client_tls_deny(int fd, const char *x509dname); - probe client_tls_fail(int fd); -}; diff --git a/daemon/remote.c b/daemon/remote.c index 245d41c..550bed4 100644 --- a/daemon/remote.c +++ b/daemon/remote.c @@ -1933,8 +1933,9 @@ authfail: virNetError(VIR_ERR_AUTH_FAILED, "%s", _("authentication failed")); virNetMessageSaveError(rerr); - PROBE(CLIENT_AUTH_FAIL, "fd=%d, auth=%d", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL); + PROBE(RPC_SERVER_CLIENT_AUTH_FAIL, + "client=%p auth=%d", + client, REMOTE_AUTH_SASL); virNetSASLSessionFree(sasl); virMutexUnlock(&priv->lock); return -1; @@ -1976,8 +1977,9 @@ remoteSASLFinish(virNetServerClientPtr client) VIR_DEBUG("Authentication successful %d", virNetServerClientGetFD(client)); identity = virNetSASLSessionGetIdentity(priv->sasl); - PROBE(CLIENT_AUTH_ALLOW, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL, identity); + PROBE(RPC_SERVER_CLIENT_AUTH_ALLOW, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_SASL, identity); virNetSASLSessionFree(priv->sasl); priv->sasl = NULL; @@ -2064,14 +2066,16 @@ remoteDispatchAuthSaslStart(virNetServerPtr server ATTRIBUTE_UNUSED, return 0; authfail: - PROBE(CLIENT_AUTH_FAIL, "fd=%d, auth=%d", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL); + PROBE(RPC_SERVER_CLIENT_AUTH_FAIL, + "client=%p auth=%d", + client, REMOTE_AUTH_SASL); goto error; authdeny: identity = virNetSASLSessionGetIdentity(priv->sasl); - PROBE(CLIENT_AUTH_DENY, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL, identity); + PROBE(RPC_SERVER_CLIENT_AUTH_DENY, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_SASL, identity); goto error; error: @@ -2160,14 +2164,16 @@ remoteDispatchAuthSaslStep(virNetServerPtr server ATTRIBUTE_UNUSED, return 0; authfail: - PROBE(CLIENT_AUTH_FAIL, "fd=%d, auth=%d", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL); + PROBE(RPC_SERVER_CLIENT_AUTH_FAIL, + "client=%p auth=%d", + client, REMOTE_AUTH_SASL); goto error; authdeny: identity = virNetSASLSessionGetIdentity(priv->sasl); - PROBE(CLIENT_AUTH_DENY, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_SASL, identity); + PROBE(RPC_SERVER_CLIENT_AUTH_DENY, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_SASL, identity); goto error; error: @@ -2295,8 +2301,9 @@ remoteDispatchAuthPolkit(virNetServerPtr server ATTRIBUTE_UNUSED, VIR_FREE(tmp); goto authdeny; } - PROBE(CLIENT_AUTH_ALLOW, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT, ident); + PROBE(RPC_SERVER_CLIENT_AUTH_ALLOW, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_POLKIT, ident); VIR_INFO("Policy allowed action %s from pid %d, uid %d", action, callerPid, callerUid); ret->complete = 1; @@ -2315,13 +2322,15 @@ error: return -1; authfail: - PROBE(CLIENT_AUTH_FAIL, "fd=%d, auth=%d", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT); + PROBE(RPC_SERVER_CLIENT_AUTH_FAIL, + "client=%p auth=%d", + client, REMOTE_AUTH_POLKIT); goto error; authdeny: - PROBE(CLIENT_AUTH_DENY, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT, (char *)ident); + PROBE(RPC_SERVER_CLIENT_AUTH_DENY, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_POLKIT, (char *)ident); goto error; } #elif HAVE_POLKIT0 @@ -2429,8 +2438,9 @@ remoteDispatchAuthPolkit(virNetServerPtr server, polkit_result_to_string_representation(pkresult)); goto authdeny; } - PROBE(CLIENT_AUTH_ALLOW, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT, ident); + PROBE(RPC_SERVER_CLIENT_AUTH_ALLOW, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_POLKIT, ident); VIR_INFO("Policy allowed action %s from pid %d, uid %d, result %s", action, callerPid, callerUid, polkit_result_to_string_representation(pkresult)); @@ -2449,13 +2459,15 @@ error: return -1; authfail: - PROBE(CLIENT_AUTH_FAIL, "fd=%d, auth=%d", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT); + PROBE(RPC_SERVER_CLIENT_AUTH_FAIL, + "client=%p auth=%d", + client, REMOTE_AUTH_POLKIT); goto error; authdeny: - PROBE(CLIENT_AUTH_DENY, "fd=%d, auth=%d, username=%s", - virNetServerClientGetFD(client), REMOTE_AUTH_POLKIT, ident); + PROBE(RPC_SERVER_CLIENT_AUTH_DENY, + "client=%p auth=%d identity=%s", + client, REMOTE_AUTH_POLKIT, ident); goto error; } diff --git a/src/.gitignore b/src/.gitignore index a619643..64e6aec 100644 --- a/src/.gitignore +++ b/src/.gitignore @@ -16,3 +16,7 @@ libvirt_qemu.def *.s remote_protocol-structs-t virt-aa-helper +libvirt_functions.stp +libvirt_probes.stp +probes.o +probes.h diff --git a/src/Makefile.am b/src/Makefile.am index 7f2f5e5..27fac3f 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -25,6 +25,9 @@ AM_LDFLAGS = $(COVERAGE_LDFLAGS) EXTRA_DIST = $(conf_DATA) util/keymaps.csv BUILT_SOURCES = +CLEANFILES = +DISTCLEANFILES = +MAINTAINERCLEANFILES = if WITH_NETWORK UUID=$(shell uuidgen 2>/dev/null) @@ -1249,6 +1252,33 @@ libvirt_la_CFLAGS = -DIN_LIBVIRT $(AM_CFLAGS) # picked out for us. libvirt_la_DEPENDENCIES = $(libvirt_la_BUILT_LIBADD) $(LIBVIRT_SYMBOL_FILE) +if WITH_DTRACE +libvirt_la_LIBADD += probes.o +nodist_libvirt_la_SOURCES = probes.h + +BUILT_SOURCES += probes.h libvirt_probes.stp libvirt_functions.stp + +tapsetdir = $(datadir)/systemtap/tapset +tapset_DATA = libvirt_probes.stp libvirt_functions.stp + +probes.h: probes.d + $(AM_V_GEN)$(DTRACE) -o $@ -h -s $< + +probes.o: probes.d + $(AM_V_GEN)$(DTRACE) -o $@ -G -s $< + +libvirt_functions.stp: $(wildcard */*.x) $(srcdir)/rpc/gensystemtap.pl + $(AM_V_GEN)perl -w $(srcdir)/rpc/gensystemtap.pl $(wildcard */*.x) > $@ + +libvirt_probes.stp: probes.d $(srcdir)/dtrace2systemtap.pl + $(AM_V_GEN)perl -w $(srcdir)/dtrace2systemtap.pl $< > $@ + +CLEANFILES += probes.h probes.o libvirt_functions.stp libvirt_probes.stp +endif + +EXTRA_DIST += probes.d + + # Create an automake "convenience library" version of libvirt_la, # just for testing, since the test harness requires access to internal # bits and pieces that we don't want to make publicly accessible. @@ -1432,6 +1462,9 @@ libvirt_lxc_LDADD = $(CAPNG_LIBS) $(YAJL_LIBS) \ $(LIBXML_LIBS) $(NUMACTL_LIBS) $(LIB_PTHREAD) \ $(LIBNL_LIBS) $(AUDIT_LIBS) $(DEVMAPPER_LIBS) \ ../gnulib/lib/libgnu.la +if WITH_DTRACE +libvirt_lxc_LDADD += probes.o +endif libvirt_lxc_CFLAGS = \ $(LIBPARTED_CFLAGS) \ $(NUMACTL_CFLAGS) \ @@ -1545,6 +1578,6 @@ if WITH_NETWORK endif rmdir "$(DESTDIR)$(localstatedir)/lib/libvirt" ||: -CLEANFILES = *.gcov .libs/*.gcda .libs/*.gcno *.gcno *.gcda *.i *.s -DISTCLEANFILES = $(GENERATED_SYM_FILES) -MAINTAINERCLEANFILES = $(REMOTE_DRIVER_GENERATED) $(VIR_NET_RPC_GENERATED) $(ESX_DRIVER_GENERATED) +CLEANFILES += *.gcov .libs/*.gcda .libs/*.gcno *.gcno *.gcda *.i *.s +DISTCLEANFILES += $(GENERATED_SYM_FILES) +MAINTAINERCLEANFILES += $(REMOTE_DRIVER_GENERATED) $(VIR_NET_RPC_GENERATED) $(ESX_DRIVER_GENERATED) diff --git a/src/dtrace2systemtap.pl b/src/dtrace2systemtap.pl new file mode 100644 index 0000000..fab066b --- /dev/null +++ b/src/dtrace2systemtap.pl @@ -0,0 +1,104 @@ +#!/usr/bin/perl +# +# 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> +# +# Generate a set of systemtap probe definitions corresponding to +# DTrace probe markers in libvirt.so +# +# perl dtrace2systemtap.pl probes.d > libvirt_probes.stp +# + +use strict; +use warnings; + +my $file; +my @files; +my %files; + +my $probe; +my $args; + +# Read the DTraceprobes definition +while (<>) { + next if m,^\s*$,; + + next if /^\s*provider\s+\w+\s*{\s*$/; + next if /^\s*};\s*$/; + + if (m,^\s*\#\s*file:\s*(\S+)\s*$,) { + $file = $1; + push @files, $file; + $files{$file} = { prefix => undef, probes => [] }; + } elsif (m,^\s*\#\s*prefix:\s*(\S+)\s*$,) { + $files{$file}->{prefix} = $1; + } else { + if (m,\s*probe\s+([a-zA-Z0-9_]+)\((.*?)(\);)?$,) { + $probe = $1; + $args = $2; + if ($3) { + push @{$files{$file}->{probes}}, [$probe, $args]; + $probe = $args = undef; + } + } elsif ($probe) { + if (m,^(.*?)(\);)?$,) { + $args .= $1; + if ($2) { + push @{$files{$file}->{probes}}, [$probe, $args]; + $probe = $args = undef; + } + } else { + die "unexpected data $_ on line $."; + } + } else { + die "unexpected data $_ on line $."; + } + } +} + +# Write out the SystemTap probes +foreach my $file (@files) { + my $prefix = $files{$file}->{prefix}; + my @probes = @{$files{$file}->{probes}}; + + print "# $file\n\n"; + foreach my $probe (@probes) { + my $name = $probe->[0]; + my $args = $probe->[1]; + + my $pname = $name; + $pname =~ s/${prefix}_/libvirt.$prefix./; + + print "probe $pname = process(\"libvirt.so\").mark(\"$name\") {\n"; + + my @args = split /,/, $args; + for (my $i = 0 ; $i <= $#args ; $i++) { + my $arg = $args[$i]; + my $isstr = $arg =~ /char\s+\*/; + $arg =~ s/^.*\s\*?(\S+)$/$1/; + + if ($isstr) { + print " $arg = user_string(\$arg", $i + 1, ");\n"; + } else { + print " $arg = \$arg", $i + 1, ";\n"; + } + } + print "}\n\n"; + } + print "\n"; +} diff --git a/src/internal.h b/src/internal.h index 1997031..5e1e0b6 100644 --- a/src/internal.h +++ b/src/internal.h @@ -242,4 +242,77 @@ /* divide value by size, rounding up */ # define VIR_DIV_UP(value, size) (((value) + (size) - 1) / (size)) + +# if WITH_DTRACE +# ifndef LIBVIRT_PROBES_H +# define LIBVIRT_PROBES_H +# include "probes.h" +# endif /* LIBVIRT_PROBES_H */ + +/* Systemtap 1.2 headers have a bug where they cannot handle a + * variable declared with array type. Work around this by casting all + * arguments. This is some gross use of the preprocessor because + * PROBE is a var-arg macro, but it is better than the alternative of + * making all callers to PROBE have to be aware of the issues. And + * hopefully, if we ever add a call to PROBE with other than 9 + * end arguments, you can figure out the pattern to extend this hack. + */ +# define VIR_COUNT_ARGS(...) VIR_ARG11(__VA_ARGS__, 10, 9, 8, 7, 6, 5, 4, 3, 2, 1) +# define VIR_ARG11(_1, _2, _3, _4, _5, _6, _7, _8, _9, _10, _11, ...) _11 +# define VIR_ADD_CAST_EXPAND(a, b, ...) VIR_ADD_CAST_PASTE(a, b, __VA_ARGS__) +# define VIR_ADD_CAST_PASTE(a, b, ...) a##b(__VA_ARGS__) + +/* The double cast is necessary to silence gcc warnings; any pointer + * can safely go to intptr_t and back to void *, which collapses + * arrays into pointers; while any integer can be widened to intptr_t + * then cast to void *. */ +# define VIR_ADD_CASTXXXX(a) ((void *)(intptr_t)(a)) +# define VIR_ADD_CAST(a) (a) +# define VIR_ADD_CAST1(a) \ + VIR_ADD_CAST(a) +# define VIR_ADD_CAST2(a, b) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b) +# define VIR_ADD_CAST3(a, b, c) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c) +# define VIR_ADD_CAST4(a, b, c, d) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d) +# define VIR_ADD_CAST5(a, b, c, d, e) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d), VIR_ADD_CAST(e) +# define VIR_ADD_CAST6(a, b, c, d, e, f) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d), VIR_ADD_CAST(e), VIR_ADD_CAST(f) +# define VIR_ADD_CAST7(a, b, c, d, e, f, g) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d), VIR_ADD_CAST(e), VIR_ADD_CAST(f), \ + VIR_ADD_CAST(g) +# define VIR_ADD_CAST8(a, b, c, d, e, f, g, h) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d), VIR_ADD_CAST(e), VIR_ADD_CAST(f), \ + VIR_ADD_CAST(g), VIR_ADD_CAST(h) +# define VIR_ADD_CAST9(a, b, c, d, e, f, g, h, i) \ + VIR_ADD_CAST(a), VIR_ADD_CAST(b), VIR_ADD_CAST(c), \ + VIR_ADD_CAST(d), VIR_ADD_CAST(e), VIR_ADD_CAST(f), \ + VIR_ADD_CAST(g), VIR_ADD_CAST(h), VIR_ADD_CAST(i) + +# define VIR_ADD_CASTS(...) \ + VIR_ADD_CAST_EXPAND(VIR_ADD_CAST, VIR_COUNT_ARGS(__VA_ARGS__), \ + __VA_ARGS__) + +# define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) +# define PROBE(NAME, FMT, ...) \ + VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ + #NAME ": " FMT, __VA_ARGS__); \ + if (LIBVIRT_ ## NAME ## _ENABLED()) { \ + PROBE_EXPAND(LIBVIRT_ ## NAME, \ + VIR_ADD_CASTS(__VA_ARGS__)); \ + } +# else +# define PROBE(NAME, FMT, ...) \ + VIR_DEBUG_INT("trace." __FILE__, __func__, __LINE__, \ + #NAME ": " FMT, __VA_ARGS__); +# endif + + #endif /* __VIR_INTERNAL_H__ */ diff --git a/src/probes.d b/src/probes.d new file mode 100644 index 0000000..202e0a7 --- /dev/null +++ b/src/probes.d @@ -0,0 +1,72 @@ +provider libvirt { + # file: src/util/event_poll.c + # prefix: event_poll + probe event_poll_add_handle(int watch, int fd, int events, void *cb, void *opaque, void *ff); + probe event_poll_update_handle(int watch, int events); + probe event_poll_remove_handle(int watch); + probe event_poll_dispatch_handle(int watch, int events); + probe event_poll_purge_handle(int watch); + + probe event_poll_add_timeout(int timer, int frequency, void *cb, void *opaque, void *ff); + probe event_poll_update_timeout(int timer, int frequency); + probe event_poll_remove_timeout(int timer); + probe event_poll_dispatch_timeout(int timer); + probe event_poll_purge_timeout(int timer); + + probe event_poll_run(int nfds, int timeout); + + + # file: src/rpc/virnetsocket.c + # prefix: rpc + probe rpc_socket_new(void *sock, int refs, int fd, int errfd, int pid, const char *localAddr, const char *remoteAddr); + probe rpc_socket_ref(void *sock, int refs); + probe rpc_socket_free(void *sock, int refs); + + + # file: src/rpc/virnetserverclient.c + # prefix: rpc + probe rpc_server_client_new(void *client, int refs, void *sock); + probe rpc_server_client_ref(void *client, int refs); + probe rpc_server_client_free(void *client, int refs); + + probe rpc_server_client_msg_tx_queue(void *client, int len, int prog, int vers, int proc, int type, int status, int serial); + probe rpc_server_client_msg_rx(void *client, int len, int prog, int vers, int proc, int type, int status, int serial); + + + # file: src/rpc/virnetclient.c + # prefix: rpc + probe rpc_client_new(void *client, int refs, void *sock); + probe rpc_client_ref(void *client, int refs); + probe rpc_client_free(void *client, int refs); + + probe rpc_client_msg_tx_queue(void *client, int len, int prog, int vers, int proc, int type, int status, int serial); + probe rpc_client_msg_rx(void *client, int len, int prog, int vers, int proc, int type, int status, int serial); + + + # file: daemon/libvirtd.c + # prefix: rpc + probe rpc_server_client_auth_allow(void *client, int authtype, const char *identity); + probe rpc_server_client_auth_deny(void *client, int authtype, const char *identity); + probe rpc_server_client_auth_fail(void *client, int authtype); + + + # file: src/rpc/virnettlscontext.c + # prefix: rpc + probe rpc_tls_context_new(void *ctxt, int refs, const char *cacert, const char *cacrl, + const char *cert, const char *key, int sanityCheckCert, int requireValidCert, int isServer); + probe rpc_tls_context_ref(void *ctxt, int refs); + probe rpc_tls_context_free(void *ctxt, int refs); + + probe rpc_tls_context_session_allow(void *ctxt, void *sess, const char *dname); + probe rpc_tls_context_session_deny(void *ctxt, void *sess, const char *dname); + probe rpc_tls_context_session_fail(void *ctxt, void *sess); + + + probe rpc_tls_session_new(void *sess, void *ctxt, int refs, const char *hostname, int isServer); + probe rpc_tls_session_ref(void *sess, int refs); + probe rpc_tls_session_free(void *sess, int refs); + + probe rpc_tls_session_handshake_pass(void *sess); + probe rpc_tls_session_handshake_fail(void *sess); + +}; diff --git a/src/rpc/gensystemtap.pl b/src/rpc/gensystemtap.pl new file mode 100644 index 0000000..1cf9c0f --- /dev/null +++ b/src/rpc/gensystemtap.pl @@ -0,0 +1,195 @@ +#!/usr/bin/perl +# +# 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> +# +# Generate a set of systemtap functions for translating various +# RPC enum values into strings +# +# perl gensystemtap.pl */*.x > libvirt_functions.stp +# + +use strict; + +my %funcs; + +my %type; +my %status; +my %auth; + +my $instatus = 0; +my $intype = 0; +my $inauth = 0; +while (<>) { + if (/enum\s+virNetMessageType/) { + $intype = 1; + } elsif (/enum\s+virNetMessageStatus/) { + $instatus = 1; + } elsif (/enum remote_auth_type/) { + $inauth = 1; + } elsif (/}/) { + $instatus = $intype = $inauth = 0; + } elsif ($instatus) { + if (/^\s+VIR_NET_(\w+)\s*=\s*(\d+),?$/) { + $status{$2} = lc $1; + } + } elsif ($intype) { + if (/^\s+VIR_NET_(\w+)\s*=\s*(\d+),?$/) { + $type{$2} = lc $1; + } + } elsif ($inauth) { + if (/^\s+REMOTE_AUTH_(\w+)\s*=\s*(\d+),?$/) { + $auth{$2} = lc $1; + } + } else { + if (/(\w+)_PROGRAM\s*=\s*0x([a-fA-F0-9]+)\s*;/) { + $funcs{lc $1} = { id => hex($2), version => undef, progs => [] }; + } elsif (/(\w+)_PROTOCOL_VERSION\s*=\s*(\d+)\s*;/) { + $funcs{lc $1}->{version} = $2; + } elsif (/(\w+)_PROC_(.*?)\s+=\s+(\d+)/) { + $funcs{lc $1}->{progs}->[$3] = lc $2; + } + } +} + +print <<EOF; +function libvirt_rpc_auth_name(type, verbose) +{ +EOF +my $first = 1; +foreach my $type (keys %auth) { + my $cond = $first ? "if" : "} else if"; + $first = 0; + print " $cond (type == ", $type, ") {\n"; + print " typestr = \"", $auth{$type}, "\"\n"; +} +print <<EOF; + } else { + typestr = "unknown"; + verbose = 1; + } + if (verbose) { + typestr = typestr . sprintf(":%d", type) + } + return typestr; +} +EOF + +print <<EOF; +function libvirt_rpc_type_name(type, verbose) +{ +EOF +$first = 1; +foreach my $type (keys %type) { + my $cond = $first ? "if" : "} else if"; + $first = 0; + print " $cond (type == ", $type, ") {\n"; + print " typestr = \"", $type{$type}, "\"\n"; +} +print <<EOF; + } else { + typestr = "unknown"; + verbose = 1; + } + if (verbose) { + typestr = typestr . sprintf(":%d", type) + } + return typestr; +} +EOF + +print <<EOF; +function libvirt_rpc_status_name(status, verbose) +{ +EOF +$first = 1; +foreach my $status (keys %status) { + my $cond = $first ? "if" : "} else if"; + $first = 0; + print " $cond (status == ", $status, ") {\n"; + print " statusstr = \"", $status{$status}, "\"\n"; +} +print <<EOF; + } else { + statusstr = "unknown"; + verbose = 1; + } + if (verbose) { + statusstr = statusstr . sprintf(":%d", status) + } + return statusstr; +} +EOF + +print <<EOF; +function libvirt_rpc_program_name(program, verbose) +{ +EOF +$first = 1; +foreach my $prog (keys %funcs) { + my $cond = $first ? "if" : "} else if"; + $first = 0; + print " $cond (program == ", $funcs{$prog}->{id}, ") {\n"; + print " programstr = \"", $prog, "\"\n"; +} +print <<EOF; + } else { + programstr = "unknown"; + verbose = 1; + } + if (verbose) { + programstr = programstr . sprintf(":%d", program) + } + return programstr; +} +EOF + + +print <<EOF; +function libvirt_rpc_procedure_name(program, version, proc, verbose) +{ +EOF +$first = 1; +foreach my $prog (keys %funcs) { + my $cond = $first ? "if" : "} else if"; + $first = 0; + print " $cond (program == ", $funcs{$prog}->{id}, " && version == ", $funcs{$prog}->{version}, ") {\n"; + + my $pfirst = 1; + for (my $id = 1 ; $id <= $#{$funcs{$prog}->{progs}} ; $id++) { + my $cond = $pfirst ? "if" : "} else if"; + $pfirst = 0; + print " $cond (proc == $id) {\n"; + print " procstr = \"", $funcs{$prog}->{progs}->[$id], "\";\n"; + } + print " } else {\n"; + print " procstr = \"unknown\";\n"; + print " verbose = 1;\n"; + print " }\n"; +} +print <<EOF; + } else { + procstr = "unknown"; + verbose = 1; + } + if (verbose) { + procstr = procstr . sprintf(":%d", proc) + } + return procstr; +} +EOF diff --git a/src/rpc/virnetclient.c b/src/rpc/virnetclient.c index b2c528a..085dc8d 100644 --- a/src/rpc/virnetclient.c +++ b/src/rpc/virnetclient.c @@ -157,7 +157,10 @@ static virNetClientPtr virNetClientNew(virNetSocketPtr sock, VIR_DEBUG("Failed to add event watch, disabling events"); } - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_CLIENT_NEW, + "client=%p refs=%d sock=%p", + client, client->refs, client->sock); + return client; no_memory: @@ -228,7 +231,9 @@ void virNetClientRef(virNetClientPtr client) { virNetClientLock(client); client->refs++; - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_CLIENT_REF, + "client=%p refs=%d", + client, client->refs); virNetClientUnlock(client); } @@ -261,7 +266,9 @@ void virNetClientFree(virNetClientPtr client) return; virNetClientLock(client); - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_CLIENT_FREE, + "client=%p refs=%d", + client, client->refs); client->refs--; if (client->refs > 0) { virNetClientUnlock(client); @@ -680,10 +687,11 @@ virNetClientCallDispatch(virNetClientPtr client) if (virNetMessageDecodeHeader(&client->msg) < 0) return -1; - VIR_DEBUG("Incoming message prog %d vers %d proc %d type %d status %d serial %d", - client->msg.header.prog, client->msg.header.vers, - client->msg.header.proc, client->msg.header.type, - client->msg.header.status, client->msg.header.serial); + PROBE(RPC_CLIENT_MSG_RX, + "client=%p len=%zu prog=%u vers=%u proc=%u type=%u status=%u serial=%u", + client, client->msg.bufferLength, + client->msg.header.prog, client->msg.header.vers, client->msg.header.proc, + client->msg.header.type, client->msg.header.status, client->msg.header.serial); switch (client->msg.header.type) { case VIR_NET_REPLY: /* Normal RPC replies */ @@ -1197,6 +1205,12 @@ int virNetClientSend(virNetClientPtr client, virNetClientCallPtr call; int ret = -1; + PROBE(RPC_CLIENT_MSG_TX_QUEUE, + "client=%p len=%zu prog=%u vers=%u proc=%u type=%u status=%u serial=%u", + client, msg->bufferLength, + msg->header.prog, msg->header.vers, msg->header.proc, + msg->header.type, msg->header.status, msg->header.serial); + if (expectReply && (msg->bufferLength != 0) && (msg->header.status == VIR_NET_CONTINUE)) { diff --git a/src/rpc/virnetserverclient.c b/src/rpc/virnetserverclient.c index 412814d..05077d6 100644 --- a/src/rpc/virnetserverclient.c +++ b/src/rpc/virnetserverclient.c @@ -328,7 +328,9 @@ virNetServerClientPtr virNetServerClientNew(virNetSocketPtr sock, client->rx->bufferLength = VIR_NET_MESSAGE_LEN_MAX; client->nrequests = 1; - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_SERVER_CLIENT_NEW, + "client=%p refs=%d sock=%p", + client, client->refs, client->sock); return client; @@ -343,7 +345,9 @@ void virNetServerClientRef(virNetServerClientPtr client) { virNetServerClientLock(client); client->refs++; - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_SERVER_CLIENT_REF, + "client=%p refs=%d", + client, client->refs); virNetServerClientUnlock(client); } @@ -535,7 +539,9 @@ void virNetServerClientFree(virNetServerClientPtr client) return; virNetServerClientLock(client); - VIR_DEBUG("client=%p refs=%d", client, client->refs); + PROBE(RPC_SERVER_CLIENT_FREE, + "client=%p refs=%d", + client, client->refs); client->refs--; if (client->refs > 0) { @@ -772,6 +778,12 @@ readmore: return; } + PROBE(RPC_SERVER_CLIENT_MSG_RX, + "client=%p len=%zu prog=%u vers=%u proc=%u type=%u status=%u serial=%u", + client, msg->bufferLength, + msg->header.prog, msg->header.vers, msg->header.proc, + msg->header.type, msg->header.status, msg->header.serial); + /* Maybe send off for queue against a filter */ filter = client->filters; while (filter) { @@ -979,6 +991,11 @@ int virNetServerClientSendMessage(virNetServerClientPtr client, virNetServerClientLock(client); if (client->sock && !client->wantClose) { + PROBE(RPC_SERVER_CLIENT_MSG_TX_QUEUE, + "client=%p len=%zu prog=%u vers=%u proc=%u type=%u status=%u serial=%u", + client, msg->bufferLength, + msg->header.prog, msg->header.vers, msg->header.proc, + msg->header.type, msg->header.status, msg->header.serial); virNetMessageQueuePush(&client->tx, msg); virNetServerClientUpdateEvent(client); diff --git a/src/rpc/virnetsocket.c b/src/rpc/virnetsocket.c index 93e062a..e4289b1 100644 --- a/src/rpc/virnetsocket.c +++ b/src/rpc/virnetsocket.c @@ -170,8 +170,10 @@ static virNetSocketPtr virNetSocketNew(virSocketAddrPtr localAddr, sock->client = isClient; - VIR_DEBUG("sock=%p localAddrStr=%s remoteAddrStr=%s", - sock, NULLSTR(sock->localAddrStr), NULLSTR(sock->remoteAddrStr)); + PROBE(RPC_SOCKET_NEW, + "sock=%p refs=%d fd=%d errfd=%d pid=%d localAddr=%s, remoteAddr=%s", + sock, sock->refs, fd, errfd, + pid, NULLSTR(sock->localAddrStr), NULLSTR(sock->remoteAddrStr)); return sock; @@ -659,6 +661,9 @@ void virNetSocketRef(virNetSocketPtr sock) { virMutexLock(&sock->lock); sock->refs++; + PROBE(RPC_SOCKET_REF, + "sock=%p refs=%d", + sock, sock->refs); virMutexUnlock(&sock->lock); } @@ -669,6 +674,10 @@ void virNetSocketFree(virNetSocketPtr sock) return; virMutexLock(&sock->lock); + PROBE(RPC_SOCKET_FREE, + "sock=%p refs=%d", + sock, sock->refs); + sock->refs--; if (sock->refs > 0) { virMutexUnlock(&sock->lock); diff --git a/src/rpc/virnettlscontext.c b/src/rpc/virnettlscontext.c index f3cc769..74a61e0 100644 --- a/src/rpc/virnettlscontext.c +++ b/src/rpc/virnettlscontext.c @@ -650,9 +650,6 @@ static virNetTLSContextPtr virNetTLSContextNew(const char *cacert, char *gnutlsdebug; int err; - VIR_DEBUG("cacert=%s cacrl=%s cert=%s key=%s sanityCheckCert=%d requireValid=%d isServer=%d", - cacert, NULLSTR(cacrl), cert, key, sanityCheckCert, requireValidCert, isServer); - if (VIR_ALLOC(ctxt) < 0) { virReportOOMError(); return NULL; @@ -721,6 +718,10 @@ static virNetTLSContextPtr virNetTLSContextNew(const char *cacert, ctxt->x509dnWhitelist = x509dnWhitelist; ctxt->isServer = isServer; + PROBE(RPC_TLS_CONTEXT_NEW, + "ctxt=%p refs=%d cacert=%s cacrl=%s cert=%s key=%s sanityCheckCert=%d requireValidCert=%d isServer=%d", + ctxt, ctxt->refs, cacert, NULLSTR(cacrl), cert, key, sanityCheckCert, requireValidCert, isServer); + return ctxt; error: @@ -933,6 +934,9 @@ void virNetTLSContextRef(virNetTLSContextPtr ctxt) { virMutexLock(&ctxt->lock); ctxt->refs++; + PROBE(RPC_TLS_CONTEXT_REF, + "ctxt=%p refs=%d", + ctxt, ctxt->refs); virMutexUnlock(&ctxt->lock); } @@ -1056,24 +1060,24 @@ static int virNetTLSContextValidCertificate(virNetTLSContextPtr ctxt, gnutls_x509_crt_deinit(cert); } -#if 0 - PROBE(CLIENT_TLS_ALLOW, "fd=%d, name=%s", - virNetServerClientGetFD(client), name); -#endif + PROBE(RPC_TLS_CONTEXT_SESSION_ALLOW, + "ctxt=%p sess=%p dname=%s", + ctxt, sess, dname); + return 0; authdeny: -#if 0 - PROBE(CLIENT_TLS_DENY, "fd=%d, name=%s", - virNetServerClientGetFD(client), name); -#endif + PROBE(RPC_TLS_CONTEXT_SESSION_DENY, + "ctxt=%p sess=%p dname=%s", + ctxt, sess, dname); + return -1; authfail: -#if 0 - PROBE(CLIENT_TLS_FAIL, "fd=%d", - virNetServerClientGetFD(client)); -#endif + PROBE(RPC_TLS_CONTEXT_SESSION_FAIL, + "ctxt=%p sess=%p", + ctxt, sess); + return -1; } @@ -1111,6 +1115,9 @@ void virNetTLSContextFree(virNetTLSContextPtr ctxt) return; virMutexLock(&ctxt->lock); + PROBE(RPC_TLS_CONTEXT_FREE, + "ctxt=%p refs=%d", + ctxt, ctxt->refs); ctxt->refs--; if (ctxt->refs > 0) { virMutexUnlock(&ctxt->lock); @@ -1225,6 +1232,10 @@ virNetTLSSessionPtr virNetTLSSessionNew(virNetTLSContextPtr ctxt, sess->isServer = ctxt->isServer; + PROBE(RPC_TLS_SESSION_NEW, + "sess=%p refs=%d ctxt=%p hostname=%s isServer=%d", + sess, sess->refs, ctxt, hostname, sess->isServer); + return sess; error: @@ -1237,6 +1248,9 @@ void virNetTLSSessionRef(virNetTLSSessionPtr sess) { virMutexLock(&sess->lock); sess->refs++; + PROBE(RPC_TLS_SESSION_REF, + "sess=%p refs=%d", + sess, sess->refs); virMutexUnlock(&sess->lock); } @@ -1388,6 +1402,9 @@ void virNetTLSSessionFree(virNetTLSSessionPtr sess) return; virMutexLock(&sess->lock); + PROBE(RPC_TLS_SESSION_FREE, + "sess=%p refs=%d", + sess, sess->refs); sess->refs--; if (sess->refs > 0) { virMutexUnlock(&sess->lock); diff --git a/src/util/event_poll.c b/src/util/event_poll.c index e8679b8..0b75471 100644 --- a/src/util/event_poll.c +++ b/src/util/event_poll.c @@ -109,7 +109,6 @@ int virEventPollAddHandle(int fd, int events, void *opaque, virFreeCallback ff) { int watch; - EVENT_DEBUG("Add handle fd=%d events=%d cb=%p opaque=%p", fd, events, cb, opaque); virMutexLock(&eventLoop.lock); if (eventLoop.handlesCount == eventLoop.handlesAlloc) { EVENT_DEBUG("Used %zu handle slots, adding at least %d more", @@ -135,6 +134,10 @@ int virEventPollAddHandle(int fd, int events, eventLoop.handlesCount++; virEventPollInterruptLocked(); + + PROBE(EVENT_POLL_ADD_HANDLE, + "watch=%d fd=%d events=%d cb=%p opaque=%p ff=%p", + watch, fd, events, cb, opaque, ff); virMutexUnlock(&eventLoop.lock); return watch; @@ -142,7 +145,9 @@ int virEventPollAddHandle(int fd, int events, void virEventPollUpdateHandle(int watch, int events) { int i; - EVENT_DEBUG("Update handle w=%d e=%d", watch, events); + PROBE(EVENT_POLL_UPDATE_HANDLE, + "watch=%d events=%d", + watch, events); if (watch <= 0) { VIR_WARN("Ignoring invalid update watch %d", watch); @@ -169,7 +174,9 @@ void virEventPollUpdateHandle(int watch, int events) { */ int virEventPollRemoveHandle(int watch) { int i; - EVENT_DEBUG("Remove handle w=%d", watch); + PROBE(EVENT_POLL_REMOVE_HANDLE, + "watch=%d", + watch); if (watch <= 0) { VIR_WARN("Ignoring invalid remove watch %d", watch); @@ -206,7 +213,7 @@ int virEventPollAddTimeout(int frequency, { unsigned long long now; int ret; - EVENT_DEBUG("Adding timer %d with %d ms freq", nextTimer, frequency); + if (virTimeMs(&now) < 0) { return -1; } @@ -234,6 +241,10 @@ int virEventPollAddTimeout(int frequency, eventLoop.timeoutsCount++; ret = nextTimer-1; virEventPollInterruptLocked(); + + PROBE(EVENT_POLL_ADD_TIMEOUT, + "timer=%d frequency=%d cb=%p opaque=%p ff=%p", + ret, frequency, cb, opaque, ff); virMutexUnlock(&eventLoop.lock); return ret; } @@ -242,7 +253,9 @@ void virEventPollUpdateTimeout(int timer, int frequency) { unsigned long long now; int i; - EVENT_DEBUG("Updating timer %d timeout with %d ms freq", timer, frequency); + PROBE(EVENT_POLL_UPDATE_TIMEOUT, + "timer=%d frequency=%d", + timer, frequency); if (timer <= 0) { VIR_WARN("Ignoring invalid update timer %d", timer); @@ -274,7 +287,9 @@ void virEventPollUpdateTimeout(int timer, int frequency) */ int virEventPollRemoveTimeout(int timer) { int i; - EVENT_DEBUG("Remove timer %d", timer); + PROBE(EVENT_POLL_REMOVE_TIMEOUT, + "timer=%d", + timer); if (timer <= 0) { VIR_WARN("Ignoring invalid remove timer %d", timer); @@ -417,6 +432,9 @@ static int virEventPollDispatchTimeouts(void) eventLoop.timeouts[i].expiresAt = now + eventLoop.timeouts[i].frequency; + PROBE(EVENT_POLL_DISPATCH_TIMEOUT, + "timer=%d", + timer); virMutexUnlock(&eventLoop.lock); (cb)(timer, opaque); virMutexLock(&eventLoop.lock); @@ -464,8 +482,9 @@ static int virEventPollDispatchHandles(int nfds, struct pollfd *fds) { int watch = eventLoop.handles[i].watch; void *opaque = eventLoop.handles[i].opaque; int hEvents = virEventPollFromNativeEvents(fds[n].revents); - EVENT_DEBUG("Dispatch n=%d f=%d w=%d e=%d %p", i, - fds[n].fd, watch, fds[n].revents, opaque); + PROBE(EVENT_POLL_DISPATCH_HANDLE, + "watch=%d events=%d", + watch, hEvents); virMutexUnlock(&eventLoop.lock); (cb)(watch, fds[n].fd, hEvents, opaque); virMutexLock(&eventLoop.lock); @@ -494,8 +513,9 @@ static void virEventPollCleanupTimeouts(void) { continue; } - EVENT_DEBUG("Purging timeout %d with id %d", i, - eventLoop.timeouts[i].timer); + PROBE(EVENT_POLL_PURGE_TIMEOUT, + "timer=%d", + eventLoop.timeouts[i].timer); if (eventLoop.timeouts[i].ff) { virFreeCallback ff = eventLoop.timeouts[i].ff; void *opaque = eventLoop.timeouts[i].opaque; @@ -541,6 +561,9 @@ static void virEventPollCleanupHandles(void) { continue; } + PROBE(EVENT_POLL_PURGE_HANDLE, + "watch=%d", + eventLoop.handles[i].watch); if (eventLoop.handles[i].ff) { virFreeCallback ff = eventLoop.handles[i].ff; void *opaque = eventLoop.handles[i].opaque; @@ -590,7 +613,9 @@ int virEventPollRunOnce(void) { virMutexUnlock(&eventLoop.lock); retry: - EVENT_DEBUG("Poll on %d handles %p timeout %d", nfds, fds, timeout); + PROBE(EVENT_POLL_RUN, + "nhandles=%d imeout=%d", + nfds, timeout); ret = poll(fds, nfds, timeout); if (ret < 0) { EVENT_DEBUG("Poll got error event %d", errno); -- 1.7.6.4

From: "Daniel P. Berrange" <berrange@redhat.com> This removes the old example for legacy probes and adds two new scripts demonstrating many of the new probe point facilities. The rpc-monitor.stp script will print out friendly detaisl of all RPC traffic between a libvirt client/server. This is incredibly useful in seeing what RPC calls are being made, and also debugging problems in the RPC protocol code The events.stp script will print out lots of info about the poll event loop, which is useful for debugging event handling problems * examples/systemtap/events.stp< examples/systemtap/rpc-monitor.stp: New examples * examples/systemtap/client.stp: Remove obsolete example --- examples/systemtap/Makefile.am | 3 +- examples/systemtap/client.stp | 28 ------- examples/systemtap/events.stp | 133 ++++++++++++++++++++++++++++++ examples/systemtap/rpc-monitor.stp | 158 ++++++++++++++++++++++++++++++++++++ 4 files changed, 293 insertions(+), 29 deletions(-) delete mode 100644 examples/systemtap/client.stp create mode 100644 examples/systemtap/events.stp create mode 100644 examples/systemtap/rpc-monitor.stp diff --git a/examples/systemtap/Makefile.am b/examples/systemtap/Makefile.am index 6eb0546..df4e476 100644 --- a/examples/systemtap/Makefile.am +++ b/examples/systemtap/Makefile.am @@ -1,4 +1,5 @@ ## Copyright (C) 2005-2011 Red Hat, Inc. ## See COPYING.LIB for the License of this software -EXTRA_DIST = client.stp +EXTRA_DIST = $(wildcard *.stp) + diff --git a/examples/systemtap/client.stp b/examples/systemtap/client.stp deleted file mode 100644 index bf32402..0000000 --- a/examples/systemtap/client.stp +++ /dev/null @@ -1,28 +0,0 @@ -#!/usr/bin/stap - -probe libvirt.daemon.client.connect { - printf("Client fd=%d connected readonly=%d addr=%s\n", fd, readonly, addr); -} -probe libvirt.daemon.client.disconnect { - printf("Client fd=%d disconnected addr=%s\n", fd, addr); -} - -probe libvirt.daemon.client.tls_allow { - printf("Client fd=%d tls allow %s\n", fd, x509dname); -} -probe libvirt.daemon.client.tls_deny { - printf("Client fd=%d tls deny %s\n", fd, x509dname); -} -probe libvirt.daemon.client.tls_fail { - printf("Client fd=%d tls fail\n", fd); -} - -probe libvirt.daemon.client.auth_allow { - printf("Client fd=%d auth %s allow %s\n", fd, authname, identity); -} -probe libvirt.daemon.client.auth_deny { - printf("Client fd=%d auth %s deny %s\n", fd, authname, identity); -} -probe libvirt.daemon.client.auth_fail { - printf("Client fd=%d auth %s fail\n", fd, authname); -} diff --git a/examples/systemtap/events.stp b/examples/systemtap/events.stp new file mode 100644 index 0000000..b148630 --- /dev/null +++ b/examples/systemtap/events.stp @@ -0,0 +1,133 @@ +#!/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 operation of the libvirt event loop +# in both client and server. Example output is: +# +# 0.000 begin +# 2.359 18185 + handle 1 4 1 +# 2.360 18185 + handle 2 6 1 +# 2.360 18185 * handle 2 0 +# 2.360 14370 > handle 3 1 +# 2.360 14370 + handle 33 16 1 +# 2.361 14370 ~ 7 -1 +# 2.361 14370 > handle 33 1 +# 2.361 14370 * handle 33 1 +# 2.361 14370 * handle 33 1 +# 2.361 14370 * handle 33 3 +# 2.361 14370 ~ 7 -1 +# 2.361 14370 > handle 1 1 +# 2.361 14370 ~ 7 -1 +# 2.361 14370 > handle 33 2 +# 2.361 14370 * handle 33 1 +# 2.361 14370 ~ 7 -1 +# 2.361 18185 * handle 2 1 +# 2.362 18185 * handle 2 0 +# 2.362 14370 > handle 33 1 +# 2.362 14370 * handle 33 1 +# 2.362 14370 * handle 33 1 +# 2.362 14370 ~ 7 -1 +# 2.367 14370 * handle 33 3 +# 2.367 14370 > handle 1 1 +# 2.367 14370 ~ 7 -1 +# 2.367 14370 > handle 33 2 +# 2.367 14370 * handle 33 1 +# 2.367 14370 ~ 7 -1 +# 2.370 18185 - timeout 1 +# 2.370 14370 ! handle 33 +# 2.371 14370 - handle 33 +# 2.371 14370 ~ 6 -1 +# +# Legend: +# + Add +# - Remove +# * Update +# > dispatch +# ! purge +# ~ Iterate +# +# + +# Show all updates to registered timeouts/handles +global showUpdates = 1 + +# Show when handles/timeouts are dispatched +global showDispatch = 1 + +# Show iterations of the event loop +global showIter = 1 + +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); +} + +probe begin { + start = gettimeofday_ns() / (1000*1000) + print_ts("begin"); +} + +probe libvirt.event_poll.add_handle { + print_ts(sprintf("%d + handle %d %d %d", pid(), watch, fd, events)); +} +probe libvirt.event_poll.remove_handle { + print_ts(sprintf("%d - handle %d", pid(), watch)); +} +probe libvirt.event_poll.update_handle { + if (showUpdates) + print_ts(sprintf("%d * handle %d %d", pid(), watch, events)); +} +probe libvirt.event_poll.purge_handle { + print_ts(sprintf("%d ! handle %d", pid(), watch)); +} +probe libvirt.event_poll.dispatch_handle { + if (showDispatch) + print_ts(sprintf("%d > handle %d %d", pid(), watch, events)); +} + +probe libvirt.event_poll.add_timeout { + print_ts(sprintf("%d + timeout %d %d", pid(), timer, frequency)); +} +probe libvirt.event_poll.remove_timeout { + print_ts(sprintf("%d - timeout %d", pid(), timer)); +} +probe libvirt.event_poll.update_timeout { + if (showUpdates) + print_ts(sprintf("%d * timeout %d %d", pid(), timer, frequency)); +} +probe libvirt.event_poll.purge_timeout { + print_ts(sprintf("%d ! timeout %d", pid(), timer)); +} + +probe libvirt.event_poll.dispatch_timeout { + if (showDispatch) + print_ts(sprintf("%d > timeout %d", pid(), timer)); +} + +probe libvirt.event_poll.run { + if (showIter) + print_ts(sprintf("%d ~ %d %d", pid(), nfds, timeout)); +} \ No newline at end of file diff --git a/examples/systemtap/rpc-monitor.stp b/examples/systemtap/rpc-monitor.stp new file mode 100644 index 0000000..b868bf7 --- /dev/null +++ b/examples/systemtap/rpc-monitor.stp @@ -0,0 +1,158 @@ +#!/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 RPC messages going in/out of libvirtd and +# any connected clients. Example output: +# +# 0.000 begin +# 2.632 C + 0x7f1ea57dc010 local=127.0.0.1;0 remote=127.0.0.1;0 +# 2.632 C > 0x7f1ea57dc010 msg=remote.1.auth_list(call, ok, 0) len=28 +# 2.632 + S 0x1c1f710 local=127.0.0.1;0 remote=127.0.0.1;0 +# 2.632 > S 0x1c1f710 msg=remote.1.auth_list(call, ok, 0) len=28 +# 2.633 < S 0x1c1f710 msg=remote.1.auth_list(reply, ok, 0) len=36 +# 2.633 C < 0x7f1ea57dc010 msg=remote.1.auth_list(reply, ok, 0) len=36 +# 2.633 C > 0x7f1ea57dc010 msg=remote.1.open(call, ok, 1) len=40 +# 2.633 > S 0x1c1f710 msg=remote.1.open(call, ok, 1) len=40 +# 2.639 < S 0x1c1f710 msg=remote.1.open(reply, ok, 1) len=28 +# 2.639 C < 0x7f1ea57dc010 msg=remote.1.open(reply, ok, 1) len=28 +# 2.639 C > 0x7f1ea57dc010 msg=remote.1.get_uri(call, ok, 2) len=28 +# 2.639 > S 0x1c1f710 msg=remote.1.get_uri(call, ok, 2) len=28 +# 2.639 < S 0x1c1f710 msg=remote.1.get_uri(reply, ok, 2) len=48 +# 2.640 C < 0x7f1ea57dc010 msg=remote.1.get_uri(reply, ok, 2) len=48 +# 2.640 C > 0x7f1ea57dc010 msg=remote.1.domain_lookup_by_id(call, ok, 3) len=32 +# 2.640 > S 0x1c1f710 msg=remote.1.domain_lookup_by_id(call, ok, 3) len=32 +# 2.640 < S 0x1c1f710 msg=remote.1.domain_lookup_by_id(reply, error, 3) len=180 +# 2.641 C < 0x7f1ea57dc010 msg=remote.1.domain_lookup_by_id(reply, error, 3) len=180 +# 2.641 C > 0x7f1ea57dc010 msg=remote.1.close(call, ok, 4) len=28 +# 2.641 > S 0x1c1f710 msg=remote.1.close(call, ok, 4) len=28 +# 2.641 < S 0x1c1f710 msg=remote.1.close(reply, ok, 4) len=28 +# 2.641 C < 0x7f1ea57dc010 msg=remote.1.close(reply, ok, 4) len=28 +# 2.641 C - 0x7f1ea57dc010 local= remote= +# 2.641 - S 0x1c1f710 local=127.0.0.1;0 remote=127.0.0.1;0 + + +global start + +# If this is set to '1', then all the raw RPC values are postfixed +# to the string translation +global verbose=0 + +# 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") +} + + +# Format an RPC message +function msginfo(prefix, client, len, prog, version, proc, type, status, serial) +{ + progstr = libvirt_rpc_program_name(prog, verbose); + procstr = libvirt_rpc_procedure_name(prog, version, proc, verbose); + typestr = libvirt_rpc_type_name(type, verbose); + statusstr = libvirt_rpc_status_name(status, verbose); + + + print_ts(sprintf("%s %-16p msg=%s.%d.%s(%s, %s, %d) len=%d", + prefix, client, progstr, version, procstr, + typestr, statusstr, serial, len)); +} + +# Catch all tx/rx of RPC messages by clients & libvirtd +probe libvirt.rpc.server_client_msg_rx { + if (len) + msginfo("> S", client, len, prog, vers, proc, type, status, serial) +} +probe libvirt.rpc.server_client_msg_tx_queue { + if (len) + msginfo("< S", client, len, prog, vers, proc, type, status, serial) +} +probe libvirt.rpc.client_msg_rx { + if (len) + msginfo("C <", client, len, prog, vers, proc, type, status, serial) +} +probe libvirt.rpc.client_msg_tx_queue { + if (len) + msginfo("C >", client, len, prog, vers, proc, type, status, serial) +} + + +# Used to track connection info +global localAddrs +global remoteAddrs; +global clientSocks +global serverSocks + + +# Watch for all sockets opened/closed +probe libvirt.rpc.socket_new { + localAddrs[pid(), sock] = localAddr; + remoteAddrs[pid(), sock] = remoteAddr; +} + +probe libvirt.rpc.socket_free { + if (refs == 1) { + delete localAddrs[pid(), sock]; + delete remoteAddrs[pid(), sock]; + } +} + + +# Print whenever a client opens / closes a connection +probe libvirt.rpc.client_new { + clientSocks[pid(), client] = sock; + print_ts(sprintf("C + %-16p local=%s remote=%s", client, localAddrs[pid(), sock], remoteAddrs[pid(), sock])); +} + +probe libvirt.rpc.client_free { + if (refs == 1) { + print_ts(sprintf("C - %-16p local=%s remote=%s", client, + localAddrs[pid(), clientSocks[pid(), client]], + remoteAddrs[pid(), clientSocks[pid(), client]])); + delete clientSocks[pid(), client]; + } +} + + +# print whenever the server receives a client connection open/close +probe libvirt.rpc.server_client_new { + serverSocks[pid(), client] = sock; + print_ts(sprintf("+ S %-16p local=%s remote=%s", client, localAddrs[pid(), sock], remoteAddrs[pid(), sock])); +} + +probe libvirt.rpc.server_client_free { + if (refs == 1) { + print_ts(sprintf("- S %-16p local=%s remote=%s", client, + localAddrs[pid(), serverSocks[pid(), client]], + remoteAddrs[pid(), serverSocks[pid(), client]])); + delete serverSocks[pid(), client]; + } +} + -- 1.7.6.4