Utilisation CPU élevée par le processus d'enregistrement des alarmes sur les routeurs exécutant IOS-XR

Introduction

tacacsd est un processus IOS XR associé au service AAA de Tacacs. Ce document traite d'un bogue logiciel et de ses symptômes qui peuvent amener les routeurs exécutant IOS XR version 4.2.X ou antérieure à observer une utilisation élevée constante du CPU.

Conditions préalables

Aucune exigence spécifique n'est associée à ce document.

Composants utilisés

Le problème abordé dans ce document concerne Cisco GSR, ASR9000, CRS et d'autres routeurs exécutant IOS XR. Les résultats utilisés ci-dessous proviennent d’un routeur de travaux pratiques exécutant une version d’IOS XR antérieure à 4.2.X. 

Problème

Les routeurs exécutant IOS XR version 4.2.X ou inférieure peuvent observer une utilisation élevée constante du CPU en raison d'un processus d'enregistrement d'alarme dû à un bogue logiciel connu. La sortie show process cpu indique que le processus du journal d'alarmes consomme la quantité maximale d'utilisation du processeur.

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>

Dans la mémoire tampon de journalisation, vous pouvez voir des journaux continus similaires à :

tacacsd[XXXX] : %SECURITY-TACACSD-7-GENERIC_ERROR : échec de l'obtention de la demande pour : 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

 les détails des processus alarm-logger et tacacsd sont visibles ci-dessous.

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>

Un CPU élevé est provoqué par un déluge de messages syslog, ce qui entraîne le remplissage du tampon du journal d'alarme. Par conséquent, le processus de l'enregistreur d'alarmes reste occupé à essayer de traiter le message et à faire face à la condition de mémoire tampon pleine en même temps.  Dans ce cas, le processus TACACS accable le système d'enregistrement des alarmes. Comme le journal des alarmes est une victime, le redémarrage du processus du journal des alarmes ne sera pas utile car la mémoire tampon partagée reste persistante après le redémarrage du processus.

Solution

Ce problème a été résolu et corrigé via le bogue logiciel CSCuh98484 - L'erreur Tacacsd "Failed to get request for key" entraîne une utilisation CPU élevée. Les détails du bogue sont présents ici

Veuillez noter que le redémarrage du processus tacacsd est une solution de contournement qui devrait arrêter les journaux et l'utilisation du CPU devrait revenir à un niveau normal. Le redémarrage du processus tacacsd n'affectera aucune fonctionnalité ou transfert de paquets de données, il placera le processus dans son état initial.

Ce bogue a été corrigé dans les versions suivantes d'IOS XR.