FreeRTOS printf可重入问题

调试程序时候常用printf来作为调试日志输出，方便定位问题所在位置。但最近出现一个现象程序运行过程中会出现莫名的异常死机。

但是在死之前有个征兆，观看打印的日志，有两条信息穿插打印的现象。所以才想起来去考虑是不是printf引起的。

在整个项目中我运行的有8个任务，而在每一个任务里面几乎都会有使用printf进行调试信息打印。所以从开始就埋下了一颗定时炸弹。只是要碰下运行，运气好的时候一切风平浪静。运气不好的时候就炸的异常到处横飞。

在看下自己代码printf重映射的fput接口用的还是HAL_UART_Transmit 阻塞发送函数接口。这样在波特率为115200的情况下，假如打印一条200bytes的日志信息就要约等于19ms的时间。这岂不严重影响其他任务的实时性。

所以先把fput改为非阻塞的形式，这个可以使用freertos的stream_buffer,这个可以把要发送的数据压入buffer，然后真正的发送就使用串口发送为空中断从stream_buffer一个个byte进行读取发送。这样可以保证调用printf——》到fput 就只是写stream_buffer。而不再是阻塞式调用一次printf就要等待串口完全把数据发送完。fput的代码如下：
int fputc(int ch,FILE *file)
{
xStreamBufferSend(streamDebug,&ch,1,1000);
__HAL_UART_ENABLE_IT(&DEBUG_UART,UART_FLAG_TXE);
return ch;
}
本以为把阻塞改为非阻塞，这个bug解决完的美妙心情就要到来了的时候，按下了复位按键，啥？运行了还没10秒钟就又死了，甚至比之前更惨烈。

而现在调用printf的最关键的一条代码就是xStreamBufferSend() 只能默默的打开freertos的参考手册，看下stream的详细描述。而在注意里面有下面一段话：
有多个不同的writers或者多个不同的readers是不安全的。也就是说在多个不同的任务中调用发送就会有可能有问题。这不正符合了我现在的场景，多个任务可能同时调用printf，相当于多个任务同时调用stream的write接口。

stream有这个限制，那注定printf就是不可重入的了。而针对不可重入的资源最简单的办法就是用互斥量进行保护。所以我就把printf进行包装了一层取名为debug_printf:

void debug_printf(const char *fmt, …)
{
va_list args;
if(xSemaphoreTake(semDebug,portMAX_DELAY);
va_start(args,fmt);
vprintf(fmt,args);
va_end(args);
xSemaphoreGive(semDebug);
}
当调用debug_printf的时候先去获取信号量semDebug，如果获取不到就一直等待直到获取。该函数执行完毕以后再释放信号量。这样就充分保证了资源的独占，同时只可能有一个任务再进行debug_printf。需要说明的是vprintf底层最终还是会调用我们重映射的fput函数。

再次上电，打印终于正常了，但是，还有但是……一波未平一波又起。开锁的时候失败了，开锁任务是一个需要实时的任务，要检测传感器转动位置。而这个异常明显是实时性得不到满足。

仔细分析下，问题就出在printf互斥量的获取。有可能造成高优先级任务产生延时，甚至造成优先级翻转。

假如有三个任务：任务A、任务B、任务C，优先级从低到高。现在任务A调用了debug_printf 获取了信号量，而高优先级的任务C也需要调用debug_printf,但因为获取不到信号量就会造成暂时挂起，等到任务A打印完成把信号量释放了任务C才能得以运行。这样高优先级的任务无法抢占低优先级任务而降低了实时性。如下图所示：
上图的是一种情况，还不算最坏的。还有可能出现优先级翻转的问题，造成延时更大。同样最低优先级任务A先运行并且调用了debug_printf获取到了信号量，而这时候任务c也需要运行并调用了debug_printf。但是因为A已经把信号量占用而无法获取到，所以暂时被挂起。任务A开始打印，在打印到一半的时候，被中等优先级的任务B给打断了（任务B不调用debug_printf所以可以打断A）。这时候A又挂起了，任务B开始运行，等到B运行完以后继续运行A。等A运行完信号量释放了，高优先任务C终于可以得到运行了。如下图所示，这时候看看任务C本来可以实时的运行的，现在却中间又穿插先运行了中优先级任务B。造成一个中优先级比高优先级任务先得到运行的优先级翻转现象。而实时性相比上图就更差了。

并且这个延时是不可估量的，想想任务B还可能再被更高优先级的任务打断。高优先级任务C反而被一再延时执行。所以出现高优先级任务出现问题就不难理解了。

发现了问题还是要解决问题。根据分析肯定要改造一下debug_printf，同时为了实时性得到满足。我就把任务C高优级的打印LOG暂时关闭。

而针对debug_printf中获取信号量修改为有时间限制，不再无限期等待。这样顶多出现获取不到信号量5ms超时返回少打印一条log信息，总比把任务卡出异常要好的多。改造后的debug_printf如下：

void debug_printf(const char *fmt, …)
{
va_list args;
if(xSemaphoreTake(semDebug,5)==pdFALSE)return;
va_start(args,fmt);
vprintf(fmt,args);
va_end(args);
xSemaphoreGive(semDebug);
}