對多個資料處理卡因過多的npumgr崩潰而關閉進行故障排除
下載選項
已更新: 2020 年 1 月 27 日
文件 ID:215216
無偏見用語
本產品的文件集力求使用無偏見用語。針對本文件集的目的，無偏見係定義為未根據年齡、身心障礙、性別、種族身分、民族身分、性別傾向、社會經濟地位及交織性表示歧視的用語。由於本產品軟體使用者介面中硬式編碼的語言、根據 RFP 文件使用的語言，或引用第三方產品的語言，因此本文件中可能會出現例外狀況。深入瞭解思科如何使用包容性用語。
關於此翻譯
思科已使用電腦和人工技術翻譯本文件，讓全世界的使用者能夠以自己的語言理解支援內容。請注意，即使是最佳機器翻譯，也不如專業譯者翻譯的內容準確。Cisco Systems, Inc. 對這些翻譯的準確度概不負責，並建議一律查看原始英文文件（提供連結）。
簡介
本文說明如何解決由於npumgr崩潰而在極短時間內關閉多個資料處理卡(DPC)時出現的問題。
必要條件
需求
思科建議您瞭解以下主題：
- ASR5000/5500的硬體知識
- StarOS
- 路由基礎知識
採用元件
本文件所述內容不限於特定軟體和硬體版本。
本文中的資訊是根據特定實驗室環境內的裝置所建立。文中使用到的所有裝置皆從已清除（預設）的組態來啟動。如果您的網路運作中，請確保您瞭解任何指令可能造成的影響
縮寫
| SPGW | 服務和封包資料網路閘道器 |
| DPC | 資料處理卡 |
| VLAN | 虛擬區域網 |
| NPU | 網路處理單元 |
問題
作為計畫活動的一部分，新介面在VLAN中繫結到已完成的埠。本練習的第二部分是通過這些介面建立靜態路由。為流量開啟VLAN後，npumgr立即崩潰並隨後使所有DPC卡多次關閉。
疑難排解
本節提供的資訊用於解決由於npumgr崩潰而在極短時間內關閉多個DPC卡的問題。
此處顯示收集的Show Support Details(SSD)、活動日誌和覆蓋問題日誌的系統日誌。首先，檢查rct統計資訊以確定這些關閉的原因。在此可以看到，它們由於過多的npumgr崩潰而關閉。
******** 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
然後，檢查npumgr崩潰的詳細資訊。在此，您會看到npumgr在函式nexthop_get處崩潰。因此，當您嘗試獲取下一跳時，您會看到一些問題的指示。
********************* 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
*******************************************************
您可以檢查活動日誌，以下是所發生事件的時間順序。作為練習的一部分，介面建立後是靜態路由。
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)#
然後，在埠內部配置VLAN，並在9月19日00:08:16前後為流量開啟。
(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
在這裡，用於建立介面和靜態路由的計畫活動的步驟和配置以及隨後的VLAN內部繫結看起來不錯。但在此之後不久，可以看到npumgr開始崩潰，然後由於npumgr崩潰過多而導致DPC卡關閉。
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
作為即時解決辦法，VLAN會從連線埠中移除。很快，刪除VLAN後，npumgr崩潰將停止。
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
當您進一步檢查syslogs時，可以看到系統嘗試獲取下一跳，但是在9月19日00:08:16失敗，即在為流量開啟VLAN後不久。
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
當您進一步從SSD檢查配置時，還可以看到在計畫活動開始之前（介面和靜態路由配置）已經存在一個靜態路由。
context SGi
ipv6 route a:b:c:d:1/128 next-hop x:y:z:w::1 interface C
#exit
從配置中可以看到，已經存在通過介面C下一跳作為跳的x:y:z:w::1的IP a:b:c:d:1/128靜態路由。但是，在練習中，又將下一跳定義為跳的x:y:z:w::2。
因此，當為流量開啟VLAN時，系統無法按最初定義獲取下一跳x:y:z:w::1。此外，還有日誌顯示無法到達下一躍點的等價多路徑(ECMP)路由失敗。因此，它無法轉發這些VLAN流量的資料包，這最終會導致npumgr崩潰。
多卡切換是系統中過多的npumgr崩潰的副產品。
解決方案
有多個靜態路由通過同一介面到達同一目標，但不同的下一跳導致npumgr無法轉發資料包，然後是npumgr崩潰。
因此，會從配置中刪除錯誤的靜態路由。相同的配置隨後成功應用到另一個維護視窗，沒有任何問題。
由思科工程師貢獻
- Satya Narayan PandaCisco TAC工程師
意見