"inspect": Plugin Debugging Dinamis Lua Apache APISIX

Mengapa Kita Membutuhkan Plugin Debugging Dinamis Lua?

Apache APISIX mengandung banyak kode Lua. Adakah cara untuk memeriksa nilai variabel dalam kode saat runtime tanpa mengubah kode sumber?

Mengubah kode sumber Lua untuk debugging memiliki beberapa kekurangan:

Lingkungan produksi seharusnya tidak dan sering kali tidak mengizinkan modifikasi kode sumber
Mengubah kode sumber mengharuskan reloading, yang mengganggu proses bisnis
Sulit untuk mengubah kode sumber di lingkungan yang dikontainerisasi
Kode yang dihasilkan sementara rentan untuk diabaikan saat rollback, menyebabkan masalah pemeliharaan

Kita biasanya perlu memeriksa nilai variabel, tidak hanya saat fungsi dimulai atau berakhir, tetapi juga ketika kondisi tertentu terpenuhi, seperti ketika loop mencapai jumlah iterasi tertentu atau ketika kondisi tertentu benar. Selain itu, tidak selalu cukup hanya dengan mencetak nilai variabel; mungkin juga perlu mengirim informasi yang relevan ke sistem eksternal. Lebih lanjut, bagaimana membuat proses ini dinamis, dan dapatkah dilakukan tanpa berdampak negatif pada kinerja program?

Plugin debugging dinamis Lua, inspect, membantu Anda memenuhi persyaratan di atas.

Penanganan breakpoint yang dapat disesuaikan
Pengaturan breakpoint dinamis
Beberapa breakpoint dapat diatur
Breakpoint dapat diatur untuk hanya memicu sekali
Dampak kinerja dapat dikontrol dan dijaga dalam lingkup tertentu

Prinsip Kerja Plugin

Plugin ini memanfaatkan sepenuhnya fungsi Debug API Lua untuk mengimplementasikan fiturnya. Selama mode interpreter, setiap bytecode yang dieksekusi dapat dipetakan ke file tertentu dan nomor baris. Untuk mengatur breakpoint, kita hanya perlu memeriksa apakah nomor baris sama dengan nilai yang diharapkan dan menjalankan fungsi breakpoint yang telah kita definisikan. Ini memungkinkan kita untuk memproses informasi konteks dari baris yang sesuai, termasuk upvalue, variabel lokal, dan beberapa metadata, seperti stack.

APISIX menggunakan implementasi JIT Lua: LuaJIT, di mana banyak jalur kode panas dikompilasi menjadi kode mesin untuk dieksekusi. Namun, ini tidak terpengaruh oleh Debug API, jadi kita perlu membersihkan cache JIT sebelum mengaktifkan breakpoint. Kuncinya adalah kita dapat memilih hanya membersihkan cache JIT dari fungsi Lua tertentu, mengurangi dampak pada kinerja global. Saat program berjalan, banyak blok kode yang dikompilasi JIT akan diberi nama trace di LuaJIT. Trace ini terkait dengan fungsi Lua, dan satu fungsi Lua mungkin mencakup beberapa trace, merujuk pada jalur panas yang berbeda dalam fungsi tersebut.

Kita dapat menentukan objek fungsi mereka dan membersihkan cache JIT mereka untuk fungsi global dan tingkat modul. Namun, jika nomor baris sesuai dengan jenis fungsi lain, seperti fungsi anonim, kita tidak dapat memperoleh objek fungsi secara global. Dalam kasus seperti itu, kita hanya dapat membersihkan semua cache JIT. Trace baru tidak dapat dihasilkan selama debugging, tetapi trace yang ada yang belum dibersihkan terus berjalan. Selama kita memiliki kontrol yang cukup, kinerja program tidak akan terpengaruh karena sistem online yang telah berjalan lama biasanya tidak akan menghasilkan trace baru. Setelah debugging berakhir dan semua breakpoint telah dicabut, sistem akan kembali ke mode JIT normal, dan cache JIT yang dibersihkan akan dihasilkan kembali begitu memasuki hotspot lagi.

Instalasi dan Konfigurasi

Plugin ini diaktifkan secara default.

Konfigurasikan conf/confg.yaml dengan benar untuk mengaktifkan plugin ini:

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

Plugin membaca definisi breakpoint dari file '/usr/local/apisix/plugin_inspect_hooks.lua' setiap 3 detik secara default. Untuk melakukan debugging, Anda hanya perlu mengedit file ini.

Kami merekomendasikan membuat tautan simbolis ke jalur ini sehingga lebih mudah untuk mengarsipkan berbagai versi historis dari file breakpoint.

Harap dicatat bahwa ketika file dimodifikasi, plugin akan membersihkan semua breakpoint sebelumnya dan mengaktifkan semua breakpoint baru yang didefinisikan dalam file breakpoint. Breakpoint ini akan efektif di semua proses worker.

Secara umum, tidak perlu menghapus file, karena saat mendefinisikan breakpoint, Anda dapat menentukan kapan harus mencabutnya.

Menghapus file ini akan membatalkan semua breakpoint untuk semua proses worker.

Log dari mulai dan berhentinya breakpoint akan dicatat pada level log 'WARN'.

Mendefinisikan Breakpoint

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

file, nama file, yang bisa berupa nama file atau path yang tidak ambigu.
line, nomor baris dalam file, harap dicatat bahwa breakpoint terkait erat dengan nomor baris, jadi jika kode berubah, nomor baris juga harus berubah.
func, nama fungsi yang trace-nya harus dibersihkan. Jika nil, maka semua trace dalam luajit vm akan dibersihkan.
filter_func, fungsi Lua kustom yang menangani breakpoint
- Parameter input disebut table yang mencakup berikut ini:
  - finfo: nilai kembalian dari debug.getinfo(level, "nSlf")
  - uv: tabel hash upvalues
  - vals: tabel hash variabel lokal
- Jika nilai kembalian fungsi adalah true, maka breakpoint akan secara otomatis dicabut. Jika tidak, breakpoint akan terus efektif.

Contoh:

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)
--- lebih banyak breakpoint ...

Harap dicatat bahwa breakpoint demo mengatur beberapa informasi dan mengirimkannya ke server eksternal. Juga, library resty.http yang digunakan adalah library asinkron berbasis cosocket.

Setiap kali memanggil API asinkron OpenResty, itu harus dikirim dengan penundaan menggunakan timer, karena menjalankan fungsi pada breakpoint adalah sinkron dan memblokir, itu tidak akan kembali ke program utama nginx untuk pemrosesan asinkron, jadi perlu ditunda.

Kasus Penggunaan

Menentukan Rute Berdasarkan Konten Body Permintaan

Misalkan kita memiliki persyaratan: bagaimana kita dapat mengatur rute yang hanya menerima permintaan POST dengan string APISIX: 666 dalam body permintaan?

Dalam konfigurasi rute, ada bidang vars, yang dapat digunakan untuk memeriksa nilai variabel nginx untuk menentukan apakah rute harus cocok. Variabel $request_body yang disediakan oleh nginx berisi nilai body permintaan, jadi kita dapat menggunakan variabel ini untuk mengimplementasikan persyaratan kita.

Mari kita coba mengkonfigurasi rute:

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

Kemudian kita bisa mencoba ini:

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

Aneh, mengapa kita tidak bisa mencocokkan rute ini?

Kita kemudian akan melihat dokumentasi untuk variabel ini di nginx:

Nilai variabel tersedia di lokasi yang diproses oleh direktif proxy_pass, fastcgi_pass, uwsgi_pass, dan scgi_pass ketika body permintaan dibaca ke buffer memori.

Dengan kata lain, kita perlu membaca body permintaan terlebih dahulu sebelum menggunakan variabel ini.

Saat mencocokkan rute, apakah variabel ini akan kosong? Kita dapat menggunakan plugin inspect untuk memverifikasinya.

Kita menemukan baris kode yang mencocokkan rute:

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

Mari kita verifikasi variabel request_body di baris 515, yaitu router.router_http.match(api_ctx).

Mengatur Breakpoint

Edit file /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)

Buat tautan simbolis ke jalur file breakpoint:

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

Periksa log untuk memastikan bahwa breakpoint efektif.

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

Picu ulang pencocokan rute:

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

Periksa log:

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"

Tentu saja, request_body kosong!

Solusi

Karena kita tahu bahwa kita perlu membaca body permintaan untuk menggunakan variabel request_body, jadi kita tidak bisa menggunakan vars untuk melakukan ini. Sebagai gantinya, kita dapat menggunakan bidang filter_func dalam rute untuk mencapai persyaratan kita.

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

Mari kita verifikasi:

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

Masalah teratasi!

Mencetak Beberapa Log yang Telah Diblokir oleh Level Log.

Secara umum, kita tidak mengaktifkan log level INFO di lingkungan produksi, tetapi terkadang kita perlu memeriksa beberapa informasi detail. Bagaimana kita bisa melakukannya?

Kita biasanya tidak akan langsung mengatur level INFO dan kemudian reload, karena ini memiliki dua kekurangan:

Terlalu banyak log, yang memengaruhi kinerja dan meningkatkan kesulitan pemeriksaan
Reloading menyebabkan koneksi persisten terputus, memengaruhi lalu lintas online

Biasanya, kita hanya perlu memeriksa log dari titik tertentu; misalnya, kita semua tahu bahwa APISIX menggunakan etcd sebagai database distribusi konfigurasi, jadi bisakah kita melihat kapan konfigurasi rute diperbarui secara inkremental ke data plane? Data spesifik apa yang telah diperbarui?

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

Fungsi Lua untuk sinkronisasi inkremental adalah sync_data(), tetapi ini mencetak data inkremental dari watch etcd di level INFO.

Jadi mari kita coba menggunakan plugin inspect untuk menampilkan. Kami hanya akan menunjukkan perubahan sumber daya rute.

Edit /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)

Logika fungsi penanganan breakpoint ini jelas menunjukkan kemampuan penyaringan. Jika key dari watch adalah /routes, dan err kosong, itu akan mencetak data yang dikembalikan oleh etcd hanya sekali, lalu membatalkan breakpoint.

Perhatikan bahwa sync_data() adalah fungsi lokal, jadi tidak dapat dirujuk langsung. Dalam kasus itu, kita hanya dapat mengatur parameter ketiga dari set_hook menjadi nil, yang memiliki efek samping membersihkan semua trace.

Dalam contoh di atas, kita telah membuat tautan simbolis, jadi kita hanya perlu menyimpan file setelah mengedit. Breakpoint akan diaktifkan setelah beberapa detik; Anda dapat memeriksa log untuk memastikan.

Dengan memeriksa log, kita dapat memperoleh informasi yang kita butuhkan, yang dicetak pada level log WARN. Ini juga menunjukkan waktu ketika kita mendapatkan data inkremental etcd pada data plane.

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

Kesimpulan

Debugging dinamis Lua adalah fungsi bantu yang penting. Dengan plugin inspect APISIX, kita dapat melakukan banyak hal seperti:

Memecahkan masalah dan mengidentifikasi penyebab masalah
Mencetak beberapa log yang diblokir dan mengambil berbagai informasi sesuai kebutuhan
Mempelajari kode Lua dengan debugging

Silakan baca dokumentasi terkait untuk detail lebih lanjut.