Ulog使用硬件RTC时间戳信号量锁死分析

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

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

/* drv_rtc.c 文件 /
if (HAL_RTCEx_BKUPRead(&RTC_Handler, RTC_BKP_DR1) != BKUP_REG_DATA)
{
LOG_I("RTC hasn't been configured, please use 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初始化流程对比

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

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

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

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

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

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

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

方案四：使用4.0.3版本

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

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

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

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

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

（1）锁死环境复现
打开 ···rt-threadbspstm32stm32f407-atk-explorer

右键打开Env 输入scons —dist

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

右键打开Env 输入menuconfig

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

RT-Thread Comonents -> Device Drivers Using RTC device drivers

RT-Thread Comonents -> Utilities Enable ulog

log format -> Enbale timestamp format for time

Hardware Drivers Config -> On-chip Peripheral Drivers EnableRTC RTC_USING_LSE

Esc 然后选择Yes保存配置

打开 ···boardCubeMX_Config文件夹，配置CubeMX

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

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

#include
#include
#include
#define DBG_TAG "main"
#define DBG_LVL DBG_LOG
#include
/* 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及RTC其它问题的吐槽
（1）部分设备注册的日志信息无法打印
主要原因是初始化顺序不可控，使用 INIT_BOARD_EXPORT(ulog_init);

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

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

void ulog_voutput(······)
{
/* ······ /
if (!ulog.init_ok)
{
return;
}
/ ······ */
}
例如以下打印在我的测试环境下就是直接 return

LOG_I("I2C bus [%s] registered", bus_name);
（2）STM32的LSE和LSI不能同时开启
为什么需要同时开启？

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

当使用LSE作为RTC的时钟源

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

具体看以下代码

/* 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;
}