记录一次hard fault on handler的解决过程

当我把ota_init模块注释掉的时候，发现hardfualt没了，这…这怎么可能呢，这个模块我之前测试过的呀，跑了两天都是正常的。
然后我发现，设备每次出现hardfault的时候，系统的tick都是553600ms左右,如下所示，换算成分钟也就是9分钟这样，9分钟，9分钟，9分钟，9分钟的时候还没有出现hardfualt，我的ota模块，是每10分钟去服务器拉取一次做版本检测，这么说，是这里的问题了？
  | /
- RT -     Thread Operating System
/ |      4.1.0 build Jan  6 2023 17:42:12
2006 - 2022 Copyright by RT-Thread team
lwIP-2.1.2 initialized!
[4416] I/sal.skt: Socket Abstraction Layer initialize success.
[4574] I/rfid_config: reader.id : 4403061904001
[4579] I/rfid_config: reader.beep : 0
[4584] I/rfid_config: report.interval : 60
[4588] I/rfid_config: reader.power : 10
[4594] D/ota_module: ota_flag == ERASE_IAP_FLAG
msh />[4715] D/rfid_module: rfid_report tag
[65630] D/rfid_module: rfid_report tag
[126649] D/rfid_module: rfid_report tag
[187613] D/rfid_module: rfid_report tag
[248612] D/rfid_module: rfid_report tag
[309611] D/rfid_module: rfid_report tag
[370595] D/rfid_module: rfid_report tag
[430629] D/rfid_module: rfid_report tag
[491631] D/rfid_module: rfid_report tag
[552598] D/rfid_module: rfid_report tag
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tcp_ser   10  suspend 0x000001d8 0x00000800    25%   0x0000000a 000
udp_ser   10  suspend 0x00000228 0x00000400    53%   0x0000000a 000
rf_led    10  suspend 0x00000080 0x00000100    50%   0x0000000a 000
rf_send   10  suspend 0x000000a0 0x00000800    16%   0x00000003 000
rf_read   10  suspend 0x000000c0 0x00000200    37%   0x00000004 000
  | /
- RT -     Thread Operating System
/ |      4.1.0 build Jan  6 2023 17:42:12
2006 - 2022 Copyright by RT-Thread team
lwIP-2.1.2 initialized!
[4416] I/sal.skt: Socket Abstraction Layer initialize success.
[4574] I/rfid_config: reader.id : 4403061904001
[4579] I/rfid_config: reader.beep : 0
[4584] I/rfid_config: report.interval : 60
[4588] I/rfid_config: reader.power : 10
[4594] D/ota_module: ota_flag == ERASE_IAP_FLAG
msh />[4716] D/rfid_module: rfid_report tag
[65642] D/rfid_module: rfid_report tag
[126601] D/rfid_module: rfid_report tag
[151604] D/rfid_module: rfid_report tag
[187619] D/rfid_module: rfid_report tag
[248596] D/rfid_module: rfid_report tag
[309616] D/rfid_module: rfid_report tag
[370621] D/rfid_module: rfid_report tag
[431620] D/rfid_module: rfid_report tag
[492616] D/rfid_module: rfid_report tag
[553600] D/rfid_module: rfid_report tag
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
rf_led    10  suspend 0x00000080 0x00000100    50%   0x0000000a 000
rf_send   10  suspend 0x000000a0 0x00000800    16%   0x00000009 000
rf_read   10  suspend 0x000000c0 0x00000200    39%   0x00000003 000
于是我把OTA的时间改成每10秒一次，果然10秒以后，就出现了hardfault
峰回路转
那么问题很明确了，就是这个OTA模块的问题，于是我在OTA模块里面打断点排查，发现在socket里面，发送UDP数据包的时候，就出现了hardfault，如下所示

现象。线索又断了….怎么办呢？我左思右想，问题就出现在这，到底是什么原因？
柳暗花明
udp发送，udp发送，会不会是这个线程爆栈了，于是我瞟了一眼这个线程的栈大小，哎哟我去，512字节。
thread = rt_thread_create("ota", ota_thread, RT_NULL, 512, 10, 10);
那我就改一下吧，改1024试试，果然，正常了….松了一口气…
原来这个线程的栈是1024字节的，后面我使用ps命令看了这个线程栈的利用率还很低，于是我改成了512字节，这也就是说，为什么我之前测试了2天这个模块都是正常的，现在却不行了。因为我使用ps命令的时候，那会才运行了几分钟，看到的线程栈利用率是没有调用udp发送函数的，也就是说，那会看到的栈利用率，是不准的，那时候我去减小它，肯定就容易出问题了
当系统正常以后，我再次去ps，发现线程实际的栈利用率是92%，如下所示（前面的ps是没有调用udp函数之前的，后面的ps是调用udp函数以后的，这时候的栈我设置的大小是1024），也就是说，512字节，肯定是不够的，甚至1024都快爆了，还得增大。
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
ota       10  suspend 0x0000007c 0x00000400    32%   0x00000005 000
sys_led   10  suspend 0x0000007c 0x00000100    48%   0x0000000a 000
tshell    20  running 0x00000094 0x00001000    13%   0x00000003 000
tcpip     10  suspend 0x000000d0 0x00002000    07%   0x00000014 000
etx       12  suspend 0x00000094 0x00000400    14%   0x00000010 000
erx       12  suspend 0x00000094 0x00000400    56%   0x00000010 000
sys work  23  suspend 0x00000060 0x00000800    53%   0x0000000a 000
tidle0    31  ready   0x00000048 0x00000100    45%   0x00000009 000
timer      4  suspend 0x00000064 0x00000200    24%   0x00000009 000
main      10  suspend 0x00000084 0x00000800    33%   0x0000000e 000
msh />
msh />
msh />
msh />
msh />[14598] D/udp_module: send success
[14628] D/ota_module: ota_flag == ERASE_IAP_FLAG
ps
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
ota       10  suspend 0x0000007c 0x00000400    92%   0x00000001 000
sys_led   10  suspend 0x0000007c 0x00000100    48%   0x0000000a 000
tshell    20  running 0x0000020c 0x00001000    13%   0x00000007 000
tcpip     10  suspend 0x000000d0 0x00002000    07%   0x00000014 000
etx       12  suspend 0x00000094 0x00000400    14%   0x00000010 000
erx       12  suspend 0x00000094 0x00000400    56%   0x00000010 000
sys work  23  suspend 0x00000060 0x00000800    53%   0x0000000a 000
tidle0    31  ready   0x00000058 0x00000100    45%   0x00000018 000
timer      4  suspend 0x00000064 0x00000200    24%   0x00000009 000
main      10  suspend 0x00000084 0x00000800    33%   0x0000000e 000
总结
使用了网络的线程，一定要将线程栈开大一点，512字节肯定是不够的，最少1536字节以上
使用ps命令打印出来的线程栈最大使用率，是在代码运行过一段时间以后，才准的，比如我的代码中，udp发送数据是在系统启动10分钟以后才运行到，所以我在前面几分钟的时候使用的ps命令看，ota线程是没有爆栈的，只有在运行到这个网络发送数据的代码，这个栈才会溢出。因此如果有一些代码不是立即运行的，在调试的时候，可以把这个时间提前，尽量让系统上电以后，把所有的代码都能跑一遍，这样对于一些跑了一段时间才出现栈溢出的问题，比较容易复现，容易复现也就容易解决。
或者可以在调试代码的时候，可以把线程栈设置大一些，让代码先能够正常跑起来，然后跑个几天，再去ps一下看看栈的最大利用率，几天以后所有的代码、流程应该基本上都跑过一遍了，这时候的栈利用率才是比较准的，这时候才去优化这个栈大小，会比较合适。
在遇到hardfault的时候，不要怕，用工具不行，我们就手动一个一个模块去排查，把问题的范围缩小，尽管耗费的时间会长一点，但是总会定位到问题的。
最后我想，如果rt-thread可以在栈溢出的时候，自动检测并且定位出来就好了，比如我这个ota的线程栈溢出了，rt-thread就告诉我，xxxx线程栈溢出啦，你得开辟大一点，就好了。



原作者：BruceTan