lttng: Basic tracing of librbd

Signed-off-by: Adam Crume <adamcrume@gmail.com>

diff --git a/src/Makefile-env.am b/src/Makefile-env.am
index 2ad2f58b147f13dbbe5ebe2df9606c208c83aa66..d46d6e65a075c87936f25d914ee27d4e1e5f4212 100644 (file)
--- a/src/Makefile-env.am
+++ b/src/Makefile-env.am
@@ -159,6 +159,7 @@ LIBERASURE_CODE = liberasure_code.la
 LIBCOMMON_TP = tracing/libcommon_tp.la
 LIBOSD_TP = tracing/libosd_tp.la
 LIBRADOS_TP = tracing/librados_tp.la
+LIBRBD_TP = tracing/librbd_tp.la
 
 if WITH_LIBAIO
 LIBOS += -laio

diff --git a/src/librbd/Makefile.am b/src/librbd/Makefile.am
index 0a3600da3a24cf29b6295433ff4a7dc2e21bbf00..ca153695e85be91bf27b180fd5ccb8dc6551c124 100644 (file)
--- a/src/librbd/Makefile.am
+++ b/src/librbd/Makefile.am
@@ -9,7 +9,8 @@ librbd_la_SOURCES = \
 librbd_la_LIBADD = \
        $(LIBRADOS) $(LIBOSDC) \
        libcls_rbd_client.la libcls_lock_client.la \
-       $(PTHREAD_LIBS) $(EXTRALIBS)
+       $(PTHREAD_LIBS) $(EXTRALIBS) \
+       $(LIBRBD_TP)
 librbd_la_LDFLAGS = ${AM_LDFLAGS} -version-info 1:0:0
 if LINUX
 librbd_la_LDFLAGS += -export-symbols-regex '^rbd_.*'

diff --git a/src/librbd/internal.cc b/src/librbd/internal.cc
index 53169a531d3c16e6ecb4138a36252246a6f527ad..30cbc452e81391050df4f24292a45a50db5047f2 100644 (file)
--- a/src/librbd/internal.cc
+++ b/src/librbd/internal.cc
@@ -23,6 +23,7 @@
 #include "include/util.h"
 
 #include "librados/snap_set_diff.h"
+#include "tracing/librbd.h"
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
@@ -709,12 +710,14 @@ reprotect_and_return_err:
   int create_v1(IoCtx& io_ctx, const char *imgname, uint64_t bid,
                uint64_t size, int order)
   {
+    tracepoint(librbd, create_v1_enter, io_ctx.get_pool_name().c_str(), io_ctx.get_id(), imgname, bid, size, order);
     CephContext *cct = (CephContext *)io_ctx.cct();
     ldout(cct, 2) << "adding rbd image to directory..." << dendl;
     int r = tmap_set(io_ctx, imgname);
     if (r < 0) {
       lderr(cct) << "error adding image to directory: " << cpp_strerror(r)
                 << dendl;
+      tracepoint(librbd, create_v1_exit, r);
       return r;
     }
 
@@ -736,10 +739,12 @@ reprotect_and_return_err:
                   << "header creation failed: "
                   << cpp_strerror(r) << dendl;
       }
+      tracepoint(librbd, create_v1_exit, r);
       return r;
     }
 
     ldout(cct, 2) << "done." << dendl;
+    tracepoint(librbd, create_v1_exit, 0);
     return 0;
   }
 
@@ -747,6 +752,7 @@ reprotect_and_return_err:
                int order, uint64_t features, uint64_t stripe_unit,
                uint64_t stripe_count)
   {
+    tracepoint(librbd, create_v2_enter, io_ctx.get_pool_name().c_str(), io_ctx.get_id(), imgname, bid, size, order, features, stripe_unit, stripe_count);
     ostringstream bid_ss;
     uint32_t extra;
     string id, id_obj, header_oid;
@@ -760,6 +766,7 @@ reprotect_and_return_err:
     if (r < 0) {
       lderr(cct) << "error creating rbd id object: " << cpp_strerror(r)
                 << dendl;
+      tracepoint(librbd, create_v2_exit, r);
       return r;
     }
 
@@ -801,6 +808,7 @@ reprotect_and_return_err:
     }
 
     ldout(cct, 2) << "done." << dendl;
+    tracepoint(librbd, create_v2_exit, 0);
     return 0;
 
   err_remove_header:
@@ -824,6 +832,7 @@ reprotect_and_return_err:
                 << cpp_strerror(remove_r) << dendl;
     }
 
+    tracepoint(librbd, create_v2_exit, r);
     return r;
   }
 
@@ -1363,6 +1372,7 @@ reprotect_and_return_err:
 
   int remove(IoCtx& io_ctx, const char *imgname, ProgressContext& prog_ctx)
   {
+    tracepoint(librbd, remove_enter, io_ctx.get_pool_name().c_str(), io_ctx.get_id(), imgname);
     CephContext *cct((CephContext *)io_ctx.cct());
     ldout(cct, 20) << "remove " << &io_ctx << " " << imgname << dendl;
 
@@ -1382,6 +1392,7 @@ reprotect_and_return_err:
       if (ictx->snaps.size()) {
        lderr(cct) << "image has snapshots - not removing" << dendl;
        close_image(ictx);
+       tracepoint(librbd, remove_exit, -ENOTEMPTY);
        return -ENOTEMPTY;
       }
 
@@ -1390,11 +1401,13 @@ reprotect_and_return_err:
       if (r < 0) {
         lderr(cct) << "error listing watchers" << dendl;
         close_image(ictx);
+       tracepoint(librbd, remove_exit, r);
         return r;
       }
       if (watchers.size() > 1) {
         lderr(cct) << "image has watchers - not removing" << dendl;
         close_image(ictx);
+       tracepoint(librbd, remove_exit, -EBUSY);
         return -EBUSY;
       }
       assert(watchers.size() == 1);
@@ -1413,6 +1426,7 @@ reprotect_and_return_err:
       if (r < 0 && r != -ENOENT) {
        lderr(cct) << "error removing child from children list" << dendl;
         close_image(ictx);
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
       close_image(ictx);
@@ -1421,6 +1435,7 @@ reprotect_and_return_err:
       r = io_ctx.remove(header_oid);
       if (r < 0 && r != -ENOENT) {
        lderr(cct) << "error removing header: " << cpp_strerror(-r) << dendl;
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
     }
@@ -1432,6 +1447,7 @@ reprotect_and_return_err:
       if (r < 0 && !unknown_format) {
        lderr(cct) << "error removing img from old-style directory: "
                   << cpp_strerror(-r) << dendl;
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
     }
@@ -1440,12 +1456,14 @@ reprotect_and_return_err:
       r = io_ctx.remove(id_obj_name(imgname));
       if (r < 0 && r != -ENOENT) {
        lderr(cct) << "error removing id object: " << cpp_strerror(r) << dendl;
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
 
       r = cls_client::dir_get_id(&io_ctx, RBD_DIRECTORY, imgname, &id);
       if (r < 0 && r != -ENOENT) {
        lderr(cct) << "error getting id of image" << dendl;
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
 
@@ -1454,11 +1472,13 @@ reprotect_and_return_err:
       if (r < 0) {
        lderr(cct) << "error removing img from new-style directory: "
                   << cpp_strerror(-r) << dendl;
+       tracepoint(librbd, remove_exit, r);
        return r;
       }
     } 
 
     ldout(cct, 2) << "done." << dendl;
+    tracepoint(librbd, remove_exit, 0);
     return 0;
   }
 
@@ -2090,6 +2110,7 @@ reprotect_and_return_err:
 
   int open_image(ImageCtx *ictx)
   {
+    tracepoint(librbd, open_image_enter, ictx->name.c_str(), ictx->id.c_str());
     ldout(ictx->cct, 20) << "open_image: ictx = " << ictx
                         << " name = '" << ictx->name
                         << "' id = '" << ictx->id
@@ -2117,15 +2138,18 @@ reprotect_and_return_err:
     if ((r = _snap_set(ictx, ictx->snap_name.c_str())) < 0)
       goto err_close;
 
+    tracepoint(librbd, open_image_exit, 0);
     return 0;
 
   err_close:
     close_image(ictx);
+    tracepoint(librbd, open_image_exit, r);
     return r;
   }
 
   void close_image(ImageCtx *ictx)
   {
+    tracepoint(librbd, close_image_enter, ictx->name.c_str(), ictx->id.c_str());
     ldout(ictx->cct, 20) << "close_image " << ictx << dendl;
     if (ictx->object_cacher)
       ictx->shutdown_cache(); // implicitly flushes
@@ -2141,6 +2165,7 @@ reprotect_and_return_err:
       ictx->unregister_watch();
 
     delete ictx;
+    tracepoint(librbd, close_image_exit);
   }
 
   // 'flatten' child image by copying all parent's blocks
@@ -2641,6 +2666,12 @@ reprotect_and_return_err:
 
   ssize_t read(ImageCtx *ictx, const vector<pair<uint64_t,uint64_t> >& image_extents, char *buf, bufferlist *pbl)
   {
+    tracepoint(librbd, read_enter, ictx->name.c_str(), ictx->id.c_str());
+    for (vector<pair<uint64_t,uint64_t> >::const_iterator r = image_extents.begin();
+        r != image_extents.end();
+        ++r) {
+      tracepoint(librbd, read_extent, r->first, r->second);
+    }
     Mutex mylock("IoCtxImpl::write::mylock");
     Cond cond;
     bool done;
@@ -2652,6 +2683,7 @@ reprotect_and_return_err:
     if (r < 0) {
       c->release();
       delete ctx;
+      tracepoint(librbd, read_exit, r);
       return r;
     }
 
@@ -2660,11 +2692,13 @@ reprotect_and_return_err:
       cond.Wait(mylock);
     mylock.Unlock();
 
+    tracepoint(librbd, read_exit, ret);
     return ret;
   }
 
   ssize_t write(ImageCtx *ictx, uint64_t off, size_t len, const char *buf)
   {
+    tracepoint(librbd, write_enter, ictx->name.c_str(), ictx->id.c_str(), off, len, buf);
     utime_t start_time, elapsed;
     ldout(ictx->cct, 20) << "write " << ictx << " off = " << off << " len = "
                         << len << dendl;
@@ -2677,8 +2711,10 @@ reprotect_and_return_err:
 
     uint64_t mylen = len;
     int r = clip_io(ictx, off, &mylen);
-    if (r < 0)
+    if (r < 0) {
+      tracepoint(librbd, write_exit, r);
       return r;
+    }
 
     Context *ctx = new C_SafeCond(&mylock, &cond, &done, &ret);
     AioCompletion *c = aio_create_completion_internal(ctx, rbd_ctx_cb);
@@ -2686,6 +2722,7 @@ reprotect_and_return_err:
     if (r < 0) {
       c->release();
       delete ctx;
+      tracepoint(librbd, write_exit, r);
       return r;
     }
 
@@ -2694,13 +2731,16 @@ reprotect_and_return_err:
       cond.Wait(mylock);
     mylock.Unlock();
 
-    if (ret < 0)
+    if (ret < 0) {
+      tracepoint(librbd, write_exit, ret);
       return ret;
+    }
 
     elapsed = ceph_clock_now(ictx->cct) - start_time;
     ictx->perfcounter->tinc(l_librbd_wr_latency, elapsed);
     ictx->perfcounter->inc(l_librbd_wr);
     ictx->perfcounter->inc(l_librbd_wr_bytes, mylen);
+    tracepoint(librbd, write_exit, mylen);
     return mylen;
   }
 

diff --git a/src/tracing/Makefile.am b/src/tracing/Makefile.am
index 59d48c42dd09db1d0006ec77ae5c5ef2741077c1..82bd09cee72955ee2a878d3ad986f90db8e411b3 100644 (file)
--- a/src/tracing/Makefile.am
+++ b/src/tracing/Makefile.am
@@ -3,6 +3,7 @@
 
 dist_noinst_DATA = \
        librados.tp \
+       librbd.tp \
        mutex.tp \
        oprequest.tp \
        osd.tp \
@@ -33,13 +34,22 @@ librados_tp_la_LIBADD = -llttng-ust -ldl
 librados_tp_la_CPPFLAGS = -DTRACEPOINT_PROBE_DYNAMIC_LINKAGE
 librados_tp_la_LDFLAGS =
 
+librbd_tp_la_SOURCES = \
+       librbd.c \
+       librbd.h
+librbd_tp_la_LIBADD = -llttng-ust -ldl
+librbd_tp_la_CPPFLAGS = -DTRACEPOINT_PROBE_DYNAMIC_LINKAGE
+librbd_tp_la_LDFLAGS =
+
 noinst_LTLIBRARIES = \
        libcommon_tp.la \
        libosd_tp.la \
-       librados_tp.la
+       librados_tp.la \
+       librbd_tp.la
 
 BUILT_SOURCES = \
        librados.h \
+       librbd.h \
        mutex.h \
        oprequest.h \
        osd.h \

diff --git a/src/tracing/librbd.tp b/src/tracing/librbd.tp
new file mode 100644 (file)
index 0000000..70e5218
--- /dev/null
+++ b/src/tracing/librbd.tp
@@ -0,0 +1,164 @@
+#include "tracing/tracing-common.h"
+#include "include/rbd/librbd.h"
+
+TRACEPOINT_EVENT(librbd, read_enter,
+    TP_ARGS(
+        const char*, name,
+        const char*, id),
+    TP_FIELDS(
+        ctf_string(name, name)
+        ctf_string(id, id)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, read_extent,
+    TP_ARGS(
+        uint64_t, offset,
+        uint64_t, length),
+    TP_FIELDS(
+        ctf_integer(uint64_t, offset, offset)
+        ctf_integer(uint64_t, length, length)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, read_exit,
+    TP_ARGS(
+        ssize_t, retval),
+    TP_FIELDS(
+        ctf_integer(ssize_t, retval, retval)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, write_enter,
+    TP_ARGS(
+        const char*, name,
+        const char*, id,
+        uint64_t, off,
+        size_t, len,
+        const char*, buf),
+    TP_FIELDS(
+        ctf_string(name, name)
+        ctf_string(id, id)
+        ctf_integer(uint64_t, off, off)
+        ceph_ctf_sequence(unsigned char, buf, buf, size_t, len)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, write_exit,
+    TP_ARGS(
+        ssize_t, retval),
+    TP_FIELDS(
+        ctf_integer(ssize_t, retval, retval)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, open_image_enter,
+    TP_ARGS(
+        const char*, name,
+        const char*, id),
+    TP_FIELDS(
+        ctf_string(name, name)
+        ctf_string(id, id)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, open_image_exit,
+    TP_ARGS(
+        int, retval),
+    TP_FIELDS(
+        ctf_integer(int, retval, retval)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, close_image_enter,
+    TP_ARGS(
+        const char*, name,
+        const char*, id),
+    TP_FIELDS(
+        ctf_string(name, name)
+        ctf_string(id, id)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, close_image_exit,
+    TP_ARGS(),
+    TP_FIELDS()
+)
+
+TRACEPOINT_EVENT(librbd, create_v1_enter,
+    TP_ARGS(
+        const char*, pool_name,
+        int64_t, id,
+        const char*, imgname,
+        uint64_t, bid,
+        uint64_t, size,
+        int, order),
+    TP_FIELDS(
+        ctf_string(pool_name, pool_name)
+        ctf_integer(int64_t, id, id)
+        ctf_string(imgname, imgname)
+        ctf_integer(uint64_t, bid, bid)
+        ctf_integer(uint64_t, size, size)
+        ctf_integer(int, order, order)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, create_v1_exit,
+    TP_ARGS(
+        int, retval),
+    TP_FIELDS(
+        ctf_integer(int, retval, retval)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, create_v2_enter,
+    TP_ARGS(
+        const char*, pool_name,
+        int64_t, id,
+        const char*, imgname,
+        uint64_t, bid,
+        uint64_t, size,
+        int, order,
+        uint64_t, features,
+        uint64_t, stripe_unit,
+        uint64_t, stripe_count),
+    TP_FIELDS(
+        ctf_string(pool_name, pool_name)
+        ctf_integer(int64_t, id, id)
+        ctf_string(imgname, imgname)
+        ctf_integer(uint64_t, bid, bid)
+        ctf_integer(uint64_t, size, size)
+        ctf_integer(int, order, order)
+        ctf_integer(uint64_t, features, features)
+        ctf_integer(uint64_t, stripe_unit, stripe_unit)
+        ctf_integer(uint64_t, stripe_count, stripe_count)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, create_v2_exit,
+    TP_ARGS(
+        int, retval),
+    TP_FIELDS(
+        ctf_integer(int, retval, retval)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, remove_enter,
+    TP_ARGS(
+        const char*, pool_name,
+        int64_t, id,
+        const char*, imgname),
+    TP_FIELDS(
+        ctf_string(pool_name, pool_name)
+        ctf_integer(int64_t, id, id)
+        ctf_string(imgname, imgname)
+    )
+)
+
+TRACEPOINT_EVENT(librbd, remove_exit,
+    TP_ARGS(
+        int, retval),
+    TP_FIELDS(
+        ctf_integer(int, retval, retval)
+    )
+)