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

소개

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

사전 요구 사항

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

사용되는 구성 요소

이 문서에서 설명한 문제는 Cisco GSR, ASR9000, CRS 및 IOS XR을 실행하는 기타 라우터에 적용됩니다. 아래 사용된 출력은 4.2.X 미만의 IOS XR 버전을 실행하는 랩 라우터에서 가져왔습니다. 

문제

IOS XR 버전 4.2.X 이하를 실행하는 라우터는 알려진 소프트웨어 버그로 인해 alarm-logger 프로세스로 인해 CPU 사용률이 지속적으로 높게 나타날 수 있습니다. Show process cpu 출력은 최대 CPU 사용률을 소비하는 alarm-logger 프로세스를 표시합니다.

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>

High CPU(높은 CPU)는 syslog 메시지의 홍수로 인해 alarm-logger 버퍼가 가득 찼습니다. 따라서 alarm-logger 프로세스는 메시지를 처리하려고 시도하면서 동시에 버퍼 가득 참 상태를 확인하는 동안 계속 사용 중입니다.  이 경우 TACACS 프로세스는 압도적인 경보 로거입니다. alarm-logger는 피해자이므로 프로세스 재시작 후 공유 메모리 버퍼가 계속 유지되므로 alarm-logger 프로세스를 재시작하는 것이 도움이 되지 않습니다.

솔루션

이 문제는 소프트웨어 버그 CSCuh를 통해 해결 및 수정되었습니다98484 - Tacacsd "키 요청을 가져오지 못했습니다." 오류로 인해 CPU가 높습니다. 버그 세부사항이 여기 있습니다.

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

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