feature: supported to print the input parameters and return values of… (

apache#641)

* feature: supported to print the input parameters and return values of the specified function for debugging.

conf/debug.yaml

@@ -0,0 +1,15 @@
+hook_conf:
+  enable: false                 # enable or disable this feature
+  name: hook_phase              # the name of module and function list
+  log_level: warn               # log level
+  is_print_input_args: true     # print the input arguments
+  is_print_return_value: true   # print the return value
+
+hook_phase:                     # module and function list, name: hook_phase
+  apisix:                       # required module name
+    - http_access_phase         # function name
+    - http_header_filter_phase
+    - http_body_filter_phase
+    - http_log_phase
+
+#END

doc/architecture-design-cn.md

@@ -422,11 +422,11 @@ HTTP/1.1 503 Service Temporarily Unavailable
 
 ## Debug mode
 
-开启调试模式后，会在请求应答时，输出更多的内部信息，比如加载了哪些插件等。
+### 基本调试模式
 
-设置 `conf/config.yaml` 中的 `apisix.enable_debug` 为 `true`，即可开启调试模式。
+设置 `conf/config.yaml` 中的 `apisix.enable_debug` 为 `true`，即可开启基本调试模式。
 
-比如对 `/hello` 开启了 `limit-conn`和`limit-count`插件，这时候应答头中会有 `Apisix-Plugins: limit-conn, limit-count` 出现。
+比如对 `/hello` 开启了 `limit-conn`和`limit-count`插件，这时候应答头中会有 `Apisix-Plugins: limit-conn, limit-count`。
 
 ```shell
 $ curl http://127.0.0.1:1984/hello -i
@@ -442,4 +442,40 @@ Server: openresty
 hello world
 ```
 
+### 高级调试模式
+
+设置 `conf/debug.yaml` 中的选项，开启高级调试模式。由于 APISIX 服务启动后是每秒定期检查该文件，
+当可以正常读取到 `#END` 结尾时，才认为文件处于写完关闭状态。
+
+根据文件最后修改时间判断文件内容是否有变化，如有变化则重新加载，如没变化则跳过本次检查。
+所以高级调试模式的开启、关闭都是热更新方式完成。
+
+|名字|可选项|说明|默认值|
+|----|-----|---------|---|
+|hook_conf.enable|必选项|是否开启 hook 追踪调试。开启后将打印指定模块方法的请求参数或返回值|false|
+|hook_conf.name|必选项|开启 hook 追踪调试的模块列表名称||
+|hook_conf.log_level|必选项|打印请求参数和返回值的日志级别|warn|
+|hook_conf.is_print_input_args|必选项|是否打印输入参数|true|
+|hook_conf.is_print_return_value|必选项|是否打印返回值|true|
+
+请看下面示例：
+
+```yaml
+hook_conf:
+  enable: false                 # 是否开启 hook 追踪调试
+  name: hook_phase              # 开启 hook 追踪调试的模块列表名称
+  log_level: warn               # 日志级别
+  is_print_input_args: true     # 是否打印输入参数
+  is_print_return_value: true   # 是否打印返回值
+
+hook_phase:                     # 模块函数列表，名字：hook_phase
+  apisix:                       # 引用的模块名称
+    - http_access_phase         # 函数名：数组
+    - http_header_filter_phase
+    - http_body_filter_phase
+    - http_log_phase
+
+#END
+```
+
 [返回目录](#目录)

lua/apisix.lua

@@ -70,6 +70,8 @@ function _M.http_init_worker()
     if core.config == require("apisix.core.config_yaml") then
         core.config.init_worker()
     end
+
+    require("apisix.debug").init_worker()
 end
 
 

lua/apisix/debug.lua

@@ -0,0 +1,191 @@
+local yaml         = require("tinyyaml")
+local log          = require("apisix.core.log")
+local json         = require("apisix.core.json")
+local process      = require("ngx.process")
+local lfs          = require("lfs")
+local io           = io
+local ngx          = ngx
+local re_find      = ngx.re.find
+local type         = type
+local pairs        = pairs
+local require      = require
+local setmetatable = setmetatable
+local pcall        = pcall
+local ipairs       = ipairs
+local unpack       = unpack
+local debug_yaml_path = ngx.config.prefix() .. "conf/debug.yaml"
+local debug_yaml
+local debug_yaml_ctime
+
+
+local _M = {version = 0.1}
+
+
+local function read_debug_yaml()
+    local attributes, err = lfs.attributes(debug_yaml_path)
+    if not attributes then
+        log.notice("failed to fetch ", debug_yaml_path, " attributes: ", err)
+        return
+    end
+
+    -- log.info("change: ", json.encode(attributes))
+    local last_change_time = attributes.change
+    if debug_yaml_ctime == last_change_time then
+        return
+    end
+
+    local f, err = io.open(debug_yaml_path, "r")
+    if not f then
+        log.error("failed to open file ", debug_yaml_path, " : ", err)
+        return
+    end
+
+    local found_end_flag
+    for i = 1, 10 do
+        f:seek('end', -i)
+
+        local end_flag = f:read("*a")
+        -- log.info(i, " flag: ", end_flag)
+        if re_find(end_flag, [[#END\s*]], "jo") then
+            found_end_flag = true
+            break
+        end
+    end
+
+    if not found_end_flag then
+        f:close()
+        log.notice("missing valid end flag in file ", debug_yaml_path)
+        return
+    end
+
+    f:seek('set')
+    local yaml_config = f:read("*a")
+    f:close()
+
+    local debug_yaml_new = yaml.parse(yaml_config)
+    if not debug_yaml_new then
+        log.error("failed to parse the content of file conf/debug.yaml")
+        return
+    end
+
+    debug_yaml_new.hooks = debug_yaml_new.hooks or {}
+    debug_yaml = debug_yaml_new
+    debug_yaml_ctime = last_change_time
+end
+
+
+local sync_debug_hooks
+do
+    local pre_mtime
+    local enabled_hooks = {}
+
+local function apple_new_fun(module, fun_name, file_path, hook_conf)
+    local log_level = hook_conf.log_level or "warn"
+
+    if not module or type(module[fun_name]) ~= "function" then
+        log.error("failed to find function [", fun_name,
+                  "] in module:", file_path)
+        return
+    end
+
+    local fun = module[fun_name]
+    local fun_org
+    if enabled_hooks[fun] then
+        fun_org = enabled_hooks[fun].org
+        enabled_hooks[fun] = nil
+    else
+        fun_org = fun
+    end
+
+    local t = {fun_org = fun_org}
+    local mt = {}
+
+    function mt.__call(self, ...)
+        local arg = {...}
+        if hook_conf.is_print_input_args then
+            log[log_level]("call require(\"", file_path, "\").", fun_name,
+                           "() args:", json.delay_encode(arg, true))
+        end
+
+        local ret = {self.fun_org(...)}
+        if hook_conf.is_print_return_value then
+            log[log_level]("call require(\"", file_path, "\").", fun_name,
+                           "() return:", json.delay_encode(ret, true))
+        end
+        return unpack(ret)
+    end
+
+    setmetatable(t, mt)
+    enabled_hooks[t] = {
+        org = fun_org, new = t, mod = module,
+        fun_name = fun_name
+    }
+    module[fun_name] = t
+end
+
+
+function sync_debug_hooks()
+    if not debug_yaml_ctime or debug_yaml_ctime == pre_mtime then
+        return
+    end
+
+    for _, hook in pairs(enabled_hooks) do
+        local m = hook.mod
+        local name = hook.fun_name
+        m[name] = hook.org
+    end
+
+    enabled_hooks = {}
+
+    local hook_conf = debug_yaml.hook_conf
+    if not hook_conf.enable then
+        pre_mtime = debug_yaml_ctime
+        return
+    end
+
+    local hook_name = hook_conf.name or ""
+    local hooks = debug_yaml[hook_name]
+    if not hooks then
+        pre_mtime = debug_yaml_ctime
+        return
+    end
+
+    for file_path, fun_names in pairs(hooks) do
+        local ok, module = pcall(require, file_path)
+        if not ok then
+            log.error("failed to load module [", file_path, "]: ", module)
+
+        else
+            for _, fun_name in ipairs(fun_names) do
+                apple_new_fun(module, fun_name, file_path, hook_conf)
+            end
+        end
+    end
+
+    pre_mtime = debug_yaml_ctime
+end
+
+end --do
+
+
+local function sync_debug_status(premature)
+    if premature then
+        return
+    end
+
+    read_debug_yaml()
+    sync_debug_hooks()
+end
+
+
+function _M.init_worker()
+    if process.type() ~= "worker" and process.type() ~= "single" then
+        return
+    end
+
+    sync_debug_status()
+    ngx.timer.every(1, sync_debug_status)
+end
+
+
+return _M

t/APISIX.pm

@@ -287,9 +287,12 @@ _EOC_
     }
 
     my $user_yaml_config = $block->yaml_config // $yaml_config;
+    my $user_debug_config = $block->debug_config // "";
 
     my $user_files = $block->user_files;
     $user_files .= <<_EOC_;
+>>> ../conf/debug.yaml
+$user_debug_config
 >>> ../conf/config.yaml
 $user_yaml_config
 >>> ../conf/cert/apisix.crt