从 traceback 一直做到埋点
目标
能够在三分钟内从 traceback 中定位原因,不仅完成修复,还能加入有助于下一次调查的观测手段。
为什么重要
阅读 traceback 要从下往上。最底下一行给出异常类型和原因,它正上方是实际出错的代码行,更上方则是到达该处的调用路径。而且异常消息通常包含导致问题的实际值,用这个值搜索原始数据,往往几秒内就能找出罪魁祸首所在的行。
另一个重点是,traceback 并非写到标准输出,而是写到标准错误。客户的批处理作业经常因为 cron 配置中遗漏 2>&1,连续几个月都没有在任何地方留下失败原因。听到“日志里什么都没有”时,请先检查这一点。
最后,如果修完就结束,同样的问题下周还会重演。只需增加一行记录被跳过数据的代码,就能把下一次调查从 30 分钟缩短到 1 分钟。这就是加入观测手段,也是处理无法稳定复现问题的标准方法。
步骤
- 创建
/root/trace,并将/opt/app/report.py复制到/root/trace/report.py。 - 将失败运行的输出连同标准错误一起保存到
/root/trace/traceback.txt。 - 仅将所发生异常的名称写入
/root/trace/error_type.txt。 - 将第一个导致程序停止的行的
id值写入/root/trace/bad_row.txt。 - 按规范修改
/root/trace/report.py,使其以退出码 0 结束。 - 将修复后脚本的输出保存到
/root/trace/out.txt。输出应为rows=18 total=130400。 - 加入观测代码,将被跳过的行逐行记录到
/root/trace/skipped.log。 - 针对
/opt/data/orders_api.csv运行同一脚本,并将输出保存到/root/trace/out2.txt。
参考
python3 report.py > /root/trace/traceback.txt 2>&1- 可以使用
grep -n abc /opt/data/orders.csv在原始数据中查找异常消息里的值。 report.py通过参数接收文件路径。第 8 步的形式为python3 report.py /opt/data/orders_api.csv。- 最整洁的方式是将诊断输出写到标准错误,再通过重定向保存到文件。例如:
python3 report.py > out.txt 2> skipped.log - 第 8 步的文件中没有需要跳过的行。请把第 8 步运行产生的诊断输出发送到其他路径或丢弃,以免覆盖
skipped.log。 - 常见错误 1:第 2 步遗漏
2>&1,结果得到空文件。 - 常见错误 2:第 7 步只把被跳过的行输出到屏幕。必须保存到文件,后续人员才能查看。
创建工作副本
创建 /root/trace,并将 /opt/app/report.py 复制到 /root/trace/report.py。
创建 /root/trace,并将 /opt/app/report.py 复制到其中。
保留失败原文
将失败运行的输出连同标准错误一起保存到 /root/trace/traceback.txt。
traceback 不会写到标准输出,而会写到标准错误。重定向中需要包含 2>&1。
记录异常类型
仅将所发生异常的名称写入 /root/trace/error_type.txt。
traceback 最后一行中冒号前面的部分就是异常名称。只写名称。
定位首个失败行
将第一个导致程序停止的行的 id 值写入 /root/trace/bad_row.txt。
异常消息中包含实际值。请在原始 CSV 中找到包含该值的行,并确定其 id。
使程序以退出码 0 结束
按规范修改 /root/trace/report.py,使其以退出码 0 结束。
docstring 中写明了有效行的三个条件。不符合条件时应跳过该行并继续处理。
保存汇总结果
将修复后脚本的输出保存到 /root/trace/out.txt。输出应为 rows=18 total=130400。
将修复后脚本的原始输出直接重定向到文件。rows= 和 total= 两个值都必须存在。
记录被跳过的行
加入观测代码,将被跳过的行逐行记录到 /root/trace/skipped.log。
此步骤要加入观测手段,以便下次发生同样问题时能在一分钟内完成调查。每个被跳过的行各记录一行。
针对另一份输入运行
针对 /opt/data/orders_api.csv 运行同一脚本,并将输出保存到 /root/trace/out2.txt。
只针对今天的数据生效的修改不算真正的修复。请用 /opt/data/orders_api.csv 运行同一脚本并保存结果。