我们需要谨慎操作Cache
WangGaojie Lv4

成都有疫情有半个月了,在家办公的日子总是很枯燥的,很多的工作无法正常开展。今天有时间,我尝试对Ymodem的传输效率进行优化并完善其中的一些细节实现,本来一个简单的优化工作却牵出一个严重的问题,并最终折腾了一天才解决。这是一个并不典型的内存溢出问题,这种溢出的方式在以前的工作中完全没有遇到过。记录今天排查问题的过程以提醒自己,不严谨的Cache操作会导致内存溢出。

今天一开始在修改并测试Ymodem相关的一些功能,主要是优化了内部数据封装逻辑,并改善数据传输速度。测试发现向单片机发送文件,速度有较大的改善。为了确认数据传输的正确性,使用Ymodem将单片机内的文件读取出来。

惊!发送和接收到的文件数据不一致。

查!🧐

更换多个文件后测试发现,问题能够稳定复现,且每次从单片机内读取出的文件数据都不一样。是Ymodem在单片机内的发送有问题还是接收有问题呢?我决定使用系统内的FTP文件服务来协助排查,通过FTP能够非常方便的上传和下载文件。

惊!😱

通过FTP上传和下载的文件依旧存在问题。通过两种文件传输方式,每次文件都能稳定的传输,传输过程中没有出现任何问题,连Ymodem都没有发出NAK的消息,而且文件大小也没有问题,就唯独内容乱码,我是根据7zip的CRC校验来确认的。这就把问题牵扯到Ymodem功能以外的地方了,很显然该问题不是Ymodem直接导致的。

到这里我认为这个问题比较严重了,这个工程代码中文件系统相关的代码一直运行都比较稳定。

开始排查问题!

我首先构造了一个内容清晰的文本文件abc.txt,约1700字节。使用FTP先上传到系统中,通过串口的命令行,使用指令查看文件内容,cat abc.txt。发现偶尔存在几行文本的乱码。但是更严重的是我发现连续发送cat abc.txt系统就崩溃了,最后一次的数据也没有显示出来。

我到这里就基本上确认文件系统存在问题,且这个问题大概率是和文件传输不一致相关的问题。有了这个更容易复现的bug,我决定先从这里入手,相信这个问题很快就能解决。

但实际上我真的低估这个问题了,我几乎花了一天的时间来排查这个问题,最终仅仅依靠一行代码解决。这充分诠释了一个真理,高端的BUG往往只需要最朴素的方式进行处理。

下面我回顾一下我是如何一步一步排查问题的。

问题的入口点肯定是cat指令,通过分析代码,定位到如下的逻辑:

1
2
3
4
5
6
7
8
9
10
11
12
13
uint8_t tmp[4];
file_h = vfopen(path, "r");
if(file_h){
while(1){
len = vfread(file_h, tmp, 4);
if(len > 0){
output(tmp, len);
}else{
break;
}
}
vfclose(file_h);
}

这段代码逻辑非常简单,打开文件,以4字节长度的方式依次读取数据并将它显示出来,直到全部数据读取完成。

看到这里并没有什么好的想法,我决定打开调试器仿真。仿真起来后,发现问题点好像不是很稳定,偶尔会进入到hardfault,有时会陷入死循环。

通过检查hardfault的触发原因,应该是访问了不该访问的地址,这个地址并没有什么意义,但是检查触发时的PC指针,基本能够定位到malloc模块中。

进一步来看,前面说的还会进入死循环,这个循环也是在malloc模块中,死循环的原因是堆内存的空闲链表中出现了异常的值,导致链表出现问题。具体来说时malloc在分配内存时需要进行链表的操作,查询链表时无法正常触发结束条件导致进入了死循环。

将问题定位到这里已经废了很大劲了,但是依然没有办法确定导致问题的原因。

通过malloc的问题点进行栈回溯,确认是文件系统在申请内存,终于和文件系统关联上了。到此问题依然很迷茫,因为内存导致的问题通常不会花费我那么多时间。

这个内存破坏分子到底是谁呢???

我开始尝试打开内存的分配日志,保守起见,我先使用一种简单点的日志模型,它不会破坏现有的内存分配结构。

通过日志我基本确认了出问题点前后所发送的事情,也就是在file_h = vfopen(path, “r”);会触发两次内存申请的操作。在多次执行cat abc.txt时,可能是前面内存分配的数据结构出现严重问题,导致后面分配内存就会出错。

我开始怀疑是栈溢出导致内存链表出现问题,但是通过内存的分配日志,逐渐将这个想法排除,因为所有的任务栈都不在这段内存附近。

逐渐陷入僵局,居然连内存出现破坏的点都没有捕获到!

我决定使用更高级的内存日志来分析问题,但这可能会导致问题不复现,因为这种内存日志分析方法会在用户申请的内存前后额外再申请一部分空间,用来检测内存边界上是否出现破坏。我一开始担心内存布局出现变化会导致问题不复现,但是测试后发现这种方法是可行的,我终于定位到内存破坏的点了。也就是vfopen返回的文件句柄,这是一个动态申请的内存,大小为4184字节。通过内存日志分析,该段内存在释放时检查发现内存末尾出现数据溢出的情况。

通过添加多个内存检查点,基本确认了内存破坏的代码段,也就是在vfread函数中,但是我任然不是很确定。毕竟这是一个多任务的系统。

我决定使用内存断点来排查问题,通常内存断点都是能够很轻松的解决这类内存溢出的问题,在内存溢出位置设置监视断点,很容易查到是什么代码在修改内存数据。但是这次内存断点并没有帮我解决问题,内存断点看起来并没有起作用。我没有在这里纠缠太久,我不想去查内存断点为什么没有生效。因为今天大部分时间都在盯着这个问题,精神也有点儿恍惚了。

为什么读取文件数据会将句柄外的数据破坏了呢?我发现句柄结构体中末尾是一个4096字节的数据缓存,是在读取数据时导致内存溢出吗?

我检查了许久文件系统中文件读取相关的代码,并没有可疑的地方。

我开始尝试在存储介质上寻找原因,存储介质是一块8M的flash,spi总线访问。

前面都没有提到这个存储介质,因为我能够确认这个存储介质是完好的,它能够稳定的存储数据,并可靠的读取出来。

我通过日志分析从falsh读取数据时将数据填充到那些地址空间下。flash读取出的数据并没有填充到那个被破坏的地址下,这也就排除了DMA的问题。

本来到此我决定放过存储介质上的驱动代码,但是我还是做了一些尝试。我在flash驱动的读取函数入口处先检查一遍那个内存边界是否破坏,在出口再检查一遍内存是否破坏。

喜!🎉🎉🎉

居然问题就在这个驱动函数中。通过逐行分析,最终确认问题点。

flash读取函数大致是这样的:

  • 1.构造数据读取请求;
  • 2.发送数据读取请求;
  • 3.通过DMA将数据直接传输到内存中;
  • 4.将该段内存相对应的Cache清除;

就是第4个代码存在问题,在存在Cache的系统中,使用DMA传输数据后,为了后面CPU从物理地址中取得有效数据,需要将Cache中的数据清除掉,这是非常必要且正常的逻辑(除非内存不具备Cache特性)。

但是这里忽略了一个点,清除Cache的操作并不是想清除那段内存就清除那段内存,它是需要字节对齐的,32字节对齐,在这个系统中Cache的操作接口不是原生的CMSIS接口,而是包装过的,它为了保证数据操作可靠,它会自动对齐到32字节的边界上,首尾均是这样。如果操作的内存地址不是32字节对齐时,会导致在清除Cache时错误的将期望内存外的数据都清除掉了,而这部分数据可能还没有及时的写入到物理内存中。这类似与一种数据溢出的效果,但是又与一般的内存溢出有很大的区别。

内存

最终,我尝试了一个简单的解决办法,在触发DMA数据传输前,将Cache中的数据先同步到物理内存中,这样问题就解决了。只需要一行代码,完美解决了cat指令导致系统出错的问题,连同最开始文件传输数据异常都一并解决了。到这里也解释了为什么内存断点为什么没有生效,由Cache引入的内存问题使用内存断点的排查手段不一定有效。再说一句,通过DMA写入的内存数据,内存断点也是无法捕获的。

这个问题以前没有暴露出来肯能是因为以前的那个内存地址正好是32字节对齐的。检查GIT提交记录,该问题已经暴露很长时间了。

通过这个问题,反应了滥用SCB_InvalidateDCache_by_Addr()接口导致数据溢出的问题。后面需要再次排查系统中其它Cache操作,看看是否存在类似问题。