ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

日志跟踪工具ponytail:解决tail -f痛点,支持断点续跟与过滤

日志跟踪工具ponytail:解决tail -f痛点,支持断点续跟与过滤 我们平时排查线上问题很大一部分时间都花在盯日志上。项目跑起来之后日志文件哗哗往上涨你要看最新刷出来的报错总不能用编辑器反复打开关闭那样太折腾了。绝大多数人第一反应是用tail -f盯着看但真到了多文件、多节点、日志疯狂滚动的时候系统自带的工具往往不够顺手。我前阵子花了一晚上写了个叫ponytail的小工具专门解决我就想干净利落地跟踪日志尾部这件事这里把整个设计和落地过程完整复盘一下。1. 从马尾辫说起ponytail 到底要解决什么问题先解释一下这个奇怪的名字。英文里 ponytail 是马尾辫头发扎成一把垂在脑后形态上很像日志文件末尾不断追加的新内容。而 Linux 下查看文件尾部有一个经典命令tail所以 ponytail 就是一个用起来更顺手的日志尾部跟踪工具。1.1 现有工具为什么不够用我知道你肯定想说tail -f已经够用了为什么要重复造轮子这个质疑很合理我自己一开始也是这么想的。但实际用了一段时间之后你会发现几个很具体的问题第一tail -f对多文件支持太简陋。你可以同时跟多个文件但输出全部混在一起没有清晰的文件名前缀也没有颜色区分。日志一多你根本分不清哪行是哪个服务打的。第二崩溃恢复能力约等于零。网络断开、终端退出、进程被杀重新打开终端后只能从头再tail。如果想接着上次的位置继续看原生命令做不到。而实际排查问题时候经常是看一会去改个配置回来还得重新翻半天才能定位到刚才看到哪。第三没有任何过滤和格式化能力。一个服务日志里 INFO 和 ERROR 混在一起你要只想看 ERROR要么grep管道在外面包一层要么就眼睁睁刷屏。想看某个 request_id 关联的所有日志那就更麻烦了。第四对日志轮转的支持比较被动。很多服务用 logrotate 做日志切割文件被重命名或者新文件顶上来tail -f有时候会跟丢。你盯着屏幕发现没输出其实文件已经切走了。这些痛点不大但都踩在盯日志这个高频场景上。ponytail 就是为了解决这些具体问题做的。1.2 我给自己定的需求清单动手之前我先列了需求不至于写着写着跑偏支持同时跟踪多个文件每个文件有独立的前缀标识颜色可区分支持断点续跟记住上次看到的位置下次打开接着看支持正则过滤保留匹配的行或者排除匹配的行支持日志轮转文件被切割后能自动跟随新文件给每行打上时间戳如果原日志本身没有的话依赖尽量少部署简单最好一个脚本文件就能跑这个清单出来的时候我心里已经大概有数了根本不需要 C 或者 Go一个 Python 脚本就能全干完。但一开始我还真不是用 Python 写的第一版是用 Bash 拼的。2. 第一版原型用 Bash 理解 tail 的本质2.1 tail 的实现原理比想象中简单tail命令的核心逻辑其实很朴素打开文件把指针挪到文件末尾往前数 N 行然后输出。tail -f则在输出完末尾 N 行之后继续盯着文件一旦有新内容写入立刻追加输出。实现盯着文件有两条路轮询polling每隔几百毫秒去查一下文件大小有没有变变了就读取新增部分事件驱动event-driven利用操作系统提供的文件系统通知机制Linux 的 inotify、macOS 的 FSEvents等内核告诉你这个文件有变化你再响应第一版原型我走了最简单的轮询路线因为在 Bash 里搞 inotify 太绕了轮询只需要一个while循环加sleep。2.2 原型代码长什么样Bash 版本的 ponytail 大概长这样#!/bin/bash FILE$1 OFFSET0 while true; do SIZE$(stat -c %s $FILE 2/dev/null) if [ -z $SIZE ]; then echo [$FILE] 文件不存在或已被删除 sleep 2 continue fi if [ $SIZE -lt $OFFSET ]; then # 文件变小了说明被截断或轮转从头开始 OFFSET0 fi if [ $SIZE -gt $OFFSET ]; then # 从上次位置开始读到文件末尾 tail -c $((OFFSET 1)) $FILE OFFSET$SIZE fi sleep 1 done用stat获取文件当前字节大小然后用tail -c N从第 N 个字节开始读到文件末尾。每次记录新的偏移量等下次轮询时接着读。如果文件变小了大概率是 logrotate 做了 copytruncate复制后清空原文件那就重置偏移量从头读。这个版本能跑几个核心问题也暴露得非常明显效率很差。每秒钟stat一次文件还行但如果同时跟十几个文件而且有些文件特别大tail -c N每次都要从 N 开始扫描到 EOF日志行很多时 CPU 占用非常难看轮询间隔难取舍。sleep 1意味着日志最多延迟 1 秒显示如果设成sleep 0.1CPU 占用立刻上去没有颜色没有过滤。全部输出糊在一起可读性差tail -c N处理大文件时性能差比如一个 2GB 的日志文件偏移量在 1.8GB 处每次都要从 1.8GB 开始扫描虽然只输出新增部分但扫描本身消耗不小2.3 从 Bash 原型里学到的关键经验Bash 这个原型虽然糙但它帮我理清了 ponytail 最核心的数据模型文件偏移量offset是跟踪日志的第一公民。你想日志跟踪本质上就是一件事记住上次读到哪个字节了然后每次都从那个字节继续往下读。什么颜色高亮、正则过滤、多文件都是在读出新内容之后的附加动作。只要偏移量这一层做扎实了上面盖什么都稳。这个理解非常重要后面所有的设计都围绕这个数据模型展开。比如断点续跟能力本质上就是把偏移量持久化到磁盘上下次启动时加载回来。再比如日志轮转的应对也是基于偏移量和文件 inode 的变化来做判断。3. 重写第二版Python 版本的核心架构与踩坑记录3.1 为什么不用 Bash 继续磨原型跑起来之后我很快就决定用 Python 重写。原因有三一是 Bash 处理文本编码太痛苦。日志文件里常混着 UTF-8 中文和 ANSI 转义符Bash 的字符串按字节处理碰到多字节字符很容易截出乱码。二是 Bash 没有好用的正则库。grep和sed虽然能用但一旦要匹配到某行就变颜色提取某个字段再格式化那就要写一堆管道可读性极差。三是 Python 生态里有非常成熟的日志处理库比如watchdog就是基于 inotify 的跨平台文件监控库而且标准库的os.open、os.lseek、os.read可以直接操作文件描述符做偏移量控制非常顺手。3.2 核心模块怎么组织第二版我按模块拆了三块文件跟踪模块负责维护每个文件的偏移量、inode、当前路径用os.stat获取文件状态用os.lseek和os.read从指定偏移量读取新增内容。过滤与格式化模块负责对读出来的每一行做正则匹配、时间戳添加、颜色渲染、输出前缀处理。状态持久化模块负责把每个文件的跟踪状态主要是偏移量和 inode写入一个 JSON 状态文件实现断点续跟。核心代码不长大致是下面这个思路import os import time import json import re import sys from pathlib import Path class FileTailer: def __init__(self, path, stateNone): self.path Path(path) self.fd None self.offset state.get(offset, 0) if state else 0 self.inode state.get(inode, None) if state else None self._open() def _open(self): self.fd os.open(self.path, os.O_RDONLY) st os.stat(self.fd) self.inode st.st_ino # 如果文件大小已经小于偏移量说明被截断过 if st.st_size self.offset: self.offset 0 os.lseek(self.fd, self.offset, os.SEEK_SET) def read_new_lines(self): new_data os.read(self.fd, 65536) if not new_data: return [] self.offset len(new_data) # 按换行符切分成行保留最后不完整的一段 lines new_data.decode(utf-8, errorsreplace).split(\n) if lines[-1] ! : # 最后一行不完整需要把偏移量回退到最后一个换行之后 incomplete lines.pop() self.offset - len(incomplete.encode(utf-8)) os.lseek(self.fd, self.offset, os.SEEK_SET) return lines[:-1] if lines[-1] else lines这里有一个非常隐蔽的坑需要注意用os.read按固定字节数读的话可能会把一行日志从中间截断。比如一个中文字符占 3 个字节你读了 65536 字节最后几个字节可能只是完整字符的一部分。如果直接转字符串并按换行拆分最后一行就是乱码而且下一轮读取时偏移量就错了。处理方式是把按字节读到的内容解码后按换行符拆开如果最后一行没有换行符结尾说明这是一个不完整行把它暂存起来同时把文件偏移量回退到不完整行开始的位置留到下一轮继续读。这个处理不复杂但不注意的话日志里只要出现多字节字符跟一段时间就全是乱码。3.3 中断恢复把偏移量变成可持久化的状态偏移量持久化这块我直接用了一个 JSON 文件来存结构是这样的{ /var/log/myapp/app.log: { inode: 273482, offset: 188322, last_read: 2024-05-20 14:30:22, color: green }, /var/log/myapp/error.log: { inode: 273489, offset: 221, last_read: 2024-05-20 14:30:22, color: red } }每次读取完一批新行之后立即更新内存中的这段状态并写回 JSON 文件。这样即使进程被 CtrlC 杀掉或者终端断开状态文件里也保存着最后一次成功读取到的位置。下次再运行 ponytail把它作为启动参数传入工具会先检查文件的 inode 是否和状态文件里的一致。如果一致说明还是同一个文件直接从offset位置继续读如果 inode 变了说明文件已经被轮转或者被替换了那么分为两种情况如果新文件比旧文件小说明是典型的 logrotate旧文件被重命名成.log.1新文件从 0 开始写。这时应该从新文件的开头开始读因为日志切割后新文件内容少从 0 开始读几乎没有成本如果新文件比旧文件大说明只是文件被删掉又重新创建比如容器重启后重新写日志文件。这种情况也从头开始读写入状态文件要小心一点不能每读一行就写一次磁盘那样性能太差。我是攒了一批再一次写入一般是每 2 秒或者每次读到超过 4KB 新数据时写一次。极端情况下进程被kill -9最多丢失最近 2 秒的状态也就是重复读一小段日志不会造成严重后果。3.4 颜色高亮与输出格式的细节颜色这块用的是 ANSI 转义序列不是第三方库。核心是一个映射表COLORS { green: \033[32m, red: \033[31m, yellow: \033[33m, blue: \033[34m, magenta: \033[35m, cyan: \033[36m, reset: \033[0m, }给每个文件分配一个颜色输出时在每行最前面加上文件名前缀 时间戳 原始日志内容。比如说14:30:22 [app.log ] INFO 收到请求耗时 12ms 14:30:23 [error.log ] ERROR 数据库连接超时retry 1这里有一个实际体会文件名前缀的宽度最好对齐。多个文件名长短不一的时候不对齐会导致输出列抖动看起来非常乱。我用ljust把文件名部分固定到固定宽度比如 16 个字符不够就补空格超过的直接截断拿前面部分。这样输出一直是整齐的表格感多文件切换时也不容易看花眼。另外如果不是终端而是管道输出比如你ponytail -f log | grep ERROR要把 ANSI 颜色禁用掉否则颜色控制字符会混进管道数据里导致 grep 或者重定向文件里一坨乱码。检测方法很简单sys.stdout.isatty()返回真就是终端假就是管道。3.5 正则过滤器的设计过滤这一块我参考了 grep 的做法提供两个参数--include和--exclude。逻辑是先应用--include没匹配上的行直接丢弃剩下的行再应用--exclude匹配上的行丢弃这个顺序很重要。比如你要看包含 request_idabc123 的 ERROR 行如果用单条正则写容易漏掉一些边界情况。拆成两步之后排查问题时的组合思路清晰得多。ponytail -f /var/log/app.log --include ERROR --include request_idabc123 ponytail -f /var/log/app.log --include request_idabc123 --exclude healthcheck我还加了一个--highlight参数法是把匹配到的关键词用醒目颜色标记出来而不是整行过滤。这在日志行很长的时候特别有用一行 500 个字符里找那个 IP整行高亮不如只看关键词高亮。用正则替换把匹配部分包上颜色转义码就完了但是要注意如果同一行里匹配到多个关键词要用带回调的re.sub给每个匹配项都包上颜色不能只替换第一个。4. 对比测试ponytail 和 tail -f 的差距在哪写完之后我当然要和老牌工具对比一下不然也不好意思说它更好用。4.1 多文件跟踪场景tail -f同时跟踪两个文件输出是这个效果 /var/log/myapp/app.log INFO 收到请求耗时 12ms /var/log/myapp/error.log ERROR 数据库连接超时retry 1 INFO 收到请求耗时 15ms文件切换时用一行分割但这一行不是日志内容混在输出里容易误导脚本。而且没有任何颜色长时间盯着屏幕很容易疲劳。ponytail 的输出是14:30:22 [app.log ] INFO 收到请求耗时 12ms 14:30:23 [error.log ] ERROR 数据库连接超时retry 1 14:30:24 [app.log ] INFO 收到请求耗时 15ms文件名、时间戳、日志内容一行一个颜色区分结构稳定。4.2 断点续跟的实用性tail -f没有断点续跟的概念。我举个例子你正在跟踪一个日志找某个错误用 CtrlC 中断去服务器上改了个配置再回来执行tail -f它默认从文件末尾开始你上次看到的那个错误上下文已经刷过去了只能手动往上翻。ponytail 因为有状态文件重新执行的时候自动从上次位置继续读。我自己的习惯是跟踪 - 发现异常 - 中断 - 改配置 - 重新运行 ponytail - 继续看异常后面的内容。这整个过程非常连贯不用记住看到了哪一行也不用来回翻屏幕。4.3 日志轮转时的表现对比模拟一个 logrotate 场景文件app.log被重命名为app.log.1新app.log从空文件开始写。tail -f跟的是文件描述符它仍然会跟在app.log.1后面直到这个旧文件被删除才算完。这时候你等于是盯着一个已经不再写入的旧日志新日志刷没刷你完全不知道ponytail 每轮循环会重新stat文件路径发现 inode 变了、大小也变了立刻切到新文件从头开始读这是 ponytail 在服务端场景下最能拉开差距的地方。生产环境几乎必有日志轮转你扛着tail -f跟到文件被轮转却不自知的情况我碰到过不止一次。4.4 性能与资源占用量我做了个粗略对比让它跟踪一个每秒写入 2000 行的日志文件观察 CPU 和内存占用工具启动 10 秒后 CPU启动 10 秒后内存备注tail -f0.3%5 MB单文件无额外逻辑ponytail事件驱动0.8%18 MBPython 运行时开销 状态维护ponytail轮询模式6.5%18 MB每秒轮询一次开销明显事件驱动模式用的是 watchdog 库在 Linux 下走 inotify写文件事件触发时才去读取CPU 非常省。轮询模式虽然代码更简单但每秒statlseekread在文件数多时 CPU 会上去。所以最终版本里默认用事件驱动只有在内核不支持 inotify 的环境比如某些老容器才回退到轮询。内存方面Python 启动本身就有基础开销但运行过程中没有累积问题因为每次读 64KB 数据处理完就释放不会把整个日志文件载入内存。这决定了一个上限ponytail 可以跟踪远大于内存的单文件日志只要磁盘能装下。5. 一些容易忽略但很关键的细节5.1 处理 ANSI 转义序列带来的假长度很多程序往日志里写颜色转义码比如有些框架会在 ERROR 级别的日志外包裹红色 ANSI 码。如果你直接拿转义码那部分去做前缀对齐和宽度计算会得到错误的结果。我一开始没注意这个问题出了一个很滑稽的事文件名前缀明明对齐了但因为日志内容里带着 ANSI 码终端计算宽度时把不可见字符也算了进去整个输出错位。解决办法是先剥离日志内容里的 ANSI 转义序列再做宽度计算但输出时保留原始内容。这样终端在渲染时是原始内容而计算对齐宽度时用的是可见字符的数量。5.2 文件编码问题不假设 UTF-8开发机上日志都是 UTF-8但生产环境你什么都可能遇到。有些老服务用 GBK 输出日志有些混合编码。如果你按照 UTF-8 硬解码遇到非法字节会直接抛异常或者用errorsreplace替换成日志就没法看了。ponytail 的处理方式是默认尝试 UTF-8失败时按 GBK再失败就退到latin-1。latin-1是字节映射到 Unicode 的一一对应编码永远不会失败。它不是最准确的解析但至少不会让进程崩掉。实际使用中latin-1应对大部分乱码问题都够用因为你是盯着看人眼对中文上下文的理解能力远强于机器。5.3 为什么状态文件不用 SQLite有人看到断点续跟可能会问为什么不直接用 SQLite 存状态查询起来还方便我的回答是没必要。ponytail 不是高并发写密集的场景它只是每隔几秒写几个整数和字符串JSON 文件足够。SQLite 引入一个二进制库依赖部署时还要考虑版本兼容。对于命令行工具来说零配置文件、零数据库文件、只有一个 JSON 状态的使用体验最舒坦。当然如果你要同时管理几百个文件的跟踪状态JSON 的加载和写入效率会逐渐吃紧到那时候再考虑 SQLite 也完全来得及。5.4 跟远程日志的思路有些人问能不能直接用 ponytail 跟远程服务器上的日志答案是不行至少目前版本不行。远程场景的正确打开方式是在远程服务器上用 ponytail 跟踪把输出通过管道传给本地或者把状态文件同步到本地再读取。但更常用的方案是配合日志采集 Agent比如 Filebeat、Fluentd把日志汇总到中央日志平台然后你在本地用 ponytail 跟踪中央平台吐出的最终日志文件。我在实战中就是这么用的中央日志机上挂着一个汇聚后的merged.log本地再用 ponytail 跟踪它配合--include过滤出我关心的内容比直接在各个节点上翻日志高效得多。5.5 状态文件损坏的兜底JSON 状态文件如果写入一半进程挂了可能导致文件损坏。我加了一个简单的兜底每次写状态时先写临时文件再原子性地重命名覆盖。这样即使崩溃旧的状态文件也完整存在。下次启动加载时如果发现 JSON 解析失败干脆忽略所有历史状态全部从头开始读同时打出一条警告让你知道续跟的位置丢了。这个兜底逻辑不复杂但能避免状态文件损坏导致整个工具起不来的尴尬局面。毕竟排查故障的时候工具起不来比看不到历史日志更让人抓狂。6. 整理一下使用场景和命令示例6.1 基础用法# 跟踪单个文件 ponytail -f /var/log/app/app.log # 跟踪多个文件并自动分配颜色 ponytail -f /var/log/app/app.log -f /var/log/app/error.log -f /var/log/app/access.log # 只看 ERROR同时排除 healthcheck 心跳日志 ponytail -f /var/log/app/app.log --include ERROR --exclude healthcheck # 关键词高亮 ponytail -f /var/log/app/app.log --highlight request_idabc123 --highlight Timeout # 从上次中断的位置继续跟 ponytail -f /var/log/app/app.log --resume6.2 组合用法# 把包含时间戳和文件名前缀的完整输出存到本地文件 ponytail -f /var/log/app/app.log /tmp/ponytail_$(date %Y%m%d_%H%M%S).log # 配合 grep只提取含 IP 地址的行 ponytail -f /var/log/app/app.log --no-color | grep -E [0-9]\.[0-9]\.[0-9]\.[0-9] # 跟踪一段时间后统计错误数 ponytail -f /var/log/app/app.log --no-color --include ERROR | wc -l6.3 不适合 ponytail 的场景也不是所有日志场景都适合用它。下面这几种情况建议用专门的工具不要硬上需要对历史日志做复杂聚合分析比如按时间窗口统计 QPS、按 IP 维度做分组用 ClickHouse 或者 Elasticsearch 那一套更合适实时告警ponytail 只是一个终端工具没有内置告警规则引擎。真要做告警用 Prometheus Alertmanager 或者自建告警服务别拿日志跟踪工具硬凑超大集群的日志检索几千个节点的日志不可能挨个用 ponytail 去跟这场景需要中心化日志平台7. 个人经验总结这个工具从最初 20 行的 Bash 原型到后来 300 多行的 Python 实现给我的最大体会是日志跟踪工具的核心不是读文件而是记住你看到哪了。所有好用、难用、能续跟、能过滤、能防轮转都是围绕这个核心展开的。另外一个体会是工具能做得多顺手取决于你对自己工作流的观察有多细。我做这个工具之前实际上已经忍受了tail -f很久只是一直没有把痛点一条一条列出来。真列出清单之后发现每个痛点其实都不难解决难的是愿意花时间把顺手这个模糊的感受变成清晰的技术需求。如果你也想做一个类似的工具我的建议是从最小闭环开始先实现多文件 偏移量读取 轮询跑通一次完整的跟踪过程再逐步加颜色、过滤、状态持久化。Bash 版本虽然性能不行但作为理解数据模型的原型非常合格比一开始就上 Python watchdog 要少踩很多调试弯路。最后分享一个小技巧如果你经常排查线上问题建议把 ponytail 和一个简单的临时状态目录绑定使用默认把状态文件写到/tmp/ponytail_state/而不是当前目录。这样不管你从哪个目录启动都能利用上一次的状态做断点续跟。我自己用下来的感受是这个功能比颜色高亮更加回不去。你一旦习惯打开终端就能接着上次的位置继续看日志就再也受不了每次从头翻起了。
返回列表