机器崩溃后游标文件变成一串 0,事件流悄悄停了一天
1740 字约 6 分钟
摘要论坛的 QQ 机器人靠一个事件流同步数据,游标写在一个状态文件里。电脑崩溃重启后,这个文件只剩 16 个空字节,读取出错让后台任务悄悄退出,日志里什么都没有,整整一天后才发现。
我做的论坛有一个 QQ 机器人插件,它通过一个事件流和论坛保持同步。论坛里发生了新帖子、抽奖开奖、得到金徽章、新成员激活,都会作为事件推过来,机器人收到后更新自己的向量索引,往群里发开奖结果和祝贺。为了重启后能接着读,它把读到的位置记在一个状态文件里,叫游标,每收到一个事件就写一次。
这个机制平时没有任何存在感,直到有一天我问助手,“猜你想问”这个功能上线以来触发得怎么样。
触发得太少了
助手翻了翻记录,上线以来只触发了两次。它又一条条检查今天本该推荐的提问,发现有一条最该被推荐的,论坛里明明有一个相似度 0.738 的帖子,比实际推出去的两个都高,却没有被找到。
于是它去查向量索引,里面只有 259 个帖子,可论坛上已经有 1212 个了。历史收录进来的 950 个左右的帖子,一个也不在索引里。
向量索引是靠事件流更新的,所以真正的问题不是这个功能本身,而是更新索引的那条链路坏了。
事件流在前一晚就停了
继续往下追,事件流从前一晚 21:45 起就没有再收到过事件。时间对得上,21:41 前后我电脑上的 Windows 崩溃过,机器人所在的程序在 21:45 重启。
重启之后,插件去读那个游标文件,发现里面只有 16 个空字节,也就是 16 个 NUL,一个有效的字符都没有。
读取游标的那一行代码,当时没有放在错误处理里。解析失败的异常一路往上抛,事件流这个后台任务就这样退出了。更糟的是,任务退出后,它的任务对象还留在内存里,没有任何人去等待它的结果,所以日志里一个字也没有。
为什么崩溃后文件会变成一串 0这类现象通常是因为,程序已经请求了写入,系统先把文件的长度记录更新了,真正的数据却还留在内存缓冲区里没有落到磁盘。这时机器突然崩溃,重启后文件的长度是对的,内容却是还没来得及写进去的空白。
要避免它,写完之后要主动要求系统把数据刷到磁盘(fsync),而不是默认它会及时落盘。
事件流停了,不只是索引不再更新。通过它传递的开奖结果、金徽章祝贺、新成员的签名同步,也都一起停了。这段时间碰巧没有人开奖或得到金徽章,所以没有人察觉。我是靠一个无关的问题,顺藤摸瓜才找到它。
把游标改回去,又冲掉了一批帖子
线上的修复起初很简单。把游标文件改成崩溃前最后一个事件的编号,重载插件,让它把积压的事件重新处理一遍。助手事先核对过,这段时间没有金徽章和开奖,重新处理积压事件时不会往群里发任何消息。
处理完后,事件流追上了,索引从 259 个帖子变成了 1004 个,还更新了 77 个被编辑过的主楼。
但重载这一下,又暴露出第三个问题。崩溃之前已经收进索引的约 230 个帖子,被冲掉了。
原因是索引文件要等自动收录跑第一批时才会读进内存。在那之前,如果事件流先收到了新帖子,就往一个空的索引里添加,保存的时候,把磁盘上原有的所有帖子都覆盖掉了。猜你想问也有类似的问题,在那之前它是对着空索引在找。
这约 230 个帖子没法从现有文件里补回来,只能等修好的代码部署时,先删掉线上的索引文件,让它从论坛整个重建。
三个对应的修复
这次一共暴露了三个问题,各自对应一个提交。
- 状态文件先刷到盘上再换上。 凡是整个重写的状态文件,一共八处,原来就是先写临时文件再改名,缺的是改名之前的 fsync,现在补上了。需要一行行追加的待处理队列,每追加一行也 fsync 一次。这样崩溃时,要么是旧的完整内容,要么是新的完整内容,不会出现半截。
- 后台任务出错退出时记日志。 以前它悄悄消失,现在会留下一行错误。事件流停一天而没人发现,主要就是因为这一点。
- 索引第一次使用前先从文件读进来。 不再等自动收录的第一批,事件流往里加帖子之前,先保证已有的内容在内存里。这条加了测试。
通俗比喻:改稿子时先写在草稿纸上直接在原稿上涂改,如果中途停电,原稿就成了一团墨。更稳妥的做法是,把新稿写在一张新纸上,确认字迹都干了(fsync),再把它换到原稿的位置。
这样不管什么时候停电,桌上要么是完整的旧稿,要么是完整的新稿。
这件事留下的几个习惯
回头看,这次故障没有一个环节是复杂的,但它们连在一起,让一个机器崩溃变成了一天的静默失败。我把它们归成三条。
写状态文件,要想到“写了”不等于“落盘了”,整个重写用临时文件加刷盘再替换,追加用刷盘。后台任务,退出本身就是应该被记录的事件,哪怕它的退出方式是抛出异常。有持久化的缓存或索引,在接受增量更新之前,先把已有的内容读进来。
另外,这件事是靠“功能效果不好”这个间接信号发现的,并不是被什么监控发现的。事件流停止这种事,原本就应该有一个直接的信号,比如几分钟没有收到任何事件就报警。目前的修复只保证任务退出时会在日志里留下一行,并不会主动通知我,这一点还可以再补。
适用边界我没有复现崩溃时文件变成空字节的过程,只是根据现象和提交说明,判断是没有刷盘导致的。不同的操作系统和文件系统,在崩溃后的表现并不相同,这里的机器是 Windows。