Hohe CPU-Auslastung durch Alarm-Logger-Prozess auf Routern mit IOS-XR

Einleitung

tacacsd ist ein IOS XR-Prozess, der mit dem Tacacs AAA-Service verknüpft ist. In diesem Dokument werden ein Softwarefehler und seine Symptome beschrieben, die dazu führen können, dass Router mit IOS XR Version 4.2.X oder niedriger eine konstant hohe CPU-Auslastung beobachten.

Voraussetzungen

Es gibt keine spezifischen Anforderungen für dieses Dokument.

Verwendete Komponenten

Das in diesem Dokument behandelte Problem betrifft Cisco GSR, ASR9000, CRS und andere Router mit IOS XR. Die unten angegebenen Ausgaben stammen von einem Übungs-Router, auf dem die IOS XR-Version kleiner als 4.2.X ausgeführt wird. 

Problem

Router mit IOS XR Version 4.2.X oder niedriger beobachten aufgrund eines bekannten Softwarefehlers möglicherweise eine konstant hohe CPU-Auslastung aufgrund des Alarm-Logger-Prozesses. Prozess-CPU-Ausgabe würde Alarm-Logger-Prozess mit maximaler CPU-Auslastung anzeigen.

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>

Im Protokollierungspuffer werden fortlaufende Protokolle angezeigt, ähnlich wie:

tacacsd[XXXX]: %SECURITY-TACACSD-7-GENERIC_ERROR : Fehler beim Abrufen der Anforderung für: Schlüssel -XXXXX/XXXX/XXXX/XXXX-Sitzung 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

 Die Details zu Warnmeldungsprotokollen und TACACSDs-Prozessen sind unten aufgeführt.

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>

Eine hohe CPU wird durch eine Flut von Syslog-Meldungen verursacht, die dazu führen, dass der Alarm-Logger-Puffer voll wird. Daher bleibt der Alarm-Logger-Prozess damit beschäftigt, die Nachricht zu verarbeiten und gleichzeitig den Pufferstatus "Voll" anzunehmen.  In diesem Fall ist der TACACS-Prozess eine überwältigende Warnmeldungs-Protokollierung. Da die Warnmeldungs-Protokollierung zum Opfer fällt, ist ein Neustart des Warnmeldungs-Protokollierungsprozesses nicht hilfreich, da der Puffer des freigegebenen Speichers nach dem Neustart des Prozesses erhalten bleibt.

Lösung

Dieses Problem wurde mithilfe des Softwarefehlers CSCuh98484 behoben. - Tacacsd "Failed to get request for key" (Fehler beim Abrufen der Schlüsselanforderung) verursacht eine hohe CPU. Details zu Fehlern finden Sie hier.

Bitte beachten Sie, dass der Neustart von tacacsd eine Problemumgehung ist, bei der die Protokolle gestoppt und die CPU-Auslastung auf den normalen Stand zurückgesetzt werden sollte. Das Neustarten des TACACSD-Prozesses wirkt sich nicht auf die Funktionalität oder die Datenpaketweiterleitung aus. Der Prozess befindet sich im ursprünglichen Zustand.

Dieser Fehler wurde in den folgenden IOS XR-Versionen behoben.