From: Sage Weil <sage@redhat.com>
Date: Thu, 15 Dec 2016 23:14:03 +0000 (-0500)
Subject: common/TrackedOp: add const char* and string variants of event
X-Git-Tag: v12.0.0~45^2~8
X-Git-Url: http://git.apps.os.sepia.ceph.com/?a=commitdiff_plain;h=670c9059fff7ff5099ace3ddf0350232024392ad;p=ceph-ci.git

common/TrackedOp: add const char* and string variants of event

This avoids the full std::string (copy) for most events.  Wrap it up
into an Event class to hide some of the guts.

Signed-off-by: Sage Weil <sage@redhat.com>
---

diff --git a/src/common/TrackedOp.cc b/src/common/TrackedOp.cc
index de607180263..0a29cf2aa54 100644
--- a/src/common/TrackedOp.cc
+++ b/src/common/TrackedOp.cc
@@ -338,12 +338,26 @@ void TrackedOp::mark_event(const string &event)
   utime_t now = ceph_clock_now();
   {
     Mutex::Locker l(lock);
-    events.push_back(make_pair(now, event));
+    events.push_back(Event(now, event));
   }
   tracker->mark_event(this, event.c_str());
   _event_marked();
 }
 
+void TrackedOp::mark_event(const char *event)
+{
+  if (!state)
+    return;
+
+  utime_t now = ceph_clock_now(g_ceph_context);
+  {
+    Mutex::Locker l(lock);
+    events.push_back(Event(now, event));
+  }
+  tracker->mark_event(this, event);
+  _event_marked();
+}
+
 void TrackedOp::dump(utime_t now, Formatter *f) const
 {
   // Ignore if still in the constructor
diff --git a/src/common/TrackedOp.h b/src/common/TrackedOp.h
index d4247530e5a..df1a8bea356 100644
--- a/src/common/TrackedOp.h
+++ b/src/common/TrackedOp.h
@@ -144,7 +144,36 @@ protected:
   std::atomic_int nref = {0};  ///< ref count
 
   utime_t initiated_at;
-  list<pair<utime_t, string> > events; /// list of events and their times
+
+  struct Event {
+    utime_t stamp;
+    string str;
+    const char *cstr = nullptr;
+
+    Event(utime_t t, const string& s) : stamp(t), str(s) {}
+    Event(utime_t t, const char *s) : stamp(t), cstr(s) {}
+
+    int compare(const char *s) const {
+      if (cstr)
+	return strcmp(cstr, s);
+      else
+	return str.compare(s);
+    }
+
+    const char *c_str() const {
+      if (cstr)
+	return cstr;
+      else
+	return str.c_str();
+    }
+
+    void dump(Formatter *f) const {
+      f->dump_stream("time") << stamp;
+      f->dump_string("event", c_str());
+    }
+  };
+
+  list<Event> events; /// list of events and their times
   mutable Mutex lock; /// to protect the events list
   string current; /// the current state the event is in
   uint64_t seq; /// a unique value set by the OpTracker
@@ -210,21 +239,25 @@ public:
 
   double get_duration() const {
     Mutex::Locker l(lock);
-    if (!events.empty() && events.rbegin()->second.compare("done") == 0)
-      return events.rbegin()->first - get_initiated();
+    if (!events.empty() && events.rbegin()->compare("done") == 0)
+      return events.rbegin()->stamp - get_initiated();
     else
       return ceph_clock_now() - get_initiated();
   }
 
   void mark_event(const string &event);
+  void mark_event(const char *event);
+
   virtual const char *state_string() const {
     Mutex::Locker l(lock);
-    return events.rbegin()->second.c_str();
+    return events.rbegin()->c_str();
   }
+
   void dump(utime_t now, Formatter *f) const;
+
   void tracking_start() {
     if (tracker->register_inflight_op(this)) {
-      events.push_back(make_pair(initiated_at, "initiated"));
+      events.push_back(Event(initiated_at, "initiated"));
       state = STATE_LIVE;
     }
   }
diff --git a/src/mds/Mutation.cc b/src/mds/Mutation.cc
index 812d1a7a05a..a8bd18d3709 100644
--- a/src/mds/Mutation.cc
+++ b/src/mds/Mutation.cc
@@ -368,13 +368,8 @@ void MDRequestImpl::_dump(Formatter *f) const
   {
     f->open_array_section("events");
     Mutex::Locker l(lock);
-    for (list<pair<utime_t, string> >::const_iterator i = events.begin();
-         i != events.end();
-         ++i) {
-      f->open_object_section("event");
-      f->dump_stream("time") << i->first;
-      f->dump_string("event", i->second);
-      f->close_section();
+    for (auto& i : events) {
+      f->dump_object("event", i);
     }
     f->close_section(); // events
   }
diff --git a/src/mds/Server.cc b/src/mds/Server.cc
index dff75670230..a3251165680 100644
--- a/src/mds/Server.cc
+++ b/src/mds/Server.cc
@@ -1022,7 +1022,7 @@ void Server::submit_mdlog_entry(LogEvent *le, MDSLogContextBase *fin, MDRequestR
   if (mdr) {
     string event_str("submit entry: ");
     event_str += event;
-    mdr->mark_event(event_str);
+    mdr->mark_event_string(event_str);
   } 
   mdlog->submit_entry(le, fin);
 }
diff --git a/src/mon/MonOpRequest.h b/src/mon/MonOpRequest.h
index 2080b606e56..af7b23f6bb5 100644
--- a/src/mon/MonOpRequest.h
+++ b/src/mon/MonOpRequest.h
@@ -42,7 +42,7 @@ struct MonOpRequest : public TrackedOp {
   void mark_svc_event(const string &service, const string &event) {
     string s = service;
     s.append(":").append(event);
-    mark_event(s);
+    mark_event_string(s);
   }
 
   void mark_logmon_event(const string &event) {
@@ -112,12 +112,8 @@ private:
     {
       f->open_array_section("events");
       Mutex::Locker l(lock);
-      for (list<pair<utime_t,string> >::const_iterator i = events.begin();
-           i != events.end(); ++i) {
-        f->open_object_section("event");
-        f->dump_stream("time") << i->first;
-        f->dump_string("event", i->second);
-        f->close_section();
+      for (auto& i : events) {
+	f->dump_object("event", i);
       }
       f->close_section();
       f->open_object_section("info");
diff --git a/src/mon/PaxosService.h b/src/mon/PaxosService.h
index bb550d1ca07..95ce338131d 100644
--- a/src/mon/PaxosService.h
+++ b/src/mon/PaxosService.h
@@ -541,7 +541,7 @@ public:
    */
   void wait_for_finished_proposal(MonOpRequestRef op, Context *c) {
     if (op)
-      op->mark_event(service_name + ":wait_for_finished_proposal");
+      op->mark_event_string(service_name + ":wait_for_finished_proposal");
     waiting_for_finished_proposal.push_back(c);
   }
   void wait_for_finished_proposal_ctx(Context *c) {
@@ -556,7 +556,7 @@ public:
    */
   void wait_for_active(MonOpRequestRef op, Context *c) {
     if (op)
-      op->mark_event(service_name + ":wait_for_active");
+      op->mark_event_string(service_name + ":wait_for_active");
 
     if (!is_proposing()) {
       paxos->wait_for_active(op, c);
@@ -583,7 +583,7 @@ public:
      * happens to be readable at that specific point in time.
      */
     if (op)
-      op->mark_event(service_name + ":wait_for_readable");
+      op->mark_event_string(service_name + ":wait_for_readable");
 
     if (is_proposing() ||
 	ver > get_last_committed() ||
@@ -591,7 +591,7 @@ public:
       wait_for_finished_proposal(op, c);
     else {
       if (op)
-        op->mark_event(service_name + ":wait_for_readable/paxos");
+        op->mark_event_string(service_name + ":wait_for_readable/paxos");
 
       paxos->wait_for_readable(op, c);
     }
@@ -609,7 +609,7 @@ public:
    */
   void wait_for_writeable(MonOpRequestRef op, Context *c) {
     if (op)
-      op->mark_event(service_name + ":wait_for_writeable");
+      op->mark_event_string(service_name + ":wait_for_writeable");
 
     if (is_proposing())
       wait_for_finished_proposal(op, c);
diff --git a/src/mon/mon_types.h b/src/mon/mon_types.h
index b4bc0a64fd1..8b5aa68b511 100644
--- a/src/mon/mon_types.h
+++ b/src/mon/mon_types.h
@@ -231,7 +231,7 @@ struct C_MonOp : public Context
 
   void mark_op_event(const string &event) {
     if (op)
-      op->mark_event(event);
+      op->mark_event_string(event);
   }
 
   virtual void _finish(int r) = 0;
diff --git a/src/osd/OpRequest.cc b/src/osd/OpRequest.cc
index 3c2c32ea140..099ca5f3d45 100644
--- a/src/osd/OpRequest.cc
+++ b/src/osd/OpRequest.cc
@@ -63,13 +63,8 @@ void OpRequest::_dump(Formatter *f) const
   {
     f->open_array_section("events");
     Mutex::Locker l(lock);
-    for (list<pair<utime_t, string> >::const_iterator i = events.begin();
-	 i != events.end();
-	 ++i) {
-      f->open_object_section("event");
-      f->dump_stream("time") << i->first;
-      f->dump_string("event", i->second);
-      f->close_section();
+    for (auto& i : events) {
+      f->dump_object("event", i);
     }
     f->close_section();
   }
@@ -143,7 +138,7 @@ void OpRequest::set_skip_handle_cache() { set_rmw_flags(CEPH_OSD_RMW_FLAG_SKIP_H
 void OpRequest::set_skip_promote() { set_rmw_flags(CEPH_OSD_RMW_FLAG_SKIP_PROMOTE); }
 void OpRequest::set_force_rwordered() { set_rmw_flags(CEPH_OSD_RMW_FLAG_RWORDERED); }
 
-void OpRequest::mark_flag_point(uint8_t flag, const string& s) {
+void OpRequest::mark_flag_point(uint8_t flag, const char *s) {
 #ifdef WITH_LTTNG
   uint8_t old_flags = hit_flag_points;
 #endif
@@ -151,6 +146,18 @@ void OpRequest::mark_flag_point(uint8_t flag, const string& s) {
   current = s;
   hit_flag_points |= flag;
   latest_flag_point = flag;
+  tracepoint(oprequest, mark_flag_point, reqid.name._type,
+	     reqid.name._num, reqid.tid, reqid.inc, rmw_flags,
+	     flag, s, old_flags, hit_flag_points);
+}
+
+void OpRequest::mark_flag_point_string(uint8_t flag, const string& s) {
+#ifdef WITH_LTTNG
+  uint8_t old_flags = hit_flag_points;
+#endif
+  mark_event_string(s);
+  hit_flag_points |= flag;
+  latest_flag_point = flag;
   tracepoint(oprequest, mark_flag_point, reqid.name._type,
 	     reqid.name._num, reqid.tid, reqid.inc, rmw_flags,
 	     flag, s.c_str(), old_flags, hit_flag_points);
diff --git a/src/osd/OpRequest.h b/src/osd/OpRequest.h
index d92042e50b1..f4b27ad45f4 100644
--- a/src/osd/OpRequest.h
+++ b/src/osd/OpRequest.h
@@ -170,13 +170,13 @@ public:
     mark_flag_point(flag_reached_pg, "reached_pg");
   }
   void mark_delayed(const string& s) {
-    mark_flag_point(flag_delayed, s);
+    mark_flag_point_string(flag_delayed, s);
   }
   void mark_started() {
     mark_flag_point(flag_started, "started");
   }
   void mark_sub_op_sent(const string& s) {
-    mark_flag_point(flag_sub_op_sent, s);
+    mark_flag_point_string(flag_sub_op_sent, s);
   }
   void mark_commit_sent() {
     mark_flag_point(flag_commit_sent, "commit_sent");
@@ -197,7 +197,8 @@ public:
 
 private:
   void set_rmw_flags(int flags);
-  void mark_flag_point(uint8_t flag, const string& s);
+  void mark_flag_point(uint8_t flag, const char *s);
+  void mark_flag_point_string(uint8_t flag, const string& s);
 };
 
 typedef OpRequest::Ref OpRequestRef;
diff --git a/src/osd/ReplicatedBackend.cc b/src/osd/ReplicatedBackend.cc
index 175af3dd9b3..6af8b333d65 100644
--- a/src/osd/ReplicatedBackend.cc
+++ b/src/osd/ReplicatedBackend.cc
@@ -701,14 +701,14 @@ void ReplicatedBackend::sub_op_modify_reply(OpRequestRef op)
       if (ip_op.op) {
         ostringstream ss;
         ss << "sub_op_commit_rec from " << from;
-	ip_op.op->mark_event(ss.str());
+	ip_op.op->mark_event_string(ss.str());
       }
     } else {
       assert(ip_op.waiting_for_applied.count(from));
       if (ip_op.op) {
         ostringstream ss;
         ss << "sub_op_applied_rec from " << from;
-	ip_op.op->mark_event(ss.str());
+	ip_op.op->mark_event_string(ss.str());
       }
     }
     ip_op.waiting_for_applied.erase(from);