RT-Thread-RT-Thread 应用笔记 - 不正确使用LOG也会引发hard faultRT-Thread问答社区

RT-Thread 应用笔记 - 不正确使用LOG也会引发hard fault

发布于 2020-11-28 10:31:06 浏览：2228 订阅该版

[tocm]

[RT-Thread 入门学习笔记 - 目录](https://club.rt-thread.org/ask/article/3420.html)

[RT-Thread 应用笔记 - 不正确使用LOG也会引发hard fault](https://club.rt-thread.org/ask/article/2329.html)

[RT-Thread 应用笔记 - RTC Alarm 组件的使用](https://club.rt-thread.org/ask/article/2312.html)

[RT-Thread 应用笔记 - freemodbus RTU RS485 从机](https://club.rt-thread.org/ask/article/2346.html)

[RT-Thread 应用笔记 - freemodbus RTU RS485 主机](https://club.rt-thread.org/ask/article/2353.html)

[RT-Thread 应用笔记 - libmodbus RTU RS485 从机](https://club.rt-thread.org/ask/article/2378.html)

[RT-Thread 应用笔记 - libmodbus RTU RS485 主机](https://club.rt-thread.org/ask/article/2382.html)

[RT-Thread 应用笔记 - STM32 CAN 通信双机](https://club.rt-thread.org/ask/article/2385.html)

## 前言

* 最近在调试RT-Thread的代码时，使用了 **LOG_D** 这样的基于串口输出的调试方式进行调试信息或错误信息的打印。

* 调试的LOG输出，在代码发布时，不需要逐行的注释掉，只需要更改DBG_LEVEL，可以【一键关闭所有LOG，或LOG分级过滤输出】，大大提高调试效率。

* 大部分的代码是调试出来的，LOG是比较实用的调试方法之一。

## DEBUG LOG开启的方式如下：

```c
#define DBG_ENABLE
#define DBG_SECTION_NAME    "main"
#define DBG_LEVEL           DBG_LOG
#include <rtdbg.h>
```

## DEBUG LOG 的使用方法如下：
```c
void dump_system_clk(void)
{
    LOG_D("%s:SysClockFreq=%d, HCLKFreq=%d,PCLK1Freq=%d,PCLK2Freq=%d\n",
            __func__,
            HAL_RCC_GetSysClockFreq(),
            HAL_RCC_GetHCLKFreq(),
            HAL_RCC_GetPCLK1Freq(),
            HAL_RCC_GetPCLK2Freq()
    );
}
 
MSH_CMD_EXPORT(dump_system_clk, dump system clock);
```

## 问题描述

* 为了快速定位，在调试的时候，一般会把函数名与行号都打印出来，__func__, __line__等。

* 但是如果打印时，前面的打印格式：如%s：%d,%d,%d，与后面的参数，没有一一对应好，就会引发各种【奇怪】问题！

* 问题轻点的：打印的数据不对，甚至有乱码出现。

* 严重的：产生了断言与hardfault。

* 如果前期没有规范LOG输出，后期规范了，但忘记一一测试LOG的输出，某个参数巨多的LOG输出，需要额外注意下。

* 如果LOG_E这样的，一般不会进入触发，但特殊条件触发了，出现了由于打印引发的【hard fault】。

* 如果你根本分不清除是代码引起的，还是LOG输出引起的，调试起来很头疼

* 我的问题是：**关闭LOG后，测试没问题，开启LOG后，高概率会hardfault**

* 【排雷】过程中，发现自己在LOG_D时，多了个%s，或者少了个__func__，就出现了【hardfault】。

* 经过反复的确认代码，发现没有更多的异常，最终确认这个问题的根因：LOG打印时，少了参数，并且这个LOG打印，是在极端情况下才会打印！

* 所以代码编写后，需要细心，还要大面积的【覆盖】测试与验证

## Bad Code 示例

* 参数多了，可能遗漏__func__，多加了%d，等等，需要认真对待。

* 例子：以下为漏了__func__：
 
```c
void dump_system_clk(void)
{
    LOG_D("%s:SysClockFreq=%d, HCLKFreq=%d,PCLK1Freq=%d,PCLK2Freq=%d\n",
            HAL_RCC_GetSysClockFreq(),
            HAL_RCC_GetHCLKFreq(),
            HAL_RCC_GetPCLK1Freq(),
            HAL_RCC_GetPCLK2Freq()
    );
}
```

执行MSH cmd命令后：

```c
msh >dump_system_clk
[D/main] psr: 0x01000000
r00: 0x04c4b400
r01: 0x04c4b400
r02: 0x04c4b400
r03: 0x20003ed4
r04: 0x2000161c
r05: 0x00000000
r06: 0x2000171b
r07: 0xffffffff
r08: 0x2000161c
r09: 0xffffffff
r10: 0xdeadbeef
r11: 0xdeadbeef
r12: 0x00000001
 lr: 0x0800f0cf
 pc: 0x0800dd32
hard fault on thread: tshell
 
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
emq_pms   28  suspend 0x0000007c 0x00000800    08%   0x0000002c 000
tshell    20  running 0x00000084 0x00001000    07%   0x0000000a 000
serial    25  suspend 0x00000088 0x00000400    13%   0x00000007 000
tidle0    31  ready   0x00000050 0x00000800    05%   0x0000000a 000
main      10  suspend 0x0000009c 0x00000800    41%   0x0000000c 000
bus fault:
SCB_CFSR_BFSR:0x82 PRECISERR SCB->BFAR:04C4B400
 
```
* 修复的方法：补充上__func__即可

* LOG_D、 LOG_I、LOG_E等调试信息输出，是用来定位程序问题的，本身不能成为问题。

## 小结

* 增强LOG输出时的检查，格式化输出时，参数的数量、格式，都要认真处理好，很长的LOG确认是否可以精简。

* 代码调试中，遇到各种【诡异】的问题，只要细心，总能找到【准确】的解释或【正确】的答案。

* 代码编写要细心，调试要细心，这样才能产出高质量的代码。

* 正确使用LOG_D、 LOG_E等，大大提高程序的移植性、可调试性，能提高调试的效率。