作者羅錦華，API7.ai 技術(shù)專家/技術(shù)工程師，開源項目 pgcat，lua-resty-ffi，lua-resty-inspect 的作者。

原文鏈接

為什么需要 Lua 動態(tài)調(diào)試插件？

Apache APISIX 有很多 Lua 代碼，如何在運行時不觸碰源代碼的情況下，檢查代碼里面的變量值？

修改 Lua 源碼來調(diào)試有如下缺點：

• 生產(chǎn)環(huán)境不允許也不應該修改源碼
• 修改源碼需要 reload，使得業(yè)務功能失效
• 容器環(huán)境難以修改源碼
• 產(chǎn)生的臨時代碼容易忘記回滾，導致維護問題

很多時候我們不僅僅需要在函數(shù)開始或結(jié)束的時候去檢查變量，而且需要在滿足一定條件，例如某個循環(huán)體被循環(huán)到了一定次數(shù)，
或者某個條件判斷為真的時候我們才查看變量值，并且也不僅僅是簡單打印變量值，有時候還可能需要將相關信息發(fā)送到外圍系統(tǒng)。
并且，這個過程如何做到動態(tài)化呢？而且，開啟調(diào)試后，能否不影響程序運行的性能呢？

Lua 動態(tài)調(diào)試插件就是輔助你完成以上需求的插件，該插件被命名為 inspect 插件。

• 斷點處理可定制
• 斷點設置動態(tài)化
• 多個斷點
• 斷點可被定義為只生效一次
• 可控制性能影響范圍

插件原理

它充分利用了 Lua 提供的 Debug API 來實現(xiàn)功能。解釋器模式執(zhí)行的每一個字節(jié)碼都可以對應到它所屬的文件以及行號，我們只需要判斷行號是否等于期望值，然后執(zhí)行我們定義的斷點函數(shù)，對該行對應的上下文信息，包括 upvalue ，局部變量，還有一些元信息，例如堆棧，進行處理即可。

APISIX 使用的是 Lua 的 JIT 實現(xiàn)：LuaJIT，很多熱點代碼路徑會被編譯成機器碼執(zhí)行，而它們是不受 Debug API 的影響的，所以我們需要在開啟斷點前清空 JIT 緩存。關鍵就在這里了，我們可以選擇只清空某個具體 Lua 函數(shù)的 JIT 緩存，減小對全局性能的影響。一個程序運行起來，會有很多 JIT 編譯代碼塊，在 LuaJIT 里被稱為 trace，這些 trace 跟 Lua 函數(shù)是關聯(lián)起來的，一個 Lua 函數(shù)可能包括多個 trace ，指代函數(shù)內(nèi)不同的熱點路徑。

對于全局函數(shù)、模塊級別的函數(shù)，我們可以指定它們的函數(shù)對象，清空它們的 JIT 緩存。但是如果某行號對應的是其他函數(shù)類型，例如匿名函數(shù)，我們無法在全局獲取函數(shù)的對象，那么只能清空所有 JIT 緩存了。在調(diào)試開啟期間，新的 trace 無法被生成，但是已有的未被清理的 trace 還繼續(xù)運行，所以只要控制的好，程序性能不會受到影響，因為一個已經(jīng)運行很久的線上系統(tǒng)，基本不會有新 trace 的生成。當調(diào)試結(jié)束后，也就是所有斷點都被撤銷后，系統(tǒng)會恢復正常的 JIT 模式，被清理掉的 JIT 緩存，一旦重新進入熱點，會被重新生成 trace。

安裝與配置

該插件默認被啟用。

配置好 conf/confg.yaml 啟用插件：

plugins:
...
  - inspect

plugin_attr:
  inspect:
    delay: 3
    hooks_file: "/usr/local/apisix/plugin_inspect_hooks.lua"

插件默認每隔3秒從文件 /usr/local/apisix/plugin_inspect_hooks.lua 讀取斷點定義，想調(diào)試就編輯該文件即可。

建議創(chuàng)建軟鏈接到該路徑，這樣比較方便地存檔不同歷史版本的斷點文件。

注意每次該文件的更改時間有變，插件會清空所有舊的斷點，并且啟用斷點文件所定義的所有新斷點。斷點將在所有工作進程生效。

一般情況下不需要刪除該文件，因為定義斷點的時候，可以定義什么時候撤銷斷點。

刪除文件會取消所有工作進程的所有斷點。

斷點的啟停都會通過 WARN 日志級別打印日志。

定義斷點

require("apisix.inspect.dbg").set_hook(file, line, func, filter_func)

• file 文件名，可以是任何無歧義的文件名部分，可包含路徑
• line 文件的行號，注意斷點跟行號是密切掛鉤的，所以如果代碼變了，行號就得跟著變。
• func 要清除哪個函數(shù)的 trace，如果為 nil，則清除 luajit vm 里面所有 trace
• filter_func 處理該斷點的自定義 Lua 函數(shù)
  • 函數(shù)的入?yún)橐粋€ table，包含以下內(nèi)容
    • finfo: debug.getinfo(level, "nSlf")的返回值
    • uv: upvalues hash table
    • vals: local variables hash table
  • 函數(shù)的返回值為 true，則該斷點自動注銷，返回為 false，則該斷點繼續(xù)生效

例子：

local dbg = require "apisix.inspect.dbg"

dbg.set_hook("limit-req.lua", 88, require("apisix.plugins.limit-req").access,
function(info)
    ngx.log(ngx.INFO, debug.traceback("foo traceback", 3))
    ngx.log(ngx.INFO, dbg.getname(info.finfo))
    ngx.log(ngx.INFO, "conf_key=", info.vals.conf_key)
    return true
end)

dbg.set_hook("t/lib/demo.lua", 31, require("t.lib.demo").hot2, function(info)
    if info.vals.i == 222 then
        ngx.timer.at(0, function(_, body)
            local httpc = require("resty.http").new()
            httpc:request_uri("http://127.0.0.1:9080/upstream1", {
                method = "POST",
                body = body,
            })
        end, ngx.var.request_uri .. "," .. info.vals.i)
        return true
    end
    return false
end)

--- more breakpoints ...

注意到 demo 這個斷點，它將一些信息整理后發(fā)送到外部的服務器上，使用的 resty.http 庫是基于 cosocket 的異步庫。

凡是調(diào)用 OpenResty 的異步 API ，必須使用 timer 延遲發(fā)送，因為在斷點上執(zhí)行函數(shù)是同步阻塞的，不會再返回到 nginx 的主程序做異步處理，所以需要延后發(fā)送。

使用示例

根據(jù)請求體的內(nèi)容來決定路由

假設我們有個需求，如何設置讓某個路由僅接受請求體中攜帶了 APISIX: 666 的 POST 請求？

路由配置里面有個 vars 字段，是用來檢查 nginx 變量的值來判斷是否匹配該路由的，
而 $request_body 則是 nginx 提供的變量，包含請求體的值，那我們可以利用這個變量來實現(xiàn)我們的需求？

讓我們來嘗試一下，先配置一下路由：

curl http://127.0.0.1:9180/apisix/admin/routes/var_route \
-H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -i -d '
{
    "uri": "/anything",
    "methods": ["POST"],
    "vars": [["request_body", "~~", "APISIX: 666"]],
    "upstream": {
        "type": "roundrobin",
        "nodes": {
            "httpbin.org": 1
        }
    }
}'

然后我們嘗試一下：

curl http://127.0.0.1:9080/anything
{"error_msg":"404 Route Not Found"}

curl -i http://127.0.0.1:9080/anything -X POST -d 'hello, APISIX: 666.'
HTTP/1.1 404 Not Found
Date: Thu, 05 Jan 2023 03:53:35 GMT
Content-Type: text/plain; charset=utf-8
Transfer-Encoding: chunked
Connection: keep-alive
Server: APISIX/3.0.0

{"error_msg":"404 Route Not Found"}

奇怪，為什么匹配不上這個路由呢？

我們再查看一下 NGINX 對該變量的文檔說明：

The variable’s value is made available in locations processed by the proxy_pass, fastcgi_pass, uwsgi_pass, and scgi_pass directives when the request body was read to a memory buffer.

也就是說，使用該變量前需要先讀取 request body 。

那是不是匹配路由的時候，這個變量為空呢？我們可以使用 inspect 插件來驗證一下。

我們找到了匹配路由的代碼行：

apisix/init.lua

...
api_ctx.var.request_uri = api_ctx.var.uri .. api_ctx.var.is_args .. (api_ctx.var.args or "")

router.router_http.match(api_ctx)

local route = api_ctx.matched_route
if not route then
...

我們就在 515 行，也就是 router.router_http.match(api_ctx) 這行驗證一下變量 request_body 吧。

設置斷點

編輯文件 /usr/local/apisix/example_hooks.lua：

local dbg = require("apisix.inspect.dbg")
dbg.set_hook("apisix/init.lua", 515, require("apisix").http_access_phase, function(info)
    core.log.warn("request_body=", info.vals.api_ctx.var.request_body)
    return true
end)

創(chuàng)建軟鏈接到斷點文件路徑：

ln -sf /usr/local/apisix/example_hooks.lua /usr/local/apisix/plugin_inspect_hooks.lua

檢查日志看看確認斷點生效：

2023/01/05 12:02:43 [warn] 1890559#1890559: *15736 [lua] init.lua:68: setup_hooks():
set hooks: err: true, hooks: ["apisix\/init.lua#515"], context: ngx.timer

再觸發(fā)一次路由匹配：

curl -i http://127.0.0.1:9080/anything -X POST -d 'hello, APISIX: 666.'

查看日志：

2023/01/05 12:02:59 [warn] 1890559#1890559: *16152
[lua] [string "local dbg = require("apisix.inspect.dbg")..."]:39:
request_body=nil, client: 127.0.0.1, server: _,
request: "POST /anything HTTP/1.1", host: "127.0.0.1:9080"

果然，request_body 是空的！

解決方案

既然我們知道需要讀取請求體才能用 request_body 變量，那么我們就不能通過 vars 來做了，那我們可以通過路由里面的 filter_func 字段來實現(xiàn)需求。

curl http://127.0.0.1:9180/apisix/admin/routes/var_route \
-H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -i -d '
{
    "uri": "/anything",
    "methods": ["POST"],
    "filter_func": "function(_) return require(\"apisix.core\").request.get_body():find(\"APISIX: 666\") end",
    "upstream": {
        "type": "roundrobin",
        "nodes": {
            "httpbin.org": 1
        }
    }
}'

驗證一下：

curl http://127.0.0.1:9080/anything -X POST -d 'hello, APISIX: 666.'
{
  "args": {},
  "data": "",
  "files": {},
  "form": {
    "hello, APISIX: 666.": ""
  },
  "headers": {
    "Accept": "*/*",
    "Content-Length": "19",
    "Content-Type": "application/x-www-form-urlencoded",
    "Host": "127.0.0.1",
    "User-Agent": "curl/7.68.0",
    "X-Amzn-Trace-Id": "Root=1-63b64dbd-0354b6ed19d7e3b67013592e",
    "X-Forwarded-Host": "127.0.0.1"
  },
  "json": null,
  "method": "POST",
  "origin": "127.0.0.1, xxx",
  "url": "http://127.0.0.1/anything"
}

問題解決！

打印一些被日志級別屏蔽的日志

生產(chǎn)環(huán)境一般不會開啟 INFO 級別的日志，但是有時候我們又需要檢查一些詳細信息，那怎么辦呢？

我們一般不會直接設置 INFO 級別然后 reload，因為這樣做有兩個缺點：

• 日志太多，影響性能和加大檢查難度
• reload 導致長連接被斷開，影響在線流量

一般我們只需要檢查具體某個點的日志，例如我們都知道 APISIX 使用 etcd 作為配置分發(fā)數(shù)據(jù)庫，那么可否看看什么時候路由配置被增量更新到了數(shù)據(jù)面呢？更新了什么具體數(shù)據(jù)呢？

apisix/core/config_etcd.lua

local function sync_data(self)
...
    log.info("waitdir key: ", self.key, " prev_index: ", self.prev_index + 1)
    log.info("res: ", json.delay_encode(dir_res, true), ", err: ", err)
...
end

增量同步的lua函數(shù)是 sync_data()，但是它是通過 INFO 級別來打印從 etcd watch 到的增量數(shù)據(jù)的。

那么我們來試一下使用 inspect plugin 來顯示一下？只顯示路由資源的變化。

編輯 /usr/local/apisix/example_hooks.lua ：

local dbg = require("apisix.inspect.dbg")
local core = require("apisix.core")
dbg.set_hook("apisix/core/config_etcd.lua", 393, nil, function(info)
    local filter_res = "/routes"
    if info.vals.self.key:sub(-#filter_res) == filter_res and not info.vals.err then
        core.log.warn("etcd watch /routes response: ", core.json.encode(info.vals.dir_res, true))
        return true
    end
    return false
end)

這個斷點處理函數(shù)的邏輯很好表達了過濾能力，如果 watch 的 key 是 /routes，以及 err 為空的情況下，就打印 etcd 返回的數(shù)據(jù)，并且打印一次就夠了，就取消斷點。

注意 sync_data() 是局部函數(shù)，所以無法獲取它的引用，我們只能設置 set_hook 的第三個參數(shù)為 nil，這樣做的副作用就是它會清空所有 trace。

上面例子我們已經(jīng)創(chuàng)建了軟鏈接，所以編輯后保存文件即可。等幾秒鐘后，斷點就會被啟用，可觀察日志確認。

檢查日志，我們可以得到我們需要的信息，而這些信息用 WARN 日志級別打印，并且也顯示了我們在數(shù)據(jù)面獲取到 etcd 增量數(shù)據(jù)的時間。

2023/01/05 14:33:10 [warn] 1890562#1890562: *231311
[lua] [string "local dbg = require("apisix.inspect.dbg")..."]:41:
etcd watch /routes response: {"headers":{"X-Etcd-Index":"24433"},
"body":{"node":[{"value":{"uri":"\/anything",
"plugins":{"request-id":{"header_name":"X-Request-Id","include_in_response":true,"algorithm":"uuid"}},
"create_time":1672898912,"status":1,"priority":0,"update_time":1672900390,
"upstream":{"nodes":{"httpbin.org":1},"hash_on":"vars","type":"roundrobin","pass_host":"pass","scheme":"http"},
"id":"reqid"},"key":"\/apisix\/routes\/reqid","modifiedIndex":24433,"createdIndex":24429}]}}, context: ngx.timer

結(jié)論

Lua 動態(tài)調(diào)試是很重要的輔助功能。我們可以通過 APISIX inspect 插件來做很多事情，例如：

• 排查問題，定位原因
• 打印一些被屏蔽的日志，按需獲取各種信息
• 通過調(diào)試來學習 Lua 代碼

更多詳情請查閱相關文檔介紹。

關于 API7.ai 與 APISIX

API7.ai 是一家提供 API 處理和分析的開源基礎軟件公司，于 2019 年開源了新一代云原生 API 網(wǎng)關 -- APISIX 并捐贈給 Apache 軟件基金會。此后，API7.ai 一直積極投入支持 Apache APISIX 的開發(fā)、維護和社區(qū)運營。與千萬貢獻者、使用者、支持者一起做出世界級的開源項目，是 API7.ai 努力的目標。文章來源地址http://www.zghlxwxcb.cn/news/detail-412932.html

到了這里，關于詳解 APISIX Lua 動態(tài)調(diào)試插件 inspect的文章就介紹完了。如果您還想了解更多內(nèi)容，請在右上角搜索TOY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關文章，希望大家以后多多支持TOY模板網(wǎng)！