问题背景
- 单板类型:自研板;
- 软件版本:openUBMC 25.12;
- 涉及功能:升级,告警,NanFlash;
- 触发条件:裁剪了devmon组件出包升级;
- 业务表现:预期无任何告警,实际上环境产生0x1A000043告警。
问题复现步骤
- manifest.yaml裁剪了devmon组件;
- 重新构建出包;
- 升级后,间隔一定时间后查看当前告警信息;
关键日志信息
web页面告警信息:
查看framework日志:
journal日志如下:
定位过程
查看Flash每天的写入量;可以看到每天的写入量超过3GB,如此大的写入量应该会影响BMC的运行性能,也会缩短BMC Flash的寿命
确认大量写入的进程;使用/proc/*/io中的write_bytes查找写入最多的10个进程,脚本如下: 脚本结果如下: 可以看到2367进程的写入量达到18GB、1273的写入量也达到了10.6GB: 通过进程号接着定位到两个进程分别对应framework和systemd-journal;
systemd-journal大量写入信息查询; 可以看到打开的文件主要是记录journal日志,直接使用journalctl -f查看: 从日志中可知devmon一直在崩溃重启,且重启次数已达到27万次;
framework大量写入socket信息查询; 从日志截图可以看到主要是写入多个sqlite3的数据库; 查看framework日志: 可以看到只是per_poweroff.db一天备份了几次,不会有太大的写入量;
通过sqlite查看dbinfo:使用sqlite3的.dbinfo查看数据库的相关信息,使用的脚本如下: 最终结果如下: 可以看到/data/trust/persistence/per_poweroff.db被修改了106915次,/opt/bmc/pram/persistence.local/maca.db被修改了348329次,这应该就是framework进程大量写入的主要原因;尝试修复devmon反复重启问题后,写入数据量从每天3GB下降至0.7GB:
问题原因
前面看到devmon重启了27万次,这和maca.db的修改次数35万次是大致吻合的!且devmon反复重启问题修复后,写入数据量明显下降,因此可以确定根本原因是devmon组件反复重启和maca.db的频繁更新导致的.
解决方案
新增systemd服务journal_export用于导出journalctl内存日志,同时限制systemd服务日志条数,调整限流记录路径;代码修改后,重新按照脚本,将裁剪了devmem的升级包升级到环境,按照脚本跑出结果,查看是否日志等信息确认BMC NandFlash是否依然存在大量写入的情况;代码修改如下PR链接.