实测STM32F4中printf的效率问题
实测STM32F4中printf的效率问题
⼀直认为printf所做的⼯作就是格式化字符串，然后依次调⽤fputc函数发送出去。于是以前都认为printf函数的瓶颈是在fputc这⾥，是因为发送⼀个字节所占的时间太长，才导致printf效率慢。也就是说，⼀直认为如果串⼝的波特率设置成115200的话，printf⾄少也是能达到115200的波特率的。
⽽这⼏天在学习ucOS，于是想到，如果printf的瓶颈是在等在串⼝发送完成的话，那么我在等待串⼝发送完成中断的时候是不是挂起⼀个信号量，然后就可以去做点别的事情了呢？这也正是RTOS的⽬的之⼀嘛————最⼤化利⽤CPU。
花了点时间时间试了下之后，发现完全没有改善！于是有了测试两次进⼊fputc间隔时间的想法。
测试环境：MDK5.12 + ⾃带STM32F4 HAL层 + UCOS3.04.04模拟串口使用printf函数
硬件平台：安富莱V5板卡，主芯⽚STM32F407IG，USB转串⼝线CH430芯⽚，ThinkPad T420
代码如下：
int fputc(int ch, FILE *f)
{
OS_ERR err;
CPU_TS ts;
Dbg_printf_time[Dbg_printf_cnt++] = STK_VAL_REG;  //进⼊函数前读取systick的寄存器值
Dbg_printf_inter[Dbg_printf_cnt] = Dbg_printf_time[Dbg_printf_cnt-2] - Dbg_printf_time[Dbg_printf_cnt-1];//⽤刚读取的寄存器值减去上⼀次退出该函数的寄存器值，从⽽得到两次进⼊该函数之间的时间    while (HAL_UART_Transmit_IT(&huart, (uint8_t *)&ch, 1) != HAL_OK)
{
OSTaskSemPend(10, OS_OPT_PEND_BLOCKING, &ts, &err);
//check “err”
}
Dbg_printf_time[Dbg_printf_cnt++] = STK_VAL_REG; //退出函数前读取systick的寄存器值
Dbg_printf_inter[Dbg_printf_cnt] = Dbg_printf_time[Dbg_printf_cnt-2] - Dbg_printf_time[Dbg_printf_cnt-1];//⽤刚读取的寄存器值减去进⼊该函数的寄存器值，从⽽得到两次进⼊该函数之间的时间
if (Dbg_printf_cnt > 90)
{
Dbg_printf_cnt = 1;
}
return ch;
}
重点关注Dbg_printf_inter的值，结果如下：
可以看到进⼊两次fputc之间的间隔达到了15937个tick，考虑到主频为168M
由
time=tick/sysfreq
可以计算得出time=94.86us。
⽽115200波特率的串⼝在发送两个Byte之间的时间是：86.5us
也就是说：⽤115200波特率的速度打印printf就已经把STM32的CPU都耗光了！
实在是好奇printf⾥⾯都做了什么？？作为库函数，它不应该是精简，效率的典范吗？怎么会这么慢？
抛出这个问题，求⾼⼿解答，同时也欢迎像我这么⽆聊的同学在别的平台上验证两次fputc之间的时间差。