lua require缓存踩坑记录
0x0 背景
最近在配合自动化pipeline上线，需要给websocket长连接服务增加prestop机制，大致原理是通过k8s的prestop hook触发更新前优雅退出的逻辑。
通过prestop hook执行我们的检测脚本， 检测脚本会定期请求服务暴露的/prestop接口，该接口会做两件事情：
1. 检测当前实例中活跃连接的数量，如果没有活跃连接的则返回ok, 表示可以关闭服务了
2. 设置prestop标识，让服务进入prestop状态，开启连接检查
此后每条连接会进入连接关闭逻辑检查，分为两类：
1. 空闲连接检测，这种是被动检测，由客户端报文触发，每次客户端发送业务报文时重置连接空闲时间，每次客户端发送ping报文时检测连接空闲时长，根据空闲连接判断算法决定是否需要关闭连接。
2. 业务session检测，这种属于主动检测，由服务主动触发，每次服务返回业务报文给客户端之后，根据发送的报文是否符合关闭的条件决定是否需要关闭连接。
流程如下：
同时，为了支持reload, 我们在exit_worker_by_lua* 阶段增加了清理逻辑，触发reload/quit之后，会对prestop设置过的数据进行清理。
0x1 问题
代码开发完了prestop模块后，集成到服务中进行测试的时候发现了一个诡异的问题，在prestop api和 exit_worker_by_lua*阶段，我们设置和清理的数据在业务代码中嵌入的检测方法处获取不到。
2020/12/11 18:13:53 [info] 133#133: *26584428 [lua] prestop.lua:154: check_close(): ###table: 0x7f95715817d82020/12/11 18:15:49 [info] 133#133: [lua] exit_worker_by_lua:4: ###DEBUG:table: 0x7f95716028b8
0x2 分析
local t = {}for k, v in pairs(package.loaded) doif type(v) == "table" thentable.insert(t, {key = k, value = tostring(v)})endendngx.log(ngx.INFO, "###DEBUG: ", cjson.encode(t))
得到的列表如下
[{"key":"resty.websocket.protocol","value":"table: 0x7f1335d7c3a0"},...{"key":"app.models.prestop","value":"table: 0x7f1335c42be8"},{"key":"resty.core.ndk","value":"table: 0x7f1381882788"},...{"key":"prestop","value":"table: 0x7f1335d86938"},...{"key":"jit","value":"table: 0x7f13818a1bd0"}]
可以看到出现了两个prestop的module，key分别是"app.src.prestop"和"prestop", 结合不同文件里引用的require语句:
local prestop = require("prestop")local prestop = require('app.models.prestop')
可以看到缓存用的name是require中的全路径，那为什么两个路径不一样，也都能找到这个模块呢？通过查看lua_package_path的配置:
lua_package_path '/usr/local/openresty/lualib/?.lua;?.lua;./app/?.lua;./app/lib/?.lua;./app/models/?.lua;$prefix/deps/share/lua/5.1/?.lua;$prefix/deps/share/lua/5.1/?/init.lua;;';原因是在我们的nginx.conf中的lua_package_path有这样一条path: ./app/models/?.lua; 通过它我们，直接require("prestop")也可以找到模块下的文件。
带着疑问看了一下luajit的代码，可以看到在src/lib_package.c的lj_cf_package_require函数里，会尝试在_LOADED表中查找模块名name是否有缓存，如果有则说明已经加载过了，如果没有查到，会进入require逻辑加载一次模块并缓存起来:
lua_settop(L, 1); /* _LOADED table will be at index 2 */lua_getfield(L, LUA_REGISTRYINDEX, "_LOADED");lua_getfield(L, 2, name);if (lua_toboolean(L, -1)) { /* is it there? */if ((L->top-1)->u64 == KEY_SENTINEL) /* check loops */luaL_error(L, "loop or previous error loading module " LUA_QS, name);return 1; /* package is already loaded */}lua_getfield(L, LUA_ENVIRONINDEX, "loaders");if (!lua_istable(L, -1))luaL_error(L, LUA_QL("package.loaders") " must be a table");lua_pushliteral(L, ""); /* error message accumulator */for (i = 1; ; i++) {lua_rawgeti(L, -2, i); /* get a loader */if (lua_isnil(L, -1))luaL_error(L, "module " LUA_QS " not found:%s",name, lua_tostring(L, -2));lua_pushstring(L, name);lua_call(L, 1, 1); /* call it */if (lua_isfunction(L, -1)) /* did it find module? */break; /* module loaded successfully */else if (lua_isstring(L, -1)) /* loader returned error message? */lua_concat(L, 2); /* accumulate it */elselua_pop(L, 1);}(L->top++)->u64 = KEY_SENTINEL;lua_setfield(L, 2, name); /* _LOADED[name] = sentinel */lua_pushstring(L, name);lua_call(L, 1, 1); /* run loaded module */if (!lua_isnil(L, -1)) /* non-nil return? */lua_setfield(L, 2, name); /* _LOADED[name] = returned value */lua_getfield(L, 2, name);if ((L->top-1)->u64 == KEY_SENTINEL) { /* module did not set a value? */lua_pushboolean(L, 1); /* use true as result */lua_pushvalue(L, -1); /* extra copy to be returned */lua_setfield(L, 2, name); /* _LOADED[name] = true */}
在第4行前加入如下打印验证一下我们的猜想
printf("#####DEBUG: %s, %s\n", name, (lua_toboolean(L, -1) ? "true" : "false"));dumpstack(L);测试代码local t = require("t")print(tostring(t))t = require("t")print(tostring(t))得到如下打印#####DEBUG: t, falsedumpstack:1 string t2 table 0x7fb4433935983 nil niltable: 0x7fb443391d48#####DEBUG: t, truedumpstack:1 string t2 table 0x7fb4433935983 table 0x7fb443391d48table: 0x7fb443391d48
可以看到第二次require "t"的时候，lua_getfield返回值已经不是nil了，并且table已经在栈里面，说明有cache了，接下来修改测试代码，更改require的模块名
local t = require("t")print(tostring(t))t = require("./t")print(tostring(t))#####DEBUG: t, falsedumpstack:1 string t2 table 0x7f84469815983 nil niltable: 0x7f844697fd48#####DEBUG: ./t, falsedumpstack:1 string ./t2 table 0x7f84469815983 nil niltable: 0x7f8446980810
可以看到第二次 require的模块name为"./t"，并且没有cache。
0x3 修复
2020/12/14 13:05:44 [info] 126#126: *96292006 [lua] prestop.lua:159: check_close(): ###DEBUG:table: 0x7f1335c0f3c82020/12/14 13:07:24 [info] 126#126: [lua] exit_worker_by_lua:4: ###DEBUG:table: 0x7f1335c0f3c
再次查看package.loaded中加载的模块只有一个app.models.prestop的key了:
[{"key":"ngx.re","value":"table: 0x7f13819133c0"},...{"key":"app.models.prestop","value":"table: 0x7f1335c0f3c8"},...]
0x4 反思
1. 如果require同一个文件，但是使用的路径不一样，很可能在package.loaded中缓存了两份，需要检查一遍代码
2. 开了lua_code_cache就以为操作了同一个module了，人类认为的同一个文件对计算机来说可能并不是，写代码的时候切记不能想当然