最近遇到一个概率性产品工作异常的问题，最后定位原因是队列满导致，记录下完整的分析及定位过程.
问题现象
融合机框内有交换，刀片，管理板；在机框反复上下电测试(power cycle)过程中，会出现4个交换板反复重启的现象；
上环境问题定界分析
- 一个机框有4块交换板；其中1，4槽的交换型号一致，2，3槽的交换型号一致
- 从环境上来看，4块交换确实一直在反复重启，而且都无法启动到正常状态
- 重启前，交换板都会打印目前的动作：begin to get config file from smm.
- 从管理板的日志来看，交换都没有成功拿到配置文件
看到这，毋庸置疑，肯定是管理板的问题了，基本原因：交换板启动时，尝试从管理板获取配置策略失败，导致无法正常启动.
思路整理
看到这里，感觉脑袋有点翁，问题现象很严重，大概问题原因清楚，但是为什么会获取调速策略失败？策略是MM板和交换板通过IPMI消息相互传递的，也就是大概可能有两个原因
- IPMI报文交互问题
- MM处理策略获取部分代码有问题
- 对于第一点，IPMI报文收发模块一定是稳定的，因为还有大量别的报文依赖该通道，目前工作正常，且日志中没有出现大量的超时现象；
- 分析日志来看，每次获取调速策略的流程都停在同一个位置；
流程分析
mark，等待上流程图
队列分析
通过标准的linux队列查询命令：ipcs，可以看到如下
bash# ipcs -q|awk '{printf $0;a=$3;printf("%c%c%c%c\n",rshift(a,24),rshift(a,16),rshift(a,8),a);}'
------ Message Queues --------Q
key msqid owner perms used-bytes messages o
....
0x00000000 1671216 1165374261 666 0 0 Ev35
0x00000000 1703985 1165374262 666 0 0 Ev36
0x00000000 1736754 1232104809 666 0 0 Ipmi
0x100e2096 1769523 root 666 0 0 r
0x030e20f0 5865524 root 0 0 0 r
0x030e20f1 5898293 root 0 0 0 r
0x030e20f3 5931062 root 0 0 0 r
0x030e20f8 5963831 root 0 0 0 r
0x010e20f0 5996600 root 0 0 0 r
0x010e20f1 6029369 root 0 0 0 r
0x010e20f3 6062138 root 0 0 0 r
0x010e20f8 6094907 root 0 0 0 r
0x70011891 2326588 root 666 0 0 r
0x00000000 2359357 1667655533 666 2348 3429 cfgm
0x00000000 2392126 1667655526 666 0 0 cfgf
0x100e591c 2424895 root 666 0 0 r
0x00000000 2457664 1768975714 666 0 0 ipmb
0x00000000 2490433 1650551552 666 0 0 bak
0x00000000 2523202 1363963751 666 0 0 QLog
0x00000000 2555971 1399153484 666 0 0 SecL
0x00000000 2588740 1400468293 666 0 0 SysE
0x00000000 2621509 1400468293 666 0 0 SysE
0x00000000 2654278 1165373488 666 0 0 Ev00
....
从中可以看出cfgm队列出现了严重拥堵，无法及时处理消息
而通过代码分析可以看出，cfgm队列是专门用来服务于交换从MM获取启动策略的，且所有交换板公用同一队列；如果该队列拥堵无法及时处理，则有可能影响所有交换板正常启动
如果分析到底是堵在哪了？
是什么阻塞了消息的正常处理，导致队列拥堵？
- 一般流畅的代码每个函数都应该是微秒级的，这种函数是肯定不会影响消息处理速度的
- 如果某个函数处理时间特别长，使得每次有请求过来，都花大量的时间在该函数上，则该函数会大幅提高整个任务的完成速度
- 如果我们在问题的环境上，反复多次打印交换从MM获取策略线程的调用栈，如果其中多次的最上层函数都是同一个，那该函数很可能就是我们要找的问题函数.
还是用老方法
./gdb7123 -p $(pidof smmipmi.out) -batch -ex ' thr a a bt'
反复打了10次，发现有8次都是下面这个调用栈
Thread 123 (LWP 1418):
#0 0x1e4d8254 in select () from /lib/libc.so.6
#1 0x2004fb80 in OSAL_TaskDelay (ulMillSecs=10) at *******
#2 0x2005d994 in VOS_TaskDelay (ulMillSecs=10) at ******
#3 0x200663c4 in VOS_VFS_FileLength (szFileName=0x539fe4f8 "*****.cfg") at *******
#4 0x2038567c in CFGRestore::GetMD5FromCFGFile (ucSlotNum=36 '$', ulCfgFileVer=65793, pMD5CheckSum1=0x539fe97c "") at *******
#5 0x20385a14 in CFGRestore::CfgCmdReqMsgProc (this=0x20ef9e00, pData=0x9200afc0) at *******
#6 0x203883d0 in CBlade::CfgMsgDisp_Handler (ulPara1=<optimized out>, ulPara2=<optimized out>, ulPara3=<optimized out>, ulPara4=<optimized out>) at *******
#7 0x2005d938 in VOS_TaskEntry (pulArg=0x1001f) at ******
#8 0x1f10a2cc in ?? () from /lib/libpthread.so.0
#9 0x1e4e0198 in clone () from /lib/libc.so.6
找到了问题关键点：在获取配置文件MD5值时，有个usleep(10)动作，导致阻塞；
为什么10ms的影响会这么大呢？继续分析代码，原来
-
每个报文过来，MM板都会扫描特定目录下的所有配置文件
- 每个配置文件都会先计算MD5值，看看是不是要找的文件
- usleep(10)
- 出问题的测试环境有200多个配置文件，则至少要2s以上的sleep时间
- sleep(10)的原因是防止cpu被该线程无限占用
总结
- 在涉及队列消息处理流畅中，如果要使用sleep，一定要分析清楚最坏的场景及是否会有for循环；
- 在往消息队列中添加数据时，判断下队列目前是否已经有数据阻塞(获取队列数据长度即可)；
- 根据业务实际情况，如果队列长度超过一定数据，记日志或者采取下一步行动,帮助定位解决问题；