"inspect": Apache APISIX Lua Dynamic Debugging Plugin

Warum benötigen wir das Lua Dynamic Debugging Plugin?

Apache APISIX enthält eine beträchtliche Menge an Lua-Code. Gibt es eine Möglichkeit, die Werte von Variablen im Code zur Laufzeit zu überprüfen, ohne den Quellcode zu ändern?

Das Ändern von Lua-Quellcode zum Debuggen hat mehrere Nachteile:

Produktionsumgebungen sollten und dürfen oft keine Änderungen am Quellcode zulassen
Das Ändern des Quellcodes erfordert ein Neuladen, was den Betrieb von Geschäftsprozessen stört
Es kann schwierig sein, den Quellcode in containerisierten Umgebungen zu ändern
Temporär generierte Codes werden oft übersehen, um sie zurückzusetzen, was zu Wartungsproblemen führt

Wir müssen oft die Werte von Variablen überprüfen, nicht nur wenn Funktionen beginnen oder enden, sondern auch wenn bestimmte Bedingungen erfüllt sind, wie z.B. wenn eine Schleife eine bestimmte Anzahl von Iterationen erreicht oder wenn eine bestimmte Bedingung wahr ist. Darüber hinaus reicht es nicht immer aus, einfach die Variablenwerte auszudrucken; es kann auch notwendig sein, relevante Informationen an externe Systeme zu senden. Außerdem, wie kann dieser Prozess dynamisch gestaltet werden, und kann dies ohne negative Auswirkungen auf die Leistung des Programms geschehen?

Das Lua-Dynamic-Debugging-Plugin, inspect, hilft Ihnen, die oben genannten Anforderungen zu erfüllen.

Anpassbare Breakpoint-Behandlung
Dynamische Breakpoint-Setzung
Mehrere Breakpoints können gesetzt werden
Breakpoints können so eingestellt werden, dass sie nur einmal ausgelöst werden
Die Leistungsauswirkungen können kontrolliert und in einem bestimmten Bereich gehalten werden

Funktionsprinzip des Plugins

Es nutzt die Debug API-Funktion von Lua vollständig, um seine Funktionen zu implementieren. Während des Interpreter-Modus kann jeder ausgeführte Bytecode einer bestimmten Datei und einer Zeilennummer zugeordnet werden. Um Breakpoints zu setzen, müssen wir nur überprüfen, ob die Zeilennummer dem erwarteten Wert entspricht, und die bereits definierte Breakpoint-Funktion ausführen. Dies ermöglicht es uns, die Kontextinformationen der entsprechenden Zeile zu verarbeiten, einschließlich Upvalue, lokaler Variablen und einiger Metadaten, wie z.B. des Stacks.

APISIX verwendet die LuaJIT-Implementierung von Lua, bei der viele häufig genutzte Codepfade in Maschinencode kompiliert werden, um ausgeführt zu werden. Diese werden jedoch nicht von der Debug API beeinflusst, daher müssen wir den JIT-Cache löschen, bevor wir Breakpoints aktivieren. Der Schlüsselpunkt ist, dass wir nur den JIT-Cache einer bestimmten Lua-Funktion löschen können, um die Auswirkungen auf die globale Leistung zu reduzieren. Wenn ein Programm läuft, werden viele JIT-kompilierte Codeblöcke in LuaJIT als trace bezeichnet. Diese Traces sind mit Lua-Funktionen verbunden, und eine einzelne Lua-Funktion kann mehrere Traces enthalten, die sich auf verschiedene Hot-Paths innerhalb der Funktion beziehen.

Wir können ihre Funktionsobjekte angeben und ihren JIT-Cache für globale und modulare Funktionen löschen. Wenn die Zeilennummer jedoch anderen Funktionstypen entspricht, wie z.B. anonymen Funktionen, können wir das Funktionsobjekt nicht global erhalten. In solchen Fällen können wir nur den gesamten JIT-Cache löschen. Während des Debuggens können keine neuen Traces generiert werden, aber bestehende, nicht gelöschte Traces laufen weiter. Solange wir genügend Kontrolle haben, wird die Programleistung nicht beeinträchtigt, da ein Online-System, das bereits lange läuft, normalerweise keine neuen Traces generiert. Sobald das Debuggen beendet ist und alle Breakpoints aufgehoben wurden, kehrt das System in den normalen JIT-Modus zurück, und der gelöschte JIT-Cache wird neu generiert, sobald er wieder in den Hotspot gelangt.

Installation und Konfiguration

Dieses Plugin ist standardmäßig aktiviert.

Konfigurieren Sie conf/confg.yaml korrekt, um dieses Plugin zu aktivieren:

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

Das Plugin liest Breakpoint-Definitionen standardmäßig alle 3 Sekunden aus der Datei '/usr/local/apisix/plugin_inspect_hooks.lua'. Zum Debuggen müssen Sie nur diese Datei bearbeiten.

Wir empfehlen, einen symbolischen Link zu diesem Pfad zu erstellen, damit es einfacher ist, verschiedene historische Versionen der Breakpoint-Datei zu archivieren.

Bitte beachten Sie, dass beim Ändern der Datei das Plugin alle vorherigen Breakpoints löscht und alle neuen Breakpoints aktiviert, die in der Breakpoint-Datei definiert sind. Diese Breakpoints gelten für alle Worker-Prozesse.

Im Allgemeinen ist es nicht notwendig, die Datei zu löschen, da Sie beim Definieren von Breakpoints angeben können, wann sie aufgehoben werden sollen.

Das Löschen dieser Datei hebt alle Breakpoints für alle Worker-Prozesse auf.

Protokolle über das Starten und Stoppen von Breakpoints werden auf der Protokollebene 'WARN' aufgezeichnet.

Breakpoints definieren

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

file, der Dateiname, der ein beliebiger eindeutiger Dateiname oder Pfad sein kann.
line, die Zeilennummer in der Datei. Bitte beachten Sie, dass Breakpoints eng mit Zeilennummern verknüpft sind. Wenn sich der Code ändert, muss sich auch die Zeilennummer ändern.
func, der Name der Funktion, deren Trace gelöscht werden soll. Wenn dieser nil ist, werden alle Traces in der luajit vm gelöscht.
filter_func, eine benutzerdefinierte Lua-Funktion, die den Breakpoint behandelt
- Der Eingabeparameter ist eine table, die Folgendes enthält:
  - finfo: der Rückgabewert von debug.getinfo(level, "nSlf")
  - uv: Upvalues-Hash-Tabelle
  - vals: Hash-Tabelle der lokalen Variablen
- Wenn der Rückgabewert der Funktion true ist, wird der Breakpoint automatisch aufgehoben. Andernfalls bleibt der Breakpoint weiterhin aktiv.

Beispiel:

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)
--- mehr Breakpoints ...

Bitte beachten Sie, dass der demo-Breakpoint einige Informationen organisiert und an einen externen Server sendet. Außerdem ist die verwendete resty.http-Bibliothek eine asynchrone Bibliothek, die auf cosocket basiert.

Wenn Sie die asynchrone API von OpenResty aufrufen, muss dies mit einer Verzögerung gesendet werden, indem Sie timer verwenden, da die Ausführung von Funktionen auf Breakpoints synchron und blockierend ist. Sie kehrt nicht zum Hauptprogramm von nginx zurück, um asynchrone Verarbeitung durchzuführen, daher muss sie verzögert werden.

Anwendungsfälle

Routen basierend auf dem Inhalt des Anfragekörpers bestimmen

Angenommen, wir haben eine Anforderung: Wie können wir eine Route einrichten, die nur POST-Anfragen mit der Zeichenfolge APISIX: 666 im Anfragekörper akzeptiert?

In der Routenkonfiguration gibt es ein vars-Feld, das verwendet werden kann, um den Wert von nginx-Variablen zu überprüfen, um festzustellen, ob die Route übereinstimmen soll. Die von nginx bereitgestellte Variable $request_body enthält den Wert des Anfragekörpers, daher können wir diese Variable verwenden, um unsere Anforderung zu implementieren.

Lassen Sie uns versuchen, die Routen zu konfigurieren:

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
        }
    }
}'

Dann können wir dies versuchen:

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"}

Seltsam, warum können wir diese Route nicht abgleichen?

Wir werden dann einen Blick auf die Dokumentation für diese Variable in nginx werfen:

Der Wert der Variablen ist in den Locations verfügbar, die von den Direktiven proxy_pass, fastcgi_pass, uwsgi_pass und scgi_pass verarbeitet werden, wenn der Anfragekörper in einen Speicherpuffer gelesen wurde.

Mit anderen Worten, wir müssen den Anfragekörper zuerst lesen, bevor wir diese Variable verwenden können.

Wenn die Route abgeglichen wird, wird diese Variable dann leer sein? Wir können das inspect-Plugin verwenden, um dies zu überprüfen.

Wir haben die Codezeile gefunden, die die Route abgleicht:

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
...

Lassen Sie uns die Variable request_body in Zeile 515 überprüfen, die router.router_http.match(api_ctx) ist.

Breakpoints einrichten

Bearbeiten Sie die Datei /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)

Erstellen Sie einen symbolischen Link zum Breakpoint-Dateipfad:

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

Überprüfen Sie die Protokolle, um sicherzustellen, dass der Breakpoint aktiv ist.

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

Lösen Sie den Routenabgleich erneut aus:

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

Überprüfen Sie die Protokolle:

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"

Natürlich ist request_body leer!

Lösung

Da wir wissen, dass wir den Anfragekörper lesen müssen, um die Variable request_body zu verwenden, können wir vars nicht dafür verwenden. Stattdessen können wir das filter_func-Feld in der Route verwenden, um unsere Anforderung zu erfüllen.

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
        }
    }
}'

Lassen Sie uns dies überprüfen:

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"
}

Problem gelöst!

Einige Protokolle ausdrucken, die durch die Protokollebene blockiert wurden.

Im Allgemeinen aktivieren wir INFO-Protokolle in einer Produktionsumgebung nicht, aber manchmal müssen wir einige detaillierte Informationen überprüfen. Wie können wir das tun?

Wir setzen normalerweise nicht direkt die INFO-Ebene und laden dann neu, da dies zwei Nachteile hat:

Zu viele Protokolle, was die Leistung beeinträchtigt und die Überprüfung erschwert
Das Neuladen führt dazu, dass persistente Verbindungen getrennt werden, was den Online-Verkehr beeinträchtigt

Normalerweise müssen wir nur die Protokolle eines bestimmten Punktes überprüfen; zum Beispiel wissen wir alle, dass APISIX etcd als Konfigurationsverteilungsdatenbank verwendet. Können wir also sehen, wann die Routenkonfiguration inkrementell auf die Datenebene aktualisiert wird? Welche spezifischen Daten wurden aktualisiert?

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

Die Lua-Funktion für die inkrementelle Synchronisation ist sync_data(), aber sie gibt die inkrementellen Daten von etcd watch auf der INFO-Ebene aus.

Lassen Sie uns also versuchen, das inspect-Plugin zu verwenden, um dies anzuzeigen. Wir werden nur die Änderungen der Routenressourcen anzeigen.

Bearbeiten Sie /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)

Die Logik dieser Breakpoint-Verarbeitungsfunktion zeigt deutlich die Filterfähigkeit. Wenn der key von watch /routes ist und err leer ist, wird es die von etcd zurückgegebenen Daten nur einmal ausdrucken und dann den Breakpoint aufheben.

Beachten Sie, dass sync_data() eine lokale Funktion ist, daher kann sie nicht direkt referenziert werden. In diesem Fall können wir nur den dritten Parameter von set_hook auf nil setzen, was den Nebeneffekt hat, alle Traces zu löschen.

Im obigen Beispiel haben wir einen symbolischen Link erstellt, daher müssen wir nur die Datei nach der Bearbeitung speichern. Breakpoints werden nach einigen Sekunden aktiviert; Sie können das Protokoll überprüfen, um dies zu bestätigen.

Durch die Überprüfung des Protokolls können wir die benötigten Informationen erhalten, die auf der Protokollebene WARN ausgegeben werden. Es zeigt auch die Zeit an, zu der wir die inkrementellen Daten von etcd auf der Datenebene erhalten.

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

Fazit

Lua-Dynamic-Debugging ist eine wichtige Hilfsfunktion. Mit dem inspect-Plugin von APISIX können wir viele Dinge tun, wie z.B.:

Probleme beheben und die Ursache identifizieren
Einige blockierte Protokolle ausdrucken und verschiedene Informationen nach Bedarf abrufen
Lua-Code durch Debugging lernen

Bitte lesen Sie diese verwandten Dokumentationen für weitere Details.