故障排查——var磁盘空间被已删除日志占满

cuixiaogang

根因:/var/log/messages 在仍被 rsyslogd(写)与日志采集 agent(读)持有句柄时被 rm 删除,deleted 文件钉住约 2.1G 空间,df 不降而 du 不可见;messages 被删的诱因是其被内核 audit 规则风暴刷长(auditd 早已停止、事件无处投递而灌入 syslog),腾空间式的删除留下悬挂句柄。

现象

部分机器触发 /var 磁盘空间不足告警,本次排查由此开始:

接手查看告警机器时,/var 已用率 86%,且 dfdu 统计对不上,差额约 2.1G:

1
2
3
4
5
6
[root@<主机名> var]# du -sh /var/
946M /var/
[root@<主机名> var]# df -h /var
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/VolGroup00-LogVol02
3.9G 3.1G 555M 86% /var

差额去哪了——这是本篇要回答的问题。

环境

  • 老式 CentOS/RHEL 6 风格系统(service 管理,rsyslogd 带 -c 4 启动参数);/var 独立 LVM 卷,仅 3.9G。
  • rsyslog 统一写 /var/log/messages 等系统日志;另有一个由 supervise 守护的日志采集 agent,以读方式 tail 这些日志。
  • 内核 audit 规则由安全类 agent 运行时动态注入(全量 syscall 级),用户态 auditd 进程已长期停止。

排查过程

第一步:确认差额不在普通文件里

跨文件系统统计 /var 各子目录(-x 避免串挂载):

1
2
3
4
5
[root@<主机名> var]# du -xsh /var/*
829M /var/cache
74M /var/lib
41M /var/log
...(其余目录均为 KB 级)

加总仍是 900M 量级——目录树里根本不存在那 2.1G。推断:要么是被挂载点遮挡的旧文件,要么是没有目录项的文件(deleted)。

第二步:lsof 锁定 deleted 大文件

1
2
3
4
[root@<主机名> var]# lsof | grep deleted | grep /var
rsyslogd 2534 root 4w REG 253,3 2264498020 47 /var/log/messages (deleted)
logagent 6404 root 10r REG 253,3 2264498020 47 /var/log/messages (deleted)
(另有若干 pid/lock 类 deleted 小文件,KB 级,忽略)

两个进程以同一 inode 47 持有同一个已删除的 /var/log/messages,2264498020 字节 ≈ 2.1G,与差额吻合。FD 列 4w/10r 表明:rsyslogd 还在往里(文件仍在增长),采集 agent 只是(钉住不放)。锁定机制方向:deleted 文件未被释放。

第三步:先释放写方

对 rsyslogd 发 HUP 让它重开日志文件:

1
2
3
4
[root@<主机名> var]# kill -HUP 2534
[root@<主机名> var]# lsof | grep deleted | grep /var
logagent 6404 root 10r REG 253,3 2264671509 47 /var/log/messages (deleted)
(rsyslogd 各行已消失)

写方闭环。但空间并未释放——只剩采集 agent 一个读句柄钉着 inode;且 size 比 HUP 前多了 173489 字节,属发信号到旧 FD 关闭之间窗口内的尾巴写入,正常。推断:Linux 按「nlink=0 且无任何进程打开」才回收,读者不放手同样不释放。下一步必须重启采集 agent(kill 后 supervise 自动拉起)。

第四步:追问 messages 为何会被删——发现 audit 风暴

顺着「谁删了 messages、为什么删」排查,先看日志内容,tail /var/log/messages 被内核审计记录刷屏:

1
2
3
kernel: type=1300 audit(...): arch=c000003e syscall=59 success=no exit=-2 ... comm="perl" ... key="EXEC"
kernel: type=1300 audit(...): arch=c000003e syscall=42 success=no exit=-115 ... saddr=020000500B7BFD52 ... key="CONNECT"
kernel: __ratelimit: 861 callbacks suppressed

逐字段读:这些多数不是故障——exit=-2 是 ENOENT(perl 找 /usr/bin/date 失败、随后 /bin/date 成功,PATH 探测噪音);exit=-115 是 EINPROGRESS(非阻塞 connect 正常中间态);saddr 十六进制解码出该 agent 在连 <内网IP>:80<外网IP>:53__ratelimit ... suppressed 则说明实际事件量远超看到的刷屏量。

查 audit 子系统状态坐实根因:

1
2
# auditctl -s
AUDIT_STATUS: enabled=1 flag=0 pid=0 rate_limit=102400 backlog_limit=163840 lost=154041485 backlog=0

pid=0 表示内核 audit 没有用户态消费者(auditd 早已停止,audit.log 停在 2024 年 9 月 10 日),但 enabled=1 且规则仍在:内核持续产生事件、无处投递,fallback 进 syslog 灌入 messages,已累计丢弃 1.54 亿条。查规则来源:

1
2
3
4
# auditctl -l
LIST_RULES: exit,always ppid!=25563 (0x63db) pid!=25563 (0x63db) key=CONNECT syscall=connect
LIST_RULES: exit,always ppid!=25563 (0x63db) pid!=25563 (0x63db) key=EXEC syscall=clone,execve
(另有 LISTEN 与 8 条目录监控规则,均带同样的 ppid/pid 自排除)

/etc/audit/audit.rulesrules.d/ 里查无这些规则——说明是某进程运行时动态注入的;ppid!=25563 pid!=25563 的自排除是安全 agent 注入规则的指纹。至此因果链闭合:规则过宽 + auditd 停止 → messages 疯长 → 被删除腾空间 → deleted 句柄钉住空间

第五步:轮转链取证,反证悬挂已持续数周

翻遍 root 的 crontab 与 bash_history 都找不到 rm messages 的手——正常,清理本就内嵌在 crond → /etc/cron.daily/logrotate → /etc/logrotate.d/syslog 轮转链里,且配置完好(含 postrotate 对 rsyslogd 发 HUP)。决定性证据在轮转产物:

1
2
3
4
5
6
# ls -l /var/log/messages*
-rw------- 1 root root 34M Sep 14 10:18 /var/log/messages
-rw------- 1 root root 0 Aug 23 03:20 /var/log/messages-20260823
-rw------- 1 root root 0 Aug 30 03:34 /var/log/messages-20260830
-rw------- 1 root root 0 Sep 6 03:33 /var/log/messages-20260906
-rw------- 1 root root 0 Sep 13 03:3x /var/log/messages-20260913

轮转每周凌晨都在正常跑(mtime 为证),但连续 4 个历史文件全部 0 字节——路径上的 messages 长期是空的,写者一直在往 deleted 旧 inode 写。既反证了本次 deleted 悬挂并非刚发生,也解释了 2.1G 的体积来源。另注意 postrotate 里的 2> /dev/null || true 会静默吞掉 HUP 失败,是「配置正确但行为异常」的常见藏身处。

根因

  • 直接原因/var/log/messages 被删除时,rsyslogd 与采集 agent 仍持有其文件句柄。rm 只解除目录项(nlink 归 0),而空间释放要等最后一个打开的 FD 关闭;inode 未回收,du 遍历目录树不可见、df 按文件系统块统计仍计入,于是差出 2.1G。
  • 为什么会被删:audit 风暴使 messages 疯长,在 /var 仅 3.9G 的环境里被删除腾空间;删除者已不可考(无 rm 痕迹),且 logrotate 虽配置正确,postrotate 的 HUP 若失败会被 || true 静默吞掉。
  • 上游原因:全量 syscall 级 audit 规则被安全 agent 动态注入,而 auditd 用户态进程已停止,事件无消费者、灌入 syslog。
  • 如实存疑:事后回看,messages 的增长未必只归因于 audit——也可能另有某个错误故障推波助澜;但相关 deleted 文件随重启已被清理,此疑点已无法取证。

解决

按序执行,两处动作:

1
2
kill -HUP $(cat /var/run/syslogd.pid)   # 让写方 rsyslogd 重开新文件(实录已验证 deleted 行消失)
kill <采集agent的PID> # supervise 自动拉起,等效重启,释放读句柄;有 svc 时可用 svc -t <服务目录>

后续回访补录:重启 rsyslogd 与采集 agent 后,df -h /var 用量下降约 2G,deleted 文件不复存在;其后未再复发。正确的日志清理姿势同步纠正——截断而非删除:

1
: > /var/log/messages        # inode 不变,写者无需重开,不产生 deleted

防复发

  • 收窄 audit 规则(待办,需上机复核)auditctl -D 清掉过宽规则或要求安全组件改用 -w 关键路径 -p wa -k 标签 式窄规则;注意 -D 只清内核运行态,重启后来源规则可能回来,须与注入方约定。记录结束时未见此步执行回执。
  • 轮转兜底:logrotate 对 messages 增加 size 触发条件(weekly 不会因体积暴涨提前轮转);去掉 postrotate 的 || true,让 HUP 失败留下痕迹。
  • 操作纪律:清理日志一律截断、不 rm/var 仅 3.9G,容量规划上给日志留量或分区。
  • 采集侧:tail 型 agent 若不具备 close→reopen 能力,重启它只是恢复手段,长期留意其对轮转的适配。

关键知识点总结

磁盘空间统计与文件生命周期

  • df 与 du 口径不同df 读文件系统超级块的块统计,du 遍历目录树逐个 stat;deleted-but-open 文件没有目录项,只有 df 看得见——两者差额本身就是「悬挂句柄」的信号。
  • 释放条件是双重的:nlink=0(rm/unlink) open FD 数为 0,缺一空间不回收;读者与写者同等钉住 inode,lsofw/r 仅区分「谁还在写」与「谁只钉着」。
  • 信号不跨进程传 FD:HUP 只让 rsyslogd 自己重开文件,其他持有同一 inode 的进程必须各自重启/重开。
  • deleted 文件是否还在长:间隔两次 lsof 比对 size,不变即只剩钉住的读方。
  • 截断优于删除: > 文件 / cat /dev/null > 文件 不换 inode;rm 必然产生悬挂引用(有进程打开时)。
  • 轮转产物可反证异常:历史轮转文件连续 0 字节 ⇒ 路径上的活动日志长期为空 ⇒ 写者在往 deleted 旧 inode 写。

logrotate 取证与陷阱

  • 正常清理链是 crond/anacron → /etc/cron.daily/logrotate → logrotate.d/*,用户 crontab 与 bash_history 查不到 rm 属正常。
  • /var/lib/logrotate.status 记录各日志上次轮转时间;logrotate -d 干跑、-f 强制轮转。
  • weekly 不防体积爆炸,需 size/maxsize 兜底;copytruncate 可免 HUP 但有丢日志窗口。
  • postrotate 惯用 || true + 吞 stderr,失败静默——排查「配置对、行为错」时先盯这类写法。

Linux Audit 子系统

  • 内核 audit 与用户态 auditd 解耦:规则活在内核里,auditd 死了事件照产生;pid=0 即无消费者,事件降级灌入 /var/log/messages
  • auditctl -s 关键字段:enabled(内核开关)、pid(消费者)、lost(累计丢弃,衡量风暴烈度)、backlog/backlog_limit
  • 动态注入判别法auditctl -l 有、配置文件无 ⇒ 运行时注入;-D 只清运行态,重启后配置文件规则会回来。ppid!=N pid!=N 自排除是注入方指纹。
  • 全量 syscall 审计是反模式:execve/connect 全审计在繁忙主机上必然日志爆炸;正确姿势是 -w 窄规则、排除可信主体、排障窗口临时开启用完摘除。
  • audit 日志里 success=no 不等于应用故障:exit=-2 是 ENOENT(PATH 探测)、exit=-115 是 EINPROGRESS(非阻塞 connect 中间态)。
  • __ratelimit: N callbacks suppressed 是「事件洪水」的定量下限证据——真实量远大于看到的。
  • saddr 按 sockaddr_in 解码:前 2 字节 AF_INET、随后 2 字节网络序端口、再 4 字节 IP。

进程守护语义

  • 被 supervise(daemontools 系)守护的进程,kill 即被自动拉起,等效安全重启;正规入口是 svc -t。重启采集类进程的代价评估:短暂停采、有无 offset 断点决定漏采或重复。