Fix graph profiling data format

src/common/datatypes/HostAddr.h

@@ -40,8 +40,13 @@ struct HostAddr {
 
   std::string toString() const {
     std::stringstream os;
-    os << "\"" << host << "\""
-       << ":" << port;
+    os << "\"" << host << "\":" << port;
+    return os.str();
+  }
+
+  std::string toRawString() const {
+    std::stringstream os;
+    os << host << ":" << port;
     return os.str();
   }
 

src/graph/executor/StorageAccessExecutor.cpp

@@ -148,16 +148,5 @@ StatusOr<std::vector<Value>> StorageAccessExecutor::buildRequestListByVidType(It
   return internal::buildRequestList<std::string>(space, exprCtx, iter, expr, dedup, isCypher);
 }
 
-std::string StorageAccessExecutor::getStorageDetail(
-    optional_field_ref<const std::map<std::string, int32_t> &> ref) const {
-  if (ref.has_value()) {
-    auto content = util::join(*ref, [](auto &iter) -> std::string {
-      return folly::sformat("\n  {}:{}(us)", iter.first, iter.second);
-    });
-    return "{" + content + "}";
-  }
-  return "";
-}
-
 }  // namespace graph
 }  // namespace nebula

src/graph/executor/StorageAccessExecutor.h

@@ -9,6 +9,7 @@
 
 #include "clients/storage/StorageClientBase.h"
 #include "graph/executor/Executor.h"
+#include "graph/util/Utils.h"
 
 namespace nebula {
 
@@ -140,22 +141,15 @@ class StorageAccessExecutor : public Executor {
   }
 
   template <typename RESP>
-  void addStats(RESP &resp, std::unordered_map<std::string, std::string> &stats) const {
+  void addStats(storage::StorageRpcResponse<RESP> &resp,
+                std::unordered_map<std::string, std::string> &stats) const {
     auto &hostLatency = resp.hostLatency();
     for (size_t i = 0; i < hostLatency.size(); ++i) {
-      auto &info = hostLatency[i];
-      stats.emplace(folly::sformat("{} exec/total", std::get<0>(info).toString()),
-                    folly::sformat("{}(us)/{}(us)", std::get<1>(info), std::get<2>(info)));
-      auto detail = getStorageDetail(resp.responses()[i].result_ref()->latency_detail_us_ref());
-      if (!detail.empty()) {
-        stats.emplace("storage_detail", detail);
-      }
+      auto info = util::collectRespProfileData(resp.responses()[i].get_result(), hostLatency[i]);
+      stats.emplace(folly::sformat("resp[{}]", i), folly::toPrettyJson(info));
     }
   }
 
-  std::string getStorageDetail(
-      apache::thrift::optional_field_ref<const std::map<std::string, int32_t> &> ref) const;
-
   bool isIntVidType(const SpaceInfo &space) const;
 
   StatusOr<DataSet> buildRequestDataSetByVidType(Iterator *iter,

src/graph/executor/algo/ShortestPathBase.cpp

@@ -8,6 +8,7 @@
 #include "graph/util/Utils.h"
 
 using apache::thrift::optional_field_ref;
+using nebula::graph::util::collectRespProfileData;
 using nebula::storage::StorageClient;
 
 namespace nebula {
@@ -70,17 +71,6 @@ std::vector<Value> ShortestPathBase::handlePropResp(PropRpcResponse&& resps) {
   return vertices;
 }
 
-std::string ShortestPathBase::getStorageDetail(
-    optional_field_ref<const std::map<std::string, int32_t>&> ref) const {
-  if (ref.has_value()) {
-    auto content = util::join(*ref, [](auto& iter) -> std::string {
-      return folly::sformat("{}:{}(us)", iter.first, iter.second);
-    });
-    return "{" + content + "}";
-  }
-  return "";
-}
-
 Status ShortestPathBase::handleErrorCode(nebula::cpp2::ErrorCode code, PartitionID partId) const {
   switch (code) {
     case nebula::cpp2::ErrorCode::E_KEY_NOT_FOUND:
@@ -171,55 +161,35 @@ void ShortestPathBase::addStats(RpcResponse& resp,
                                 size_t stepNum,
                                 int64_t timeInUSec,
                                 bool reverse) const {
+  folly::dynamic stats = folly::dynamic::array();
   auto& hostLatency = resp.hostLatency();
-  std::stringstream ss;
-  ss << "{\n";
   for (size_t i = 0; i < hostLatency.size(); ++i) {
     size_t size = 0u;
     auto& result = resp.responses()[i];
     if (result.vertices_ref().has_value()) {
       size = (*result.vertices_ref()).size();
     }
-    auto& info = hostLatency[i];
-    ss << "{" << folly::sformat("{} exec/total/vertices: ", std::get<0>(info).toString())
-       << folly::sformat("{}(us)/{}(us)/{},", std::get<1>(info), std::get<2>(info), size) << "\n"
-       << folly::sformat("total_rpc_time: {}(us)", timeInUSec) << "\n";
-    auto detail = getStorageDetail(result.result.latency_detail_us_ref());
-    if (!detail.empty()) {
-      ss << folly::sformat("storage_detail: {}", detail);
-    }
-    ss << "\n}";
-  }
-  ss << "\n}";
-  if (reverse) {
-    statsLock_.lock();
-    stats_->emplace(folly::sformat("reverse step {}", stepNum), ss.str());
-    statsLock_.unlock();
-  } else {
-    statsLock_.lock();
-    stats_->emplace(folly::sformat("step {}", stepNum), ss.str());
-    statsLock_.unlock();
+    auto info = util::collectRespProfileData(result.result, hostLatency[i], size, timeInUSec);
+    stats.push_back(std::move(info));
   }
+
+  auto key = folly::sformat("{}step[{}]", reverse ? "reverse " : "", stepNum);
+  statsLock_.lock();
+  stats_->emplace(key, folly::toPrettyJson(stats));
+  statsLock_.unlock();
 }
 
 void ShortestPathBase::addStats(PropRpcResponse& resp, int64_t timeInUSec) const {
+  folly::dynamic stats = folly::dynamic::array();
   auto& hostLatency = resp.hostLatency();
-  std::stringstream ss;
-  ss << "{\n";
   for (size_t i = 0; i < hostLatency.size(); ++i) {
-    auto& info = hostLatency[i];
-    ss << "{" << folly::sformat("{} exec/total: ", std::get<0>(info).toString())
-       << folly::sformat("{}(us)/{}(us),", std::get<1>(info), std::get<2>(info)) << "\n"
-       << folly::sformat("total_rpc_time: {}(us)", timeInUSec) << "\n";
-    auto detail = getStorageDetail(resp.responses()[i].result_ref()->latency_detail_us_ref());
-    if (!detail.empty()) {
-      ss << folly::sformat("storage_detail: {}", detail);
-    }
-    ss << "\n}";
+    const auto& result = resp.responses()[i].get_result();
+    auto info = util::collectRespProfileData(result, hostLatency[i], 0, timeInUSec);
+    stats.push_back(std::move(info));
   }
-  ss << "\n}";
+
   statsLock_.lock();
-  stats_->emplace(folly::sformat("get_prop "), ss.str());
+  stats_->emplace("get_prop", folly::toPrettyJson(stats));
   statsLock_.unlock();
 }
 

src/graph/executor/algo/ShortestPathBase.h

@@ -74,9 +74,6 @@ class ShortestPathBase {
     return Result::State::kSuccess;
   }
 
-  std::string getStorageDetail(
-      apache::thrift::optional_field_ref<const std::map<std::string, int32_t>&> ref) const;
-
  protected:
   const ShortestPath* pathNode_{nullptr};
   QueryContext* qctx_{nullptr};

src/graph/executor/algo/SubgraphExecutor.cpp

@@ -5,6 +5,7 @@
 #include "graph/executor/algo/SubgraphExecutor.h"
 
 #include "graph/service/GraphFlags.h"
+#include "graph/util/Utils.h"
 
 using nebula::storage::StorageClient;
 namespace nebula {
@@ -59,14 +60,8 @@ folly::Future<Status> SubgraphExecutor::getNeighbors() {
           if (result.vertices_ref().has_value()) {
             size = (*result.vertices_ref()).size();
           }
-          auto& info = hostLatency[i];
-          otherStats_.emplace(
-              folly::sformat("{} exec/total/vertices", std::get<0>(info).toString()),
-              folly::sformat("{}(us)/{}(us)/{},", std::get<1>(info), std::get<2>(info), size));
-          auto detail = getStorageDetail(result.result.latency_detail_us_ref());
-          if (!detail.empty()) {
-            otherStats_.emplace("storage_detail", detail);
-          }
+          auto info = util::collectRespProfileData(result.result, hostLatency[i], size);
+          otherStats_.emplace(folly::sformat("resp[{}]", i), folly::toPrettyJson(info));
         }
         vids_.clear();
         return handleResponse(std::move(resp));

src/graph/executor/query/GetDstBySrcExecutor.cpp

@@ -5,6 +5,7 @@
 #include "graph/executor/query/GetDstBySrcExecutor.h"
 
 #include "graph/service/GraphFlags.h"
+#include "graph/util/Utils.h"
 
 using nebula::storage::StorageClient;
 using nebula::storage::StorageRpcResponse;
@@ -55,14 +56,8 @@ folly::Future<Status> GetDstBySrcExecutor::execute() {
           if (result.dsts_ref().has_value()) {
             size = (*result.dsts_ref()).size();
           }
-          auto& info = hostLatency[i];
-          otherStats_.emplace(
-              folly::sformat("{} exec/total/vertices", std::get<0>(info).toString()),
-              folly::sformat("{}(us)/{}(us)/{},", std::get<1>(info), std::get<2>(info), size));
-          auto detail = getStorageDetail(result.result.latency_detail_us_ref());
-          if (!detail.empty()) {
-            otherStats_.emplace("storage_detail", detail);
-          }
+          auto info = util::collectRespProfileData(result.result, hostLatency[i], size);
+          otherStats_.emplace(folly::sformat("resp[{}]", i), folly::toPrettyJson(info));
         }
         return handleResponse(resp, this->gd_->colNames());
       });

src/graph/executor/query/GetNeighborsExecutor.cpp

@@ -5,6 +5,7 @@
 #include "graph/executor/query/GetNeighborsExecutor.h"
 
 #include "graph/service/GraphFlags.h"
+#include "graph/util/Utils.h"
 
 using nebula::storage::StorageClient;
 using nebula::storage::StorageRpcResponse;
@@ -69,14 +70,8 @@ folly::Future<Status> GetNeighborsExecutor::execute() {
           if (result.vertices_ref().has_value()) {
             size = (*result.vertices_ref()).size();
           }
-          auto& info = hostLatency[i];
-          otherStats_.emplace(
-              folly::sformat("{} exec/total/vertices", std::get<0>(info).toString()),
-              folly::sformat("{}(us)/{}(us)/{},", std::get<1>(info), std::get<2>(info), size));
-          auto detail = getStorageDetail(result.result.latency_detail_us_ref());
-          if (!detail.empty()) {
-            otherStats_.emplace("storage_detail", detail);
-          }
+          auto info = util::collectRespProfileData(result.result, hostLatency[i], size);
+          otherStats_.emplace(folly::sformat("resp[{}]", i), folly::toPrettyJson(info));
         }
         return handleResponse(resp);
       });

src/graph/executor/query/TraverseExecutor.cpp

@@ -7,6 +7,7 @@
 #include "clients/storage/StorageClient.h"
 #include "graph/service/GraphFlags.h"
 #include "graph/util/SchemaUtil.h"
+#include "graph/util/Utils.h"
 
 using nebula::storage::StorageClient;
 using nebula::storage::StorageRpcResponse;
@@ -120,27 +121,18 @@ Expression* TraverseExecutor::selectFilter() {
 }
 
 void TraverseExecutor::addStats(RpcResponse& resp, int64_t getNbrTimeInUSec) {
+  folly::dynamic stepInfo = folly::dynamic::array();
   auto& hostLatency = resp.hostLatency();
-  std::stringstream ss;
-  ss << "{\n";
   for (size_t i = 0; i < hostLatency.size(); ++i) {
     size_t size = 0u;
     auto& result = resp.responses()[i];
     if (result.vertices_ref().has_value()) {
       size = (*result.vertices_ref()).size();
     }
-    auto& info = hostLatency[i];
-    ss << "{" << folly::sformat("{} exec/total/vertices: ", std::get<0>(info).toString())
-       << folly::sformat("{}(us)/{}(us)/{},", std::get<1>(info), std::get<2>(info), size) << "\n"
-       << folly::sformat("total_rpc_time: {}(us)", getNbrTimeInUSec) << "\n";
-    auto detail = getStorageDetail(result.result.latency_detail_us_ref());
-    if (!detail.empty()) {
-      ss << folly::sformat("storage_detail: {}", detail);
-    }
-    ss << "\n}";
+    auto info = util::collectRespProfileData(result.result, hostLatency[i], size, getNbrTimeInUSec);
+    stepInfo.push_back(std::move(info));
   }
-  ss << "\n}";
-  otherStats_.emplace(folly::sformat("step {}", currentStep_), ss.str());
+  otherStats_.emplace(folly::sformat("step[{}]", currentStep_), folly::toPrettyJson(stepInfo));
 }
 
 folly::Future<Status> TraverseExecutor::handleResponse(RpcResponse&& resps) {

src/graph/util/CMakeLists.txt

@@ -14,6 +14,7 @@ nebula_add_library(
     ParserUtil.cpp
     PlannerUtil.cpp
     ValidateUtil.cpp
+    Utils.cpp
 )
 
 nebula_add_library(

src/graph/util/Utils.cpp

@@ -0,0 +1,39 @@
+// Copyright (c) 2022 vesoft inc. All rights reserved.
+//
+// This source code is licensed under Apache 2.0 License.
+
+#include "graph/util/Utils.h"
+
+#include "interface/gen-cpp2/storage_types.h"
+
+namespace nebula::graph::util {
+
+folly::dynamic getStorageDetail(const std::map<std::string, int32_t>& profileDetail) {
+  folly::dynamic profileData = folly::dynamic::object();
+  for (auto& p : profileDetail) {
+    profileData.insert(p.first, folly::sformat("{}(us)", p.second));
+  }
+  return profileData;
+}
+
+folly::dynamic collectRespProfileData(const storage::cpp2::ResponseCommon& resp,
+                                      const std::tuple<HostAddr, int32_t, int32_t>& info,
+                                      size_t numVertices,
+                                      size_t totalRpcTime) {
+  folly::dynamic stat = folly::dynamic::object();
+  stat.insert("host", std::get<0>(info).toRawString());
+  stat.insert("exec", folly::sformat("{}(us)", std::get<1>(info)));
+  stat.insert("total", folly::sformat("{}(us)", std::get<2>(info)));
+  if (numVertices > 0) {
+    stat.insert("vertices", numVertices);
+  }
+  if (totalRpcTime > 0) {
+    stat.insert("total_rpc_time", folly::sformat("{}(us)", totalRpcTime));
+  }
+  if (resp.latency_detail_us_ref().has_value()) {
+    stat.insert("storage_detail", getStorageDetail(*resp.get_latency_detail_us()));
+  }
+  return stat;
+}
+
+}  // namespace nebula::graph::util

src/graph/util/Utils.h

@@ -6,11 +6,18 @@
 #define GRAPH_UTIL_UTILS_H_
 
 #include <folly/String.h>
+#include <folly/dynamic.h>
 
 #include <iterator>
 #include <string>
 #include <vector>
 
+#include "common/datatypes/HostAddr.h"
+
+namespace nebula::storage::cpp2 {
+class ResponseCommon;
+}
+
 namespace nebula::graph::util {
 
 // Iterates the container and for each element, apply the function fn(). Joins the results of the
@@ -24,6 +31,13 @@ std::string join(const Container& container, Fn fn, const std::string& delimiter
   return folly::join(delimiter, strs);
 }
 
+folly::dynamic getStorageDetail(const std::map<std::string, int32_t>& profileDetail);
+
+folly::dynamic collectRespProfileData(const storage::cpp2::ResponseCommon& resp,
+                                      const std::tuple<HostAddr, int32_t, int32_t>& info,
+                                      size_t numVertices = 0UL,
+                                      size_t totalRpcTime = 0UL);
+
 }  // namespace nebula::graph::util
 
 #endif  // GRAPH_UTIL_UTILS_H_

src/storage/query/GetDstBySrcProcessor.cpp

@@ -31,7 +31,7 @@ void GetDstBySrcProcessor::doProcess(const cpp2::GetDstBySrcRequest& req) {
   if (req.common_ref().has_value() && req.get_common()->profile_detail_ref().value_or(false)) {
     profileDetailFlag_ = true;
     profileDetail("GetDstBySrcProcessorTotal", 0);
-    profileDetail("Dedup", 0);
+    profileDetail("GetDstBySrcProcessorDedup", 0);
   }
 
   spaceId_ = req.get_space_id();
@@ -320,7 +320,7 @@ void GetDstBySrcProcessor::onProcessFinished() {
   resp_.dsts_ref() = std::move(resultDataSet_);
 
   if (profileDetailFlag_) {
-    profileDetail("Dedup", dedupDuration_.elapsedInUSec());
+    profileDetail("GetDstBySrcProcessorDedup", dedupDuration_.elapsedInUSec());
     profileDetail("GetDstBySrcProcessorTotal", totalDuration_.elapsedInUSec());
   }
 }