Add verbose query execution info (#36)

Co-authored-by: Marko Budiselic <marko.budiselic@memgraph.com>

Author: jmatak

CMakeLists.txt

@@ -15,7 +15,7 @@
 # along with this program.  If not, see <https://www.gnu.org/licenses/>.
 
 cmake_minimum_required(VERSION 3.4)
-project(mgconsole VERSION 1.2)
+project(mgconsole VERSION 1.3)
 include(CTest)
 
 set(CMAKE_MODULE_PATH ${CMAKE_MODULE_PATH} ${PROJECT_SOURCE_DIR}/cmake)

src/main.cpp

@@ -14,14 +14,14 @@
 // You should have received a copy of the GNU General Public License
 // along with this program.  If not, see <https://www.gnu.org/licenses/>.
 
+#include <signal.h>
+
 #include <algorithm>
 #include <cstdio>
 #include <iostream>
 #include <optional>
 #include <thread>
 
-#include <signal.h>
-
 #ifdef _WIN32
 
 #include <cstdlib>
@@ -58,6 +58,8 @@ DEFINE_bool(term_colors, false, "Use terminal colors syntax highlighting.");
 DEFINE_string(output_format, "tabular",
               "Query output format. Can be csv/tabular. If output format is "
               "other than tabular `fit-to-screen` flag is ignored.");
+DEFINE_bool(verbose_execution_info, false,
+            "Output the additional information about query such is query cost, parsing, planning and execution times.");
 DEFINE_validator(output_format, [](const char *, const std::string &value) {
   if (value == constants::kCsvFormat || value == constants::kTabularFormat) {
     return true;
@@ -252,13 +254,11 @@ int main(int argc, char **argv) {
     if (query->empty()) {
       continue;
     }
-
     try {
       auto ret = query::ExecuteQuery(session.get(), *query);
       if (ret.records.size() > 0) {
         Output(ret.header, ret.records, output_opts, csv_opts);
       }
-
       if (console::is_a_tty(STDIN_FILENO)) {
         std::string summary;
         if (ret.records.size() == 0) {
@@ -268,7 +268,7 @@ int main(int argc, char **argv) {
         } else {
           summary = std::to_string(ret.records.size()) + " rows in set";
         }
-        std::printf("%s (%.3lf sec)\n", summary.c_str(), ret.wall_time.count());
+        std::printf("%s (round trip in %.3lf sec)\n", summary.c_str(), ret.wall_time.count());
         auto history_ret = save_history();
         if (history_ret != 0) {
           cleanup_resources();
@@ -280,6 +280,9 @@ int main(int argc, char **argv) {
         if (ret.stats) {
           console::EchoStats(ret.stats.value());
         }
+        if (FLAGS_verbose_execution_info && ret.execution_info) {
+          console::EchoExecutionInfo(ret.execution_info.value());
+        }
       }
     } catch (const utils::ClientQueryException &e) {
       if (!console::is_a_tty(STDIN_FILENO)) {

src/utils/utils.cpp

@@ -1,4 +1,5 @@
 #include <string.h>
+
 #include <algorithm>
 #include <chrono>
 #include <cmath>
@@ -504,6 +505,8 @@ std::map<std::string, std::string> ParseNotifications(const mg_value *mg_notific
   return notifications;
 }
 
+double ParseFloat(const mg_value *mg_val_float) { return mg_value_float(mg_val_float); }
+
 }  // namespace
 
 namespace console {
@@ -567,6 +570,21 @@ void EchoInfo(const std::string &message) {
   }
 }
 
+void EchoExecutionInfo(const std::map<std::string, double> &execution_info) {
+  std::cout << "Additional execution time info:" << std::endl;
+  for (const auto &[key, value] : execution_info) {
+    if (key == "cost_estimate") {
+      std::cout << "  Query COST estimate: " << value << std::endl;
+    } else if (key == "parsing_time") {
+      std::cout << "  Query PARSING time: " << value << " sec" << std::endl;
+    } else if (key == "planning_time") {
+      std::cout << "  Query PLANNING time: " << value << " sec" << std::endl;
+    } else if (key == "plan_execution_time") {
+      std::cout << "  Query PLAN EXECUTION time: " << value << " sec" << std::endl;
+    }
+  }
+}
+
 void EchoStats(const std::map<std::string, std::int64_t> &stats) {
   for (const auto &[key, value] : stats) {
     if (value == 0) {
@@ -814,6 +832,18 @@ QueryData ExecuteQuery(mg_session *session, const std::string &query) {
 
   const mg_map *summary = mg_result_summary(result);
   if (summary && mg_map_size(summary) > 0) {
+    {
+      std::map<std::string, double> execution_info;
+      for (auto key : {"cost_estimate", "parsing_time", "planning_time", "plan_execution_time"}) {
+        if (const mg_value *info = mg_map_at(summary, key); info) {
+          execution_info.emplace(key, ParseFloat(info));
+        }
+      }
+      if (!execution_info.empty()) {
+        ret.execution_info = execution_info;
+      }
+    }
+
     if (const mg_value *mg_stats = mg_map_at(summary, "stats"); mg_stats) {
       ret.stats.emplace(ParseStats(mg_stats));
     }

src/utils/utils.hpp

@@ -178,6 +178,8 @@ void EchoStats(const std::map<std::string, std::int64_t> &stats);
 
 void EchoNotification(const std::map<std::string, std::string> &notification);
 
+void EchoExecutionInfo(const std::map<std::string, double> &execution_info);
+
 /// Helper function that sets default input for 'readline'
 int SetDefaultText();
 
@@ -210,6 +212,7 @@ struct QueryData {
   std::chrono::duration<double> wall_time;
   std::optional<std::map<std::string, std::string>> notification;
   std::optional<std::map<std::string, std::int64_t>> stats;
+  std::optional<std::map<std::string, double>> execution_info;
 };
 
 std::optional<std::string> GetQuery(Replxx *replxx_instance);