0x0背景
在基于openresty的项目中文件按照一定规则进行组织,类似下面:
[gerrard@gerrard or_demo]$ tree src/
src/
├── bar
│ └── api.lua
└── foo
└── api.lua
最后对应到业务逻辑的文件名称很可能是一样的,这时如果我们在代码里记录了一些日志,最后在日志文件中打印出来的文件名都是同一个。但是实际上,这些日志来源于不同文件夹下的文件,我们需要能够在日志中一目了然的看出来打印自哪个文件。
[gerrard@gerrard]$ curl 127.0.0.1:9000/foo
reply from src.foo.api
[gerrard@gerrard]$ curl 127.0.0.1:9000/bar
reply from src.bar.api
日志类似这样
2018/09/25 09:38:25 [info] 5693#0: *1 [lua] api.lua:16: log from src.foo.api, client: 127.0.0.1, server: , request: "GET /foo HTTP/1.1", host: "127.0.0.1:9000"
2018/09/25 09:38:28 [info] 5693#0: *2 [lua] api.lua:16: log from src.bar.api, client: 127.0.0.1, server: , request: "GET /bar HTTP/1.1", host: "127.0.0.1:9000"
0x1方案
解决这个问题初步有两个方案
- 自己定义一个文件所在位置的变量,在ngx.log时取出来。
- 直接修改 ngx_lua 源码,注意到openresty对于lua级的代码奔溃时,调用栈是有完整的代码路径的,因此修改 ngx_lua 的源码理论上是可行的。
方案1需要修改每个模块的日志,并且openresty打印的日志已经有文件名称了,有点重复,因此选择了方案2进行尝试。
0x2探索
在openresty处理栈奔溃的代码 ngx_http_lua_util.c 的 ngx_http_lua_thread_traceback 接口中,可以看到奔溃信息是通过lua_Debug这个结构体获取的。
这里lua_Debug 给出了lua_Debug中各个字段的含义,我们看到文件名信息使用了short_src这个变量,它是source变量的一个可打印版本。也就是说我们可以在 ngx.log 接口实现处使用该变量进行替换。
我们找到ngx.log的C代码,ngx_http_lua_log.c 文件的 ngx_http_lua_ngx_log 接口,其返回处调用了一个日志包装函数 log_wrapper 接口,在这里我们找到了 lua_Debug 的身影。
if (name.data == NULL) {
name.len = 0;
} else {
p = name.data;
while (*p != '\0') {
if (*p == '/' || *p == '\\') {
name.data = p + 1;
}
p++;
}
name.len = p - name.data;
}
从代码可以看到 log_wrapper 对 short_src 进行了处理,在循环中寻找'/‘和’'开头的字符,把name的数据域指针不断更新,过滤掉文件夹名称,使得name.data最终只包含最后的文件名称。
0x3效果
根据上面分析,我们修改了ngx_http_lua_log.c 中 log_wrapper 接口对于文件名的处理,注释掉了对文件名的路径截断的判断。
if (name.data == NULL) {
name.len = 0;
} else {
p = name.data;
while (*p != '\0') {
/*
if (*p == '/' || *p == '\\') {
name.data = p + 1;
}
*/
p++;
}
name.len = p - name.data;
}
重新下编译,运行程序后效果如下,可以看到对应的日志现在记录日志的文件完整路径打印出来了。
[gerrard@gerrard]$ curl 127.0.0.1:9000/foo
reply from src.foo.api
[gerrard@gerrard]$ curl 127.0.0.1:9000/bar
reply from src.bar.api
2018/09/25 09:46:36 [info] 15240#0: *1 [lua] ./src/foo/api.lua:16: log from src.foo.api, client: 127.0.0.1, server: , request: "GET /foo HTTP/1.1", host: "127.0.0.1:9000"
2018/09/25 09:46:39 [info] 15240#0: *2 [lua] ./src/bar/api.lua:16: log from src.bar.api, client: 127.0.0.1, server: , request: "GET /bar HTTP/1.1", host: "127.0.0.1:9000"