RT-Thread-Ulog使用硬件RTC时间戳信号量锁死【分析问题+复现+临时解决方案】RT-Thread问答社区

Ulog使用硬件RTC时间戳信号量锁死【分析问题+复现+临时解决方案】

发布于 2022-03-14 02:27:42 浏览：2426 订阅该版

[tocm]

- [一、现象描述](#一、现象描述)

- [二、对比分析](#二、对比分析)

- [三、临时解决方案](#三、临时解决方案)

- [四、场景复现](#四、场景复现)
  - [（1）锁死环境复现](#（1）锁死环境复现)
  - [（2）对比环境复现](#（2）对比环境复现)
  
- [五、Ulog及RTC其它问题的吐槽](#五、Ulog及RTC其它问题的吐槽)
  - [（1）锁死环境复现](#（1）锁死环境复现)
  - [（2）STM32的LSE和LSI不能同时开启](#（2）STM32的LSE和LSI不能同时开启)

# 一、现象描述

在使能硬件RTC，初始化阶段未设置时间的情况下【测试环境为4.1.0版本Env创建的Keil工程】
如果开启Ulog时间戳，打印日志导致线程锁死

根本原因为打印时间戳日志的过程中由于未设置时间，导致再次调用日志打印，在以下函数中挂起线程

```c
/* drv_rtc.c 文件 */
if (HAL_RTCEx_BKUPRead(&RTC_Handler, RTC_BKP_DR1) != BKUP_REG_DATA)
{
 LOG_I("RTC hasn't been configured, please use <date> command to config.");

/* 其他代码省略 */
}
```
在LOG_I()中再次运行LOG_I()导致output_lock上锁两次
output_lock上锁本质为接收信号量ulog.output_locker
ulog初始化的信号量为1
第一次上锁信号量减一
再次调用LOG_I导致第二次上锁
第一次的锁还没有解开
第二次上锁导致锁死现象，直接挂起线程
Ulog无法输出任何信息

# 二、对比分析

由于之前使用RT-Studio的4.0.3版本可以正常输出提示

所以将4.1.0与4.0.3对比分析并排查问题

硬件平台：STM32F407 正点原子探索者开发板

以下表格是在进入**主线程之前为未设置时间**的RTC初始化流程对比

| 版本 | 4.0.3 | 4.1.0 |
|-----|--------|------|
| IDE | Studio | Keil |
|工程类型|基于芯片|bsp|
|RTC初始化流程|1. rt_hw_rtc_init() 2. rt_hw_rtc_register() 3. rt_rtc_config() **打印*RTC hasn't been configured···*** 4. HAL_RTC_Init() 5. 初始化完毕，进入主线程 之后打印日志不会打印 *RTC hasn't been configured*|1. rt_hw_rtc_init() 2. rt_hw_rtc_register() 3. rt_device_register() 4. 进入主线程打印日志**LOG_D** 5. **output_lock() 上锁** 6. gettimeofday() 7. get_timeval() 8. rt_device_open 9. rt_rtc_init() 10. stm32_rtc_init() 11. **再次打印*RTC hasn't been configured···*** 导致死锁|

# 三、临时解决方案

- 方案一：避开初始化未设置时间的提示，增加RTC初始化函数，**在进入主线程之前设置时间**

缺点：如果真的忘记设置时间，导致死锁又要踩坑，花时间排查原因，影响开发进度

- 方案二：保留始化未设置时间的提示，避开第二次上锁，将 **LOG_I** 修改为 **rt_kprintf**

缺点：无论是否开启Ulog，依旧会有提示，其实影响不是很大，甚至在未开启Ulog也会有提示

【前提条件是开启了串口或者其他控制台输出，如果没开启控制台输出不知道会发生什么】

- 方案三：直接将**未设置时间的提示**注释掉，由于不会第二次上锁，所以日志打印正常

缺点：未设置时间不会提示

- 方案四：使用4.0.3版本

- 方案五：Ulog不使用时间戳格式

# 四、场景复现

理论上只要是STM32的单片机都会有这个问题，其他厂家的未测试过

以下测试平台以正点原子的探索者开发板为参考，场景复现大同小异

据说该开发板的启动电路的串口设置为控制台打印会有一些冲突

如果发现不能正常打印最好换一个串口或者使用RTT作为控制台输出

## （1）锁死环境复现

1. 打开 **···\rt-thread\bsp\stm32\stm32f407-atk-explorer**

2. 右键打开Env 输入<kbd>scons --dist</kbd>

3. 打开dist文件夹中新生成的bsp工程

4. 右键打开Env 输入<kbd>menuconfig</kbd>

进入 **RT-Thread Kernel -> Kernel Device Object** 修改可以使用的控制台设备【如：uart1，jlinkRtt】

5. **RT-Thread Comonents -> Device Drivers** <kbd>Using RTC device drivers</kbd>

6. **RT-Thread Comonents -> Utilities** <kbd>Enable ulog</kbd>

7. **log format** -> <kbd>Enbale timestamp format for time</kbd>

8. **Hardware Drivers Config -> On-chip Peripheral Drivers** <kbd>EnableRTC</kbd> <kbd>RTC_USING_LSE</kbd>

9. Esc 然后选择Yes保存配置

10. 打开 ···\board\CubeMX_Config文件夹，配置CubeMX

11. 打开Keil，复制生成的时钟配置，注释掉msp文件的**Error_Handler()**已防止后续编译错误

12. 复制一下内容到 **main.c** 仅供参考

```C
#include <rtthread.h>
#include <rtdevice.h>
#include <board.h>

#define DBG_TAG "main"
#define DBG_LVL DBG_LOG
#include <rtdbg.h>

/* defined the LED0 pin: PF9 */
#define LED0_PIN    GET_PIN(F, 9)

int main(void)
{
    /* set LED0 pin mode to output */
    rt_pin_mode(LED0_PIN, PIN_MODE_OUTPUT);

while (1)
    {
        rt_pin_write(LED0_PIN, PIN_HIGH);
        rt_thread_mdelay(500);
        rt_pin_write(LED0_PIN, PIN_LOW);
        rt_thread_mdelay(500);
        LOG_D("Hello RT-Thread!");
    }
}
```

编译代码并下载到芯片，发现日志打印失败，灯不闪烁，此时 **main线程**已经挂起

## （2）对比环境复现

测试平台为RT-Studio 2.2.1【其实和Studio版本关系不大】

基于芯片创建的RT-Thread工程

本文就不详细说明Studio的配置步骤了

以下图片为Ulog配置

复制上面的main函数，一切运行正常，并有未设置时间的提示

![Ulog.png](https://oss-club.rt-thread.org/uploads/20220314/fbb814fd43b6015386ea97dc50c77abb.png)

# 五、Ulog及RTC其它问题的吐槽

## （1）部分设备注册的日志信息无法打印

主要原因是初始化顺序不可控，使用 **INIT_BOARD_EXPORT(ulog_init);**

**不能保证在设备注册之前初始化**

使初始化阶段部分打印之间 **return**

```C
void ulog_voutput(······)
{
    /* ······ */
    if (!ulog.init_ok)
    {
        return;
    }
    /* ······ */
}
```

例如以下打印在我的测试环境下就是直接 **return**

```C
LOG_I("I2C bus [%s] registered", bus_name);
```

## （2）STM32的LSE和LSI不能同时开启

为什么需要同时开启？

因为**独立看门狗**的时钟源是LSI

![IWDG.png](https://oss-club.rt-thread.org/uploads/20220314/d586fa4eab4501a36c0924708aa5204e.png.webp)

当使用LSE作为RTC的时钟源

如果关闭LSI是否会导致**独立看门狗**工作异常？【实际情况未测试，可能和初始化顺序有关】

具体看以下代码

```C
/* drv_rtc.c */
static rt_err_t stm32_rtc_init(void)
{
    __HAL_RCC_PWR_CLK_ENABLE();

RCC_OscInitTypeDef RCC_OscInitStruct = {0};
#ifdef BSP_RTC_USING_LSI
    RCC_OscInitStruct.OscillatorType = RCC_OSCILLATORTYPE_LSI;
    RCC_OscInitStruct.PLL.PLLState = RCC_PLL_NONE;
    RCC_OscInitStruct.LSEState = RCC_LSE_OFF;
    RCC_OscInitStruct.LSIState = RCC_LSI_ON;
#else
    RCC_OscInitStruct.OscillatorType = RCC_OSCILLATORTYPE_LSE;
    RCC_OscInitStruct.PLL.PLLState = RCC_PLL_NONE;
    RCC_OscInitStruct.LSEState = RCC_LSE_ON;
    RCC_OscInitStruct.LSIState = RCC_LSI_OFF;
#endif
    HAL_RCC_OscConfig(&RCC_OscInitStruct);

if (rt_rtc_config() != RT_EOK)
    {
        LOG_E("rtc init failed.");
        return -RT_ERROR;
    }

return RT_EOK;
}
```