mds: add extra details for cache drop output

Signed-off-by: Patrick Donnelly <pdonnell@redhat.com>
(cherry picked from commit 3bc093fd9e9daf99f09abe68ce0c0077ef0f58da)

diff --git a/src/mds/MDSRank.cc b/src/mds/MDSRank.cc
index 24416aa20d2b38d16cad6bc5a3d9db91b5f3c08e..89b6e97b0658006c74a46d3ab6f1eebfe150a7d5 100644 (file)
--- a/src/mds/MDSRank.cc
+++ b/src/mds/MDSRank.cc
@@ -319,7 +319,7 @@ private:
   void recall_client_state() {
     dout(20) << __func__ << dendl;
     auto now = mono_clock::now();
-    auto duration = std::chrono::duration<double>(recall_start-now).count();
+    auto duration = std::chrono::duration<double>(now-recall_start).count();
 
     MDSGatherBuilder *gather = new MDSGatherBuilder(g_ceph_context);
     auto result = server->recall_client_state(gather, Server::RecallFlags::STEADY);
@@ -329,6 +329,7 @@ private:
              << (throttled ? " (throttled)" : "")
              << " recalled " << count << " caps" << dendl;
 
+    caps_recalled += count;
     if ((throttled || count > 0) && (recall_timeout == 0 || duration < recall_timeout)) {
       auto timer = new FunctionContext([this](int _) {
         recall_client_state();
@@ -362,6 +363,7 @@ private:
     f->open_object_section("client_recall");
     f->dump_int("return_code", r);
     f->dump_string("message", cpp_strerror(r));
+    f->dump_int("recalled", caps_recalled);
     f->close_section();
 
     // we can still continue after recall timeout
@@ -406,6 +408,7 @@ private:
     dout(10) << __func__
              << (throttled ? " (throttled)" : "")
              << " trimmed " << count << " caps" << dendl;
+    dentries_trimmed += count;
     if (throttled && count > 0) {
       auto timer = new FunctionContext([this](int _) {
         trim_cache();
@@ -419,9 +422,12 @@ private:
   void cache_status() {
     dout(20) << __func__ << dendl;
 
+    f->open_object_section("trim_cache");
+    f->dump_int("trimmed", dentries_trimmed);
+    f->close_section();
+
     // cache status section
     mdcache->cache_status(f);
-    f->close_section();
 
     complete(0);
   }
@@ -429,6 +435,10 @@ private:
   void finish(int r) override {
     dout(20) << __func__ << ": r=" << r << dendl;
 
+    auto d = std::chrono::duration<double>(mono_clock::now()-recall_start);
+    f->dump_float("duration", d.count());
+
+    f->close_section();
     on_finish->complete(r);
   }
 
@@ -442,6 +452,8 @@ private:
 
   int retval = 0;
   std::stringstream ss;
+  uint64_t caps_recalled = 0;
+  uint64_t dentries_trimmed = 0;
 
   // so as to use dout
   mds_rank_t whoami;

diff --git a/src/mds/Server.cc b/src/mds/Server.cc
index dea4a35a5bb6129441c914709afb1fbad47cc42d..6e4b874dcf925550ca4139453f9ec59e369f3249 100644 (file)
--- a/src/mds/Server.cc
+++ b/src/mds/Server.cc
@@ -1319,9 +1319,8 @@ std::pair<bool, uint64_t> Server::recall_client_state(MDSGatherBuilder* gather,
       if (gather) {
         flush_session(session, gather);
       }
-      session->notify_recall_sent(newlim);
+      caps_recalled += session->notify_recall_sent(newlim);
       recall_counter.hit(ceph_clock_now(), recall);
-      caps_recalled += recall;
     }
   }
 

diff --git a/src/mds/SessionMap.cc b/src/mds/SessionMap.cc
index 8b58295e45ea097e906d98bcb9e1efbeab376440..a5439165f10e5b9c1c09669d0b1d66927cd971c6 100644 (file)
--- a/src/mds/SessionMap.cc
+++ b/src/mds/SessionMap.cc
@@ -874,9 +874,10 @@ void Session::notify_cap_release(size_t n_caps)
  * in order to generate health metrics if the session doesn't see
  * a commensurate number of calls to ::notify_cap_release
  */
-void Session::notify_recall_sent(const size_t new_limit)
+uint64_t Session::notify_recall_sent(const size_t new_limit)
 {
   const auto num_caps = caps.size();
+  ceph_assert(new_limit < num_caps);
   const auto count = num_caps-new_limit;
 
   /* Entering recall phase, set up counters so we can later judge whether the
@@ -884,6 +885,7 @@ void Session::notify_recall_sent(const size_t new_limit)
    * released caps from a previous recall.
    */
 
+  uint64_t new_change;
   if (recall_limit != new_limit) {
     const auto now = clock::now();
     recalled_at = now;
@@ -891,6 +893,9 @@ void Session::notify_recall_sent(const size_t new_limit)
     recall_count = count;
     recall_release_count = 0;
     recall_limit = new_limit;
+    new_change = count;
+  } else {
+    new_change = 0; /* no change! */
   }
 
   /* Always hit the session counter as a RECALL message is still sent to the
@@ -899,6 +904,7 @@ void Session::notify_recall_sent(const size_t new_limit)
    * throttle future RECALL messages).
    */
   cap_recalled.hit(count);
+  return new_change;
 }
 
 void Session::clear_recalled()

diff --git a/src/mds/SessionMap.h b/src/mds/SessionMap.h
index 24cf2113f9276f43378e5dd9e2628de6b735f716..a9fc880e64e021553be0ca6764e79889161390e6 100644 (file)
--- a/src/mds/SessionMap.h
+++ b/src/mds/SessionMap.h
@@ -176,7 +176,7 @@ public:
   interval_set<inodeno_t> pending_prealloc_inos; // journaling prealloc, will be added to prealloc_inos
 
   void notify_cap_release(size_t n_caps);
-  void notify_recall_sent(const size_t new_limit);
+  uint64_t notify_recall_sent(const size_t new_limit);
   auto cap_recalled_counter() const {
     return cap_recalled.get(ceph_clock_now());
   }