From: Anjaneya Chagam Date: Mon, 5 Dec 2016 19:58:22 +0000 (-0700) Subject: common: extend lttng tracing infrastructure X-Git-Tag: v12.0.0~142^2~1 X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=b3b20449dabbdfae6fb035d3e7efca52c21e9869;p=ceph.git common: extend lttng tracing infrastructure New function and oid lttng tracing enhancements that provide function and oid level latency breakdown. Requires WITH_EVENTTRACE=ON option to enable. Signed-off-by: Anjaneya Chagam --- diff --git a/CMakeLists.txt b/CMakeLists.txt index 46f99d02568d..207c82e61b87 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -413,6 +413,9 @@ set(HAVE_LIBROCKSDB 1) # -lz link into kv find_package(ZLIB REQUIRED) +#option for EventTrace +option(WITH_EVENTTRACE "Event tracing support" OFF) + #option for LTTng option(WITH_LTTNG "LTTng tracing is enabled" ON) if(${WITH_LTTNG}) diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 409981e575d1..9cfdfcf63cce 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -516,6 +516,12 @@ elseif(FREEBSD OR APPLE) message(STATUS " Using EventKqueue for events.") endif(LINUX) +if(WITH_LTTNG AND WITH_EVENTTRACE) + message(STATUS " Using EventTrace class.") + add_definitions("-DWITH_EVENTTRACE") + list(APPEND libcommon_files common/EventTrace.cc) +endif() + set(mon_common_files auth/AuthSessionHandler.cc auth/cephx/CephxSessionHandler.cc diff --git a/src/common/EventTrace.cc b/src/common/EventTrace.cc new file mode 100644 index 000000000000..5a39089a9fd4 --- /dev/null +++ b/src/common/EventTrace.cc @@ -0,0 +1,131 @@ +// -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*- +// vim: ts=8 sw=2 smarttab +/* + * Ceph - scalable distributed file system + * + * Copyright (C) Intel Corporation. + * All rights reserved. + * + * Author: Anjaneya Chagam + * + * This is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License version 2.1, as published by the Free Software + * Foundation. See file COPYING. + * + */ + +#include "common/EventTrace.h" +#include "common/dout.h" +#include "common/TracepointProvider.h" +#include "messages/MOSDOp.h" +#include "messages/MOSDOpReply.h" +#include +#include + +#ifdef WITH_LTTNG +#define TRACEPOINT_DEFINE +#define TRACEPOINT_PROBE_DYNAMIC_LINKAGE +#include "tracing/eventtrace.h" +#undef TRACEPOINT_PROBE_DYNAMIC_LINKAGE +#undef TRACEPOINT_DEFINE +#else +#define tracepoint(...) +#endif + +TracepointProvider::Traits event_tracepoint_traits("libeventtrace_tp.so", "event_tracing"); +bool EventTrace::tpinit = false; + +void EventTrace::init_tp(CephContext *_ctx) +{ + if (unlikely(!_ctx)) + return; + + if (unlikely(!tpinit)) { + TracepointProvider::initialize(_ctx); + tpinit = true; + } +} + +void EventTrace::set_message_attrs(Message *m, string& oid, string& context, bool incl_oid) +{ + // arg1 = oid, arg2 = message type, arg3 = source!source_addr!tid!sequence + if (m && (m->get_type() == CEPH_MSG_OSD_OP || m->get_type() == CEPH_MSG_OSD_OPREPLY)) { + if (incl_oid) { + if (m->get_type() == CEPH_MSG_OSD_OP) + oid = ((MOSDOp *)m)->get_oid().name; + else + oid = ((MOSDOpReply *)m)->get_oid().name; + } + + ostringstream buf; + buf << m->get_source() << "!" << m->get_source_addr() << "!" + << m->get_tid() << "!" << m->get_seq() << "!" << m->get_type();; + context = buf.str(); + } +} + +EventTrace::EventTrace(CephContext *_ctx, const char *_file, const char *_func, int _line) : + ctx(_ctx), + file(_file), + func(_func), + line(_line) +{ + if (unlikely(!ctx)) + return; + last_ts = ceph_clock_now(); + init_tp(ctx); + + lsubdout(ctx, eventtrace, LOG_LEVEL) << "ENTRY (" << func << ") " << file << ":" << line << dendl; + tracepoint(eventtrace, func_enter, file.c_str(), func.c_str(), line); +} + +EventTrace::~EventTrace() +{ + if (unlikely(!ctx)) + return; + lsubdout(ctx, eventtrace, LOG_LEVEL) << "EXIT (" << func << ") " << file << dendl; + tracepoint(eventtrace, func_exit, file.c_str(), func.c_str()); +} + +void EventTrace::log_event_latency(const char *event) +{ + utime_t now = ceph_clock_now(); + double usecs = (now.to_nsec()-last_ts.to_nsec())/1000; + OID_ELAPSED("", usecs, event); + last_ts = now; +} + +void EventTrace::trace_oid_event(const char *oid, const char *event, const char *context, + const char *file, const char *func, int line) +{ + if (unlikely(!g_ceph_context)) + return; + init_tp(g_ceph_context); + tracepoint(eventtrace, oid_event, oid, event, context, file, func, line); +} + +void EventTrace::trace_oid_event(Message *m, const char *event, const char *file, + const char *func, int line, bool incl_oid) +{ + string oid, context; + set_message_attrs(m, oid, context, incl_oid); + trace_oid_event(oid.c_str(), event, context.c_str(), file, func, line); +} + +void EventTrace::trace_oid_elapsed(const char *oid, const char *event, const char *context, + double elapsed, const char *file, const char *func, int line) +{ + if (unlikely(!g_ceph_context)) + return; + init_tp(g_ceph_context); + tracepoint(eventtrace, oid_elapsed, oid, event, context, elapsed, file, func, line); +} + +void EventTrace::trace_oid_elapsed(Message *m, const char *event, double elapsed, + const char *file, const char *func, int line, bool incl_oid) +{ + string oid, context; + set_message_attrs(m, oid, context, incl_oid); + trace_oid_elapsed(oid.c_str(), event, context.c_str(), elapsed, file, func, line); +} diff --git a/src/common/EventTrace.h b/src/common/EventTrace.h new file mode 100644 index 000000000000..2d9f10684e62 --- /dev/null +++ b/src/common/EventTrace.h @@ -0,0 +1,81 @@ +// -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*- +// vim: ts=8 sw=2 smarttab +/* + * Ceph - scalable distributed file system + * + * Copyright (C) 2016 Intel Corporation. + * All rights reserved. + * + * Author: Anjaneya Chagam + * + * This is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License version 2.1, as published by the Free Software + * Foundation. See file COPYING. + * + */ + +#ifndef _EventTrace_h_ +#define _EventTrace_h_ + +#include +#include "msg/Message.h" +#include "common/ceph_context.h" + +#if defined(WITH_LTTNG) && defined(WITH_EVENTTRACE) + +#define OID_EVENT_TRACE(oid, event) \ + EventTrace::trace_oid_event(oid, event, "", __FILE__, __func__, __LINE__) +#define OID_EVENT_TRACE_WITH_MSG(msg, event, incl_oid) \ + EventTrace::trace_oid_event(msg, event, __FILE__, __func__, __LINE__, incl_oid) +#define OID_ELAPSED(oid, elapsed, event) \ + EventTrace::trace_oid_elapsed(oid, event, "", elapsed, __FILE__, __func__, __LINE__) +#define OID_ELAPSED_WITH_MSG(m, elapsed, event, incl_oid) \ + EventTrace::trace_oid_elapsed(m, event, elapsed, __FILE__, __func__, __LINE__, incl_oid) +#define FUNCTRACE() EventTrace _t1(g_ceph_context, __FILE__, __func__, __LINE__) +#define OID_ELAPSED_FUNC_EVENT(event) _t1.log_event_latency(event) + +#else + +#define OID_EVENT_TRACE(oid, event) +#define OID_EVENT_TRACE_WITH_MSG(msg, event, incl_oid) +#define OID_ELAPSED(oid, elapsed, event) +#define OID_ELAPSED_WITH_MSG(m, elapsed, event, incl_oid) +#define FUNCTRACE() +#define OID_ELAPSED_FUNC_EVENT(event) + +#endif + +#define LOG_LEVEL 1 + +class EventTrace { +private: + CephContext *ctx; + string file; + string func; + int line; + utime_t last_ts; + + static bool tpinit; + + static void init_tp(CephContext *_ctx); + static void set_message_attrs(Message *m, string& oid, string& context, bool incl_oid); + +public: + + EventTrace(CephContext *_ctx, const char *_file, const char *_func, int line); + ~EventTrace(); + void log_event_latency(const char *tag); + + static void trace_oid_event(const char *oid, const char *event, const char *context, + const char *file, const char *func, int line); + static void trace_oid_event(Message *m, const char *event, const char *file, + const char *func, int line, bool incl_oid); + + static void trace_oid_elapsed(const char *oid, const char *event, const char *context, + double elapsed, const char *file, const char *func, int line); + static void trace_oid_elapsed(Message *m, const char *event, double elapsed, + const char *file, const char *func, int line, bool incl_oid); + +}; +#endif diff --git a/src/common/config_opts.h b/src/common/config_opts.h index 04338d2ce7ff..b6053f98ecc4 100644 --- a/src/common/config_opts.h +++ b/src/common/config_opts.h @@ -165,6 +165,7 @@ SUBSYS(fuse, 1, 5) SUBSYS(mgr, 1, 5) SUBSYS(mgrc, 1, 5) SUBSYS(dpdk, 1, 5) +SUBSYS(eventtrace, 1, 5) OPTION(key, OPT_STR, "") OPTION(keyfile, OPT_STR, "") @@ -1613,6 +1614,8 @@ OPTION(rgw_torrent_encoding, OPT_STR, "") // torrent field encoding OPTION(rgw_torrent_origin, OPT_STR, "") // torrent origin OPTION(rgw_torrent_sha_unit, OPT_INT, 512*1024) // torrent field piece length 512K +OPTION(event_tracing, OPT_BOOL, false) // true if LTTng-UST tracepoints should be enabled + // This will be set to true when it is safe to start threads. // Once it is true, it will never change. OPTION(internal_safe_to_start_threads, OPT_BOOL, false) diff --git a/src/tracing/CMakeLists.txt b/src/tracing/CMakeLists.txt index 8b153935ec25..734056675acf 100644 --- a/src/tracing/CMakeLists.txt +++ b/src/tracing/CMakeLists.txt @@ -44,4 +44,8 @@ add_tracing_library(rbd_tp librbd.tp 1.0.0) add_tracing_library(os_tp objectstore.tp 1.0.0) install(TARGETS rados_tp osd_tp rbd_tp os_tp DESTINATION ${CMAKE_INSTALL_LIBDIR}) +if(WITH_LTTNG AND WITH_EVENTTRACE) + add_tracing_library(eventtrace_tp eventtrace.tp 1.0.0) + install(TARGETS eventtrace_tp DESTINATION ${CMAKE_INSTALL_LIBDIR}) +endif() diff --git a/src/tracing/eventtrace.c b/src/tracing/eventtrace.c new file mode 100644 index 000000000000..54ebae020b63 --- /dev/null +++ b/src/tracing/eventtrace.c @@ -0,0 +1,5 @@ +#define TRACEPOINT_CREATE_PROBES +/* + * The header containing our TRACEPOINT_EVENTs. + */ +#include "tracing/eventtrace.h" diff --git a/src/tracing/eventtrace.tp b/src/tracing/eventtrace.tp new file mode 100644 index 000000000000..f28ded100ecf --- /dev/null +++ b/src/tracing/eventtrace.tp @@ -0,0 +1,61 @@ +#include "include/int_types.h" + +TRACEPOINT_EVENT(eventtrace, func_enter, + TP_ARGS( + const char*, file, + const char*, func, + uint32_t, line), + TP_FIELDS( + ctf_string(file, file) + ctf_string(func, func) + ctf_integer(uint32_t, line, line) + ) +) + +TRACEPOINT_EVENT(eventtrace, func_exit, + TP_ARGS( + const char*, file, + const char*, func), + TP_FIELDS( + ctf_string(file, file) + ctf_string(func, func) + ) +) + +TRACEPOINT_EVENT(eventtrace, oid_event, + TP_ARGS( + const char*, oid, + const char*, event, + const char*, context, + const char*, file, + const char*, func, + uint32_t, line), + TP_FIELDS( + ctf_string(oid, oid) + ctf_string(event, event) + ctf_string(context, context) + ctf_string(file, file) + ctf_string(func, func) + ctf_integer(uint32_t, line, line) + ) +) + +TRACEPOINT_EVENT(eventtrace, oid_elapsed, + TP_ARGS( + const char*, oid, + const char*, event, + const char*, context, + double, elapsed, + const char*, file, + const char*, func, + uint32_t, line), + TP_FIELDS( + ctf_string(oid, oid) + ctf_string(event, event) + ctf_string(context, context) + ctf_float(double, elapsed, elapsed) + ctf_string(file, file) + ctf_string(func, func) + ctf_integer(uint32_t, line, line) + ) +)