Nginx Lua 日志收集

美丽联合安全

Author：JoyChou@Meili-inc
Date：20180620

申明，如果文章内容，有任何问题，欢迎读者进行评论指正。我也是这方面的初学者，我也一直在寻找最优秀、有效的方式。

0x00 背景

在WAF命中规则后，需要记录拦截的日志，之前使用的方法是ngx.log。运行了一段时间，遇到一个瓶颈，ngx.log记录每行最长长度为2048字节。

但这个限制可以通过修改nginx源码修改，但是让运维修改nginx源码，重新编译nginx，打一个新RPM包，这个方法我自己都不想接受。

所以，我尝试着，换另外的方法去解决这个问题。

<!--more-->

0x01 比较开源WAF

名字	方式	github地址	代码地址
tengine_waf	io.open	https://github.com/lanzsec/tengine_waf	https://github.com/lanzsec/tengine_waf/blob/8b55bd477603c772ca87948d8610a0bce258e334/conf/init.lua
waf	io.open	https://github.com/unixhot/waf	https://github.com/unixhot/waf/blob/master/waf/lib.lua
lua-resty-waf	三种方式给选择	https://github.com/p0pr0ck5/lua-resty-waf	https://github.com/p0pr0ck5/lua-resty-waf/blob/master/lib/resty/waf/log.lua
ngx_lua_waf	io.open	https://github.com/loveshell/ngx_lua_waf	https://github.com/loveshell/ngx_lua_waf/blob/master/init.lua
openstar	io.open	https://github.com/starjun/openstar	https://github.com/starjun/openstar/blob/master/log.lua

可以看到，基本是用的Lua的io.open，但是任何文件操作都会造成nginx请求的阻塞。

所以，这是我完全不能接收的，所以我做了压测对比。使用ab压测一个拦截页面，压测命令如下：

ab -n 100000 -c 100 http://x.x.x.x/payload

第一次 表示 第一次压测每条请求的平均时间，单位是ms

方式	第一次	第二次	平均值
没有WAF	0.121	0.126	0.1235
syslog-ng本地日志，buffer为4096	0.199	0.193	0.196
syslog-ng本地日志，buffer为1	0.205	0.230	0.2175
syslog-ng远程日志，buffer为4096	0.498	0.165	0.3315
io.open	0.233	0.241	0.237
ngx.log	0.165	0.176	0.1705

消耗时间为ngx.log < syslog-ng < io.open

ngx.log和io.open都会阻塞请求，所以我选择syslog-ng。

那么，有个问题来了，既然syslog-ng不阻塞请求，为什么消耗时间不是最慢的？

我也一直在思考这个问题，我的结论是：syslog-ng方式的时间消耗在了TCP的连接上以及syslog-ng写日志的IO操作上，另外两个方法只有IO消耗。所以我也用syslog-ng做了远程日志的测试，发现最低的时间0.165其实已经是最低的消耗时间，但是由于网路的不稳定性，两次消耗时间差距较大，也放弃了远程日志的方式。

0x02 Lua代码和syslog-ng配置

Lua代码:

local logger = require "resty.logger_socket"

-- 使用lua-resty-logger-socket向syslog-ng写入日志
-- 当满足一定的条件，syslog-ng即会进入垃圾收集状态，而暂时不再接受日志信息。这时，会造成非连接的传输协议的日志丢失(例如UDP)
function _M.logger_socket(log_data, blocktype, rulename)
    if not logger.initted() then
        local ok, err = logger.init {
            host = "127.0.0.1",
            port = 514, -- 默认使用tcp方式，使用UDP会造成日志丢失。
            flush_limit = 4096, -- 大小累计到该数值，才进行socket连接。该值可以加快socket速度，不用每条都请求。
            --drop_limit = 5678
        }
        if not ok then
            ngx.log(ngx.ERR, "failed to initialize the logger: ", err)
            return
        end
    end
    local bytes, err = logger.log("data\n")

    if err then
        ngx.log(ngx.ERR, "failed to log message: ", err)
        return
    end
end

logger-socket代码地址：https://github.com/cloudflare/lua-resty-logger-socket

syslog-ng配置

@version:3.2

# filepath: /etc/syslog-ng/syslog-ng.conf

source s_sys {
    tcp(ip(127.0.0.1) port(514));
};

destination test {
    file("/var/log/syslog-ng.log");
};

log {
    source(s_sys);
    destination(test);
};

当满足一定的条件，syslog-ng即会进入垃圾收集状态，而暂时不再接受日志信息。这时，会造成非连接的传输协议的日志丢失(例如UDP)。

所以要使用TCP协议。

0x03 用logrotate轮询syslog-ng日志

为了让日志的文件内容体积不会越来越大，选择使用Logrotate轮询syslog-ng的日志。轮询的时候，需要解决一个问题：

当轮询完成后，之前的/var/log/syslog-ng.log文件名会被重命名类似/var/log/syslog-ng.log-20171217的文件名。此时，syslog-ng就不能写日志了，因为配置的/var/log/syslog-ng.log文件不存在了。

测试发现，reload syslog-ng服务后，配置的文件又能重新生成。后来，我提了一个issue咨询是否还有其他方式，作者提供了一种更优雅的方式来替代reload操作：对syslog-ng发一个reopen信号。

对syslog-ng进程发起reopen信号的命令为：

/bin/kill -SIGUSR1 `cat /var/run/syslogd.pid 2> /dev/null` 2> /dev/null

Github上提问的ISSUE链接：https://github.com/balabit/syslog-ng/issues/1774

最后，logrotate的配置文件为

/var/log/syslog-ng.log {
    rotate 7
    missingok
    daily
    dateext
    nocompress
    postrotate
        /bin/kill -SIGUSR1 `cat /var/run/syslogd.pid 2> /dev/null` 2> /dev/null
    endscript
}

其中：

• /var/run/syslogd.pid文件记录着syslog-ng运行的pid
• 可以发现，利用logrotate可以执行shell命令，所以这也是一种留后门的攻击方式。

0x04 Logrotate运行时间

Logrotate每天会自动运行，因为在cron.daily定时任务里。

cat /etc/cron.daily/logrotate

#!/bin/sh

/usr/sbin/logrotate /etc/logrotate.conf >/dev/null 2>&1
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
    /usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit 0

那cron.daily每天什么时候执行？

可以看到/etc/cron.daily定义在/etc/anacrontab里。

$ cat /etc/anacrontab
# /etc/anacrontab: configuration file for anacron
# See anacron(8) and anacrontab(5) for details.
SHELL=/bin/sh
PATH=/sbin:/bin:/usr/sbin:/usr/bin
MAILTO=root
# the maximal random delay added to the base delay of the jobs
RANDOM_DELAY=45
# the jobs will be started during the following hours only
START_HOURS_RANGE=3-22
#period in days delay in minutes job-identifier command
1    5    cron.daily        nice run-parts /etc/cron.daily
7    25    cron.weekly        nice run-parts /etc/cron.weekly
@monthly 45    cron.monthly        nice run-parts /etc/cron.monthly

start_hours_range=3-22表示3点到22点之间运行，cron.daily会延迟5分钟，并且最大的随机延迟为45分钟。

所以运行时间为，3.05- 3.50。关于这个时间点，网上真的有很多谬论。

看看已经生成的日志文件时间：

-rw-------   1 root root      0 Dec 15 03:25 syslog-ng.log-20171216
-rw-------   1 root root      0 Dec 14 03:17 syslog-ng.log-20171215
-rw-------   1 root root      0 Dec 13 03:41 syslog-ng.log-20171214
-rw-------   1 root root      0 Dec 12 03:17 syslog-ng.log-20171213
-rw-------   1 root root      0 Dec 11 03:18 syslog-ng.log-20171212

感谢分享

琴心丶剑胆 发表于 2018-6-22 09:34
感谢分享

相互交流学习哦~

666666666666666666666666

66666666666666666

66666666666666666666666

支持一下~