Contenido

Introducción

Prerequisites

Requirements

Componentes Utilizados

Abreviaturas

Problema

Troubleshoot

Solución

Introducción

Este documento describe cómo resolver un problema que ocurre cuando se apagan varias tarjetas de procesamiento de datos (DPC) en un período muy corto debido a caídas de npumgr.

Prerequisites

Requirements

Cisco recomienda que tenga conocimiento sobre estos temas:

- Conocimiento de hardware de ASR5000/5500

- StarOS

- Conocimiento básico del routing

Componentes Utilizados

Este documento no tiene restricciones específicas en cuanto a versiones de software y de hardware.

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. Si tiene una red en vivo, asegúrese de entender el posible impacto de cualquier comando

Abreviaturas

SPGW

Gateway de red de datos de servidor y paquetes

DPC

Tarjeta de procesamiento de datos

VLAN

Red de área local virtual

NPU

Unidad de procesamiento de red

Problema

Como parte de una actividad planificada, las nuevas interfaces se enlazan en VLAN bajo los puertos hechos. La segunda parte de la actividad es crear rutas estáticas a través de estas interfaces. Tan pronto como se abre la VLAN para el tráfico, npumgr se bloquea y posteriormente hizo que todas las tarjetas DPC se cerraran varias veces.

Troubleshoot

Esta sección proporciona información para resolver el problema del cierre de varias tarjetas DPC en un período muy corto debido a caídas de npumgr.

Aquí se muestran los detalles de asistencia (SSD) recopilados, los registros de actividad y los registros del sistema que cubren los registros del problema. En primer lugar, las estadísticas del rct se comprueban para ver la razón de estos bloqueos. Se puede ver aquí que están cerrados debido a demasiados caídas de 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

Luego, verifique los detalles de los desperfectos de npumgr. Aquí, verá que npumgr se bloquea en la función nexthop_get. Por lo tanto, verá una indicación de algunos problemas cuando intente obtener el salto siguiente.

********************* 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

*******************************************************

Puede comprobar los registros de actividad y aquí está la cronología de los eventos que ocurrieron. Como parte de una actividad, las interfaces se crean seguido de rutas estáticas.

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)#

Luego, la VLAN se configura dentro del puerto y se abre para el tráfico alrededor del 19 de septiembre 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

Aquí, los pasos y las configuraciones de la actividad planificada para crear interfaces y rutas estáticas son seguidos por el enlace dentro de la VLAN se ve bien. Pero poco después de esto, se pudo ver que el npumgr empezó a fallar seguido de apagones de tarjeta DPC debido a demasiados desperfectos de npumgr.

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

Como solución inmediata, las VLAN se quitan del puerto. Pronto, después de quitar las VLAN, el npumgr se detiene.

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

Cuando verifica los registros del sistema, se puede ver que el sistema intentó obtener el salto siguiente pero no tuvo éxito a las 19 de septiembre 00:08:16. es decir, poco después de que la VLAN se abriera para el tráfico.

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

Cuando verifica la configuración desde SSD, también se puede ver que ya existe una ruta estática antes del inicio de la actividad planificada (configuraciones de interfaz y ruta estática).

context SGi

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

#exit

A partir de la configuración, se puede ver que ya había una ruta estática presente para IP a:b:c:d:1/128 a través de la interfaz C next-hop como salto x:y:z:w::1. Pero como parte de la actividad, se define una ruta estática más con el salto siguiente como el salto x:y:z:w::2.

Por lo tanto, cuando las VLAN se abren para el tráfico, el sistema no puede obtener el salto siguiente x:y:z:w::1 como se definió primero. Además, había registros que indicaban que el routing de múltiples rutas de igual costo (ECMP) al salto siguiente no era exitoso porque no era alcanzable. Como resultado, no fue capaz de reenviar paquetes de este tráfico de VLAN que eventualmente llevaron a caídas de npumgr.

El switchover de varias tarjetas es un subproducto de demasiados errores npumgr en el sistema.

Solución

Hay varias rutas estáticas al mismo destino a través de la misma interfaz, pero el siguiente salto diferente que conduce al npumgr no puede reenviar paquetes seguido de caídas de npumgr.

Por lo tanto, la ruta estática incorrecta se elimina de la configuración. Las mismas configuraciones se aplican con éxito en otra ventana de mantenimiento sin ningún problema.