现象:板子不发送任何CAN/LIN报文,心跳灯不闪烁,严重怀疑Aurix TC367 挂掉了。
动作:劳特巴赫 attach上午后发现是asert在prvProcessReceivedCommands( void )函数里面。
if( ( pxTimer->ucStatus & tmrSTATUS_IS_AUTORELOAD ) != 0 )
{
xResult = xTimerGenericCommand( pxTimer, tmrCOMMAND_START_DONT_TRACE, xMessage.u.xTimerParameters.xMessageValue + pxTimer->xTimerPeriodInTicks, NULL, tmrNO_DELAY );
configASSERT( xResult );
( void ) xResult;
}
分析:由于assert在上面的代码里,又不能破坏现场,只能硬啃代码,看看是哪里把xResult置为0了。正常情况下xQueueGenericSend 会返回pdPASS,或者errQUEUE_FULL。因此比较容易定位到出错的地方。
Call stack:
xTimerGenericCommand
xQueueSendToBack // xQueueGenericSend( ( xQueue ), ( pvItemToQueue ), ( xTicksToWait ), queueSEND_TO_BACK )
出错的地方:
if( xTicksToWait == ( TickType_t ) 0 )
{
/* The queue was full and no block time is specified (or
the block time has expired) so leave now. */
taskEXIT_CRITICAL();
/* Return to the original privilege level before exiting
the function. */
traceQUEUE_SEND_FAILED( pxQueue );
return errQUEUE_FULL;
}
后续来了:
为什么timer queue会满呢?当前的timer queue size的设定是30,后来加大到50发现也会满,极端一些, 加大到256, 居然也会满,这就很神奇了。
动作与思考:
1. 劳特巴赫接上,在trace32里面发现timer的task是running的状态,其实就像上面提到的,assert在configASSERT( xResult ); 这个宏世纪上是关中断,然后是个for循环。
2. timer的task除了watchdog和tcpip task的优先级比它高之外,只剩下另外一个task和它的优先级一样都是是7,其他task优先级都跟更低。除了timer queue满了之外,从timer的菜单也观察到timer list里面的很多timer的timeout值都是负数,思考后觉得最大的可能性是timer的task被饿着了。由于产品本身是车辆网关,CAN/LIN/ETH的通行非常的忙碌,另外一个优先级为7的task就负责CAN/LIN通信。一开始是想是不是这个task抢占的cpu资源比较多,从而让timer task挨饿了。
3. 由于芯片不支持on-chip trace的功能, 因此无法准确知道在timer queue满的前面的一段时间内系统到底发生了什么。只能先从task的状态之类的先查起,由于watchdog的task显示的是block,有点可疑,先检查了watchdog task,不过没发现什么异常的状态。又发现有个spi通信的task是唯一一个uxcriticalnesting 为1 的task,uxcriticalnesting=1表示发生了一次中断嵌套。检查了一下代码也没发现什么可疑的地方。
4. 和北美同事交流后大家也没什么想法。由于事情又很紧急,这是个block版本发布的bug,于是祭出版本回滚比较打法,找到有第一个有同样问题的版本和前面那个版本去对比。严重怀疑是app那边加了一个20ms的timer导致的,把这个代码回滚就没问题。
5. 接下来就是去看这个代码到底有什么幺蛾子。一个个函数看过去,看看花了多长时间,终于看到某个函数花了2ms的时间。再跟下去发现是读adc的值,等硬件coplete的过程中会调用os_thread_sleep,后果就是timer task在执行timer callback函数的时候把自己给挂起了。这就是问题之所在。
6. 顺着这个发现把所有调用这个adc 读转换结果的函数的代码都统计了一遍,让应用层去改善。