syslog 日志观测
课程(6 节,按顺序学)
① 日志不是一份完整的记录
入门 · 约 8 分钟
本课目标:先把一个直觉纠正过来:日志里没有,不等于没发生过。
一条日志要活着走完四道关
★★★ 出事翻日志、日志里没有就当没发生 —— 这个直觉是错的。一条日志要过四道关:
· 等级过滤:比设备的 logging level 更不严重的,压根不发;
· 设备限速:超过 rate-limit 的被静默合并或丢掉;
· 设备负载:CPU 打满时日志进程排不上队;
· 传输:UDP 没有重传,收集器满了也接不下。
★★★★ 要命的是这四道关都和故障相关
出事的时候:日志更多(限速更容易触发)、CPU 更高(发不出去)、链路更挤(UDP 更容易丢)。
★★★★ 所以这个模块的那句话是准确的 ——日志最可靠的时候,是你不需要它的时候。
★★ 这不是「syslog 做得不好」,是无连接、无状态、尽力而为这个设计的必然结果。
★ 先在基线上看清「对的」长什么样
这个场景里没有限速、链路不挤、时钟都对过。真实发生几次,收集器里就有几条。
★ 后面五节课每一节都是拿它做对照的 —— 先记住这张图。
实验重点
- 日志里没有 ≠ 没发生过
- 一条日志要过四道关:等级、限速、负载、传输
- ★★★ 这四道关都和故障相关,所以日志在最需要它时最不可靠
② ★★★ 丢掉的恰好是唯一有用的那条
进阶 · 约 10 分钟
本课目标:看清 UDP 在日志风暴下怎么丢,以及为什么丢的偏偏是要紧的那一条。
场景:一条链路 flap 引发风暴
一条链路在抖,于是 180 多条日志涌出来。而真正的根因是核心路由器的一条电源模块告警 —— 它只有一条,而且和风暴同一秒发生(电源问题正是 flap 的成因,它们不可能错开)。
★★★★ 收集器的容量是每秒全局共享的
★★★ 不是每个事件各有一份额度 —— 同一秒里先到先占(这就是 UDP 接收缓冲的行为)。
★★★★ 于是风暴的 120 条先把名额占满,那条电源告警一个名额都没有。它不是「也丢了几条」,它是被完全抹掉了。
★★ 而两头都没有记录:设备以为发出去了,收集器不知道有这一条。
★★ 换 TCP 能解决吗
能拿到重传,但代价是反压:收集器慢的时候设备的发送缓冲会满,然后要么阻塞产生日志的进程、要么还是丢。
★★★ 所以 TCP 只是把「丢」变成了「丢得晚一点、而且可能拖累设备」——不是免费的可靠。真正的对策是在设备侧限制风暴源、并给关键等级单独一条通路。
实验重点
- ★★★★ 收集器容量是每秒全局共享、先到先占
- 日志风暴会把唯一有用的那条挤掉
- TCP 的代价是反压,不是免费的可靠
③ ★★★★ 只有一条,不等于只发生一次
排障 · 约 8 分钟
本课目标:认识 syslog 最骗人的一种丢法 —— 它不是没到,是被合并掉了。
设备为了自保会限速
logging rate-limit 是必要的:没有它,一次风暴能把设备的 CPU 拖垮。
★★ 但超出的部分是静默丢弃的 —— 设备不会在日志里写一句「我刚丢了 4 条」。
★★★★ 为什么这种丢法最骗人
★★★★ 因为收集器里有这条日志。没人会觉得日志丢了 ——但「有一条」被读成了「发生了一次」。
链路抖了 5 次,值班的人看到「抖了一下」,于是判断成偶发、不处理。而 5 次抖动意味着一个正在恶化的硬件问题。
★★★ 对策:别用日志条数判断次数
★★★ 去读设备接口自己的计数器(flap counter、input errors)——那些不受 syslog 限速影响。
★★ 这条纪律可以推广:凡是要数次数的,都不要以日志条数为依据。日志适合回答「发生过什么」,不适合回答「发生了几次」。
实验重点
- ★★★★ 限速是静默的:收集器里有,但条数不等于次数
- 数次数要读设备自己的计数器
- 日志适合回答「发生过什么」,不适合回答「几次」
④ ★★★★ 排出来的顺序可能是错的
排障 · 约 10 分钟
本课目标:搞清为什么按时间戳排序会把你带到错的那一头。
排障的第��个动作几乎总是排序
把几台设备的日志按时间排在一起,从最早那条开始查 ——因为最早发生的那件事通常就是根因。
��★★★ 但 syslog 的时间戳是设备自己的时钟打的,不是收集器打的。
★★★★ 时钟差得比事件间隔大,顺序就翻了
这个场景里:D1 第 10 秒断(因),D2 第 12 秒受影响(果)。而 D1 的时钟快 4 秒 —— 于是日志上写的是 14 和 12。
★★★★ 按时间戳排,果排在了因前面。你会从 D2 开始查,而 D2 确实是正常的 —— 查过去发现「看起来没问题」,然后怀疑是偶发。
★★★ 这一课接着时间同步那一课
NTP / PTP 那一课讲的是对时为什么难(软件打戳的抖动、排队、路径不对称)。
★★★★ 这一课讲的是对不上时的后果 —— 而这个后果恰好落在排障最依赖的那个动作上。
★★ 顺带说:日志没有任何办法发现自己的时间戳是错的。它照样按格式写出来,看起来完全正常。
★★★ 对策:不要只按日志时间戳建立因果
交叉验证三样东西:
· 设备接口自己的计数器;
· 收集器的接收时间(那个是同一个时钟打的,所以可比);
· 路由协议自己的收敛事件。
实验重点
- ★★★★ 时间戳是设备打的,时钟差了顺序就翻
- syslog 的可用性依赖 NTP
- 收集器的接收时间是同一个时钟打的,可比
⑤ 等级、格式,和两个常见的坑
入门 · 约 9 分钟
本课目标:把 severity 和报文格式这两件事一次说清。
★★★ severity 数字越小越严重
0 = emerg,7 = debug。★★ 这一点本身就反直觉 ——很多人第一次写告警规则写成了 severity > 4,结果只收到 debug。
★★★ 所以 logging level 4 的意思是「只发 0~4」。
★★★★ 更要紧的:那个数字是厂商标的
★★★★ 各家标法不一致。同一件事在一家设备上是 warning(4)、在另一家是 notice(5)。
★★★ 而告警规则按数字写 —— 于是同一条规则在两家设备上一个报一个不报。这个场景里那条「冗余电源切到备路」就被标成了 notice(5),被 level 4 挡掉了。
★★ 而且它在设备上也查不到:没发出去,发送计数里同样没有它。
★★ 格式:RFC 3164 的时间戳缺三样东西
· 没有年份 → 跨年时排序错乱;
· 没有时区 → 跨地域的设备日志无法直接比较;
· 精度只到秒 → 同一秒内多件事的先后直接丢掉。
★★ 换 RFC 5424 或 JSON 这三样都有了。★★★ 但注意丢包问题一点没变 —— 格式解决的是可读性,不是可靠性。
实验重点
- ★★★ severity 数字越小越严重,而且是厂商标的
- level 配高了,事件在设备上也查不到
- ★★★ 格式解决可读性,不解决可靠性
⑥ ★★★ 日志通道不能依赖被监控的对象
排障 · 约 9 分钟
本课目标:这一节把 syslog 接回一条更大的原则上。
场景:收集器和设备共用一条上行
为了省一条线,日志收集器接在同一台接入交换机下面。平时一切正常。
★★★★ 那条链路一断:你既看不到设备,也看不到它为什么没了 ——而那一刻正是你最需要日志的时候。
★★★★ 这是同一条原则的又一个实例
★★★★ 「三张网」那一课的原则是:管理通道不能依赖被管理的对象。
★★★ 这一节只是把「管理通道」换成了「日志通道」——所有「远程查不出来、只能去现场」的情况,共同原因都是观测通道和故障对象共用了一段路。
★★ 落地怎么做
· 收集器走带外管理网,不跟业务上行;
· 关键设备配两个 syslog 目标,分别在不同故障域;
· 设备本地留一份缓冲(logging buffered)—— 链路恢复后还能上去捞,这是唯一能补救「断网期间」的办法;
· ★★★ 给收集器自己加监控:它不再收到日志这件事,本身要能告警。
★★ 收个尾:四种观测手段的分工
★★ 这一类的四个模块各看一样东西:
· 流量(NetFlow / IPFIX)—— 谁在跟谁说话;
· 指标(SNMP / gNMI)—— 数值随时间怎么变;
· 路由(BMP)—— 路由为什么不在我表里;
· 事件(syslog)—— 发生过什么。
★★★ 四样都会在故障时退化,而退化方式各不相同 ——这也是为什么不能只依赖一样。
实验重点
- ★★★★ 观测通道不能和故障对象共用一段路
- 关键设备配两个 syslog 目标 + 本地缓冲
- ★★★ 收集器不再收到日志,本身就该告警