From d0dc2b7c4c459afc8e0f3fa448a4982e1eafd8c7 Mon Sep 17 00:00:00 2001
From: Siyuan Zhang <siyuanzhang.zsy@alibaba-inc.com>
Date: Fri, 16 Jun 2023 11:24:17 +0800
Subject: [PATCH] Print metrics of application running time (#2908)

Fixes #2898
---
 analytical_engine/core/app/app_invoker.h     | 19 +++++++++++++------
 coordinator/gscoordinator/cluster_builder.py |  2 +-
 2 files changed, 14 insertions(+), 7 deletions(-)

diff --git a/analytical_engine/core/app/app_invoker.h b/analytical_engine/core/app/app_invoker.h
index c618cf38fa6d..be4c38ff5808 100644
--- a/analytical_engine/core/app/app_invoker.h
+++ b/analytical_engine/core/app/app_invoker.h
@@ -16,13 +16,14 @@
 #ifndef ANALYTICAL_ENGINE_CORE_APP_APP_INVOKER_H_
 #define ANALYTICAL_ENGINE_CORE_APP_APP_INVOKER_H_
 
-#include <glog/logging.h>
-
 #include <cstdint>
 #include <memory>
 #include <string>
 #include <type_traits>
 
+#include "glog/logging.h"
+#include "grape/util.h"
+
 #ifdef NETWORKX
 #include "core/object/dynamic.h"
 #endif
@@ -186,15 +187,18 @@ class AppInvoker {
   static void query_impl(std::shared_ptr<worker_t> worker,
                          const rpc::QueryArgs& query_args,
                          std::index_sequence<I...>) {
+    double start_time = grape::GetCurrentTime();
     worker->Query(
         ArgsUnpacker<typename std::remove_const<typename std::remove_reference<
             typename ArgTypeAt<I + 1, context_init_func_t>::type>::type>::
                          type>::unpack(query_args.args(I))...);
+    double end_time = grape::GetCurrentTime();
+    LOG(INFO) << "Query time: " << end_time - start_time << " seconds";
   }
 
  public:
-  static bl::result<nullptr_t> Query(std::shared_ptr<worker_t> worker,
-                                     const rpc::QueryArgs& query_args) {
+  static bl::result<std::nullptr_t> Query(std::shared_ptr<worker_t> worker,
+                                          const rpc::QueryArgs& query_args) {
     constexpr std::size_t args_num = ArgsNum<context_init_func_t>::value - 1;
     // There maybe default argument
     CHECK_OR_RAISE(args_num >= query_args.args_size());
@@ -212,15 +216,18 @@ class FlashAppInvoker {
   static void query_impl(std::shared_ptr<worker_t> worker,
                          const rpc::QueryArgs& query_args,
                          std::index_sequence<I...>) {
+    double start_time = grape::GetCurrentTime();
     worker->Query(
         ArgsUnpacker<typename std::remove_const<typename std::remove_reference<
             typename ArgTypeAt<I + 2, app_run_func_t>::type>::type>::type>::
             unpack(query_args.args(I))...);
+    double end_time = grape::GetCurrentTime();
+    LOG(INFO) << "Query time: " << end_time - start_time << " seconds";
   }
 
  public:
-  static bl::result<nullptr_t> Query(std::shared_ptr<worker_t> worker,
-                                     const rpc::QueryArgs& query_args) {
+  static bl::result<std::nullptr_t> Query(std::shared_ptr<worker_t> worker,
+                                          const rpc::QueryArgs& query_args) {
     constexpr std::size_t args_num = ArgsNum<app_run_func_t>::value - 2;
     // There maybe default argument
     CHECK_OR_RAISE(args_num >= query_args.args_size());
diff --git a/coordinator/gscoordinator/cluster_builder.py b/coordinator/gscoordinator/cluster_builder.py
index dcb47916cc9f..b7010b8f4af4 100644
--- a/coordinator/gscoordinator/cluster_builder.py
+++ b/coordinator/gscoordinator/cluster_builder.py
@@ -301,7 +301,7 @@ def get_interactive_executor_container(self, volume_mounts):
         args = [
             "bash",
             "-c",
-            self._get_tail_if_exists_cmd("/var/log/graphscope/current/executor.log"),
+            self._get_tail_if_exists_cmd("/var/log/graphscope/current/executor.*.log"),
         ]
         container = self.get_engine_container_helper(
             name,