Uso elevado de la CPU por el proceso de registro de alarmas en routers que ejecutan IOS-XR

Introducción

tacacsd es un proceso IOS XR que está asociado con el servicio Tacacs AAA. Este documento describe un error de funcionamiento del software y sus síntomas que pueden hacer que los routers que ejecutan la versión 4.2.X o inferior de IOS XR observen una alta utilización constante de la CPU.

Prerequisites

No hay requisitos específicos para este documento.

Componentes Utilizados

El problema tratado en este documento se aplica a Cisco GSR, ASR9000, CRS y otros routers que ejecutan IOS XR. Las salidas usadas a continuación han sido tomadas de un router de laboratorio que ejecuta la versión IOS XR inferior a 4.2.X. 

Problema

Los routers que ejecutan la versión 4.2.X o inferior de IOS XR pueden observar una alta utilización constante de la CPU debido al proceso de registro de alarmas debido a un error de software conocido. El resultado de show process cpu mostraría el proceso alarm-logger consumiendo la cantidad máxima de utilización de la 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>

En el buffer de registro puede ver registros continuos similares a:

tacacsd[XXXX]: %SECURITY-TACACSD-7-GENERIC_ERROR: Error al obtener la solicitud para: key -XXXXX/XXXX/XXXX/XXXX session 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

 los detalles de los procesos alarm-logger y tacacsd se pueden ver a continuación.

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>

La CPU alta es causada por la inundación de mensajes de syslog que causan que el buffer del registrador de alarmas se llene. Por lo tanto, el proceso del registrador de alarmas permanece ocupado tratando de manejar el mensaje y enfrentando la condición de buffer lleno al mismo tiempo.  En este caso, el proceso TACACS es abrumador registrador de alarmas. Como el registrador de alarmas es una víctima, reiniciar el proceso del registrador de alarmas no ayudará ya que el búfer de memoria compartida permanece persistente después del reinicio del proceso.

Solución

Este problema se ha resuelto y corregido mediante el error de software CSCuh98484 - El error Tacacsd "Failed to get request for key" causa un uso excesivo de la CPU. Los detalles del error están presentes aquí

Tenga en cuenta que reiniciar el proceso tacacsd es una solución alternativa que debe detener los registros y el uso de la CPU debe volver al nivel normal. El reinicio del proceso tacacsd no afectará a ninguna funcionalidad ni al reenvío de paquetes de datos, sino que pondrá el proceso en su estado inicial.

Este error se ha corregido en las siguientes versiones de IOS XR.