IOS-XR을 실행하는 라우터의 경보 로거 프로세스에 의한 높은 CPU 사용률

소개

tacacsd는 Tacacs AAA 서비스와 연결된 IOS XR 프로세스입니다.이 문서에서는 IOS XR 버전 4.2.X 이하를 실행하는 라우터가 지속적으로 높은 CPU 사용률을 관찰하도록 하는 소프트웨어 버그와 그 증상에 대해 설명합니다.

사전 요구 사항

이 문서에 대한 특정 요건이 없습니다.

사용되는 구성 요소

이 문서에서 해결된 문제는 IOS XR을 실행하는 Cisco GSR, ASR9000, CRS 및 기타 라우터에 적용됩니다.아래 사용된 출력은 4.2.X 이하 버전의 IOS XR를 실행하는 랩 라우터에서 가져온 것입니다. 

문제

IOS XR 버전 4.2.X 이하를 실행하는 라우터는 알려진 소프트웨어 버그로 인해 경보 로거 프로세스로 인해 지속적으로 높은 CPU 사용률을 관찰할 수 있습니다.Show process cpu 출력에서는 경보 로거 프로세스에서 최대 CPU 사용률을 사용합니다.

show proc cpu | ex "0% 0% 0%"

CPU utilization for one minute: 100%; five minutes: 100%; fifteen minutes: 100%
PID 1Min 5Min 15Min Process
<snip>
53281 2% 2% 2% syslogd_helper
57379 1% 1% 1% fabricq_prp_driver
69636 1% 1% 1% correlatord
69677 6% 6% 6% syslogd
118842 1% 1% 1% sysdb_svr_local
122962 3% 3% 3% gsp
229604 2% 2% 2% eem_ed_syslog
262456 1% 1% 1% tacacsd
452726918 67% 71% 72% alarm-logger
463302887 1% 1% 1% exec
<snip>

로깅 버퍼에서 다음과 유사한 연속 로그를 볼 수 있습니다.

tacacsd[XXXX]:%SECURITY-TACACSD-7-GENERIC_ERROR:다음에 대한 요청을 가져오지 못했습니다.키 -XXXXX/XXXX/XXXX/XXXX 세션 XXXXX

show log
<snip>
RP/0/7/CPU0:Dec 26 04:02:03.149 : tacacsd[1110]: %SECURITY-TACACSD-6-SERVER_UP : 
TACACS+ server 32.95.X.X/XXXX is UP 

RP/0/7/CPU0:Dec 26 04:02:05.956 : tacacsd[1110]: %SECURITY-TACACSD-6-SERVER_DOWN : 
TACACS+ server 32.95.X.X/XXXX is DOWN - Socket 43: Connection timed out 

RP/0/7/CPU0:Dec 26 04:02:09.468 : tacacsd[1110]: %SECURITY-TACACSD-6-SERVER_DOWN : 
TACACS+ server 199.37.X.X/XXXX is DOWN - Socket 43: Connection timed out 

RP/0/7/CPU0:Dec 26 04:02:09.647 : tacacsd[1110]: %SECURITY-TACACSD-6-TIMEOUT_IGNORED : 
A time out event has been ignored for context key -953829129/1073/60000000/6486405 
(session 6486405) 

RP/0/7/CPU0:Dec 26 04:02:11.647 : tacacsd[1110]: %SECURITY-TACACSD-7-GENERIC_ERROR : 
Failed to get request for: key -953829129/1073/60000000/6486405 session 105407493 

RP/0/0/CPU0:last message repeated 520 times

RP/0/7/CPU0:Dec 26 04:02:34.064 : tacacsd[1110]: %SECURITY-TACACSD-6-SERVER_UP : 
TACACS+ server 32.95.X.X/XXXX is UP 

RP/0/7/CPU0:Dec 26 04:02:34.064 : tacacsd[1110]: %SECURITY-TACACSD-7-GENERIC_ERROR : 
Failed to get request for: key -953829129/1073/60000000/6486405 session 105407493

 alarm-logger 및 tacacsd 프로세스 세부 정보는 아래와 같습니다.

show processes alarm-logger
<snip>
Job Id: 114
PID: 135303
Executable path: /c12k-os-4.2.4/sbin/alarm-logger
Instance #: 1
Version ID: 00.00.0000
Respawn: ON
Respawn count: 1
Max. spawns per minute: 12
Last started: Tue Aug 13 02:17:23 2013
Process state: Run
Package state: Normal
core: MAINMEM 
Max. core: 0
Level: 91
Placement: None
startup_path: /pkg/startup/alarm-logger.startup
Ready: 0.672s
Process cpu time: 1401.018 user, 49.774 kernel, 1450.792 total
JID TID Stack pri state TimeInState HR:MM:SS:MSEC NAME
114 1 88K 10 Receive 0:00:02:0071 0:00:40:0919 alarm-logger
114 2 88K 10 Receive 3242:46:17:0308 0:00:00:0000 alarm-logger
114 3 88K 10 Reply 0:00:00:0000 0:23:08:0029 alarm-logger
114 4 88K 10 Mutex 0:00:00:0000 0:00:21:0957 alarm-logger
-------------------------------------------------------------------------------
<snip>

show processes tacacsd
<snip>
Job Id: 1110
PID: 266551
Executable path: /disk0/iosxr-infra-4.2.4/bin/tacacsd
Instance #: 1
Version ID: 00.00.0000
Respawn: ON
Respawn count: 1
Max. spawns per minute: 12
Last started: Tue Aug 13 02:23:47 2013
Process state: Run
Package state: Normal
Started on config: cfg/gl/aaa/tacacs/
Process group: central-services
core: MAINMEM 
Max. core: 0
Placement: Placeable
startup_path: /pkg/startup/tacacsd.startup
Ready: 3.954s
Process cpu time: 1010.118 user, 185.932 kernel, 1196.050 total
JID TID Stack pri state TimeInState HR:MM:SS:MSEC NAME
1110 1 108K 16 Sigwaitinfo 3242:46:40:0742 0:00:00:0116 tacacsd
1110 2 108K 10 Nanosleep 0:01:03:0835 0:00:00:0019 tacacsd
1110 3 108K 10 Receive 3242:46:41:0593 0:00:00:0002 tacacsd
1110 4 108K 10 Reply 0:00:00:0000 0:08:55:0970 tacacsd
1110 5 108K 16 Receive 3242:46:40:0771 0:00:00:0000 tacacsd
1110 6 108K 10 Receive 0:07:07:0403 0:04:03:0462 tacacsd
1110 7 108K 10 Receive 0:00:01:0389 0:03:28:0939 tacacsd
1110 8 108K 10 Receive 0:00:01:0332 0:03:03:0622 tacacsd
-------------------------------------------------------------------------------
<snip>

높은 CPU는 syslog 메시지의 플러드로 인해 경보 로거 버퍼가 가득 차기 때문에 발생합니다.따라서 경보 로거 프로세스는 메시지를 처리하려고 노력하고 버퍼 가득 참 상태를 동시에 처리하는 동안 통화 중입니다.  이 경우 TACACS 프로세스는 경보 로거를 과도하게 처리합니다.alarm-logger가 피해를 입으므로 alarm-logger 프로세스를 다시 시작하면 프로세스가 다시 시작된 후에도 공유 메모리 버퍼가 계속 유지되므로 도움이 되지 않습니다.

솔루션

이 문제는 소프트웨어 버그 CSCuh98484 - Tacacsd "Failed to get request for key" 오류로 인해 CPU가 높습니다.버그 세부사항이 여기에 표시됩니다.

tacacsd 프로세스를 다시 시작하는 것은 로그를 중지하고 CPU 사용률은 정상 수준으로 돌아가야 하는 해결 방법입니다.tacacsd 프로세스를 다시 시작하면 기능이나 데이터 패킷 포워딩에 영향을 주지 않으며, 프로세스가 초기 상태로 전환됩니다.

이 버그는 다음 IOS XR 버전에서 수정되었습니다.