Filebeat 采集 Nginx 日志延迟和断点的排查实践

适用场景

这篇文章适用于 Nginx 接入 Filebeat、Logstash、Elasticsearch 或其他日志平台后，出现下面几类问题的场景：

• Nginx 访问日志本地已经写入，但日志平台几分钟后才看到。
• 部分时间段日志缺失，业务同学按 trace id 或客户端 IP 查不到请求。
• 日志轮转后采集停止，重启 Filebeat 后才恢复。
• Filebeat CPU 不高，但 published、acked 指标增长很慢。
• Logstash 或 Elasticsearch 短暂异常后，Filebeat 恢复很慢。

这类问题不要一上来就重启 Filebeat。重启可能会让现象暂时消失，但也会掩盖 registrar 状态、输出端反压、文件轮转、inode 变化等关键信息。

现象描述

一次线上问题中，Nginx 机器本地可以看到访问日志持续写入：

tail -f /var/log/nginx/access.log

但日志平台中同一时间段的日志延迟 5 到 10 分钟，偶尔还会出现短暂断点。业务反馈某些 5xx 请求在平台中查不到，但在 Nginx 本机 grep 可以命中：

grep 'request_id=9f2b7c' /var/log/nginx/access.log

Filebeat 服务状态显示运行中：

systemctl status filebeat --no-pager

这说明问题不一定是 Filebeat 进程退出，更可能是采集端、状态文件、输出端或日志轮转之间出现了阻塞。

可能原因

Filebeat 采集 Nginx 日志延迟或断点，常见原因有这些：

1. 输出端反压：Logstash、Kafka、Elasticsearch 慢，Filebeat 发送队列堆积。
2. 日志轮转配置不合理：copytruncate 导致短时间内 offset 和内容变化，采集状态容易混乱。
3. close_inactive、ignore_older、clean_inactive 参数组合不当，文件还在写却被关闭或清理状态。
4. 多个 input 重复采集同一文件，registry 中出现多条相近状态。
5. Nginx 日志量突增，Filebeat 默认 queue 或 bulk 参数偏小。
6. 磁盘 IO 高，Filebeat 读取日志或写 registry 变慢。
7. 文件路径使用通配符过宽，采集了大量历史压缩前文件或临时文件。

排查时要先判断卡在哪里：Nginx 是否持续写日志，Filebeat 是否持续读文件，Filebeat 是否能持续向下游发送。

快速判断采集链路卡点

1. 确认 Nginx 日志仍在写入

先确认源头没有停：

stat /var/log/nginx/access.log
tail -n 3 /var/log/nginx/access.log

重点看 stat 输出里的 Size 和 Modify：

• Size 持续变大，说明 Nginx 仍在写入。
• Modify 时间持续更新，说明当前文件仍活跃。
• 如果业务有 request id，优先用 request id 精确 grep，不要只按时间范围粗略判断。

也可以每 5 秒观察文件大小：

watch -n 5 'stat -c "size=%s mtime=%y file=%n" /var/log/nginx/access.log'

2. 查看 Filebeat 最近日志

journalctl -u filebeat -n 200 --no-pager

重点查这些关键词：

journalctl -u filebeat --since "30 min ago" --no-pager | egrep -i \
'error|timeout|backoff|harvester|registrar|publish|pipeline|connection|bulk|429|503'

常见线索含义：

• Failed to publish events：输出端发送失败。
• retryer: send unwait signal：发送失败后进入重试。
• Harvester started：Filebeat 开始读取某个文件。
• File is inactive：文件因 inactive 策略被关闭。
• Non-zero metrics in the last 30s：周期性指标，可用于看读取和发送是否还在增长。

3. 打开 Filebeat 内部指标日志

Filebeat 默认会周期性打印部分监控指标。也可以在配置中明确开启：

logging.level: info
logging.metrics.enabled: true
logging.metrics.period: 30s

然后观察日志中的关键字段：

journalctl -u filebeat --since "10 min ago" --no-pager | grep 'Non-zero metrics'

需要重点看：

• filebeat.events.added：采集到的事件数。
• libbeat.pipeline.events.published：进入发送管道的事件数。
• libbeat.output.events.acked：下游确认的事件数。
• libbeat.output.events.failed：发送失败数。
• registrar.states.update：registry 状态更新数。

如果 added 在增长，但 acked 不增长，问题大概率在输出端或网络链路。如果 added 本身不增长，要回到 input、harvester、文件路径和日志轮转继续查。

检查 registry 状态

Filebeat 通过 registry 记录文件 inode、路径和 offset。不同版本路径略有差异，常见位置如下：

ls -lh /var/lib/filebeat/registry/filebeat/
ls -lh /var/lib/filebeat/registry/

Filebeat 7.x/8.x 常见 registry 是 json 或 log 文件。可以先确认是否频繁更新：

stat /var/lib/filebeat/registry/filebeat/log.json

如果 registry 长时间不更新，但 Nginx 日志持续写入，说明 Filebeat 可能没有继续推进 offset，或 registrar 被阻塞。

查看当前 access.log 的 inode：

ls -li /var/log/nginx/access.log

再查 registry 中是否有对应路径：

grep -n '/var/log/nginx/access.log' /var/lib/filebeat/registry/filebeat/log.json | tail

关键判断点：

• inode 是否对应当前活跃文件。
• offset 是否接近当前文件大小。
• 同一路径是否存在多条状态。
• 轮转后的旧文件是否仍被长时间保留。

如果当前文件 size 已经很大，但 registry offset 明显落后，说明 Filebeat 读取速度跟不上或被输出端反压拖住。

排查日志轮转问题

Nginx 常见 logrotate 配置在：

cat /etc/logrotate.d/nginx

如果看到 copytruncate，需要特别小心：

copytruncate

copytruncate 的行为是复制当前日志文件后清空原文件。它不需要通知 Nginx 重新打开日志，但高并发写入时可能在复制和截断之间丢失少量日志，也可能让采集器面对同一 inode 的 size 回退。

更推荐的方式是轮转后通知 Nginx reopen：

/var/log/nginx/*.log {
    daily
    rotate 14
    missingok
    notifempty
    compress
    delaycompress
    sharedscripts
    postrotate
        [ -s /run/nginx.pid ] && kill -USR1 $(cat /run/nginx.pid)
    endscript
}

kill -USR1 会让 Nginx 重新打开日志文件。这样新日志写入新 inode，Filebeat 可以更稳定地完成旧文件收尾和新文件采集。

手动验证 Nginx reopen：

old_inode=$(ls -li /var/log/nginx/access.log | awk '{print $1}')
kill -USR1 $(cat /run/nginx.pid)
sleep 2
new_inode=$(ls -li /var/log/nginx/access.log | awk '{print $1}')
echo "old=$old_inode new=$new_inode"

如果只是发送 USR1，没有实际发生轮转，inode 不一定变化。真正验证时应结合 logrotate dry run 或在测试环境执行完整轮转流程。

检查 Filebeat input 配置

一个更稳妥的 Nginx access log input 示例：

filebeat.inputs:
  - type: filestream
    id: nginx-access
    enabled: true
    paths:
      - /var/log/nginx/access.log
      - /var/log/nginx/access.log.*
    exclude_files: ['\.gz$']
    prospector.scanner.check_interval: 10s
    close_inactive: 5m
    ignore_older: 72h
    clean_inactive: 96h

参数解释：

• id：filestream input 必须保持稳定，随意修改可能导致重复采集。
• paths：只覆盖需要采集的 Nginx access 文件，不要写成 /var/log/**/*.log 这种过宽路径。
• exclude_files：排除压缩文件，避免采集 .gz。
• close_inactive：文件超过一段时间无新增内容后关闭句柄。
• ignore_older：忽略过旧文件，必须大于 close_inactive。
• clean_inactive：清理 registry 状态，必须大于 ignore_older + scanner.check_interval，否则可能重复采集。

如果仍在使用旧版 log input，可以迁移到 filestream，但不要直接在生产上同时启用两个 input 采同一路径。迁移前先在测试机验证 registry 行为，避免重复写入日志平台。

检查输出端反压

以 Logstash 输出为例：

output.logstash:
  hosts: ["10.0.12.21:5044", "10.0.12.22:5044"]
  loadbalance: true
  worker: 2
  bulk_max_size: 2048
  timeout: 30s

排查命令：

ss -antp | grep ':5044'

重点看：

• ESTAB 是否存在，确认连接已建立。
• Send-Q 是否持续很高，可能表示对端读取慢或网络拥塞。
• 连接是否频繁进入 SYN-SENT、TIME-WAIT、CLOSE-WAIT。

如果下游是 Elasticsearch，可重点观察 bulk 错误：

journalctl -u filebeat --since "30 min ago" --no-pager | egrep -i 'bulk|429|too many requests|timeout|503'

429 通常表示 Elasticsearch 写入压力过大。此时不能只在 Filebeat 侧加大 bulk，应该同时检查 ES ingest、磁盘水位、索引副本、refresh interval 和 JVM 压力。

定位示例

某次问题中，Nginx 日志持续写入：

stat -c "size=%s mtime=%y" /var/log/nginx/access.log

5 分钟内 size 从 1.2GB 增长到 1.5GB。但 Filebeat 指标显示：

filebeat.events.added=180000
libbeat.pipeline.events.published=180000
libbeat.output.events.acked=12000
libbeat.output.events.failed=3500

这说明 Filebeat 已经读到日志并放入发送管道，但下游确认很慢。继续查看连接：

ss -antp | grep ':5044'

发现到其中一台 Logstash 的连接 Send-Q 长期较高。Logstash 机器上再看服务日志，发现 pipeline worker 被一个复杂 grok 规则拖慢，CPU 长期 100%。最终处理方式是：

1. 临时摘掉异常 Logstash 节点，只保留健康节点。
2. 简化 grok 规则，把 Nginx 日志格式改为 JSON，减少正则解析成本。
3. Filebeat 开启多 Logstash 节点负载均衡。
4. 为 Logstash pipeline 增加队列和处理线程，并补充延迟监控。

修复方案

1. 规范 Nginx 日志格式

如果条件允许，建议 Nginx 直接输出 JSON，减少 Logstash grok 压力：

log_format main_json escape=json
  '{'
  '"time":"$time_iso8601",'
  '"remote_addr":"$remote_addr",'
  '"request_method":"$request_method",'
  '"uri":"$uri",'
  '"status":$status,'
  '"body_bytes_sent":$body_bytes_sent,'
  '"request_time":$request_time,'
  '"upstream_response_time":"$upstream_response_time",'
  '"http_host":"$host",'
  '"request_id":"$request_id"'
  '}';

access_log /var/log/nginx/access.log main_json;

JSON 日志的好处是字段边界明确，解析失败率更低，也更容易按 request_id、status、request_time 做查询和告警。

2. 调整 Filebeat 队列

在日志量较大的机器上，可以适当增大内存队列：

queue.mem:
  events: 8192
  flush.min_events: 2048
  flush.timeout: 5s

注意：队列变大只能提升短时缓冲能力，不能解决下游长期消费能力不足。如果下游持续慢，队列最终还是会满。

3. 固化 logrotate 策略

避免 copytruncate，使用 postrotate 通知 Nginx reopen。上线前执行配置检查：

logrotate -d /etc/logrotate.d/nginx
nginx -t

logrotate -d 是 debug 模式，不会真正执行轮转，适合先检查规则是否匹配预期文件。

4. 避免重复采集

检查 Filebeat 所有配置文件：

grep -R "/var/log/nginx/access" /etc/filebeat/

如果同一路径出现在多个 input 中，可能造成重复写入或 registry 状态混乱。保留一个明确的 input，并给它稳定的 id。

预防措施

1. 为日志链路加延迟监控：对比 Nginx 日志时间和日志平台入库时间。
2. 监控 Filebeat acked、failed、active harvesters、output write error。
3. Logstash 或 Elasticsearch 至少保留一个可用容量余量，不要长期满负载运行。
4. Nginx 日志尽量使用 JSON 格式，降低解析复杂度。
5. logrotate 禁用 copytruncate，使用 USR1 reopen。
6. Filebeat input 路径保持收敛，排除压缩文件和临时文件。
7. 变更 Filebeat id、registry、input 类型前，先评估是否会重复采集。

总结

Filebeat 采集 Nginx 日志延迟时，核心不是先重启服务，而是把链路拆成三段看：Nginx 是否写入、Filebeat 是否读取、下游是否确认。stat、journalctl、Filebeat metrics、registry、ss 这几类信息组合起来，基本可以判断是源文件问题、采集状态问题还是输出端反压。

生产环境建议优先做好三件事：Nginx 输出 JSON 日志、logrotate 使用 reopen 而不是 copytruncate、为 Filebeat 和下游日志组件建立延迟与失败率监控。这样即使日志量突增或下游短暂抖动，也能快速定位问题并避免日志断点扩大。