Google Compute Engine Debian Stretch环境下IN_CLOSE_NOWRITE致Fail2Ban规则失效

问题描述 #

我在基于谷歌官方镜像的Google Cloud Compute Engine虚拟机上部署Fail2Ban，通过apt-get安装后服务运行正常，但规则始终不触发。使用fail2ban-regex验证规则时，规则能匹配日志文件中的对应行。

经排查发现，手动修改文件时pyinotify捕获的事件为：

<Event dir=False mask=0x20 maskname=IN_OPEN name='' path=/tmp/test pathname=/tmp/test wd=1 >
<Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/tmp/test pathname=/tmp/test wd=1 >
<Event dir=False mask=0x8 maskname=IN_CLOSE_WRITE name='' path=/tmp/test pathname=/tmp/test wd=1 >

但日志文件（如/var/log/auth.log）的事件始终以IN_CLOSE_NOWRITE结尾：

<Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x20 maskname=IN_OPEN name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x1 maskname=IN_ACCESS name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x10 maskname=IN_CLOSE_NOWRITE name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >

这是否是规则不触发的原因？我已尝试将Fail2Ban后端设置为轮询，但无改善。通过tail -f能看到日志文件有事件时会被追加内容，不确定是谷歌修改了Debian镜像还是虚拟化环境导致，请问下一步该如何排查？

以下是fail2ban.log内容：

2018-01-19 15:29:23,309 fail2ban.jail [13935]: INFO Jail 'sshd' uses pyinotify {}
2018-01-19 15:29:23,312 fail2ban.jail [13935]: INFO Initiated 'pyinotify' backend
2018-01-19 15:29:23,313 fail2ban.filter [13935]: INFO Set maxRetry = 5
2018-01-19 15:29:23,313 fail2ban.filter [13935]: INFO Added logfile = /var/log/auth.log
2018-01-19 15:29:23,314 fail2ban.filter [13935]: INFO Set findtime = 600
2018-01-19 15:29:23,314 fail2ban.actions [13935]: INFO Set banTime = 600
2018-01-19 15:29:23,314 fail2ban.filter [13935]: INFO Set jail log file encoding to UTF-8
2018-01-19 15:29:23,315 fail2ban.filter [13935]: INFO Set maxlines = 10
2018-01-19 15:29:23,338 fail2ban.server [13935]: INFO Jail sshd is not a JournalFilter instance
2018-01-19 15:29:23,342 fail2ban.jail [13935]: INFO Jail 'sshd' started

无论auth.log中有什么内容，都不会出现"[sshd] Found"记录。

排查步骤与解决方案 #

首先，你观察到的IN_CLOSE_NOWRITE确实可能是问题的导火索，但先别急着下结论，咱们一步步来验证：

1. 确认轮询后端是否真的生效了 #

你提到已经设置了轮询后端，但从fail2ban.log里看到的还是pyinotify在运行——这说明你的配置大概率没生效。按以下步骤检查：

• 打开全局配置文件/etc/fail2ban/jail.conf或者自定义的/etc/fail2ban/jail.local，找到backend字段，确保设置为backend = polling
• 检查sshd jail的单独配置（比如/etc/fail2ban/jail.d/sshd.conf），确认里面没有覆盖全局的backend设置
• 修改配置后务必执行systemctl restart fail2ban，然后查看fail2ban.log的启动日志，确认显示的是Initiated 'polling' backend

2. 检查日志文件的权限与访问性 #

GCE官方镜像可能对日志文件做了权限限制，导致Fail2Ban进程无法正常读取/var/log/auth.log：

• 查看文件权限：执行ls -l /var/log/auth.log，确认运行Fail2Ban的用户（通常是root或fail2ban）有读权限
• 如果权限不足，可临时调整测试：chmod o+r /var/log/auth.log；长期方案建议将fail2ban用户加入adm组（该组默认拥有日志读取权限）：usermod -aG adm fail2ban
• 调整后重启Fail2Ban服务再测试

3. 验证Fail2Ban监控的日志路径是否正确 #

有时候系统日志服务（如rsyslog）会将日志转发到其他位置，或者GCE镜像使用journald而非传统文件日志：

• 检查/etc/fail2ban/jail.d/sshd.conf中的logpath字段，确认是/var/log/auth.log；如果使用journald，则需要设置为logpath = %(journald)s
• 执行fail2ban-client status sshd查看当前jail状态，确认Log file list中显示的是正确的日志路径

4. 测试规则匹配的实时性 #

既然fail2ban-regex能匹配，咱们手动触发一次失败登录，再强制Fail2Ban重新扫描日志：

• 执行fail2ban-client set sshd flushlogs，该命令会让Fail2Ban重新扫描日志文件的全部内容
• 查看fail2ban.log，如果仍无[sshd] Found记录，可能是规则与日志格式存在细微差异（比如时间格式、字段顺序），可复制一条auth.log中的失败登录记录，用fail2ban-regex "你的日志行" /etc/fail2ban/filter.d/sshd.conf再次验证匹配情况

5. 排查GCE的日志代理影响 #

GCE官方Debian镜像通常会预装google-fluentd这类日志代理，它们可能以只读方式打开日志文件，导致pyinotify无法捕获到正确的写入事件（也就是你看到的IN_CLOSE_NOWRITE）：

• 查看google-fluentd状态：systemctl status google-fluentd
• 临时停止该服务：systemctl stop google-fluentd，再测试Fail2Ban是否能触发规则
• 如果停止后恢复正常，可调整google-fluentd的配置，使其以不影响文件监控的方式读取日志；或者继续使用Fail2Ban的polling后端，并设置较短的扫描间隔（在jail配置中添加pollinterval = 1，单位为秒）

6. 启用调试日志定位细节 #

如果以上步骤都未解决问题，打开Fail2Ban的调试日志获取更详细信息：

• 修改/etc/fail2ban/fail2ban.conf中的loglevel为DEBUG
• 重启Fail2Ban服务：systemctl restart fail2ban
• 查看fail2ban.log，里面会包含日志扫描的详细过程，比如是否读取到日志行、匹配失败的原因、权限问题等

最后补充：你观察到的IN_CLOSE_NOWRITE确实是因为日志文件被其他进程以只读方式打开导致的，pyinotify默认在IN_CLOSE_WRITE事件触发时扫描日志，所以只有IN_CLOSE_NOWRITE时不会触发扫描。但polling后端会定期扫描日志，所以核心问题大概率是polling后端未正确生效，先确认这一点！

内容的提问来源于stack exchange，提问作者Petri Riihikallio