Train debug (#203)

### What problem were solved in this pull request?

Problem:
与训练营配合，可以在SQL命令请求过程中，添加调试信息

### What is changed and how it works?
可以参考 debug-output.md 文档。
增加 sql_debug 变量，使用set sql_debug=1; 可以设置。
在SQL命令执行过程中，调用sql_debug函数，增加调试信息。在普通文本通讯协议中，调试信息会以 '#'
开头的形式打印出来。但是注意调试信息中不要带换行符。

### Other information

.vscode/launch.json

@@ -9,7 +9,7 @@
             "request": "launch",
             "name": "Debug",
             "program": "${workspaceFolder}/${defaultBuildTask}/bin/observer",
-            "args": ["-f", "${workspaceFolder}/etc/observer.ini", "-s", "miniob.sock"],
+            "args": ["-f", "${workspaceFolder}/etc/observer.ini", "-P", "cli"],
             "cwd": "${workspaceFolder}/${defaultBuildTask}/"
         }
     ]

build.sh

@@ -5,7 +5,7 @@ TOPDIR=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
 
 BUILD_SH=$TOPDIR/build.sh
 
-CMAKE_COMMAND="cmake -DCMAKE_EXPORT_COMPILE_COMMANDS=1"
+CMAKE_COMMAND="cmake -DCMAKE_EXPORT_COMPILE_COMMANDS=1 --log-level=WARNING"
 
 ALL_ARGS=("$@")
 BUILD_ARGS=()
@@ -73,38 +73,40 @@ function do_init
   git submodule update --init || return
   current_dir=$PWD
 
+  MAKE_COMMAND="make --silent"
+
   # build libevent
   cd ${TOPDIR}/deps/3rd/libevent && \
     git checkout release-2.1.12-stable && \
     mkdir -p build && \
     cd build && \
-    cmake .. -DEVENT__DISABLE_OPENSSL=ON -DEVENT__LIBRARY_TYPE=BOTH && \
-    make -j4 && \
+    ${CMAKE_COMMAND} .. -DEVENT__DISABLE_OPENSSL=ON -DEVENT__LIBRARY_TYPE=BOTH && \
+    ${MAKE_COMMAND} -j4 && \
     make install
 
   # build googletest
   cd ${TOPDIR}/deps/3rd/googletest && \
     mkdir -p build && \
     cd build && \
-    cmake .. && \
-    make -j4 && \
-    make install
+    ${CMAKE_COMMAND} .. && \
+    ${MAKE_COMMAND} -j4 && \
+    ${MAKE_COMMAND} install
 
   # build google benchmark
   cd ${TOPDIR}/deps/3rd/benchmark && \
     mkdir -p build && \
     cd build && \
-    cmake .. -DBENCHMARK_ENABLE_TESTING=OFF  -DBENCHMARK_INSTALL_DOCS=OFF -DBENCHMARK_ENABLE_GTEST_TESTS=OFF -DBENCHMARK_USE_BUNDLED_GTEST=OFF -DBENCHMARK_ENABLE_ASSEMBLY_TESTS=OFF && \
-    make -j4 && \
-    make install
+    ${CMAKE_COMMAND} .. -DBENCHMARK_ENABLE_TESTING=OFF  -DBENCHMARK_INSTALL_DOCS=OFF -DBENCHMARK_ENABLE_GTEST_TESTS=OFF -DBENCHMARK_USE_BUNDLED_GTEST=OFF -DBENCHMARK_ENABLE_ASSEMBLY_TESTS=OFF && \
+    ${MAKE_COMMAND} -j4 && \
+    ${MAKE_COMMAND} install
 
   # build jsoncpp
   cd ${TOPDIR}/deps/3rd/jsoncpp && \
     mkdir -p build && \
     cd build && \
-    cmake -DJSONCPP_WITH_TESTS=OFF -DJSONCPP_WITH_POST_BUILD_UNITTEST=OFF .. && \
-    make && \
-    make install
+    ${CMAKE_COMMAND} -DJSONCPP_WITH_TESTS=OFF -DJSONCPP_WITH_POST_BUILD_UNITTEST=OFF .. && \
+    ${MAKE_COMMAND} && \
+    ${MAKE_COMMAND} install
 
   cd $current_dir
 }

deps/common/log/log.h

@@ -25,15 +25,13 @@ See the Mulan PSL v2 for more details. */
 #include <map>
 #include <set>
 #include <string>
-#include  <functional>
+#include <functional>
 
 #include "common/defs.h"
 
 namespace common {
 
 const unsigned int ONE_KILO = 1024;
-const unsigned int ONE_MILLION = ONE_KILO * ONE_KILO;
-const unsigned int ONE_GIGA = ONE_MILLION * ONE_KILO;
 const unsigned int FILENAME_LENGTH_MAX = 256;  // the max filename length
 
 const int LOG_STATUS_OK = 0;
@@ -111,6 +109,11 @@ public:
 
   int rotate(const int year = 0, const int month = 0, const int day = 0);
 
+  /**
+   * @brief 设置一个在日志中打印当前上下文信息的回调函数
+   * @details 比如设置一个获取当前session标识的函数，那么每次在打印日志时都会输出session信息。
+   *          这个回调函数返回了一个intptr_t类型的数据，可能返回字符串更好，但是现在够用了。
+   */
   void set_context_getter(std::function<intptr_t()> context_getter);
   intptr_t context_id();
   
@@ -328,13 +331,4 @@ int Log::out(const LOG_LEVEL console_level, const LOG_LEVEL log_level, T &msg)
  */
 const char *lbt();
 
-/**
- * @brief 设置一个在日志中打印当前上下文信息的回调函数
- * @details 比如设置一个获取当前session标识的函数，那么每次在打印日志时都会输出session信息。
- *          这个回调函数返回了一个intptr_t类型的数据，可能返回字符串更好，但是现在够用了。
- */
-void set_log_context_getter(std::function<intptr_t()> context_getter);
-
-extern std::function<intptr_t()> g_context_getter;
-
 }  // namespace common

docs/src/design/miniob-transaction.md

 本篇文档介绍 MiniOB 中的事务模块是如何工作的。
 
 # 背景
-事务是数据库中非常基础的一个模块，也是非常核心的功能。事务有一些基本的概念，叫做ACID，分别是原子性(Atomicity)、一致性(Consistency)、隔离性(Isolation)和持久性(Durability)。如果你对事务的基本概念不太清楚，建议先学习了解事务的基本概念，比如学习[事务处理](lectures/lecture-6.md)章节，或者在网上搜索更多资料。
+事务是数据库中非常基础的一个模块，也是非常核心的功能。事务有一些基本的概念，叫做ACID，分别是原子性(Atomicity)、一致性(Consistency)、隔离性(Isolation)和持久性(Durability)。如果你对事务的基本概念不太清楚，建议先学习了解事务的基本概念，比如学习[事务处理](../lectures/lecture-6.md)章节，或者在网上搜索更多资料。
 
 # MiniOB 中的事务
 ## 实现简介

docs/src/game/debug-output.md

+本篇文档介绍如何向[训练营](https://open.oceanbase.com/train)输出调试信息。
+
+在使用训练营提交测试时，有时候会遇到本地环境没有问题，但是训练营上的输出总是不符合预期。但是训练营没有办法调试，这时候就需要在训练营上输出调试信息，以便于定位问题。
+
+**如何输出调试信息**
+
+可以参考文件 `sql_debug.h`，在需要输出调试信息的地方，调用`sql_debug`函数即可。sql_debug 的使用与打印日志类似，不过可以在向客户端输出正常结果后，再输出调试信息。
+执行`sql_debug`同时会在日志中打印DEBUG级别的日志。
+
+**示例**
+
+1. `CreateTableStmt::create`
+2. `TableScanPhysicalOperator::next`
+
+**注意**
+由于训练营上能够容纳的信息有限，所以输出太多信息会被截断。
+
+**开关**
+
+每个连接都可以开启或关闭调试，可以参考 `Session::sql_debug_`。
+
+在交互式命令行中，可以使用 `set sql_debug=1` 开启调试，使用 `set sql_debug=0` 关闭调试。
+
+> 当前没有实现查看变量的命令。
+
+示例
+
+```bash
+miniob > select * from t;
+id
+1
+
+# get a tuple: 1
+miniob > set sql_debug=0;
+SUCCESS
+miniob > select * from t;
+id
+1
+
+```
\ No newline at end of file

docs/src/game/introduction.md

@@ -21,6 +21,9 @@
 训练营的使用方法比较简单，不过这里也有一个小手册：
 [训练营使用手册](https://ask.oceanbase.com/t/topic/35600372)
 
+为了方便大家使用训练营时获取调试信息，这里有一个小手册：
+[训练营调试输出手册](./debug-output.md)
+
 注意，在训练营开始前，需要注意自己的程序输出需要满足一定的要求，请参考：
 [提交测试需要满足的输出要求](./miniob-output-convention.md)
 

src/observer/common/ini_setting.h

@@ -20,7 +20,7 @@ See the Mulan PSL v2 for more details. */
 #define MAX_CONNECTION_NUM "MAX_CONNECTION_NUM"
 #define MAX_CONNECTION_NUM_DEFAULT 8192
 #define PORT "PORT"
-#define PORT_DEFAULT 16880
+#define PORT_DEFAULT 6789
 
 #define SOCKET_BUFFER_SIZE 8192
 

src/observer/common/rc.h

@@ -71,6 +71,8 @@ See the Mulan PSL v2 for more details. */
   DEFINE_RC(FILE_SEEK)                      \
   DEFINE_RC(FILE_READ)                      \
   DEFINE_RC(FILE_WRITE)                     \
+  DEFINE_RC(VARIABLE_NOT_EXISTS)            \
+  DEFINE_RC(VARIABLE_NOT_VALID)             \
   DEFINE_RC(LOGBUF_FULL)
 
 enum class RC

src/observer/event/session_event.h

@@ -19,10 +19,15 @@ See the Mulan PSL v2 for more details. */
 
 #include "common/seda/stage_event.h"
 #include "sql/executor/sql_result.h"
+#include "event/sql_debug.h"
 
 class Session;
 class Communicator;
 
+/**
+ * @brief 表示一个SQL请求
+ * 
+ */
 class SessionEvent : public common::StageEvent 
 {
 public:
@@ -32,23 +37,17 @@ public:
   Communicator *get_communicator() const;
   Session *session() const;
 
-  void set_query(const std::string &query)
-  {
-    query_ = query;
-  }
+  void set_query(const std::string &query) { query_ = query; }
 
-  const std::string &query() const
-  {
-    return query_;
-  }
-  SqlResult *sql_result()
-  {
-    return &sql_result_;
-  }
+  const std::string &query() const { return query_; }
 
-private:
-  Communicator *communicator_ = nullptr;
-  SqlResult     sql_result_;
+  SqlResult *sql_result() { return &sql_result_; }
+
+  SqlDebug &sql_debug() { return sql_debug_; }
 
-  std::string   query_;
+private:
+  Communicator *communicator_ = nullptr;  ///< 与客户端通讯的对象
+  SqlResult     sql_result_;  ///< SQL执行结果
+  SqlDebug      sql_debug_; ///< SQL调试信息
+  std::string   query_; ///< SQL语句
 };

src/observer/event/sql_debug.cpp

+/* Copyright (c) 2021 OceanBase and/or its affiliates. All rights reserved.
+miniob is licensed under Mulan PSL v2.
+You can use this software according to the terms and conditions of the Mulan PSL v2.
+You may obtain a copy of Mulan PSL v2 at:
+         http://license.coscl.org.cn/MulanPSL2
+THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND,
+EITHER EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT,
+MERCHANTABILITY OR FIT FOR A PARTICULAR PURPOSE.
+See the Mulan PSL v2 for more details. */
+
+//
+// Created by Wangyunlai on 2023/6/29.
+//
+
+#include <stdarg.h>
+
+#include "event/sql_debug.h"
+#include "session/session.h"
+#include "event/session_event.h"
+
+using namespace std;
+
+void SqlDebug::add_debug_info(const std::string &debug_info)
+{
+  debug_infos_.push_back(debug_info);
+}
+
+void SqlDebug::clear_debug_info()
+{
+  debug_infos_.clear();
+}
+
+const list<string> &SqlDebug::get_debug_infos() const
+{
+  return debug_infos_;
+}
+
+void sql_debug(const char *fmt, ...)
+{
+  Session *session  = Session::current_session();
+  if (nullptr == session) {
+    return;
+  }
+
+  SessionEvent *request = session->current_request();
+  if (nullptr == request) {
+    return ;
+  }
+
+  SqlDebug &sql_debug = request->sql_debug();
+
+  const int buffer_size = 4096;
+  char *str = new char[buffer_size];
+
+  va_list ap;
+  va_start(ap, fmt);
+  vsnprintf(str, buffer_size, fmt, ap);
+  va_end(ap);
+
+  sql_debug.add_debug_info(str);
+  LOG_DEBUG("sql debug info: %s", str);
+
+  delete[] str;
+}

src/observer/event/sql_debug.h

+/* Copyright (c) 2021 OceanBase and/or its affiliates. All rights reserved.
+miniob is licensed under Mulan PSL v2.
+You can use this software according to the terms and conditions of the Mulan PSL v2.
+You may obtain a copy of Mulan PSL v2 at:
+         http://license.coscl.org.cn/MulanPSL2
+THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND,
+EITHER EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT,
+MERCHANTABILITY OR FIT FOR A PARTICULAR PURPOSE.
+See the Mulan PSL v2 for more details. */
+
+//
+// Created by Wangyunlai on 2023/6/29.
+//
+
+#pragma once
+
+#include <list>
+#include <string>
+
+/**
+ * @brief SQL调试信息
+ * @details 
+ * 希望在运行SQL时，可以直接输出一些调试信息到客户端。
+ * 当前把调试信息都放在了session上，可以随着SQL语句输出。
+ * 但是现在还不支持与输出调试信息与行数据同步输出。
+ */
+class SqlDebug
+{
+public:
+  SqlDebug() = default;
+  virtual ~SqlDebug() = default;
+
+  void add_debug_info(const std::string &debug_info);
+  void clear_debug_info();
+
+  const std::list<std::string> &get_debug_infos() const;
+
+private:
+  std::list<std::string> debug_infos_;
+};
+
+/**
+ * @brief 增加SQL的调试信息
+ * @details 可以在任何执行SQL语句时调用这个函数来增加调试信息。
+ * 如果当前上下文不在SQL执行过程中，那么不会生成调试信息。
+ * 在普通文本场景下，调试信息会直接输出到客户端，并增加 '#' 作为前缀。
+ */
+void sql_debug(const char *fmt, ...);

src/observer/event/sql_event.h

@@ -23,6 +23,9 @@ class SessionEvent;
 class Stmt;
 class Command;
 
+/**
+ * @brief 与SessionEvent类似，也是处理SQL请求的事件，只是用在SQL的不同阶段
+ */
 class SQLStageEvent : public common::StageEvent
 {
 public:
@@ -74,8 +77,8 @@ public:
 
 private:
   SessionEvent *session_event_ = nullptr;
-  std::string sql_;
-  std::unique_ptr<Command> command_;
-  Stmt *stmt_ = nullptr;
-  std::unique_ptr<PhysicalOperator> operator_;
+  std::string sql_;  ///< 处理的SQL语句
+  std::unique_ptr<Command> command_;  ///< 语法解析后的SQL命令
+  Stmt *stmt_ = nullptr;  ///< Resolver之后生成的数据结构
+  std::unique_ptr<PhysicalOperator> operator_; ///< 生成的执行计划，也可能没有
 };

src/observer/net/mysql_communicator.cpp

@@ -973,9 +973,7 @@ RC MysqlCommunicator::send_result_rows(SqlResult *sql_result, bool no_column_def
         break;  // TODO send error packet
       }
 
-      std::stringstream ss;
-      value.to_string(ss);
-      pos += store_lenenc_string(buf + pos, ss.str().c_str());
+      pos += store_lenenc_string(buf + pos, value.to_string().c_str());
     }
 
     int payload_length = pos - 4;

src/observer/net/plain_communicator.cpp

@@ -23,6 +23,9 @@ See the Mulan PSL v2 for more details. */
 PlainCommunicator::PlainCommunicator()
 {
   send_message_delimiter_.assign(1, '\0');
+  debug_message_prefix_.resize(2);
+  debug_message_prefix_[0] = '#';
+  debug_message_prefix_[1] = ' ';
 }
 
 RC PlainCommunicator::read_event(SessionEvent *&event)
@@ -113,42 +116,67 @@ RC PlainCommunicator::write_state(SessionEvent *event, bool &need_disconnect)
   need_disconnect = false;
   delete[] buf;
 
-  writer_->flush();
   return RC::SUCCESS;
 }
 
-RC PlainCommunicator::write_result(SessionEvent *event, bool &need_disconnect)
+RC PlainCommunicator::write_debug(SessionEvent *request, bool &need_disconnect)
 {
-  need_disconnect = true;
-
-  SqlResult *sql_result = event->sql_result();
-  if (nullptr == sql_result) {
-
-    const char *response = "Unexpected error: no result";
-    int len = strlen(response);
+  if (!session_->sql_debug_on()) {
+    return RC::SUCCESS;
+  }
 
-    RC rc = writer_->writen(response, len);
+  SqlDebug &sql_debug = request->sql_debug();
+  const std::list<std::string> &debug_infos = sql_debug.get_debug_infos();
+  for (auto &debug_info : debug_infos) {
+    RC rc = writer_->writen(debug_message_prefix_.data(), debug_message_prefix_.size());
     if (OB_FAIL(rc)) {
-      LOG_ERROR("Failed to send data back to client. ret=%s, error=%s", strrc(rc), strerror(errno));
+      LOG_WARN("failed to send data to client. err=%s", strerror(errno));
+      need_disconnect = true;
+      return RC::IOERR_WRITE;
+    }
 
-      return rc;
+    rc = writer_->writen(debug_info.data(), debug_info.size());
+    if (OB_FAIL(rc)) {
+      LOG_WARN("failed to send data to client. err=%s", strerror(errno));
+      need_disconnect = true;
+      return RC::IOERR_WRITE;
     }
 
-    rc = writer_->writen(send_message_delimiter_.data(), send_message_delimiter_.size());
+    char newline = '\n';
+    rc = writer_->writen(&newline, 1);
     if (OB_FAIL(rc)) {
-      LOG_ERROR("Failed to send data back to client. ret=%s, error=%s", strrc(rc), strerror(errno));
-      return rc;
+      LOG_WARN("failed to send new line to client. err=%s", strerror(errno));
+      need_disconnect = true;
+      return RC::IOERR_WRITE;
     }
+  }
 
-    need_disconnect = false;
-    return RC::SUCCESS;
+  need_disconnect = false;
+  return RC::SUCCESS;
+}
+
+RC PlainCommunicator::write_result(SessionEvent *event, bool &need_disconnect)
+{
+  RC rc = write_result_internal(event, need_disconnect);
+  if (!need_disconnect) {
+    (void)write_debug(event, need_disconnect);
   }
+  writer_->flush(); // TODO handle error
+  return rc;
+}
+
+RC PlainCommunicator::write_result_internal(SessionEvent *event, bool &need_disconnect)
+{
+  RC rc = RC::SUCCESS;
+  need_disconnect = true;
+
+  SqlResult *sql_result = event->sql_result();
 
   if (RC::SUCCESS != sql_result->return_code() || !sql_result->has_operator()) {
     return write_state(event, need_disconnect);
   }
 
-  RC rc = sql_result->open();
+  rc = sql_result->open();
   if (OB_FAIL(rc)) {
     sql_result->close();
     sql_result->set_return_code(rc);
@@ -215,9 +243,7 @@ RC PlainCommunicator::write_result(SessionEvent *event, bool &need_disconnect)
         return rc;
       }
 
-      std::stringstream ss;
-      value.to_string(ss);
-      std::string cell_str = ss.str();
+      std::string cell_str = value.to_string();
       rc = writer_->writen(cell_str.data(), cell_str.size());
       if (OB_FAIL(rc)) {
         LOG_WARN("failed to send data to client. err=%s", strerror(errno));
@@ -266,6 +292,5 @@ RC PlainCommunicator::write_result(SessionEvent *event, bool &need_disconnect)
     rc = rc_close;
   }
 
-  writer_->flush(); // TODO handle error
   return rc;
 }
\ No newline at end of file

src/observer/net/plain_communicator.h

@@ -34,7 +34,10 @@ public:
 
 private:
   RC write_state(SessionEvent *event, bool &need_disconnect);
+  RC write_debug(SessionEvent *event, bool &need_disconnect);
+  RC write_result_internal(SessionEvent *event, bool &need_disconnect);
 
 protected:
   std::vector<char> send_message_delimiter_; ///< 发送消息分隔符
+  std::vector<char> debug_message_prefix_; ///< 调试信息前缀
 };

src/observer/session/session.cpp

@@ -90,3 +90,13 @@ Session *Session::current_session()
 {
   return thread_session;
 }
+
+void Session::set_current_request(SessionEvent *request)
+{
+  current_request_ = request;
+}
+
+SessionEvent *Session::current_request() const
+{
+  return current_request_;
+}

src/observer/session/session.h

@@ -18,11 +18,19 @@ See the Mulan PSL v2 for more details. */
 
 class Trx;
 class Db;
+class SessionEvent;
 
+/**
+ * @brief 表示会话
+ * @details 当前一个连接一个会话，没有做特殊的会话管理，这也简化了会话处理
+ */
 class Session 
 {
 public:
-  // static Session &current();
+  /**
+   * @brief 获取默认的会话数据，新生成的会话都基于默认会话设置参数
+   * @note 当前并没有会话参数
+   */
   static Session &default_session();
 
 public:
@@ -35,18 +43,58 @@ public:
   const char *get_current_db_name() const;
   Db *get_current_db() const;
 
+  /**
+   * @brief 设置当前会话关联的数据库
+   * 
+   * @param dbname 数据库名字
+   */
   void set_current_db(const std::string &dbname);
 
+  /**
+   * @brief 设置当前事务为多语句模式，需要明确的指出提交或回滚
+   */
   void set_trx_multi_operation_mode(bool multi_operation_mode);
+
+  /**
+   * @brief 当前事务是否为多语句模式
+   */
   bool is_trx_multi_operation_mode() const;
 
+  /**
+   * @brief 当前会话关联的事务
+   * 
+   */
   Trx *current_trx();
 
+  /**
+   * @brief 设置当前正在处理的请求
+   */
+  void set_current_request(SessionEvent *request);
+
+  /**
+   * @brief 获取当前正在处理的请求
+   */
+  SessionEvent *current_request() const;
+
+  void set_sql_debug(bool sql_debug) { sql_debug_ = sql_debug; }
+  bool sql_debug_on() const { return sql_debug_; }
+
+  /**
+   * @brief 将指定会话设置到线程变量中
+   * 
+   */
   static void set_current_session(Session *session);
+
+  /**
+   * @brief 获取当前的会话
+   * @details 当前某个请求开始时，会将会话设置到线程变量中，在整个请求处理过程中不会改变
+   */
   static Session *current_session();
   
 private:
   Db *db_ = nullptr;
   Trx *trx_ = nullptr;
-  bool trx_multi_operation_mode_ = false;  // 当前事务的模式，是否多语句模式. 单语句模式自动提交
+  SessionEvent *current_request_ = nullptr; ///< 当前正在处理的请求
+  bool trx_multi_operation_mode_ = false;   ///< 当前事务的模式，是否多语句模式. 单语句模式自动提交
+  bool sql_debug_ = false;                  ///< 是否输出SQL调试信息
 };

src/observer/session/session_stage.cpp

@@ -116,6 +116,7 @@ void SessionStage::handle_request(StageEvent *event)
   }
 
   Session::set_current_session(sev->session());
+  sev->session()->set_current_request(sev);
   SQLStageEvent *sql_event = new SQLStageEvent(sev, sql);
   query_cache_stage_->handle_event(sql_event);
 
@@ -126,5 +127,6 @@ void SessionStage::handle_request(StageEvent *event)
   if (need_disconnect) {
     Server::close_connection(communicator);
   }
+  sev->session()->set_current_request(nullptr);
   Session::set_current_session(nullptr);
 }