Fehlerbehebung beim Beenden mehrerer Datenverarbeitungskarten aufgrund von zu vielen NPump-Abstürzen

Einführung

In diesem Dokument wird beschrieben, wie Sie ein Problem beheben können, das auftritt, wenn mehrere Datenverarbeitungskarten (DPCs) aufgrund von nicht Pump-Ausfällen in sehr kurzer Zeit heruntergefahren werden.

Voraussetzungen

Anforderungen

Cisco empfiehlt, über Kenntnisse in folgenden Bereichen zu verfügen:

• Hardware-Kenntnisse von ASR5000/5500
• StarOS
• Grundkenntnisse im Routing-Bereich

Verwendete Komponenten

Dieses Dokument ist nicht auf bestimmte Software- und Hardwareversionen beschränkt.

Die Informationen in diesem Dokument wurden von den Geräten in einer bestimmten Laborumgebung erstellt. Alle in diesem Dokument verwendeten Geräte haben mit einer leeren (Standard-)Konfiguration begonnen. Wenn Ihr Netzwerk in Betrieb ist, stellen Sie sicher, dass Sie die potenziellen Auswirkungen eines beliebigen Befehls verstehen.

Abkürzungen

SPGW	Server- und Paketdatennetzwerk-Gateway
DPC	Datenverarbeitungskarte
VLAN	Virtual Local Area Network
NPU	Netzwerkverarbeitungseinheit

Problem 

Im Rahmen einer geplanten Aktivität werden neue Schnittstellen unter fertig gestellten Ports in VLANs gebunden. Der zweite Teil der Aktivität besteht in der Erstellung statischer Routen über diese Schnittstellen. Sobald das VLAN für den Datenverkehr geöffnet ist, beginnt der NPumgr-Absturz und lässt anschließend alle DPC-Karten mehrmals herunterfahren.

Fehlerbehebung 

Dieser Abschnitt enthält Informationen zur Behebung des Problems der mehrfachen Abschaltung der DPC-Karte in sehr kurzer Zeit aufgrund von Npumpenabstürzen.

Hier werden zusammengefasste Support-Details (SSD), Aktivitätsprotokolle und Syslogs angezeigt, die Protokolle des Problems abdecken. Zunächst werden die Statistiken überprüft, um den Grund für diese Abschaltungen zu ermitteln. Man kann hier sehen, dass sie aufgrund zu vieler NPumgr-Abstürze abgeschaltet werden.

******** show rct stats verbose *******
Thursday September 19 03:57:04 IST 2019
RCT stats details (Last 18 Actions)
 #  Action        Type      From  To  Start Time                Duration     Status 
--- ------------- --------- ---- ---- ------------------------  -----------  -------
 7  Shutdown      N/A         2   10  2019-Sep-19+00:09:51.587    2.322 sec  Success 
 8  Shutdown      N/A         1    0  2019-Sep-19+00:10:14.541    0.005 sec  Success 
 9  Shutdown      N/A         3    0  2019-Sep-19+00:10:44.625    0.005 sec  Success 
10  Shutdown      N/A         4    0  2019-Sep-19+00:11:03.428    0.005 sec  Success 
11  Shutdown      N/A         7    0  2019-Sep-19+00:11:34.771    0.478 sec  Success 
12  Shutdown      N/A         8    0  2019-Sep-19+00:11:54.328    0.005 sec  Success 
13  Shutdown      N/A         9    0  2019-Sep-19+00:12:19.656    0.005 sec  Success 
14  Shutdown      N/A        10    0  2019-Sep-19+00:12:39.706    0.004 sec  Success 
15  Shutdown      N/A         1    9  2019-Sep-19+00:32:30.567    0.005 sec  Success 
16  Shutdown      N/A         2    0  2019-Sep-19+00:32:36.282    0.031 sec  Success 
17  Shutdown      N/A         3    0  2019-Sep-19+00:32:56.456    0.005 sec  Success 
18  Shutdown      N/A         4    0  2019-Sep-19+00:33:30.426    0.005 sec  Success 

RCT stats summary
-----------------
Migrations        =   2,  Average time = 10.890 sec
  Management Card =   2,  Average time = 10.890 sec
  Packet Card     =   0
Switchovers       =   2,  Average time = 18.526 sec

RCT stats verbose
-----------------
Stats  7:
  Action            : Shutdown
  Type              : N/A
  From              : 2
  To                : 10
  Start Time        : 2019-Sep-19+00:09:51.587
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 2.322 sec
  Graceful          : Enabled

Stats  8:
  Action            : Shutdown
  Type              : N/A
  From              : 1
  To                : 0
  Start Time        : 2019-Sep-19+00:10:14.541
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats  9:
  Action            : Shutdown
  Type              : N/A
  From              : 3
  To                : 0
  Start Time        : 2019-Sep-19+00:10:44.625
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 10:
  Action            : Shutdown
  Type              : N/A
  From              : 4
  To                : 0
  Start Time        : 2019-Sep-19+00:11:03.428
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 11:
  Action            : Shutdown
  Type              : N/A
  From              : 7
  To                : 0
  Start Time        : 2019-Sep-19+00:11:34.771
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.478 sec
  Graceful          : Enabled

Stats 12:
  Action            : Shutdown
  Type              : N/A
  From              : 8
  To                : 0
  Start Time        : 2019-Sep-19+00:11:54.328
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 13:
  Action            : Shutdown
  Type              : N/A
  From              : 9
  To                : 0
  Start Time        : 2019-Sep-19+00:12:19.656
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 14:
  Action            : Shutdown
  Type              : N/A
  From              : 10
  To                : 0
  Start Time        : 2019-Sep-19+00:12:39.706
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.004 sec
  Graceful          : Enabled

Stats 15:
  Action            : Shutdown
  Type              : N/A
  From              : 1
  To                : 9
  Start Time        : 2019-Sep-19+00:32:30.567
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 16:
  Action            : Shutdown
  Type              : N/A
  From              : 2
  To                : 0
  Start Time        : 2019-Sep-19+00:32:36.282
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.031 sec
  Graceful          : Enabled

Stats 17:
  Action            : Shutdown
  Type              : N/A
  From              : 3
  To                : 0
  Start Time        : 2019-Sep-19+00:32:56.456
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Stats 18:
  Action            : Shutdown
  Type              : N/A
  From              : 4
  To                : 0
  Start Time        : 2019-Sep-19+00:33:30.426
  Failure Reason    : NPUMGR_TOO_MANY_CRASHES
  Failure Device    : CARD
  Is Card Usable    : Yes
  Recovery Status   : Success
  Facility          : N/A
  Instance          : N/A
  Duration          : 0.005 sec
  Graceful          : Enabled

Überprüfen Sie dann die Details der Npumgr-Abstürze. Hier sehen Sie, dass npumgr bei der Funktion nexthop_get abgestürzt wird. Daher werden einige Probleme angezeigt, wenn Sie versuchen, den nächsten Hop zu erhalten.

********************* CRASH #09 ***********************
SW Version          : 21.9.7
Similar Crash Count : 16
Time of First Crash : 2019-Sep-19+00:08:16

Assertion failure at npu/npumgr/ares_npumgr_forwarding_handler.c:1829
  Function: ares_npumgr_nexthop_get()
  Expression: (nh_id) >= 0 && (nh_id) < ares_npumgr_db_get_count(SN_NPUSHM_TABREC_NH, (ares_inst)->profile)
  Proclet: npumgr (f=103000,i=30)
  Process: card=3 cpu=0 arch=X pid=7066 cpu=~0% argv0=npumgr
  Crash time: 2019-Sep-18+19:01:11 UTC
  Recent errno: 11 Resource temporarily unavailable
  Build_number: 71001
  Stack (18024@0x0xffff0000):
    [ffffe430/X] __kernel_vsyscall() sp=0xffff0428
    [0c7df834/X] sn_assert() sp=0xffff0468
    [002fcedb/X] ares_npumgr_nexthop_get() sp=0xffff04b8
    [002feb23/X] ares_npumgr_fwd_ddf2_tcam_entry_update() sp=0xffff0948
    [00301896/X] ares_npumgr_lpm_add() sp=0xffff0e98
    [003c4345/X] ares_npumgr_fwd_add() sp=0xffff1768
    [003e38fa/X] ares_npumgr_fwd_func() sp=0xffff1bf8
    [003e444a/X] ares_sn_npumgr_forwarding_add_del_mod_handler() sp=0xffff2048
    [0c892918/X] sn_msg_arriving_handle() sp=0xffff4138
    [0c8713a6/X] sn_loop_run() sp=0xffff45e8
    [0c55a3b5/X] main() sp=0xffff4658
*******************************************************

********************* CRASH #10 ***********************
SW Version          : 21.9.7
Similar Crash Count : 1
Time of First Crash : 2019-Sep-19+00:31:22

Assertion failure at npu/npumgr/ares_npumgr_port_handler.c:8409
  Note: failed to find index of created lport 5/11#11-65: status=SN_STATUS_FAILURE[1]
  Function: ares_sn_npumgr_port_lp_create_func()
  Expression: 0
  Code: CRASH
  Proclet: npumgr (f=103000,i=11)
  Process: card=1 cpu=1 arch=X pid=7181 argv0=npumgr
  Crash time: 2019-Sep-18+19:01:22 UTC
  Recent errno: 11 Resource temporarily unavailable
  Build_number: 71001
  Stack (14728@0x0xffcb8000):
    [ffffe430/X] __kernel_vsyscall() sp=0xffcb8a48
    [0c7df834/X] sn_assert() sp=0xffcb8a88
    [003bd590/X] ares_sn_npumgr_port_lp_create_func() sp=0xffcb8f18
    [003c10d4/X] ares_sn_npumgr_port_lp_create_handler() sp=0xffcb9368
    [0c892918/X] sn_msg_arriving_handle() sp=0xffcbb458
    [0c8713a6/X] sn_loop_run() sp=0xffcbb908
    [0c55a3b5/X] main() sp=0xffcbb978
*******************************************************

********************* CRASH #11 ***********************
SW Version          : 21.9.7
Similar Crash Count : 107
Time of First Crash : 2019-Sep-19+00:09:03

Assertion failure at npu/npumgr/ares_npumgr_forwarding_handler.c:1829
  Function: ares_npumgr_nexthop_get()
  Expression: (nh_id) >= 0 && (nh_id) < ares_npumgr_db_get_count(SN_NPUSHM_TABREC_NH, (ares_inst)->profile)
  Proclet: npumgr (f=103000,i=80)
  Process: card=8 cpu=0 arch=X pid=9130 cpu=~98% argv0=npumgr
  Crash time: 2019-Sep-18+19:03:35 UTC
  Recent errno: 115 Operation now in progress
  Build_number: 71001
  Stack (10360@0x0xffe58000):
    [ffffe430/X] __kernel_vsyscall() sp=0xffe58618
    [0c7df834/X] sn_assert() sp=0xffe58658
    [002fcedb/X] ares_npumgr_nexthop_get() sp=0xffe586a8
    [002feb23/X] ares_npumgr_fwd_ddf2_tcam_entry_update() sp=0xffe58b38
    [00301896/X] ares_npumgr_lpm_add() sp=0xffe59088
    [003c4345/X] ares_npumgr_fwd_add() sp=0xffe59958
    [003e1191/X] fwddb_import_add_entry() sp=0xffe59dd8
    [003e2452/X] ares_npumgr_fwddb_import() sp=0xffe5a2c8
    [0025e4ea/X] npumgr_rx_db_evt() sp=0xffe5a2f8
    [0c8660d4/X] sn_epoll_run_events() sp=0xffe5a348
    [0c872bca/X] sn_loop_run() sp=0xffe5a7f8
    [0c55a3b5/X] main() sp=0xffe5a868
*******************************************************

Sie können die Aktivitätsprotokolle überprüfen. Hier finden Sie die Chronologie der Ereignisse. Im Rahmen einer Aktivität werden Schnittstellen erstellt, gefolgt von statischen Routen.

show ipv6 interface summary

Thursday September 19 00:09:16 IST 2019
Interface Name                 Address/Mask        Port               Status
============================== =================== ================== ======
SGi_LAG100_vlan50              2401:4900:c:f::201/126 5/10 vlan 50       UP           [sec]
SGi_LAG100_vlan64_VO4G_SBC     2401:4900:c:10::1/126  5/10 vlan 64       UP    
SGi_LAG200_vlan51              2401:4900:c:f::205/126 5/11 vlan 51       UP           [sec]
SGi_LAG200_vlan65_VO4G_SBC     2401:4900:c:10::5/126  5/11 vlan 65       UP      

Total interface count: 4

(config-ctx)# ipv6 route a:b:c:d:1/128 next-hop x:y:z:w::2 interface A
Thursday September 19 00:07:13 IST 2019
(config-ctx)#
(config-ctx)# ipv6 route a:b:c:d:1/128 next-hop x:y:z:w::2 interface B
Thursday September 19 00:07:21 IST 2019
Failure: Invalid Nexthop address!
(config-ctx)#
(config-ctx)# ipv6 route a:b:c:d:1/128 next-hop x:y:z:w::6 interface C
Thursday September 19 00:07:36 IST 2019
(config-ctx)# exit
Thursday September 19 00:07:50 IST 2019
[SGi]MOH-C25-SPG-04(config)#

Das VLAN wird dann innerhalb des Ports konfiguriert und für den Datenverkehr um den 19. September 00:08:16 Uhr geöffnet.

(config)# port ethernet 5/10
Thursday September 19 00:08:01 IST 2019
(config-port-5/10)# vla
(config-port-5/10)# vlan 64
Thursday September 19 00:08:05 IST 2019
(config-port-5/10-vlan-64)# bind interface C SGi
Thursday September 19 00:08:14 IST 2019
(config-port-5/10-vlan-64)# no shu
(config-port-5/10-vlan-64)# no shutdown
Thursday September 19 00:08:17 IST 2019
(config-port-5/10-vlan-64)# exit
Thursday September 19 00:08:19 IST 2019
(config-port-5/10)# exit
Thursday September 19 00:08:21 IST 2019

Hier sehen die Schritte und Konfigurationen der geplanten Aktivitäten zum Erstellen von Schnittstellen und statischen Routen gut aus, wenn die Bindung innerhalb des VLAN erfolgt. Aber bald danach konnte man sehen, dass der NPumgr abstürzte, gefolgt von einem Herunterfahren der DPC-Karte aufgrund zu vieler NPumgr-Abstürze.

show snmp trap history verbose | grep -i mgr
Thursday September 19 00:20:22 IST 2019
Thu Sep 19 00:08:18 2019 Internal trap notification 73 (ManagerFailure) facility npumgr instance 30 card 3 cpu 0
Thu Sep 19 00:08:18 2019 Internal trap notification 150 (TaskFailed) facility npumgr instance 30 on card 3 cpu 0
Thu Sep 19 00:08:18 2019 Internal trap notification 73 (ManagerFailure) facility npumgr instance 40 card 4 cpu 0
Thu Sep 19 00:08:18 2019 Internal trap notification 150 (TaskFailed) facility npumgr instance 40 on card 4 cpu 0

Als unmittelbare Problemumgehung werden VLANs aus dem Port entfernt. Bald, nachdem Sie VLANs entfernt haben, stürzt der NPumgr ab.

configure
Thursday September 19 00:29:31 IST 2019
(config)# port eth
(config)# port ethernet 5/10
Thursday September 19 00:33:13 IST 2019
(config-port-5/10)# no vlan 64
Thursday September 19 00:33:23 IST 2019
(config-port-5/10)# exit
Thursday September 19 00:33:38 IST 2019
(config)# port ethernet 5/11
Thursday September 19 00:33:42 IST 2019
(config-port-5/11)# no vlan 65
Thursday September 19 00:33:50 IST 2019
(config-port-5/11)# end
Thursday September 19 00:33:52 IST 2019


******** show crash list *******
Thursday September 19 03:54:39 IST 2019
=== ==================== ======== ========== =============== =======================
# Time Process Card/CPU/ SW HW_SER_NUM
PID VERSION MIO / Crash Card
=== ==================== ======== ========== =============== =======================
 9 2019-Sep-19+00:31:11 npumgr 03/0/07066 21.9.7 FLM221503A5/FLM221404FF
10 2019-Sep-19+00:31:22 npumgr 01/1/07181 21.9.7 FLM221503A5/FLM221404FH
11 2019-Sep-19+00:33:35 npumgr 08/0/09130 21.9.7 FLM221503A5/FLM221404FU

Wenn Sie weitere Syslogs überprüfen, kann man sehen, dass das System versucht, Next-Hop zu bekommen, aber es war nicht erfolgreich am 19. September 00:08:16. d. h. kurz nach der Öffnung des VLAN für den Datenverkehr.

Sep 19 00:08:16 10.107.211.36 evlogd: [local-60sec16.758] [npumgr-fwd 168001 error] [3/2/7024 
     
     
       rding_handler.c:7739] [software internal system syslog] ECMP create fail - no nexthop ARP: vpnid=6, type=ip[0], action=add[1], ip=2401:4900:c:f::408/128, tb_ver=3 ifentry-flag=0, ifroute-flag=0, updatettl-flag=1, nh=2401:4900:c:10::1 dpti=0 priority=0, tos=0, ttl-decr=1, nhlfe_ix=0, lport=0x050a000a 
     
Sep 19 00:08:18 10.107.211.36 evlogd: [local-60sec18.448] [sitmain 4103 warning] [1/0/7008 
     
     
       sitproc.c:2653] [software internal system critical-info syslog] [npumgr pid 7102] async core transfer and proclet recovery is not set! 
     
Sep 19 00:08:18 10.107.211.36 evlogd: [local-60sec18.852] [sitmain 4027 critical] [2/0/6993 
     
     
       crash_mini.c:602] [software internal system callhome-crash] Process Crash Info: time 2019-Sep-18+18:38:16(hex time 5d827998) card 02 cpu 00 pid 07146 procname npumgr   crash_details  Assertion failure at npu/npumgr/ares_npumgr_forwarding_handler.c:1829   Function: ares_npumgr_nexthop_get()   Expression: (nh_id) >= 0 && (nh_id) < ares_npumgr_db_get_count(SN_NPUSHM_TABREC_NH, (ares_inst)->profile)   Proclet: npumgr (f=103000,i=20)   Process: card=2 cpu=0 arch=X pid=7146 cpu=~0% argv0=npumgr   Crash time: 2019-Sep-18+18:38:16 UTC   Recent errno: 11 Resource temporarily unavailable   Build_number: 71001   Stack (20600@0x0xffce5000):     [ffffe430/X] __kernel_vsyscall() sp=0xffce5e38     [0c7df834/X] sn_assert() sp=0xffce5e78     [002fcedb/X] ares_npumgr_nexthop_get() sp=0xffce5ec8     [002feb23/X] ares_npumgr_fwd_ddf2_tcam_entry_update() sp=0xffce6358     [00301896/X] ares_npumgr_lpm_add() sp=0xffce68a8     [003c4345 
     
Sep-18+18:38:16(hex time 5d827998) card 02 cpu 00 pid 07146 procname npumgr   crash_details  Assertion failure at npu/npumgr/ares_npumgr_forwarding_handler.c:1829   Function: ares_npumgr_nexthop_get()   Expression: (nh_id) >= 0 && (nh_id) < ares_npumgr_db_get_count(SN_NPUSHM_TABREC_NH, (ares_inst)->profile)   Proclet: npumgr (f=103000,i=20)   Process: card=2 cpu=0 arch=X pid=7146 cpu=~0% argv0=npumgr   Crash time: 2019-Sep-18+18:38:16 UTC   Recent errno: 11 Resource temporarily unavailable   Build_number: 71001   Stack (20600@0x0xffce5000):     [ffffe430/X] __kernel_vsyscall() sp=0xffce5e38     [0c7df834/X] sn_assert() sp=0xffce5e78     [002fcedb/X] ares_npumgr_nexthop_get() sp=0xffce5ec8     [002feb23/X] ares_npumgr_fwd_ddf2_tcam_entry_update() sp=0xffce6358     [00301896/X] ares_npumgr_lpm_add() sp=0xffce68a8     [003c4345

Wenn Sie die Konfiguration von SSD weiter prüfen, kann auch festgestellt werden, dass eine statische Route bereits vor Beginn der geplanten Aktivität existiert (Schnittstellen- und statische Routenkonfigurationen).

context SGi
  ipv6 route a:b:c:d:1/128 next-hop x:y:z:w::1 interface C
#exit

Aus der Konfiguration geht hervor, dass bereits eine statische Route für IP a:b:c:d:1/128 über die Schnittstelle C next-hop as hop x:y:z:w::1 vorhanden war. Im Rahmen der Aktivität wird eine weitere statische Route definiert, bei der Next-Hop als Hop x:y:z:w::2 definiert wird.

Wenn die VLANs für Datenverkehr geöffnet werden, kann das System den nächsten Hop x:y:z:w:1 nicht wie zuvor definiert abrufen. Außerdem gab es Protokolle, die zeigten, dass das Equal-Cost Multi-Path (ECMP)-Routing zum nächsten Hop nicht erfolgreich war, da es nicht erreichbar ist. Infolgedessen war es nicht in der Lage, Pakete dieses VLAN-Datenverkehrs weiterzuleiten, die schließlich zu Npumpenabstürzen führten.

Ein Wechsel auf mehrere Karten ist ein Nebenprodukt zu vielen Systemabstürzen.

Lösung

Es gibt mehrere statische Routen zum gleichen Ziel über dieselbe Schnittstelle, aber verschiedene Next-Hop-Routen, die zum NPumgr führen, können Pakete nicht weiterleiten, gefolgt von NPumgr-Abstürzen.

Daher wird die falsche statische Route aus der Konfiguration entfernt. Die gleichen Konfigurationen werden dann problemlos in einem anderen Wartungsfenster angewendet.