From: Adam Crume Date: Fri, 27 Jun 2014 23:48:19 +0000 (-0700) Subject: lttng: Basic tracing of librbd X-Git-Tag: v0.86~231^2~65 X-Git-Url: http://git.apps.os.sepia.ceph.com/?a=commitdiff_plain;h=d0834bb8412159d6ec1f6cad99f2e4d86f9528de;p=ceph.git lttng: Basic tracing of librbd Signed-off-by: Adam Crume --- diff --git a/src/Makefile-env.am b/src/Makefile-env.am index 2ad2f58b147f1..d46d6e65a075c 100644 --- 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 0a3600da3a24c..ca153695e85be 100644 --- 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 53169a531d3c1..30cbc452e8139 100644 --- 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 >& image_extents, char *buf, bufferlist *pbl) { + tracepoint(librbd, read_enter, ictx->name.c_str(), ictx->id.c_str()); + for (vector >::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 59d48c42dd09d..82bd09cee7295 100644 --- 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 index 0000000000000..70e5218b371c2 --- /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) + ) +)