说明:Radius Server是某项目中的Radius认证服务器模块,肩负终端登录认证、计费等重要功能,在实际使用中将承受高并发请求的压力。
问题:在对其进行性能测试时,发现在进行一段时间后,即使停止压力,Radius Server的CPU占用率仍然居高不下,导致系统始终处于繁忙状态。初步断定Radius Server陷入死循环中。
定位:通过pstack查看进程堆栈情况,其中一个线程的情况如下:
----------------- lwp# 32 / thread# 32 --------------------
ff040090 lwp_park (0, 0, 0)
0019a0a0 __1cUEnterCriticalSection6FpnO_pthread_mutex__v_ (3056e80, b5cc360, 0, 0, 0, 0) + 30
0017b81c __1cLCCacheTableOGetFirstBucket6MippnQtag_cache_data_u_ipipnPtag_cache_rec_t__pnStag_cache_bucket_t__ (4d1cf88, 1, 8fe0798, 2, 8fd8cd8, 8ff5910) + 1cc
00166ff4 __1cMCTableAccessFQdDuery6MI_i_ (ffffeff0, ffffefe8, fc57b32c, 79, d6226cc, 3) + 494
000e303c __1cKcEAP_CACHENQdDueryEAPState6Mipc_i_ (fc57b3f0, 7b, d6226cc, ff0e7010, ff068284, ff0709b0) + 11c
000e04f0 __1cPcEAP_BaseModuleRGetNextIdentifier6MC_C_ (d6226c0, 0, d622714, 313333, ff00, ff0000) + a0
000e5c14 __1cUcEAPTLS_AuthenticatePmodule_initiate6MpnLtRadiusItem_ipnL_EAP_PACKET_4i_i_ (d6226c0, 7d640a0, 8, ab93d60, d1c8428, d) + 6c
000ded0c __1cRcEAP_AuthenticateKeap_select6MpnR_tRadiusRequest_t_pnLtRadiusItem_pi_i_ (a104b38, 7d64068, 7d779e8, 7d7a0e8, 0, a104baf) + 15c
000de750 __1cRcEAP_AuthenticateQeap_authenticate6MpnR_tRadiusRequest_t_pnMCTableAccess_4pnLtRadiusItem_pi_i_ (a104b38, 7d64068, 8ce3cb0, 8fdc218, 7d779e8, 7d7a0e8) + 178
000ddc18 __1cLProcEAPAuth6FpnR_tRadiusRequest_t_pnMCTableAccess_3pnLtRadiusItem_pi_i_ (7d64068, 8ce3cb0, 8fdc218, 7d779e8, 7d7a0e8, 0) + e8
000c1aa8 __1cKcWiMaxProcSProcWiMaxAccessReq6MpnH_AuthDR_pnLtRadiusItem_pipc_i_ (7d77970, fc57bac8, 7d6195c, 7d6405c, fc57b960, ff0000) + 218
000c1780 __1cKcWiMaxProcOProcessRequest6MpnH_AuthDR_pnLtRadiusItem_pi_i_ (7d77970, fc57bac8, 7d6195c, 7d6405c, fc57bb09, 7d6192c) + c8
0008e7ec __1cOcLocalAuthLsnrSProcessAuthRequest6MpnH_AuthDR__i_ (7d6192c, fc57bac8, 8, fc57bac8, 8ddfa0a, 0) + 11c
0008e684 __1cOcLocalAuthLsnrQrad_authenticate6M_i_ (7d61420, 7d64068, 8eb14a0, 0, 0, 0) + 10c
0008e490 __1cOcLocalAuthLsnrLMainProcess6MpnOQdDueueElement_t__i_ (7d61420, fc57bf18, 1, fc57bf18, ffffffff, 1000) + 240
0013178c __1cNCWorkerThreadKThreadProc6M_i_ (7d61420, 0, 0, 0, 0, 1) + 204
0012e708 ExternProc (7d61420, fc57c000, 0, 0, 12e660, 1) + a8
ff03fff0 _lwp_start (0, 0, 0, 0, 0, 0)
这个工作线程就即是可疑度最高,因此需要深入研究该部分代码。通过以上堆栈中提示的函数名,找到相应的代码:
int cEAP_CACHE:QueryEAPState(int id, char *cGWIPAddr)
{
WCacheAttri * pAttri;
char * pcVal=NULL;
char temp[64];
if (pEAPState == NULL) {
plog->print_msg((char*)"Err: %s QueryEAPState: TableAccess is null!!!", EAP_LOG);
return RTN_FAIL;
}
pAttri = pEAPState->OpenIdxAttr();
pAttri->SetVal((char *)"srcip", cGWIPAddr);
sprintf(temp, "%d", id);
pAttri->SetVal((char *)"id", temp);
if(pEAPState->Query()) {
plog->print_msg((char *)"Msg: %s QueryEAPState: id(%d),ip(%s) not exist in EAPState cache", EAP_LOG, id, cGWIPAddr);
return RTN_FAIL;
}
plog->print_msg((char *)"Msg: %s QueryEAPState: id(%d),ip(%s) exist in EAPState cache",EAP_LOG, id,cGWIPAddr);
return RTN_SUCCESS;
}
其中红色部分的Query代码又调用了如下代码:
u_char cEAP_BaseModule::GetNextIdentifier(u_char CurrId)
{
cEAP_CACHE cEAPCache;
u_char identifier;
int ret;
cEAPCache.SetTableAccess(pEAPState);
while(1) {
identifier = g_EapInfo.GetRequestId(CurrId);
ret = cEAPCache.QueryEAPState((int)identifier, mGWIPAddr);
if (ret == RTN_FAIL)
break;
}
return identifier;
}
经过仔细分析,问题就是由于红色部分的代码引起,正常情况下,当ret==RTN_FAIL后会正常的break后,退出while循环。但在异常情况下就会陷入死循环。
原因分析:EAP-TLS协议中的Identifier的位数为8位,即最大为256,因此做一遍256次的循环可以判定是否还有未被使用的空余Identifier标号,当进行压力测试时,由于客户端或服务器端处理较慢,故可能256个Indetifer都处于被占用的状态,因此会出现QueryEAPState永为True的情况,导致陷入死循环。
代码修正:
int cEAP_BaseModule::GetNextIdentifier(u_char CurrId, u_char *NextId)
{
cEAP_CACHE cEAPCache;
u_char identifier;
int ret;
cEAPCache.SetTableAccess(pEAPState);
bool bFound=false;
for(int i=0;i<256;i++){
identifier = g_EapInfo.GetRequestId(CurrId);
ret = cEAPCache.QueryEAPState((int)identifier, mGWIPAddr);
if (ret == RTN_FAIL) {
bFound=true;
break;
}
}
if(!bFound) {
return RTN_FAIL;
}
*NextId = identifier;
return RTN_SUCCESS;
}
至此,修改完毕,将while(1)改为for(int i=0;i<256;i++),避免死循环的发生。从另外一个侧面也反映出,程序编写时要多考虑异常境况如何处理,养成良好的编程习惯很重要。