修改openresty日志中打印的文件名

0x0背景

在基于openresty的项目中文件按照一定规则进行组织,类似下面:

1
2
3
4
5
6
[[email protected] or_demo]$ tree src/
src/
├── bar
│ └── api.lua
└── foo
└── api.lua

最后对应到业务逻辑的文件名称很可能是一样的,这时如果我们在代码里记录了一些日志,最后在日志文件中打印出来的文件名都是同一个。但是实际上,这些日志来源于不同文件夹下的文件,我们需要能够在日志中一目了然的看出来打印自哪个文件。

1
2
3
4
[[email protected]]$ curl 127.0.0.1:9000/foo
reply from src.foo.api
[[email protected]]$ curl 127.0.0.1:9000/bar
reply from src.bar.api

日志类似这样

1
2
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方案

解决这个问题初步有两个方案

  1. 自己定义一个文件所在位置的变量,在ngx.log时取出来。
  2. 直接修改 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 的身影。

1
2
3
4
5
6
7
8
9
10
11
12
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 接口对于文件名的处理,注释掉了对文件名的路径截断的判断。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
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;
}

重新下编译,运行程序后效果如下,可以看到对应的日志现在记录日志的文件完整路径打印出来了。

1
2
3
4
[[email protected]]$ curl 127.0.0.1:9000/foo
reply from src.foo.api
[[email protected]]$ curl 127.0.0.1:9000/bar
reply from src.bar.api

1
2
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"

参考

lua_Debug

您的支持将鼓励我继续创作!