core: tracing basic i/o path for OSD

* add tracing header files { common/tracer.{h/cc} }

Signed-off-by: Deepika Upadhyay <dupadhya@redhat.com>

diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt
index 061b1927bff8878ec3a605a147cf8530a677c2d5..dd2312cfe964081a653f62c1634a64fe8588733a 100644 (file)
--- a/src/CMakeLists.txt
+++ b/src/CMakeLists.txt
@@ -383,6 +383,9 @@ set(libcommon_files
   osdc/error_code.cc
   librbd/Features.cc
   ${mds_files})
+if(WITH_JAEGER)
+  list(APPEND libcommon_files common/tracer.cc)
+endif()
 set_source_files_properties(ceph_ver.c
   APPEND PROPERTY OBJECT_DEPENDS ${CMAKE_BINARY_DIR}/src/include/ceph_ver.h)
 add_library(common-objs OBJECT ${libcommon_files})
@@ -628,6 +631,9 @@ set(ceph_osd_srcs
   osd/objclass.cc
   objclass/class_api.cc
   ceph_osd.cc)
+if(WITH_JAEGER)
+  list(APPEND ceph_osd_srcs common/tracer.cc)
+endif()
 add_executable(ceph-osd ${ceph_osd_srcs})
 add_dependencies(ceph-osd erasure_code_plugins)
 target_link_libraries(ceph-osd osd os global-static common

diff --git a/src/common/tracer.cc b/src/common/tracer.cc
new file mode 100644 (file)
index 0000000..d3a1aff
--- /dev/null
+++ b/src/common/tracer.cc
@@ -0,0 +1,86 @@
+// -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*-
+// vim: ts=8 sw=2 smarttab
+
+#include "tracer.h"
+#include <arpa/inet.h>
+#include <yaml-cpp/yaml.h>
+#ifdef __linux__
+#include <linux/types.h>
+#else
+typedef int64_t __s64;
+#endif
+
+#include "common/debug.h"
+
+#define dout_context g_ceph_context
+#define dout_subsys ceph_subsys_osd
+#undef dout_prefix
+#define dout_prefix *_dout << "jaeger_tracing "
+
+namespace jaeger_tracing {
+
+  std::shared_ptr<opentracing::v3::Tracer> tracer = nullptr;
+
+  void init_tracer(const char* tracer_name) {
+    if (!tracer) {
+       YAML::Node yaml;
+       try{
+         yaml = YAML::LoadFile("../src/jaegertracing/config.yml");
+       dout(3) << "yaml loaded" << yaml << dendl;
+       }
+       catch(std::exception &e) {
+         dout(3) << "failed to load yaml file using default config" << dendl;
+         auto yaml_config = R"cfg(
+disabled: false
+reporter:
+    logSpans: false
+    queueSize: 100
+    bufferFlushInterval: 10
+sampler:
+    type: const
+    param: 1
+headers:
+    jaegerDebugHeader: debug-id
+    jaegerBaggageHeader: baggage
+    TraceContextHeaderName: trace-id
+baggage_restrictions:
+    denyBaggageOnInitializationFailure: false
+    refreshInterval: 60
+)cfg";
+       yaml = YAML::Load(yaml_config);
+       dout(3) << "yaml loaded" << yaml << dendl;
+      }
+      static auto configuration = jaegertracing::Config::parse(yaml);
+      tracer = jaegertracing::Tracer::make( tracer_name, configuration,
+           jaegertracing::logging::consoleLogger());
+      dout(3) << "tracer_jaeger init successful" << dendl;
+    }
+    //incase of stale tracer, configure with a new global tracer
+    if (opentracing::Tracer::Global() != tracer) {
+      opentracing::Tracer::InitGlobal(
+         std::static_pointer_cast<opentracing::Tracer>(tracer));
+    }
+  }
+
+  jspan new_span(const char* span_name) {
+    return opentracing::Tracer::Global()->StartSpan(span_name);
+ }
+
+  jspan child_span(const char* span_name, const jspan& parent_span) {
+    //no parent check if parent not found span will still be constructed
+    return opentracing::Tracer::Global()->StartSpan(span_name,
+       {opentracing::ChildOf(&parent_span->context())});
+ }
+
+  void finish_span(const jspan& span) {
+    if (span) {
+      span->Finish();
+    }
+  }
+
+  void set_span_tag(const jspan& span, const char* key, const char* value) {
+    if (span) {
+      span->SetTag(key, value);
+    }
+  }
+}

diff --git a/src/common/tracer.h b/src/common/tracer.h
new file mode 100644 (file)
index 0000000..028ea04
--- /dev/null
+++ b/src/common/tracer.h
@@ -0,0 +1,32 @@
+// -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*-
+// vim: ts=8 sw=2 smarttab
+
+#ifndef TRACER_H_
+#define TRACER_H_
+
+#define SIGNED_RIGHT_SHIFT_IS 1
+#define ARITHMETIC_RIGHT_SHIFT 1
+
+#include <jaegertracing/Tracer.h>
+
+typedef std::unique_ptr<opentracing::Span> jspan;
+
+namespace jaeger_tracing {
+
+  extern std::shared_ptr<opentracing::v3::Tracer> tracer;
+
+  void init_tracer(const char* tracer_name);
+
+  //create a root jspan
+  jspan new_span(const char*);
+
+  //create a child_span used given parent_span
+  jspan child_span(const char*, const jspan&);
+
+  //finish tracing of a single jspan
+  void finish_span(const jspan&);
+
+  //setting tags in sundefined reference topans
+  void set_span_tag(const jspan&, const char*, const char*);
+}
+#endif // TRACER_H_

diff --git a/src/include/int_types.h b/src/include/int_types.h
index 3435cbcbe2aeb3d1adeccb3a64dc3e974835c80d..a704ba71d2b3afac19678522d5118019a353d30d 100644 (file)
--- a/src/include/int_types.h
+++ b/src/include/int_types.h
@@ -5,7 +5,7 @@
 
 #include <inttypes.h>
 
-#ifdef HAVE_LINUX_TYPES_H
+#ifdef __linux__
 #include <linux/types.h>
 #else
 #ifndef HAVE___U8

diff --git a/src/jaegertracing/config.yml b/src/jaegertracing/config.yml
new file mode 100644 (file)
index 0000000..340eb51
--- /dev/null
+++ b/src/jaegertracing/config.yml
@@ -0,0 +1,6 @@
+disabled: false
+reporter:
+    logSpans: true
+sampler:
+  type: const
+  param: 1

diff --git a/src/osd/ECBackend.cc b/src/osd/ECBackend.cc
index 3e6e9587a8565bf6029eb4b5a5e45979d7303120..b5c334386a774c8c6c7f249955bdc2448036a9e0 100644 (file)
--- a/src/osd/ECBackend.cc
+++ b/src/osd/ECBackend.cc
@@ -940,6 +940,11 @@ void ECBackend::handle_sub_write(
   if (msg)
     msg->mark_event("sub_op_started");
   trace.event("handle_sub_write");
+#ifdef HAVE_JAEGER
+  if (msg->osd_parent_span) {
+    auto ec_sub_trans = jaeger_tracing::child_span(__func__, msg->osd_parent_span);
+  }
+#endif
   if (!get_parent()->pgb_is_primary())
     get_parent()->update_stats(op.stats);
   ObjectStore::Transaction localt;
@@ -1529,7 +1534,12 @@ void ECBackend::submit_transaction(
   op->client_op = client_op;
   if (client_op)
     op->trace = client_op->pg_trace;
-  
+
+#ifdef HAVE_JAEGER
+  if (client_op->osd_parent_span) {
+    auto ec_sub_trans = jaeger_tracing::child_span("ECBackend::submit_transaction", client_op->osd_parent_span);
+  }
+#endif
   dout(10) << __func__ << ": op " << *op << " starting" << dendl;
   start_rmw(op, std::move(t));
 }
@@ -2098,6 +2108,12 @@ bool ECBackend::try_reads_to_commit()
       messages.push_back(std::make_pair(i->osd, r));
     }
   }
+
+#ifdef HAVE_JAEGER
+   if (op->client_op->osd_parent_span) {
+      auto sub_write_span = jaeger_tracing::child_span("EC sub write", op->client_op->osd_parent_span);
+    }
+#endif
   if (!messages.empty()) {
     get_parent()->send_message_osd_cluster(messages, get_osdmap_epoch());
   }

diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc
index db3ce3ce5929032329529b2e6c53ed3acf7b23de..335e6475997816347bc86d995b6075f43475cb58 100644 (file)
--- a/src/osd/OSD.cc
+++ b/src/osd/OSD.cc
@@ -173,6 +173,9 @@
 #else
 #define tracepoint(...)
 #endif
+#ifdef HAVE_JAEGER
+#include "common/tracer.h"
+#endif
 
 #define dout_context cct
 #define dout_subsys ceph_subsys_osd
@@ -7017,6 +7020,12 @@ void OSD::dispatch_session_waiting(const ceph::ref_t<Session>& session, OSDMapRe
 
 void OSD::ms_fast_dispatch(Message *m)
 {
+
+#ifdef HAVE_JAEGER
+  jaeger_tracing::init_tracer("osd-services-reinit");
+  dout(10) << "jaeger tracer after " << opentracing::Tracer::Global() << dendl;
+  auto dispatch_span = jaeger_tracing::new_span(__func__);
+#endif
   FUNCTRACE(cct);
   if (service.is_stopping()) {
     m->put();
@@ -7077,7 +7086,13 @@ void OSD::ms_fast_dispatch(Message *m)
     tracepoint(osd, ms_fast_dispatch, reqid.name._type,
         reqid.name._num, reqid.tid, reqid.inc);
   }
-
+#ifdef HAVE_JAEGER
+  op->set_osd_parent_span(dispatch_span);
+  if (op->osd_parent_span) {
+    auto op_req_span = jaeger_tracing::child_span("op-request-created", op->osd_parent_span);
+    op->set_osd_parent_span(op_req_span);
+  }
+#endif
   if (m->trace)
     op->osd_trace.init("osd op", &trace_endpoint, &m->trace);
 
@@ -9627,6 +9642,18 @@ void OSD::enqueue_op(spg_t pg, OpRequestRef&& op, epoch_t epoch)
   op->osd_trace.event("enqueue op");
   op->osd_trace.keyval("priority", priority);
   op->osd_trace.keyval("cost", cost);
+#ifdef HAVE_JAEGER
+  if (op->osd_parent_span) {
+    auto enqueue_span = jaeger_tracing::child_span(__func__, op->osd_parent_span);
+    enqueue_span->Log({
+       {"priority", priority},
+       {"cost", cost},
+       {"epoch", epoch},
+       {"owner", owner},
+       {"type", type}
+       });
+  }
+#endif
   op->mark_queued_for_pg();
   logger->tinc(l_osd_op_before_queue_op_lat, latency);
   if (type == MSG_OSD_PG_PUSH ||

diff --git a/src/osd/OpRequest.h b/src/osd/OpRequest.h
index dc5b5e34b1f2d28cac3f653736885c4baddec828..0a03a85ac271c28e930a4d6f3c381d24b13d8f2a 100644 (file)
--- a/src/osd/OpRequest.h
+++ b/src/osd/OpRequest.h
@@ -17,6 +17,9 @@
 #include "osd/osd_op_util.h"
 #include "osd/osd_types.h"
 #include "common/TrackedOp.h"
+#ifdef HAVE_JAEGER
+#include "common/tracer.h"
+#endif
 
 /**
  * The OpRequest takes in a Message* and takes over a single reference
@@ -88,7 +91,17 @@ public:
   epoch_t min_epoch = 0;      ///< min epoch needed to handle this msg
 
   bool hitset_inserted;
-
+#ifdef HAVE_JAEGER
+  jspan osd_parent_span = nullptr;
+  void set_osd_parent_span(jspan& span) {
+    if(osd_parent_span){
+      jaeger_tracing::finish_span(osd_parent_span);
+    }
+    osd_parent_span = move(span);
+  }
+#else
+  void set_osd_parent_span(...) {}
+#endif
   template<class T>
   const T* get_req() const { return static_cast<const T*>(request); }
 

diff --git a/src/osd/PrimaryLogPG.cc b/src/osd/PrimaryLogPG.cc
index 156da3b0a3863ecff9219e75382059f71dca2c9e..45dfb065159987a65cce825fb1d893d9e427dd2a 100644 (file)
--- a/src/osd/PrimaryLogPG.cc
+++ b/src/osd/PrimaryLogPG.cc
@@ -70,6 +70,9 @@
 #include <utility>
 
 #include <errno.h>
+#ifdef HAVE_JAEGER
+#include "common/tracer.h"
+#endif
 
 MEMPOOL_DEFINE_OBJECT_FACTORY(PrimaryLogPG, replicatedpg, osd);
 
@@ -1660,7 +1663,12 @@ void PrimaryLogPG::do_request(
     op->pg_trace.init("pg op", &trace_endpoint, &op->osd_trace);
     op->pg_trace.event("do request");
   }
-  // make sure we have a new enough map
+#ifdef HAVE_JAEGER
+  if (op->osd_parent_span) {
+    auto do_req_span = jaeger_tracing::child_span(__func__, op->osd_parent_span);
+  }
+#endif
+// make sure we have a new enough map
   auto p = waiting_for_map.find(op->get_source());
   if (p != waiting_for_map.end()) {
     // preserve ordering
@@ -1690,7 +1698,6 @@ void PrimaryLogPG::do_request(
     auto session = ceph::ref_cast<Session>(m->get_connection()->get_priv());
     if (!session)
       return;  // drop it.
-
     if (msg_type == CEPH_MSG_OSD_OP) {
       if (session->check_backoff(cct, info.pgid,
                                 info.pgid.pgid.get_hobj_start(), m)) {
@@ -2019,6 +2026,11 @@ void PrimaryLogPG::do_op(OpRequestRef& op)
           << " flags " << ceph_osd_flag_string(m->get_flags())
           << dendl;
 
+#ifdef HAVE_JAEGER
+  if (op->osd_parent_span) {
+    auto do_op_span = jaeger_tracing::child_span(__func__, op->osd_parent_span);
+  }
+#endif
   // missing object?
   if (is_unreadable_object(head)) {
     if (!is_primary()) {
@@ -3849,6 +3861,11 @@ void PrimaryLogPG::execute_ctx(OpContext *ctx)
     tracepoint(osd, prepare_tx_enter, reqid.name._type,
         reqid.name._num, reqid.tid, reqid.inc);
   }
+#ifdef HAVE_JAEGER
+  if (ctx->op->osd_parent_span) {
+    auto execute_span = jaeger_tracing::child_span(__func__, ctx->op->osd_parent_span);
+  }
+#endif
 
   int result = prepare_transaction(ctx);
 
@@ -5615,6 +5632,11 @@ int PrimaryLogPG::do_osd_ops(OpContext *ctx, vector<OSDOp>& ops)
   PGTransaction* t = ctx->op_t.get();
 
   dout(10) << "do_osd_op " << soid << " " << ops << dendl;
+#ifdef HAVE_JAEGER
+  if (ctx->op->osd_parent_span) {
+    auto do_osd_op_span = jaeger_tracing::child_span(__func__, ctx->op->osd_parent_span);
+  }
+#endif
 
   ctx->current_osd_subop_num = 0;
   for (auto p = ops.begin(); p != ops.end(); ++p, ctx->current_osd_subop_num++, ctx->processed_subop_count++) {
@@ -8496,6 +8518,11 @@ void PrimaryLogPG::finish_ctx(OpContext *ctx, int log_op_type, int result)
           << dendl;
   utime_t now = ceph_clock_now();
 
+#ifdef HAVE_JAEGER
+  if (ctx->op->osd_parent_span) {
+    auto finish_ctx_span = jaeger_tracing::child_span(__func__, ctx->op->osd_parent_span);
+  }
+#endif
   // Drop the reference if deduped chunk is modified
   if (ctx->new_obs.oi.is_dirty() &&
     (ctx->obs->oi.has_manifest() && ctx->obs->oi.manifest.is_chunked()) &&
@@ -10498,6 +10525,11 @@ void PrimaryLogPG::op_applied(const eversion_t &applied_version)
 
 void PrimaryLogPG::eval_repop(RepGather *repop)
 {
+  #ifdef HAVE_JAEGER
+  if (repop->op->osd_parent_span) {
+    auto eval_span = jaeger_tracing::child_span(__func__, repop->op->osd_parent_span);
+  }
+ #endif
   dout(10) << "eval_repop " << *repop
     << (repop->op && repop->op->get_req<MOSDOp>() ? "" : " (no op)") << dendl;
 
@@ -10552,6 +10584,11 @@ void PrimaryLogPG::issue_repop(RepGather *repop, OpContext *ctx)
   dout(7) << "issue_repop rep_tid " << repop->rep_tid
           << " o " << soid
           << dendl;
+#ifdef HAVE_JAEGER
+  if (ctx->op->osd_parent_span) {
+    auto issue_repop_span = jaeger_tracing::child_span(__func__, ctx->op->osd_parent_span);
+  }
+#endif
 
   repop->v = ctx->at_version;
 

diff --git a/src/osd/ReplicatedBackend.cc b/src/osd/ReplicatedBackend.cc
index d7ffc0533958da8ce657a664ef308c019d3de370..06f98b2c814fbf6e59d2a918e575f83f08fd48d3 100644 (file)
--- a/src/osd/ReplicatedBackend.cc
+++ b/src/osd/ReplicatedBackend.cc
@@ -502,6 +502,9 @@ void ReplicatedBackend::submit_transaction(
   ceph_assert(insert_res.second);
   InProgressOp &op = *insert_res.first->second;
 
+#ifdef HAVE_JAEGER
+  auto rep_sub_trans = jaeger_tracing::child_span("ReplicatedBackend::submit_transaction", orig_op->osd_parent_span);
+#endif
   op.waiting_for_commit.insert(
     parent->get_acting_recovery_backfill_shards().begin(),
     parent->get_acting_recovery_backfill_shards().end());
@@ -1057,6 +1060,10 @@ void ReplicatedBackend::do_repop(OpRequestRef op)
           << " " << m->logbl.length()
           << dendl;
 
+#ifdef HAVE_JAEGER
+  auto do_repop_span = jaeger_tracing::child_span(__func__, op->osd_parent_span);
+#endif
+
   // sanity checks
   ceph_assert(m->map_epoch >= get_info().history.same_interval_since);
 

diff --git a/src/osd/scheduler/OpSchedulerItem.cc b/src/osd/scheduler/OpSchedulerItem.cc
index 66308dcc0e6d97bb43cea98206b6632ea2a99f36..9d57f202cc4183a671a52a4790243a5ae5c73e29 100644 (file)
--- a/src/osd/scheduler/OpSchedulerItem.cc
+++ b/src/osd/scheduler/OpSchedulerItem.cc
@@ -14,6 +14,9 @@
 
 #include "osd/scheduler/OpSchedulerItem.h"
 #include "osd/OSD.h"
+#ifdef HAVE_JAEGER
+#include "common/tracer.h"
+#endif
 
 namespace ceph::osd::scheduler {
 
@@ -23,6 +26,9 @@ void PGOpItem::run(
   PGRef& pg,
   ThreadPool::TPHandle &handle)
 {
+#ifdef HAVE_JAEGER
+  auto PGOpItem_span = jaeger_tracing::child_span("PGOpItem::run", op->osd_parent_span);
+#endif
   osd->dequeue_op(pg, op, handle);
   pg->unlock();
 }