精选30+云产品，助力企业轻松上云！>>>

起因

于2020年3月1日时发现 kendryte K210 的 micropython 从网络下载大块文件（kmodel）的存储过程中，（大概率）随机出现 illegal instruction 的 crash 现象。

错误现场

关联 ：espcoredump、map、objdump。

错误类型 illegal instruction 指令解析错误，关联常见错误 ESP32 官方文档（五）严重错误

core dump: illegal instruction
Cause 0x0000000000000002, EPC 0xfffffff6666f7c7e
reg[00](zero ) = 0x0000000080301b28, reg[01](ra   ) = 0x7f807c76666f7c7e
reg[02](sp   ) = 0x0000000080300bd8, reg[03](gp   ) = 0x0000000080212188
reg[04](tp   ) = 0x0000000000000000, reg[05](t0   ) = 0x0000000000000019
reg[06](t1   ) = 0x0000000000001000, reg[07](t2   ) = 0x0000000000000009
reg[08](s0/fp) = 0x7d868a877476837c, reg[09](s1   ) = 0x7b6a747c826f8489
reg[10](a0   ) = 0x00000000000002d6, reg[11](a1   ) = 0x0000000080316b0a
reg[12](a2   ) = 0x00000000000002d6, reg[13](a3   ) = 0x0000000000000087
reg[14](a4   ) = 0x0000000000000284, reg[15](a5   ) = 0x000000000000055a
reg[16](a6   ) = 0x0000000000000001, reg[17](a7   ) = 0x0000000000c65d40
reg[18](s2   ) = 0x7a727b8b8a737f85, reg[19](s3   ) = 0x8474817c7a7c8a8a
reg[20](s4   ) = 0x96ff84827a7a8382, reg[21](s5   ) = 0x6d80718190608983
reg[22](s6   ) = 0x768b7f8471807976, reg[23](s7   ) = 0x83797e8e7b77818c
reg[24](s8   ) = 0x866c7d8a7e7c7a7b, reg[25](s9   ) = 0x8a847d8e78877281
reg[26](s10  ) = 0x868580848d7b7a7a, reg[27](s11  ) = 0x64887781888a877a
reg[28](t3   ) = 0x0000000000000000, reg[29](t4   ) = 0x0000000000000007
reg[30](t5   ) = 0x0000000080301b28, reg[31](t6   ) = 0x0ccccccccccccccc
freg[00](ft0 ) = 0x0000000000000000(), freg[00]() = 0x0000000080114910()
freg[02](ft2 ) = 0x0000000000000000(), freg[00]() = 0x0000000080114920()
freg[04](ft4 ) = 0x0000000000000000(), freg[00]() = 0x0000000080114930()
freg[06](ft6 ) = 0x0000000000000000(), freg[00]() = 0x0000000080114940()
freg[08](fs0 ) = 0x0000000000000000(), freg[00]() = 0x0000000080114968()
freg[10](fa0 ) = 0x0000000041200000(), freg[00]() = 0x0000000080114998()
freg[12](fa2 ) = 0x0000000000000000(), freg[00]() = 0x00000000801149c0()
freg[14](fa4 ) = 0x3733312c447a0000(), freg[-1610612736]() = 0x00000000801149d0()
freg[16](fa6 ) = 0x8faa245a00000000(), freg[-2147483648]() = 0x00000000801149e0()
freg[18](fs2 ) = 0x8e80717300000000(), freg[536870912]() = 0x0000000080114a08()
freg[20](fs4 ) = 0x8685808400000000(), freg[536870912]() = 0x0000000080114a18()
freg[22](fs6 ) = 0x866c7d8a00000000(), freg[-1073741824]() = 0x0000000080114a28()
freg[24](fs8 ) = 0x768b7f8400000000(), freg[-536870912]() = 0x0000000080114a38()
freg[26](fs10) = 0x96ff848200000000(), freg[-1610612736]() = 0x0000000080114a48()
freg[28](ft8 ) = 0x7a727b8b00000000(), freg[-536870912]() = 0x0000000080114a70()
freg[30](ft10) = 0x7d868a8700000000(), freg[-1610612736]() = 0x0000000080114a80()
W (173762547693) SYSCALL: sys_exit called by core 0 with 0x539

相关资料

寄存器基础

[MIPS 获得内核中当前进程的栈回溯信息]（https://www.cnblogs.com/sky-heaven/p/10386600.html）

cause : 触发原因

epc : exception program counter 异常程序计数器 产生异常时的PC指针的值

ra : return address 子程序的返回地址

regs : register 寄存器情况

fregs : float 寄存器情况（看 crt.s 代码应该是 SFREG Sign flag 标记寄存器 共 32 个）

sp : sp寄存器，用来跟踪程序执行过程。

关联 linux kernel panic 分析方法 根据epc 定位linux kernel panic 位置。

关于内核报错 “Unable to handle kernel paging request at virtual address” 的问题, 绝大多数都是由于程序使用了不可用的指针而引起的, 定位这类问题的办法很简单,也希望我的描述足够简单实用.

样本分析

由于这个芯片目前比较新，也没有现成工具，只好手工分析了。

注意编译后得到的 maixpy.txt 和 我创建的 error.txt ，起因在这里下载文件过程中，对 socket 进行 readinto 过程中 crash 了。

我先初步确认了表层代码的运行情况 python 最后停在了如下代码位置，也就是从这里以后的 C 代码之间出了问题。

# ------------------------------------------------------------------------

def ReadContentInto(self, buf, nbytes=None) :
if nbytes is None :
nbytes = len(buf)
if nbytes > 0 :
try :
print('self._socket.readinto(buf, nbytes)') # 这里。
x = self._socket.readinto(buf, nbytes)
if x < nbytes :
self.Close()
return x
except :
self.Close()
return 0

# ------------------------------------------------------------------------

这种指令错误多少也都是一些指针操作出了问题，琢磨着可能是 AT 没有应答或应答错误就超时处理了，对于这种情况的时候，仔细检查代码逻辑的 IF 判断，大致先定位到附近。

也就是 usocket 附近，这时候注意到，它走的是 python 标准库的 stream 流输入和输出。（需要懂一点 micropython 的架构）

现在存在三个方向可以继续分析

• 继续定位 core dump 的位置
• 继续打 log 定位实时栈数据。
• 有时候这种问题会被静态分析出来，如一些不被注意的警告可能隐含缺陷代码。

阶段二

目前已经知道是 usocket 模块出了问题，也知道是 readinto 出了问题，同时也知道是底层 C 代码出了问题。

那么单看汇编码来看整体的函数符号情况，可以知道整个 maxipy 的代码中只有 stream_readinto 和 mp_machine_spi_write_readinto 两种 readinto ，但另一边已经知道 socket 用的是 stream_readinto ，因此重点看 stream_readinto 的源码。

并且将 000000008002a0c2 <stream_readinto>: 的地址拿到 core dump 里各种长短匹配都没有，那么说明，stream_readinto 并不是报错现场，它只是我们上层代码的重点，因此继续挖掘。

静态分析的时候，可能会丢失动态链接的函数变量，因为发现 stream_readinto 汇编码中显式调用的 stream_readinto 的代码只有内部，则意味着还要继续分析其他跳转的函数。

如 mp_stream_rw ，所以我们回到代码，根据 core dump 的函数地址偏移来看错误是，暂时找不到头绪了，说明宕机的函数地址并非在这里面。

阶段三

如果 core dump 无法看到最末端的错误现场，按这个异常数据来看，应该是跑飞了，但某些寄存器还是会存在一些遗留的。

但我此时试着从代码逻辑上去理解，缩小范围判断问题，因为是从网络上下载数据到 flash 中，那么我先把 flash 移除，此时发现，问题实际上出在 flash 上。

那么前面的 socket 实际上就误导了我们，说明它是两者之间相互影响了，那么判断变成，可能是因为 fs 的 cache 导致了宕机爆 core dump 。

那么我继续看 core dump 的寄存器情况，这期间，我已经确认了，若是不将数据写入 flash 则没有问题，那么再结合最近的一些地址判断现场。

这时从 core dump 追过去，才发现发生错误的现场不是最初想的那样，所以一开始还是应该仔细核对 core dump 的值才是。

但此时观察到相关的代码都是 Sync 和 Write 有关的操作，看来应该是发现问题了。

那么如何修复呢？

等我继续更新？

如果不能抓到函数现场，那我只能写完整的 Flash 单元测试来试图触发这个事件了。

更新 2020年3月3日。

阶段四

经过 Flash 测试后，确认并非 flash 问题。

现在开始正向捕获错误，根据 core dump 的情况来看，地址已经乱了，说明跑飞的同时还经过了许多动态函数链。

截至目前，追踪函数链为

stream_readinto
-> mp_stream_read_exactly
-> mp_stream_rw
-> io_func == socket_stream_read typedef mp_uint_t (*io_func_t)(mp_obj_t obj, void *buf, mp_uint_t size, int errcode);
mp_uint_t (
recv)(struct _mod_network_socket_obj_t *socket, byte *buf, mp_uint_t len, int _errno);
-> self->nic_type->recv(self, (byte
)buf, size, errcode);
-> esp8285_socket_recv

MP_THREAD_GIL_ENTER

mp_uint_t out_sz = io_func(stream, buf, size, errcode);

out_sz 468

socket_stream_read

MP_THREAD_GIL_EXIT

self->nic_type->recv 80044422
core dump: illegal instruction

明日继续 这会必须用 printk 了。

更新 2020年3月5日

uart_stream->read(nic->uart_obj,temp_buff + temp_buff_len,1,&errcode);

又一次新增了 machine_uart_read ，见鬼，怎么还不到头。

但是运气很好的是函数栈终于退出来了，终于不闪退了，但是问题也来了。

• 如果是串口接收缓冲区问题，则调大，并没有符合预期，不是。

• 如果是函数栈不够大，测试了一下，调大 ld 文件的栈空间，发现不是。

最后判断一个情况，当把 printk 导入后，有时候发现函数执行后结束了也没有回到调用函数位置，那么应该是函数内部的指针误操作，破坏了函数栈内容，导致函数执行完成后回不去，所以 epc 和 ra 的地址才会如此混乱。

那么，要么继续检查 machine_uart_read 的指针操作，要么回到上层检查可能的指针误操作。

幸运的是已经发现大致存在的错误了。

还没办法根除问题，想来还是得拿静态分析工具来预处理一下函数。

继续，更新 2020年3月5日。

继续，2020年3月6日 02点39分 更新

经过了一天的排查和修复，姑且不会再爆 core dump 了，现在是看到 AT 8285 的驱动代码出了问题。

问题应该是 int recvPkg(esp8285_objnic,char out_buff, uint32_t out_buff_len, uint32_t data_len, uint32_t timeout, char coming_mux_id, bool* peer_closed, bool first_time_recv) 这个关键函数的设计有缺陷

在经过了一天的测试后发现几个现象，大致确认了问题的发生原因。

• esp_recv 函数 调用 recvPkg 后无法回到调用处。
• 数据量大的时候才会发生这个问题。

在面对大量数据传输的时候，在栈上动态申请的数组地址越界访问，这也就导致了 ra 地址不正常，导致无法回到上层函数。

我本来应该早点怀疑的，看到 ra 寄存器地址混乱的时候，我就该想象函数栈被破坏了，然后无法回到调用的函数位置，函数栈能被破坏，肯定是函数内部申请的数组指针被误操作破坏了，所以才会出现混乱的数据

然后看图的时候，发现有很多处访问地址不检查的代码，我心都快凉了。

整个循环都没有注意保护缓冲区的访问，直接就进行 temp_buff[temp_buff_len] 的操作，而实际上应该先 temp_buff_len < sizeof(temp_buff) 锁定边界后才操作好吧。

最后先把栈上申请的缓冲区移到堆了，也就是 static 处理，至少越界不会破坏函数栈了，所以这时候没有再出现 core dump 了，先这样处理了，然后之后再做逻辑代码的修复。

更新 2020年3月6日

估计还是得修复一下代码的细节，理一下思路再改代码。

今天继续修复，检查发现，缓存区确实存在操作不当的长度，先不做边界检查，了解逻辑代码后。

简单扩大一下缓冲区（前面通信调试时发现存在大于 1024 的情况），现在又出现新的错误，但这次总算是正常了，core dump 的 misaligned load 错误，这次数据没有混乱了，很快就定位问题了。

看一下代码的实现应该是做了双缓冲，第一层先解开数据，第二层则是合并第一层解开的数据，从而供应给上层 micropython 的接口。

阶段五

已经修复大部分问题。

修复方案：

自上次修复缓冲区的变量，防止溢出后就解决了，但 flash 的下载超时的问题仍然没解决。

现在做一下问题的总结，有如下几种验证和现象。

• 最早已经在 115200 上确认下载 380KB 的模型文件可以正常获取，说明了下载流程一般情况下是正常的，但之后开始将波特率调高到 460800 或 576000 两者。
• 接着测试 flash 读写到 2M 都没有问题，写满了启动不了 micropython 是其他问题，确定了 flash 是可以正常使用。
• 如果不将 AT esp8285 下载接收的数据写入 flash ，则会完整的下载完成，确定了下载流程是正常的。
• 如果一边下载一边写入，则此时速度会下降，可以很明显的看到下载过程的速度慢了下来，此时要么超时失败，要么极小概率卡死什么反应也没有，陷入了等待数据，但又无法判断是否超时来返回 micropython 上层。

进行下载的代码在这部分

那么我们理一下思路，当从 115200 升上来后，AT 固件给回的数据会加快，这意味着串口的接收缓冲区应该要大一些，否则 AT 被动接收的数据就会溢出，导致下载过程中在缓慢写入 Flash 的时候，将会无视或溢出这部分 AT 给回的数据，也就造成之后的超时，因为当你不去接收数据的时候，AT 仍然在吐出数据，如果吐完了停下来，那么这时候再等待数据的程序自然是等不到了，所以超时退出。

所以为了验证这个假设，取消了写入 flash 操作，然后确实能够完整获取下载的数据，表示有一半如我所想，也就是下载数据的这个过程暂时不可控，没有使用协议主动去要指定长度的数据，那么现在进一步验证，假设使用 flash 写入很慢导致超时，那么使用 sdcard 呢，结果换了 sdcard 写入速度更快，可以明显的看出返回变快，此时下载过程完整了，那么此时说明在这种不可控的下载过程中，写入文件的速度应快过下载的速度，很难想象 flash 的写入速度会低于 46kb/s ，也不知道发生了什么。

最后在下载数据传输过程中，存在小概率传输错误，这个在最后有提及，可能是串口传输的原因也可能是网络传输的原因。

很奇怪的现象还有一点，如果上面的思考是正确的，那么当我试图通过延时来模拟 file.write 写入过程带来的延时 5s 带来的效果应该是不再接收到数据，但实际上还是接收到了，要么是串口缓冲区过大可以存放（类似 DMA 缓冲），要么是两者之间，存在互斥操作，暂时还不得为知。

进一步关注以下几处功能或变量。

read_buf_len

配置后会重新生成更大的缓冲区

配置串口的接收缓冲区，对应 esp8285 的 recvPkg 接收用，如果过小，也没有配置 DMA 缓冲区的情况下，就会直接溢出 overflow ，代码还没对这种情况做处理

socket recvbuf

esp8285 的 recvPkg 接收过程中对 AT 数据的解析处理以及合并，假设 TCP 默认的数据包最大 1580 ，所以我设置为 2048 ，也许不一定有效，但调试的时候发现有时候数据长度的索引会上到 1400+ ，在来不及处理的情况下，至少有 2k 做缓冲。

（其中的代码未做边界检查）

socket timeout

micropython 在 socket 层次的超时机制，因为在执行 socket.readinto 的时候会进入临界区，此时是无法通过 Ctrl + C 退出来的，设计 socket 非阻塞很重要，绝对不能没有嘻嘻。

如果下载的时候设置为 0 表示立即返回的话，就无法得到数据了，也许用 poll 模型会有反应？还不确定，所以至少设置为 3 ~ 5 吧。

flash speed

只分了 2M 的 flash ，但写入速度很慢，也不知道是什么原因，也许 micropyton 的解析执行也在占用整片 flash 吧，而不单是从 flash 上分出来的 micropython VFS 在用。

sdcard speed

我用的是淘宝十块钱的 256M 和 1G ROM 的辣鸡内存卡，相比 flash 自然是空间大，且比 flash 的写入快，回头测一下速度。

spiffs cache

编译出来的固件与平时的区别就是在 python 的 file.write 的时候就会直接调用 flash 将数据写入磁盘，而不是等到 close 才写入，这个和 C 库 stdio 保持一致。

阶段六

文件下载过程中存在几处出错，之后要修复。

暂时通过 AT+UART_DEF=576000,8,1,2,1 添加串口的偶校验后，确定了下载文件是完整了的，没有出现错误，也不知道会不会还有其他问题，暂时再观望，多测试过后再确认吧。

尾声

其实大部分问题都算是解决了，而且对整个流程也算是理了一遍，之后再出什么问题，就再解决了就好，之后应该不会怎么更新这个问题了吧 2020年3月9日。

最开始压根不是这个问题的鸭！