JoyChou JoyChou

Nginx Lua Logging

Operations 阅读(1114) 文章转载请注明来源!

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

0x00 背景

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

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

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

0x01 比较开源WAF

名字方式github地址代码地址
tengine_wafio.openhttps://github.com/lanzsec/tengine_wafhttps://github.com/lanzsec/tengine_waf/blob/8b55bd477603c772ca87948d8610a0bce258e334/conf/init.lua
wafio.openhttps://github.com/unixhot/wafhttps://github.com/unixhot/waf/blob/master/waf/lib.lua
lua-resty-waf三种方式给选择https://github.com/p0pr0ck5/lua-resty-wafhttps://github.com/p0pr0ck5/lua-resty-waf/blob/master/lib/resty/waf/log.lua
ngx_lua_wafio.openhttps://github.com/loveshell/ngx_lua_wafhttps://github.com/loveshell/ngx_lua_waf/blob/master/init.lua
openstario.openhttps://github.com/starjun/openstarhttps://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

方式第一次第二次平均值
没有WAF0.1210.1260.1235
syslog-ng本地日志,buffer为40960.1990.1930.196
syslog-ng本地日志,buffer为10.2050.2300.2175
syslog-ng远程日志,buffer为40960.4980.1650.3315
io.open0.2330.2410.237
ngx.log0.1650.1760.1705

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

ngx.logio.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速度,不用每条都请求。
            periodic_flush = 10,
        }
        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

如果想要近实时的日志,需要将buffer值设置稍微小点,或者使用periodic_flush参数(单位是秒)来定时刷新。

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
JoyChou WeChat Pay

微信打赏

JoyChou Alipay

支付宝打赏

luanginxlogging
最后由admin修改于2017-12-27 19:05
发表新评论
博客已经运行
© Powered by JoyChou (2013-2018)
前篇 后篇
雷姆
拉姆