ASR 5000 / 5500 Series Troubleshooting port / NPU related issues
Contents
Introduction
This article presents ideas on how to troubleshoot various port related issues ASR 5000 and 5500 platforms including issues related to the Network Processing Unit (NPU), and touches a bit on Link Aggregation (LAG) issues as well. These techniques are not rocket science and in fact are mostly known by engineers, but often one or more may be skipped over in the troubleshooting process simply due to oversight in the rush through the steps towards potential resolution. The article first starts off with the port related health checks. Then it lays out all the approaches in some kind of methodical order. Finally it offers a series of real examples that go beyond basic port troubleshooting for those who want to dig deep.
Troubleshooting commands
show snmp trap history
Look for patterns of PortLinkUp and PortLinkDown. Consider:
- how often it is happening and over what time period
- multiple ports or just one port or some other pattern
- maintenance work that technicians may or may not be aware of
show port table all
- indicates whether the links are up or down
- Link Aggregation (LAG) - confirm ports are in the correct state, either + (distributing/active) or ~ (agreed/standby). Other states * or - need further investigation.
show port info
- various information such as link state, port mode, port settings, Link Aggregation (LAG) settings, SFP module, etc.
show card diag
- basic diagnostic info, usually not that helpful
show rct stats [verbose]
- tracks all PSC/DPC/SMC/MIO activity (switchovers, migrations, shutdowns, etc.) since bootup
show port utilization table
- is the throughput what is expected for the time of day
- Equal Cost Multi Path (ECMP) and LAG ports should be transmitting fairly evenly
- Rx bandwidth is under control of the other end
show logical-port utilization table
- breaks down the port utilization by VLAN ID
- if the numbers are small compared to the port utilization table, it implies packets not making it to the NPU from the port
show port datalink counters <slot/port>
- reports packet counts on the physical ports themselves
- check the various failure counters to see if any are incrementing and at what rate
- Important: this is one of those few commands that is collected TWICE in an SSD which can be very valuable for troubleshooting packet count increases in a relatively short period of time
show port npu counters <slot/port> [vlan <vlan>]
- all ports are connected to the rest of the system through the Network Processor Unit (NPU), either located on the connected Packet Services Card (PSC, ASR 5000) (whether the PSC is directly connected or mapped via the Redundancy Crossbar Cards (RCC)) or on the Management Input Output (MIO) (ASR 5500) on which the port is also located.
- check the various failure counters to see if any are incrementing and at what rate
- for LAG implementation, counters are reported for the master port capturing the totals across all the ports in the LAG group, and so there is no way to know which port is causing the failures. In that case, for ASR 5000, "show port npu stats debug all_pacs" reports failure counts at the PSC # level which hopefully helps point to the culprit card.
- Issues have been seen where increase in faliure counters from this command are caused by a failures on the Line Card, where "show port datalink counters" doesn't show the issue.
- not all NPU issues are caught with this command. There are other tech support only NPU commands (i.e. show npu stats debug all_pacs, show npu stats sf all_pacs, etc.) that capture packet dropping issues which are not covered here.
- Important: this is one of those few commands that is collected TWICE in an SSD which can be very valuable for troubleshooting packet count increases in a relatively short period of time
show logs
- look for any entries related to the ports including facilities npu, npuctrl, etc.
show port transceiver (ASR 5500 only)
- look for light levels consistent across all ports
Remediation actions
Between each of the following steps, check the output of the above commands, as applicable, to detect any improvement and/or change in behavior. If the issue is sporadic, an appropriate waiting period may be necessary before declaring success/failure.
This is not intended to be a hard and fast list that has to be executed in the order or even completely. There are too many variables that play a role in troubleshooting such issues and so this is intended to be a guide so that in the least, the troubleshooter has access to all the potential options. Those with many years experience are likely familiar with some of these approaches as they apply to other platforms, but a reminder checklist is always a good idea, and those without knowledge of the platform may not be familar with some of the platform-specific approaches and/or commands available.
Remember: each scenario is different and troubleshooting steps will reveal new information that will dictate future steps that will differ amongst scenarios. This is just a guide.
The steps considered and order taken will vary depending on the severity of the issue, potential subscriber impact, and customer sentiment.
Switchover to the redundant port or LAG
- Need to consider the fact that the port being troubleshot is now handling traffic OR not handling traffic
- ASR5000: full-sized linecards now are connected to a different PSC (NPU), while half-sized line-card will continue to be connected to same PSC
- switching over doesn't change any cabling, and so more likely doing so will not make a difference in a port bouncing scenario, but in the least, if the issue was on the active port, impact will be minimized since it is now be a standby port
Swap cable connections with redundant port
- depending on which cable is pulled first, the final active port could be either port, so the port may need to be switched back to get back to the starting layout
- if the problem remains with the troubled port, then look more closely at that port on the ASR
- if the problem switches to the other port, then look more closely at that port's connection on the far end
Clean fibers
- if the port being cleaned is active, then it needs to be switched back to after the cleaning
- cleaning fibers has definitely been an activity that frequently resolves issues
Replace elements in the path, including ethernet cable/fiber/patch panel/interconnects/taps
- if the port being cleaned is active, then it will need to be switched back to after the cleaning
- it might be surprising to find out how frequently this step resolves issues
Small form-factor pluggable (SFP) replacement on either / both sides of the connection
- the SFPs can be ordered separately
- Check for unused SFPs for testing purposes
------------------------------
ASR 5000 only:
Linecard Reboot
Linecard Reseat
- Reseating will accomplish a superset of reboot and it is more intrusive and worth trying
PSC migration
- The PSC connected to the Line Card hosting the problem port (show card mappings / show card table all))
PSC Reboot
PSC Reseat
- A PSC migration will result in the PSC being reset but it is not the equivalent of a reboot
- Similarly a PSC reset is more intrusive than a PSC reboot
- A PSC reseat will accomplish a superset of PSC reboot in one step
- In all of the above, if the issue is resolved, a migration to make the PSC active again would be necessary to confirm whether the issue is fully resolved (assuming the PSC activity has resolved the port bouncing). Note that depending on the card layout and the starting card configuration (i.e. is the Line Card having the issue physically behind the connected PSC?, etc.), switching the PSC back to active may or may not result in the same PSC <-> Line Card mapping as was the case before the activity.
System Management Card (SMC) switchover
SMC Reboot
SMC Reseat
ASR 5500 only:
MIO switchover
- this is different than just a port or LAG switchover. Any active ports on the MIO being switched over will become standby. If the problem port is already active on the Standby MIO, then the MIO switchover doesnt change the port status but is still a valid step
----------------------------------
Chassis reload
- though unlikely, it is always possible that there is some kind of anomaly that can only be resolved with a reload
Hardware replacement on adjacent switch
Hardware replacement on ASR 5x00 (PSC, LC, MIO, SMC or RCC)
Remediation steps command reference:
card migrate from <x> to <y> – PSC/DPC migration
- While lifting the lever is another way, don’t do that AND then pull the card or a card shutdown results
card switch from <x> to <y> – SMC/MIO/LC/RCC switchover
port switch to <x> – non-LAG port switchover
link-aggregation port switch to <x> – LAG switchover
- X must be the master LAG port or the master’s pair depending on direction
card reboot X
- card reset is another option but reboot is recommended
Example troubleshooting scenarios
Standby PGW Inter Chassis Session Recovery (ICSR) node is receiving high volume of traffic from Juniper MX-960
This example shows the active LAG ports receiving significant traffic even thought the chassis is Service Redundancy Protocol (SRP) Standby in which case the thruput should be almost nil. The value of the following two commands used in conjunction is that the ports are showing significant traffic being received but the NPU is showing no traffic. This implies the traffic is being dropped before reaching the NPU, possibly right at the ports themselves. The "show port datalink counters" and "show port npu counters" corraborate this since the NPU counters are hardly increasing while the datalink counters are increasing quickly.
[local]PGW-ICSR> show port utilization table
Sunday July 26 00:13:32 UTC 2015
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
5/1 1000 Ethernet 0 0 0 0 0 0
5/10 10G Ethernet 0 0 0 0 0 0
5/11 10G Ethernet 0 0 0 0 0 0
5/15 10G Ethernet 0 0 0 0 0 0
5/16 10G Ethernet 0 0 0 0 0 0
5/28 10G Ethernet 105 13 105 13 105 13
5/29 10G Ethernet 0 0 0 0 0 0
6/1 1000 Ethernet 0 0 0 0 0 0
6/10 10G Ethernet 4214 0 4121 0 3993 0
6/11 10G Ethernet 4089 0 4103 0 3995 0
6/15 10G Ethernet 4166 0 4172 0 3996 0
6/16 10G Ethernet 4163 0 4174 0 3997 0
6/28 10G Ethernet 0 0 0 0 0 0
6/29 10G Ethernet 1 0 1 0 1 0
[local]PGW-ICSR> show logical-port utilization table
Sunday July 26 00:13:45 UTC 2015
------ Average Port Utilization (in mbps) ------
Slot/Port vlan Current 5min 15min
Rx Tx Rx Tx Rx Tx
-------------- -------- -------- -------- -------- -------- --------
5/10 2427 0 0 0 0 0 0
5/10 2407 0 0 0 0 0 0
5/10 2011 0 0 0 0 0 0
5/10 2405 0 0 0 0 0 0
5/10 2015 0 0 0 0 0 0
5/10 2455 0 0 0 0 0 0
6/10 2427 0 0 0 0 0 0
6/10 2407 0 0 0 0 0 0
6/10 2011 0 0 0 0 0 0
6/10 2405 0 0 0 0 0 0
6/10 2015 0 0 0 0 0 0
6/10 2455 0 0 0 0 0 0
6/29 31 0 0 0 0 0 0
[local]PGW-ICSR> clear port npu counters all
Saturday July 25 01:44:38 UTC 2015
[local]PGW-ICSR> clear port data count all
Saturday July 25 01:44:43 UTC 2015
[local]PGW-ICSR> show port data counters 6/10
Saturday July 25 01:45:30 UTC 2015
rt npu counteCounters for port 6/10:
Line Card 10 Gigabit Ethernet Port
Rx Counter Data | Tx Counter Data
----------------------- -------------- + ----------------------- -------------
RX Bytes 20310895783 | TX Bytes 9746
RX Unicast frames 25564965 | TX Unicast frames 41
RX Multicast frames 85 | TX Multicast frames 48
RX Broadcast frames 0 | TX Broadcast frames 0
RX Size 64 frames 338598 | TX Size 64 frames 9
RX Size 65 .. 127 fr 6881254 | TX Size 65 .. 127 fr 32
RX Size 128 .. 255 fr 4151284 | TX Size 128 .. 255 fr 48
RX Size 256 .. 511 fr 761933 | TX Size 256 .. 511 fr 0
RX Size 512 .. 1023 fr 599377 | TX Size 512 .. 1023 fr 0
RX Size 1024 .. 1518 fr 12678554 | TX Size 1024 .. 1518 fr 0
RX Size 1519 .. 1522 fr 154050 | TX Size 1519 .. 1522 fr 0
[local]PGW-ICSR> show port npu counters 6/10
Saturday July 25 01:45:31 UTC 2015
Counters for port 6/10
Counter Rx Frames Rx Bytes Tx Frames Tx Bytes
---------------------- -------------------- ----------- --------------------
Unicast 147 11716 150 12234
Multicast 870 73376 416 51584
Broadcast 4 240 0 0
IPv4 unicast 66 4436 66 4550
IPv4 non-unicast 238 15232 0 0
IPv6 unicast 83 7400 84 7684
IPv6 non-unicast 632 8144 0 0
Fragments received 0 0 n/a n/a
Packets reassembled 0 0 n/a n/a
Fragments to kernel 0 0 n/a n/a
HW error 0 0 n/a n/a
Port non-operational 0 0 0 0
SRC MAC is multicast 0 0 n/a n/a
Unknown VLAN tag 0 0 n/a n/a
Other protocols 97 8240 n/a n/a
Not IPv4 399 36472 n/a n/a
Bad IPv4 header 0 0 n/a n/a
Missing packets between datalink and npu counters
This example for ASR 5000 shows output comparing datalink and npu counters. In this case, the multicast and broadcast packets match between commands, but the Rx count for npu is less than for datalink. The command "show npu stats debug" can possibly account for the difference, but not in all cases, as is the case here where none of the counters from that command can account for the differences.
[local]DO-HSGW> clear port npu counters all
Thursday August 06 02:05:51 UTC 2015
[local]DO-HSGW> clear port datalink counters all
Thursday August 06 02:05:52 UTC 2015
[local]DO-HSGW> show npu stats debug all-pacs clear
Thursday August 06 02:05:52 UTC 2015
[local]DO-HSGW> show card table
Thursday August 06 02:18:59 UTC 2015
Slot Card Type Oper State SPOF Attach
----------- -------------------------------------- ------------- ---- ------
5: PSC Packet Services Card 3 Active No 21 37
[local]DO-HSGW> show port npu count 21/1
Thursday August 06 02:13:52 UTC 2015
Counters for port 21/1
sCounter Rx Frames Rx Bytes Tx Frames Tx Bytes
-------------------- ------------- --------------- ------------- ---------------
Unicast 2502 289800 1726 308932
Multicast 1091 92000 0 0
Broadcast 1231 79781 0 0
IPv4 unicast 2400 283272 1624 304240
IPv4 non-unicast 534 34176 0 0
IPv6 unicast 0 0 0 0
IPv6 non-unicast 539 52982 0 0
Fragments received 0 0 n/a n/a
Packets reassembled 0 0 n/a n/a
Fragments to kernel 0 0 n/a n/a
HW error 0 0 n/a n/a
Port non-operational 0 0 0 0
SRC MAC is multicast 0 0 n/a n/a
Unknown VLAN tag 0 0 n/a n/a
Other protocols 50 7850 n/a n/a
Not IPv4 0 0 n/a n/a
Bad IPv4 header 0 0 n/a n/a
IPv4 MRU exceeded 0 0 n/a n/a
TCP tiny fragment 0 0 0 0
No ACL match 0 0 0 0
Filtered by ACL 0 0 0 0
TTL expired 0 0 n/a n/a
Flow lookup twice 0 0 n/a n/a
Unknown IPv4 class 0 0 n/a n/a
Too short: IP 0 0 n/a n/a
Too short: ICMP 0 0 0 0
Too short: IGMP 0 0 0 0
Too short: TCP 0 0 0 0
Too short: UDP 0 0 0 0
Too short: IPIP 0 0 n/a n/a
Too short: GRE 0 0 n/a n/a
Too short: GRE key 0 0 n/a n/a
Don't frag discards n/a n/a 0 0
Fragment packets n/a n/a 0 0
Fragment fragments n/a n/a 0 0
IPv4VlanMap dropped 0 0 n/a n/a
IPSec NATT keep alive 0 0 n/a n/a
MPLS Flow not found 0 0 n/a n/a
MPLS unicast 0 0 0 0
Size < 17 0 0 0 0
Size 17 .. 64 1834 117376 102 4692
Size 65 .. 127 1385 113948 36 2520
Size 128 .. 255 1589 225633 1191 170710
Size 256 .. 511 16 4624 397 131010
Size 512 .. 1023 0 0 0 0
Size 1024 .. 2047 0 0 0 0
Size 2048 .. 4095 0 0 0 0
Size 4096 .. 4500 0 0 0 0
Size > 4500 0 0 0 0
[local]DO-HSGW> show port data counters 21/1
Thursday August 06 02:13:52 UTC 2015
how npu Counters for port 21/1:
Line Card Gigabit Ethernet Port
Rx Counter Data | Tx Counter Data
----------------------- -------------- + ----------------------- -------------
RX Unicast frames 5555 | TX Unicast frames 1726
RX Multicast frames 1091 | TX Multicast frames 0
RX Broadcast frames 1233 | TX Broadcast frames 0
RX Size 64 frames 0 | TX Size 64 frames 102
RX Size 65 .. 127 fr 4219 | TX Size 65 .. 127 fr 36
RX Size 128 .. 255 fr 1681 | TX Size 128 .. 255 fr 1191
RX Size 256 .. 511 fr 49 | TX Size 256 .. 511 fr 397
RX Size 512 .. 1023 fr 1828 | TX Size 512 .. 1023 fr 0
RX Size 1024 .. 1518 fr 18 | TX Size 1024 .. 1518 fr 0
RX Size > 1518 frames 84 | TX Size > 1518 frames 0
RX Bytes OK 1934599 | TX Bytes OK 317264
RX Bytes BAD 0 | TX Bytes BAD 0
RX SHORT OK 0 | TX PAUSE 0
RX SHORT CRC 0 | TX ERR 0
RX OVF 0 |
RX NORM CRC 0 |
RX LONG OK 0 |
RX LONG CRC 0 |
RX PAUSE 0 |
RX FALS CRS 0 |
RX SYM ERR 0 |
RX FIFO CORR ECC ERR 0 | TX FIFO CORR ECC ERR 0
RX FIFO UNREC ECC ERR 0 | TX FIFO UNREC ECC ERR 0
RX Disc frames 0 | TX Disc frames 0
RX Disc bytes 0 | TX Disc bytes 0
RX ERR frames 0 | TX ERR frames 0
----------------------- -------------- + ----------------------- -------------
[local]DO-HSGW> show npu stats debug slot 5
Thursday August 06 02:13:53 UTC 2015
NPU debug stats for slot 5
Total number of NPU debug stat counters: 267
WARN: ----------------------------------
lc-rx-drop (id: 234) 50
INFO: ----------------------------------
csix-idle-cnt (id: 29) 36268853
npu-resent-fc-msg (id: 45) 951
npu-tx-fc-cframe (id: 46) 44701
npu-rx-sf-xon (id: 60) 13316
cp2npu-unk-mac-drop-cnt (id: 153) 177255
ipv6-unk-nexthdr (id: 155) 262
rx-cp-sft-pkt (id: 164) 33439
rx-sf0-sft-pkt (id: 165) 33439
rx-sf1-sft-pkt (id: 166) 33439
lc-rx-arp-slowpath (id: 316) 70
flow-notfound-done-slowpath (id: 325) 1233
flow-lkup-done-slowpath (id: 326) 3473
Datalink TX Pause and RX OVF on ASR 5000
TX Pause indicates that this port has reached some peak load at some point of time and sent a PAUSE frame to the peer switch, so that peer switch can gracefully reduce the traffic towards this port. However, it seems that the peer switch is not enabled with flow control and hence there are some counters at the line card which indicates some overflow drops at the port.
Even if the average port utilization is not reaching the peak value (like 6 GBPS), the port may receive a sudden spike of traffic that can lead to TX PAUSE. Hence, it is advisable to have the flow control enabled at the peer switch always just in case.
show port datalink counters
Counters for port 21/1: Line Card 10 Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Unicast frames 11562820841545 | TX Unicast frames 8643405785924 RX Multicast frames 401729121 | TX Multicast frames 0 RX Broadcast frames 16900986 | TX Broadcast frames 0 RX Size 64 frames 2562649224215 | TX Size 64 frames 5324800463761 RX Size 65 .. 127 fr 1827916995441 | TX Size 65 .. 127 fr 1921108746736 RX Size 128 .. 255 fr 527160156402 | TX Size 128 .. 255 fr 377388275894 RX Size 256 .. 511 fr 384674712910 | TX Size 256 .. 511 fr 285180922294 RX Size 512 .. 1023 fr 335734722295 | TX Size 512 .. 1023 fr 248088896685 RX Size 1024 .. 1518 fr 5894848662488 | TX Size 1024 .. 1518 fr 486837840991 RX Size > 1518 frames 29836364100 | TX Size > 1518 frames 0 RX Bytes OK 9248285853715092 | TX Bytes OK 1491301613652484 RX Bytes BAD 5358 | TX Bytes BAD 0 RX SHORT OK 0 | TX PAUSE 639563 RX SHORT CRC 0 | TX ERR 0 RX OVF 12768 | RX NORM CRC 0 | RX LONG OK 0 | RX LONG CRC 0 | RX PAUSE 0 | RX FALS CRS 0 | RX SYM ERR 0 | RX SPI FRAME COUNT 11555373252519 | TX SPI FRAME COUNT 8637801817136 RX SPI LEN ERR 0 | TX SPI LEN ERR 0 RX SPI DIP 2 ERR 0 | TX SPI DIP 4 ERR 0 RX SPI STATUS OOF ERR 0 | TX SPI DATA OOF ERR 0 RX FIFO OVERFLOW 0 | TX FIFO FULL DROP 0 RX PAUSE COUNT 0 | TX DIP 4 PACKET DROP 0 SPI EOP/ABORT 0 | RX FRAGMENTS COUNT 0 | RX MAC ERR 26 | RX JABBER COUNT 0 |
A very low level command (Tech Support only, can be retrieved from the SSD) is "show data congestion slot X". In this example note the high congestion on slot 5 (default connected to XCLC 21/1) at the NPU to Switch Fabric (SF) interface. Specifically, a high count of flow control messaging from the Switch Fabric to the NPU, along with a high number of packet drops in that same direction confirms the issue.
******** Data-path congestion information for slot 5 ********
NPU Percentage of Frames Dropped:
Subsystem | 5 Sec | 5 Min | 15 Min | Total Frames and Drops
-------------|---------|---------|---------|-----------------------------
LC Top rx | 0.00% | 0.00% | 0.00% | Frames: 715193480189
| | | | Drops: 0
LC Top tx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC Bot rx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC Bot tx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC RCC1 rx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC RCC1 tx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC RCC2 rx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
LC RCC2 tx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
CPU rx | 0.00% | 0.00% | 0.00% | Frames: 121566003797
| | | | Drops: 0
CPU tx | 0.00% | 0.00% | 0.00% | Frames: 59870967969
| | | | Drops: 35226625
SF A rx | 0.00% | 0.00% | 0.00% | Frames: 224008179
| | | | Drops: 0
SF A tx | 0.01% | 0.00% | 0.00% | Frames: 378241304254
| | | | Drops: 274645028
SF B rx | 0.00% | 0.00% | 0.00% | Frames: 656009419
| | | | Drops: 0
SF B tx | 0.00% | 0.00% | 0.00% | Frames: 392219947264
| | | | Drops: 320394097
EDC rx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
EDC tx | 0.00% | 0.00% | 0.00% | Frames: 0
| | | | Drops: 0
NPU Received Flow Control Events:
Event | 5 Sec | 5 Min | 15 Min | Total Event Count
----------------|-------------|-------------|-------------|--------------------
rx-sf-xoff | 21668 | 843417 | 2358340 | 828378025
rx-sf-xon | 21811 | 851786 | 2383440 | 873518866
rx-lc-xoff | 0 | 0 | 0 | 0
rx-lc-xon | 0 | 0 | 0 | 0
rx-cp-xoff | 53 | 5021 | 15176 | 17316366
rx-cp-xon | 53 | 5021 | 15176 | 17316366
rx-edc-xoff | 0 | 0 | 0 | 0
rx-edc-xon | 0 | 0 | 0 | 0
Increasing TX ERR due to mismatched port settings on ASR 5500 management port
In this example, tickets started to be opened referencing an increase in TX ERR counters on port 5/1, the management port on ASR 5500. At one site, it wasn't "noticed" as a problem until after a MOP was executed that implemented the creation and generation of event record files, a feature of Enhance Charging Service. No correlation could be made between implementing that feature and a sudden increase in these failures, except to note that there was also a sudden increase on throughput for the management port, which should only carry management traffic on 12/30 when the change was made. Here variable txpackets from schema PORTSch1 is graphed showing the increase:
An audit of the network showed that the issue was happening on many nodes, for example here is just a small snippet of the audit:
*************** ALPR-DXGW-ICSR *************** show port datalink counters 5/1 | grep "TX ERR" Monday January 04 03:33:14 UTC 2016 RX SHORT CRC 0 | TX ERR 2038860 *************** ANJT-PGW *************** show port datalink counters 5/1 | grep "TX ERR" Monday January 04 03:33:14 UTC 2016 RX SHORT CRC 0 | TX ERR 1975169 *************** AZUS-PGW-00 *************** show port datalink counters 5/1 | grep "TX ERR" Monday January 04 03:33:15 UTC 2016 RX SHORT CRC 0 | TX ERR 1709395 *************** AZUSPND-PGW-00 *************** show port datalink counters 5/1 | grep "TX ERR" Monday January 04 03:33:15 UTC 2016 RX SHORT CRC 0 | TX ERR 1211060
Going back to old SSDs (since only the basic counters are being tracked by Bulkstats), it can be seen that the error was happening slowly up to 12/30, but then after the MOP execution, the error was happening at a much higher rate:
Thursday November 19 13:41:44 UTC 2015 Counters for port 5/1: Line Card Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX SHORT CRC 0 | TX ERR 5927969 Monday November 30 13:35:45 UTC 2015 Counters for port 5/1: Line Card Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX SHORT CRC 0 | TX ERR 6116249 Tuesday December 01 13:39:26 UTC 2015 Counters for port 5/1: Line Card Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX SHORT CRC 0 | TX ERR 6130958 Counters cleared ... [local]ASR5500-PGW> show port datalink counters 5/1 Monday January 04 02:41:29 UTC 2016 Counters for port 5/1: Line Card Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Unicast frames 171008921 | TX Unicast frames 221976127 RX SHORT CRC 0 | TX ERR 5852770 ******** show port datalink counters ******* Tuesday January 05 13:38:51 UTC 201 Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Unicast frames 216450269 | TX Unicast frames 8080952673 RX SHORT CRC 0 | TX ERR 11497275
******** show port info *******
Tuesday January 05 13:33:07 UTC 2016
Port: 5/1
Port Type : 1000 Ethernet
Configured Duplex : Auto
Configured Speed : Auto
Link State : Up
Link Duplex : Half
Link Speed : 100 Mb Issue fixed ... Wednesday January 06 14:29:28 UTC 2016 Counters for port 5/1: Line Card Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX SHORT CRC 0 | TX ERR 0
[local]PGW> show port info 5/1
Wednesday January 06 12:58:50 UTC 2016
Port: 5/1
Port Type : 1000 Ethernet
Role : Management Port
Configured Duplex : Auto
Configured Speed : Auto
Link State : Up
Link Duplex : Full
Link Speed : 1000 Mb
The issue turned out to be a mismatch in the port settings between the ASR 5500 and the new switch to which it connects to, the Nexus 7000. The fix was to set ports on both ends to auto-negotiate. ASR 5500 was already set to auto, while the Nexus was set manually to full duplex. The fix:
ASR 5500 (already set to this)
port ethernet 5/1
medium speed 1000 duplex full
no shutdown
bind interface 5/1-MGMT local
#exit
Nexus 7K (needed to be set to this)
interface Ethernet152/1/11
description MGMT-PORT-5/01
switchport
switchport access vlan 10
spanning-tree port type edge
no snmp trap link-status
no shutdown
It turns out that the issue was occuring all along but was never noticed because the only indicator was the TX ERR counter which is not something that can be measured through any automated reporting since there is no bulkstat variables for anything beyond the basic port counters (Tx/Rx packets/bytes, etc.). But the issue was severely exacerbated when the MOP was run and since Tx/Rx packets is captured by Bulkstats and is a KPI measured by the customer, it was then noticed.
So the next question was what caused the sudden increase in traffic? Examination of the change shows the following setting called "via local-context", which specifies using the local context port (5/1 or 6/1) for the new event traffic instead of the port 5/29 in the ECS context where existing Event Data Record (EDR) billing record traffic has always been (and continued to be) sent out the existing port 5/29 in that context. This was NOT an obvious find since that setting is rarely used in any customer config.
context ECS
interface 5/29-ECS
ip address 10.192.102.75 255.255.255.0
#exit
session-event-module file name evt-repo rotation volume 40000000 rotation time 120 storage-limit 500000000 exclude-checksum-record time-stamp rotated-format compression gzip event transfer-mode push primary encrypted-url +A19y2j... via local-context module-only edr-module active-charging-service file name FDR70 rotation volume 40000000 rotation time 300 storage-limit 500000000 headers reset-indicator edr-format-name trap-on-file-delete charging-service-name omit compression gzip file-sequence-number rulebase-seq-num cdr use-harddisk cdr remove-file-after-transfer cdr transfer-mode push primary encrypted-url +A0d2...
Increasing Bad Frames and Tx Collisions on management port due to half duplex
The interface 24/1 and 25/1 which make up the 24/1-MGMT interface are experiencing "Bad Frames", "TX Collisions" and "TX Late Collisions".
From the show support details::
******** show port datalink counters ******* Friday January 03 14:14:59 UTC 2014 Counters for port 25/1: SPIO 10/100/1000 Ethernet port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Bytes 12808872101 | TX Bytes 20451927433 RX BAD frames 0 | TX BAD frames 1403971 RX Runt frames 0 | TX Runt frames 0 RX Oversize frames 0 | TX Oversize frames 0 RX Good frames 95621882 | TX Good frames 39395979 RX Multicast frames 6686008 | TX Collisions 1501475 RX Broadcast frames 56656415 | TX Excessive collis 0 RX Code ERROR 0 | TX Late Collisions 1403968 RX CRC ERROR 0 | TX CRC ERROR 0 RX length ERROR 0 | TX ABORT 3 RX Align ERROR 0 | ----------------------- -------------- + ----------------------- -------------
From the system a little bit later, notice the increase in Bad Frames and Collisions/Late Collisions:
[local]DO-HSGW> show port datalink counters 25/1 Friday January 03 14:26:04 UTC 2014 Counters for port 25/1: SPIO 10/100/1000 Ethernet port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Bytes 12809750383 | TX Bytes 20456667635 RX BAD frames 0 | TX BAD frames 1404930 RX Runt frames 0 | TX Runt frames 0 RX Oversize frames 0 | TX Oversize frames 0 RX Good frames 95628788 | TX Good frames 39400838 RX Multicast frames 6686366 | TX Collisions 1502503 RX Broadcast frames 56659440 | TX Excessive collis 0 RX Code ERROR 0 | TX Late Collisions 1404927 RX CRC ERROR 0 | TX CRC ERROR 0 RX length ERROR 0 | TX ABORT 3 RX Align ERROR 0 | ----------------------- -------------- + ----------------------- -------------
This is usually indicative of a configuration mismatch on either end of the Ethernet interface. Both management ports have negotiated as half duplex:
[local]DO-HSGW> show port info 24/1 Friday January 03 14:33:19 UTC 2014 Port: 24/1 Port Type : 1000 Ethernet Dual Media Role : Management Port Description : (None Set) Controlled By Card : 8 (System Management Card) Redundancy Mode : Port Mode Framing Mode : Unspecified Redundant With : 25/1 Preferred Port : Non-Revertive Physical ifIndex : 402718720 Administrative State : Enabled Configured Duplex : Auto Configured Speed : Auto Media Selection : RJ45 MAC Address : 00-05-47-02-5D-EE Link State : Up Link Duplex : Half Link Speed : 100 Mb Link Aggregation Group : None Logical ifIndex : 402718721 Operational State : Down, Standby SFP Module : Present (1000BASE-SX, M5, M610G SFP+Cu)
The other end of the link, Cisco Catalyst 6500, was set to Speed = 100 and duplex = full. To fix the issue, hard-code the ASR 5000 to also be full duplex:
port ethernet 24/1
medium speed 100 duplex full
no shutdown
bind interface 24/1-MGMT local
Or alternatively, set BOTH sides to be auto-negotiate.
But having one sides as auto and the other side as full could result in half-duplex establishment.
Unexpected LAG Switchover - LAG Port 23/1 Issue
The following was observed where port 23/1 in the LAG was stuck in LAG negotiated state after an unexpected LAG switchover:
2015-May-15+16:47:40.410 [snmp 22002 info] [1/0/13147 <lagmgr:0>
trap_api.c:2387] [software internal system syslog] Internal trap notification
1205 (LAGGroupUp) card:19, port:1, partner:(007F,64-87-88-66-F7-C0,0016)
2015-May-15+16:47:40.410 [snmp 22002 info] [1/0/13147 <lagmgr:0>
trap_api.c:2387] [software internal system syslog] Internal trap notification
1204 (LAGGroupDown) card:19, port:1, partner:(007F,64-87-88-67-87-C0,0016)
2015-May-15+16:47:40.410 [lagmgr 179050 warning] [1/0/13147 <lagmgr:0>
lagmgr_state.c:1314] [software internal system critical-info syslog] LAG group
50 (global) with master port 19/1 has changed partner
from (007F,64-87-88-67-87-C0,0016) on 17/1, 19/1, 23/1, 27/1, 29/1
to (007F,64-87-88-66-F7-C0,0016) on 18/1, 20/1, 26/1, 28/1, 30/1
[local]PDSN> show port table | grep LA 17/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 18/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 19/1 Srvc 10G Ethernet Enabled - Up - None LA~ 19/1 20/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 23/1 Srvc 10G Ethernet Enabled Up Up Active None LA* 19/1 26/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 27/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 28/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 29/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 30/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1
[local]PDSN> show port info 23/1
Port: 23/1
Port Type : 10G Ethernet
Role : Service Port
Description : Ingress-Egress Line Card
Controlled By Card : 7 (Packet Services Card 3)
Redundancy Mode : Port Mode
Framing Mode : Unspecified
Redundant With : Not Redundant
Preferred Port : Non-Revertive
Physical ifIndex : 385941504
Administrative State : Enabled
Configured Duplex : Auto
Configured Speed : Auto
Configured Flow Control : Enabled
MAC Address : 00-05-47-02-A6-96
Link State : Up
Link Duplex : Full
Link Speed : 10 Gb
Flow Control : Enabled
Link Aggregation Group : 50 (global, member)
Link Aggregation LACP : Active, Short, Auto
Link Aggregation Master : 19/1
Link Aggregation State : Agreed with LACP peer
Link Aggregation Actor : (8000,00-05-47-02-B1-97,001A,8000,1701)
Link Aggregation Peer : (007F,64-87-88-67-87-C0,0016,007F,0013)
Logical ifIndex : 385941505
Operational State : Up, Active
SFP Module : Present (10G Base SR)
[local]PDSN>show card diag 23
Card 23:
Counters:
In Service Date : Tue Aug 24 06:58:31 2010 (Estimated)
Status:
IDEEPROM Magic Number : Good
Card Diagnostics : Pass
Current Failure : None
Last Failure : None
Card Usable : Yes
Current Environment:
Temperature: Card : 48 C (limit 90 C)
Temperature: LM87 : 49 C (limit 85 C)
Temperature: PHY : 48 C (limit 90 C)
Voltage: 1.2V : 1.205 V (min 1.140 V, max 1.260 V)
Voltage: 1.2V : 1.205 V (min 1.140 V, max 1.260 V)
Voltage: 2.5V : 2.522 V (min 2.375 V, max 2.625 V)
Voltage: 3.3V : 3.285 V (min 3.135 V, max 3.465 V)
Voltage: 1.8V : 1.805 V (min 1.710 V, max 1.890 V)
The datalink counters didn't show any issues::
[local]PDSN# show port datalink counters 23/1 Counters for port 23/1: Line Card 10 Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Unicast frames 3782 | TX Unicast frames 6043 RX Multicast frames 3782 | TX Multicast frames 0 RX Broadcast frames 0 | TX Broadcast frames 0 RX Size 64 frames 0 | TX Size 64 frames 0 RX Size 65 .. 127 fr 0 | TX Size 65 .. 127 fr 6043 RX Size 128 .. 255 fr 3782 | TX Size 128 .. 255 fr 0 RX Size 256 .. 511 fr 0 | TX Size 256 .. 511 fr 0 RX Size 512 .. 1023 fr 0 | TX Size 512 .. 1023 fr 0 RX Size 1024 .. 1518 fr 0 | TX Size 1024 .. 1518 fr 0 RX Size > 1518 frames 0 | TX Size > 1518 frames 0 RX Bytes OK 483456 | TX Bytes OK 748092 RX Bytes BAD 0 | TX Bytes BAD 0 RX SHORT OK 0 | TX PAUSE 0 RX SHORT CRC 0 | TX ERR 0 RX OVF 0 | RX NORM CRC 0 | RX LONG OK 0 | RX LONG CRC 0 | RX PAUSE 0 | RX FALS CRS 0 | RX SYM ERR 0 | SPI RX LEN ERR CNT 0 | SPI TX LEN ERR CNT 0 SPI RX DIP2 ERR CNT 0 | SPI TX DIP4 ERR CNT 0 SPI RX STAT OOF ERR CNT 0 | SPI TX DATA OOF ERR CNT 0 RX MAC ERR CNT 0 | RX FIFO CORR ECC ERR 0 | TX FIFO CORR ECC ERR 0 RX FIFO UNRECOV ECC ERR 0 | TX FIFO UNRECOV ECC ERR 0 RX Disc frames 0 | TX Disc frames 0 RX Disc Bytes 0 | TX Disc Bytes 0 RX ERR frames 0 | TX ERR frames 0 RX SPI FRAME COUNT 3782 | TX SPI FRAME COUNT 6044 RX SPI LEN ERR 0 | TX SPI LEN ERR 0 RX SPI DIP 2 ERR 0 | TX SPI DIP 4 ERR 0 RX SPI STATUS OOF ERR 0 | TX SPI DATA OOF ERR 0 RX FIFO OVERFLOW 0 | TX FIFO FULL DROP 0 RX PAUSE COUNT 0 | TX DIP 4 PACKET DROP 0 SPI EOP/ABORT 0 | RX FRAGMENTS COUNT 0 | RX MAC ERR 0 | RX JABBER COUNT 0 | ----------------------- -------------- + ----------------------- -------------
The NPU counters were OK also. Here are port 23/1 counters a few seconds later and nothing bad is incrementing:
[local]PDSN# show port datalink counters 23/1 Counters for port 23/1: Line Card 10 Gigabit Ethernet Port Rx Counter Data | Tx Counter Data ----------------------- -------------- + ----------------------- ------------- RX Unicast frames 3802 | TX Unicast frames 6066 RX Multicast frames 3802 | TX Multicast frames 0 RX Broadcast frames 0 | TX Broadcast frames 0 RX Size 64 frames 0 | TX Size 64 frames 0 RX Size 65 .. 127 fr 0 | TX Size 65 .. 127 fr 6066 RX Size 128 .. 255 fr 3802 | TX Size 128 .. 255 fr 0 RX Size 256 .. 511 fr 0 | TX Size 256 .. 511 fr 0 RX Size 512 .. 1023 fr 0 | TX Size 512 .. 1023 fr 0 RX Size 1024 .. 1518 fr 0 | TX Size 1024 .. 1518 fr 0 RX Size > 1518 frames 0 | TX Size > 1518 frames 0 RX Bytes OK 486016 | TX Bytes OK 750944 RX Bytes BAD 0 | TX Bytes BAD 0 RX SHORT OK 0 | TX PAUSE 0 RX SHORT CRC 0 | TX ERR 0 RX OVF 0 | RX NORM CRC 0 | RX LONG OK 0 | RX LONG CRC 0 | RX PAUSE 0 | RX FALS CRS 0 | RX SYM ERR 0 | SPI RX LEN ERR CNT 0 | SPI TX LEN ERR CNT 0 SPI RX DIP2 ERR CNT 0 | SPI TX DIP4 ERR CNT 0 SPI RX STAT OOF ERR CNT 0 | SPI TX DATA OOF ERR CNT 0 RX MAC ERR CNT 0 | RX FIFO CORR ECC ERR 0 | TX FIFO CORR ECC ERR 0 RX FIFO UNRECOV ECC ERR 0 | TX FIFO UNRECOV ECC ERR 0 RX Disc frames 0 | TX Disc frames 0 RX Disc Bytes 0 | TX Disc Bytes 0 RX ERR frames 0 | TX ERR frames 0 RX SPI FRAME COUNT 3802 | TX SPI FRAME COUNT 6067 RX SPI LEN ERR 0 | TX SPI LEN ERR 0 RX SPI DIP 2 ERR 0 | TX SPI DIP 4 ERR 0 RX SPI STATUS OOF ERR 0 | TX SPI DATA OOF ERR 0 RX FIFO OVERFLOW 0 | TX FIFO FULL DROP 0 RX PAUSE COUNT 0 | TX DIP 4 PACKET DROP 0 SPI EOP/ABORT 0 | RX FRAGMENTS COUNT 0 | RX MAC ERR 0 | RX JABBER COUNT 0 |
But Tech support command command "show lag event" showed continuous events on port 23/1. This is the best way to see the reported issue.
[local]PDSN> show lag event
lagmgr event history [4096/4096]
May 15 18:36:57.222 50 23/01 New MUX State: DETACHED
May 15 18:36:57.222 50 23/01 SYNC cleared
May 15 18:36:57.222 50 23/01 COLL disabled
May 15 18:36:58.212 50 23/01 New MUX State: WAITING
May 15 18:36:58.223 50 23/01 LACP State Change: 0x07:ACTV:TIMO:AGGR
...
Next maintenance window, Cisco contacted and a PSC migration was done to put the card mappings back to the default mapping (so that the PSC is mapped to the Line Card physically behind it: 7 + 16 = 23), as a migration was done previous to contacting Cisco.
[local]PDSN card migrate from 16 to 7 Are you sure? [Yes|No]: yes [local]PDSN# show port table | grep LA 17/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 18/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 19/1 Srvc 10G Ethernet Enabled - Up - None LA~ 19/1 20/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 23/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 26/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 27/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 28/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 29/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 30/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 [local]PDSN# show rct stats RCT stats Details (Last 8 Actions) Action Type From To Start Time Duration ----------------- --------- ---- ---- ------------------------ ---------- Migration Planned 10 15 2015-Jan-12+07:02:33.842 32.911 sec Shutdown N/A 10 0 2015-Jan-12+07:08:35.098 0.218 sec Migration Planned 16 10 2015-Jan-12+07:19:40.842 32.451 sec Shutdown N/A 1 16 2015-Mar-19+05:00:54.430 1.368 sec Migration Planned 16 1 2015-Mar-27+06:05:48.902 19.085 sec Shutdown N/A 16 0 2015-Mar-27+06:13:00.397 0.027 sec Migration Planned 7 16 2015-May-16+07:04:51.264 37.629 sec Migration Planned 16 7 2015-May-16+08:39:48.761 Unfinished RCT stats Summary ----------------- Migrations = 5, Average time = 30.519 sec Switchovers = 0 Migration Planned 16 7 2015-May-16+08:39:48.761 43.248 sec
Sat May 16 08:40:33 2015 Internal trap notification 1257 (MigrateComplete) from card 16 to card 7
A reboot of line card 23 was performed:
[local]PDSN# card reboot 23 Are you sure? [Yes|No]: yes
Sat May 16 08:41:38 2015 Internal trap notification 4 (CardRebootRequest) card
23 type 10 Gig Ethernet Line Card
Sat May 16 08:41:44 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet
Sat May 16 08:41:44 2015 Internal trap notification 1502 (EntStateOperEnabled)
Port(23/1) Admin state:"Unlocked", Alarm severity:"No active alarm"
Sat May 16 08:41:44 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card
The port is now in a good state:
[local]PDSN# show port table | grep LA 17/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 18/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 19/1 Srvc 10G Ethernet Enabled - Up - None LA~ 19/1 20/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 23/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 26/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 27/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 28/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1 29/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1 30/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1
But the Juniper side was still having errors (no output shown here).
The issue remained unresolved on the Juniper side.
The fiber was then moved from 23/1 to 17/1 and the error stayed with 23/1 and moved to a different port on the Juniper side.
Sat May 16 08:46:28 2015 Internal trap notification 1024 (PortDown) card 17 port
1 port type 10G Ethernet Sat May 16 08:46:28 2015 Internal trap notification 93 (CardStandby) card 17
type 10 Gig Ethernet Line Card Sat May 16 08:46:31 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Sat May 16 08:46:31 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card
Sat May 16 08:46:33 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Sat May 16 08:46:33 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card Sat May 16 08:46:40 2015 Internal trap notification 1025 (PortUp) card 17 port 1
port type 10G Ethernet Sat May 16 08:46:40 2015 Internal trap notification 55 (CardActive) card 17 type
10 Gig Ethernet Line Card
The fibers were moved back to the original location and the issue was still with port 23/1 (This is all from Juniper's perspective because as mentioned above, the issue was no longer being seen on the ASR 5000 after restarting Line Card 23).
Sat May 16 08:51:53 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Sat May 16 08:51:53 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card Sat May 16 08:51:57 2015 Internal trap notification 1024 (PortDown) card 17 port
1 port type 10G Ethernet Sat May 16 08:51:57 2015 Internal trap notification 93 (CardStandby) card 17
type 10 Gig Ethernet Line Card Sat May 16 08:51:58 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Sat May 16 08:51:58 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card Sat May 16 08:51:59 2015 Internal trap notification 1025 (PortUp) card 17 port 1
port type 10G Ethernet
Sat May 16 08:51:59 2015 Internal trap notification 55 (CardActive) card 17 type
10 Gig Ethernet Line Card
Swapping the SFPs between 23/1 and 17/1 didn't change anything.
Sat May 16 08:52:50 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Sat May 16 08:52:50 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card Sat May 16 08:52:58 2015 Internal trap notification 1024 (PortDown) card 17 port
1 port type 10G Ethernet Sat May 16 08:52:59 2015 Internal trap notification 93 (CardStandby) card 17
type 10 Gig Ethernet Line Card Sat May 16 08:53:46 2015 Internal trap notification 1025 (PortUp) card 17 port 1
port type 10G Ethernet Sat May 16 08:53:46 2015 Internal trap notification 55 (CardActive) card 17 type
10 Gig Ethernet Line Card Sat May 16 08:53:53 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Sat May 16 08:53:53 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card
A reseat of line card 23/1 cleared the issue on the Juniper side.
Sat May 16 08:55:39 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Sat May 16 08:55:39 2015 Internal trap notification 35 (PortLinkDown) ifindex
385941505 adminstate Disabled operstate Down Sat May 16 08:55:39 2015 Internal trap notification 1504 (CiscoFruCardStatusChanged) FRU entity Card : 23 operational status changed to
Offline Sat May 16 08:55:39 2015 Internal trap notification 60 (CardDown) card 23 type
10 Gig Ethernet Line Card Sat May 16 08:55:39 2015 Internal trap notification 1503 (EntStateOperDisabled)
Card(23) Admin state:"Locked", Alarm severity:"Critical" Sat May 16 08:55:39 2015 Internal trap notification 140 (CardSPOFClear) card 23
type 10 Gig Ethernet Line Card Sat May 16 08:55:40 2015 Internal trap notification 84 (ServiceLossLC) Slots 23
and 39 has configured for card type 10 Gig Ethernet Line Card, but neither active
Sat May 16 08:55:41 2015 Internal trap notification 1505
(CiscoFruPowerStatusChanged) FRU entity Card : 23 Power OFF Sat May 16 08:55:41 2015 Internal trap notification 1504
(CiscoFruCardStatusChanged) FRU entity Card : 23 operational status changed to
Empty Sat May 16 08:55:41 2015 Internal trap notification 7 (CardRemoved) card 23 type
10 Gig Ethernet Line Card Sat May 16 08:55:41 2015 Internal trap notification 1507 (CiscoFruRemoved) FRU
entity Card : 23 removed Sat May 16 08:55:41 2015 Internal trap notification 1505
(CiscoFruPowerStatusChanged) FRU entity Card : 23 Power OFF Sat May 16 08:56:19 2015 Internal trap notification 1505
(CiscoFruPowerStatusChanged) FRU entity Card : 23 Power ON Sat May 16 08:56:21 2015 Internal trap notification 1504
(CiscoFruCardStatusChanged) FRU entity Card : 23 operational status changed to
Offline Sat May 16 08:56:21 2015 Internal trap notification 8 (CardInserted) card 23
type 10 Gig Ethernet Line Card Sat May 16 08:56:21 2015 Internal trap notification 1506 (CiscoFruInserted) FRU
entity Card : 23 inserted Sat May 16 08:56:23 2015 Internal trap notification 1504
(CiscoFruCardStatusChanged) FRU entity Card : 23 operational status changed to
Ready Sat May 16 08:56:23 2015 Internal trap notification 5 (CardUp) card 23 type 10
Gig Ethernet Line Card Sat May 16 08:56:23 2015 Internal trap notification 1502 (EntStateOperEnabled)
Card(23) Admin state:"Unlocked", Alarm severity:"No active alarm" Sat May 16 08:56:25 2015 Internal trap notification 1504 (CiscoFruCardStatusChanged) FRU entity Card : 23 operational status changed to
Active Sat May 16 08:56:25 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card Sat May 16 08:56:26 2015 Internal trap notification 1111 (ServiceLossLCClear)
Slots 23 and 39 has configured for card type 10 Gig Ethernet Line Card, one of
them is active now Sat May 16 08:56:26 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card Sat May 16 08:56:28 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Sat May 16 08:56:28 2015 Internal trap notification 1502 (EntStateOperEnabled)
Port(23/1) Admin state:"Unlocked", Alarm severity:"No active alarm" Sat May 16 08:56:28 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card
Unexplained port errors on Juniper router peered with XGLC Port 27/1 (subscriber impacting)
This next example, had many of the same troubleshooting steps applied and is worth studying. It started off with some unknown resmgr 14537 warning logs being reported along with a port 25/1 bounce, but evolved into a port 27/1 issue and increased call setup failures.
2015-May-03+05:29:21.083 [resmgr 14537 warning] [8/0/4643 <rmmgr:80>
_resource_cpu.c:4974] [software internal system critical-info syslog] The CPU
8/0's network i/f cpeth0 is receiving 803.7 Mbit/sec over the past 5 min.
The port utilization was uneven on port 27/1:
[local]PDSN# show port utilization table
Monday May 04 17:49:02 UTC 2015
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 1058 1049 1034 1050 1022 1042
20/1 10G Ethernet 0 0 0 0 0 0
23/1 10G Ethernet 1108 1064 1114 1033 1102 1032
26/1 10G Ethernet 0 0 0 0 0 0
27/1 10G Ethernet 1002 2472 989 2456 981 2440
28/1 10G Ethernet 0 0 0 0 0 0
On the Juniper MX-960 side of the PDSN interface in question, the input errors were steadily increasing:
show interfaces xe-0/1/2 extensive | grep Error
BPDU Error: None, MAC-REWRITE Error: None, Loopback: None,
Input errors:
Errors: 2432742, Drops: 0, Framing errors: 0, Runts: 0, Policed discards: 0,
L3 incompletes: 2432742, L2 channel errors: 0, L2 mismatch timeouts: 0,
FIFO errors: 0, Resource errors: 0
Output errors:
Carrier transitions: 1, Errors: 0, Drops: 0, Collisions: 0, Aged packets: 0,
FIFO errors: 0, HS link CRC errors: 0, MTU errors: 0, Resource errors: 0
Bit errors 0
Errored blocks 1
CRC/Align errors 0 0
FIFO errors 0 0
Total errors 0 0
Output packet error count 0
{master}
show interfaces xe-0/1/2 extensive | grep Error
BPDU Error: None, MAC-REWRITE Error: None, Loopback: None,
Input errors:
Errors: 2432851, Drops: 0, Framing errors: 0, Runts: 0, Policed discards: 0,
L3 incompletes: 2432851, L2 channel errors: 0, L2 mismatch timeouts: 0,
FIFO errors: 0, Resource errors: 0
Output errors:
Carrier transitions: 1, Errors: 0, Drops: 0, Collisions: 0, Aged packets: 0,
FIFO errors: 0, HS link CRC errors: 0, MTU errors: 0, Resource errors: 0
Bit errors 0
Errored blocks 1
CRC/Align errors 0 0
FIFO errors 0 0
Total errors 0 0
Output packet error count 0
The ports on the PDSN were cleaned and as a result there was a LAG switchover and the port imbalance went away on the newly active (even numbered) ports along with the errors on the Juniper side stopping. Previsously seen CHAP and LCP errors related to Mobile IP call setups also stopped.
[local]PDSN# show port utilization table
Thursday May 07 15:27:46 UTC 2015
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- ---
19/1 10G Ethernet 0 0 0 0 0 0
20/1 10G Ethernet 908 875 901 879 904 884
23/1 10G Ethernet 0 0 0 0 0 0
26/1 10G Ethernet 916 857 922 856 929 861
27/1 10G Ethernet 0 0 0 0 0 0
28/1 10G Ethernet 835 883 838 880 844 889
37/1 1000 Ethernet 0 0 0 0 0 0
[local]PDSN# show port table
Thursday May 07 15:22:11 UTC 2015
Port Role Type Admin Oper Link State Pair Redundant
----- ---- ------------------------ -------- ---- ---- ------- ----- ----
19/1 Srvc 10G Ethernet Enabled - Up - None LA~ 19/1
20/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1
21/1 Srvc 1000 Ethernet Enabled - Up - 37/1 L2 Link
23/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1
24/1 Mgmt 1000 Ethernet Dual Media Enabled Up Up Active 25/1 L2 Link
24/2 Mgmt 1000 Ethernet Dual Media Disabled Down Down Active 25/2 L2 Link
24/3 Mgmt RS232 Serial Console Enabled Down Down Active 25/3 L2 Link
24/4 Mgmt BITS T1/E1 Timing Disabled Down Down Active 25/4 L2 Link
25/1 Mgmt 1000 Ethernet Dual Media Enabled Down Up Standby 24/1 L2 Link
25/2 Mgmt 1000 Ethernet Dual Media Disabled Down Down Standby 24/2 L2 Link
25/3 Mgmt RS232 Serial Console Enabled Down Down Standby 24/3 L2 Link
25/4 Mgmt BITS T1/E1 Timing Disabled Down Down Standby 24/4 L2 Link
26/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1
27/1 Srvc 10G Ethernet Enabled Up Up Active None LA~ 19/1
28/1 Srvc 10G Ethernet Enabled Up Up Active None LA+ 19/1
37/1 Srvc 1000 Ethernet Enabled - Up - 21/1 L2 Link
After resetting the port statistics and failing the LAG back to the odd ports, the input errors on the Juniper began increasing again. Since the path had already been cleaned it was decided to bypass the entire existing path completely, replacing both SFPs (port 0/1/2 on the Juniper and port 27/1 on the PDSN) and running a fiber directly between the nodes. Once traffic was returned to the odd LAG the input errors continued to increment exactly as had been witnessed with the existing path. The port utilization also went back to imbalanced on port 27.
show interfaces xe-0/1/2 extensive | grep Error
BPDU Error: None, MAC-REWRITE Error: None, Loopback: None,
Input errors:
Errors: 2898, Drops: 0, Framing errors: 114, Runts: 0, Policed discards: 0,
L3 incompletes: 2784, L2 channel errors: 0, L2 mismatch timeouts: 0,
FIFO errors: 0, Resource errors: 0
As both SFPs and the fiber were completely new and the path was a straight shot between the nodes, it would seem the input errors are starting upstream of the fibers, possibly in the PDSN XCLC 27. Traffic was failed back to the even ports to stop impact for the time being before deciding on next steps. Juniper did confirm bad IPv4/IPv6 packets from ASR port 27.
On a later maintenance window, the fibers were swapped between ports 23 and 27:
Mon May 11 05:33:52 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Mon May 11 05:33:52 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card Mon May 11 05:34:12 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 05:34:12 2015 Internal trap notification 93 (CardStandby) card 27
type 10 Gig Ethernet Line Card Mon May 11 05:34:13 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernetalarm" Mon May 11 05:34:13 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card Mon May 11 05:34:14 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 05:34:14 2015 Internal trap notification 93 (CardStandby) card 27
type 10 Gig Ethernet Line Card Mon May 11 05:34:20 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 05:34:21 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card Mon May 11 05:34:58 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Mon May 11 05:34:58 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card
And after a LAG switchover port 27 continued to send errors and port imbalance.
Mon May 11 05:37:20 2015 Internal trap notification 1204 (LAGGroupDown) card:19,
port:1, partner:(007F,2C-21-72-5E-57-C0,0016) Mon May 11 05:37:20 2015 Internal trap notification 1205 (LAGGroupUp) card:19,
port:1, partner:(007F,2C-21-72-1A-B7-C0,0016) [local]NWBLWICZPN2 DO-PDSN> show port utilization table
Monday May 11 05:40:06 UTC 2015
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Txx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- ----
19/1 10G Ethernet 357 386 137 138 45 46
20/1 10G Ethernet 0 0 178 168 314 301
23/1 10G Ethernet 346 349 173 185 57 61
26/1 10G Ethernet 0 0 197 189 324 316
27/1 10G Ethernet 404 1921 147 701 49 233
28/1 10G Ethernet 0 0 207 226 299 318 Mon May 11 05:40:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 05:41:05 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 05:41:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 05:42:05 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 05:49:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 05:50:04 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 05:52:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 05:53:05 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 05:54:29 2015 Internal trap notification 1204 (LAGGroupDown) card:19,
port:1, partner:(007F,2C-21-72-1A-B7-C0,0016) Mon May 11 05:54:29 2015 Internal trap notification 1205 (LAGGroupUp) card:19,
port:1, partner:(007F,2C-21-72-5E-57-C0,0016)
The fibers were swapped back:
Mon May 11 05:59:38 2015 Internal trap notification 1024 (PortDown) card 23 port
1 port type 10G Ethernet Mon May 11 05:59:38 2015 Internal trap notification 93 (CardStandby) card 23
type 10 Gig Ethernet Line Card Mon May 11 05:59:43 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 05:59:43 2015 Internal trap notification 93 (CardStandby) card 27
type 10 Gig Ethernet Line Card Mon May 11 05:59:46 2015 Internal trap notification 1025 (PortUp) card 23 port 1
port type 10G Ethernet Mon May 11 05:59:46 2015 Internal trap notification 55 (CardActive) card 23 type
10 Gig Ethernet Line Card Mon May 11 05:59:54 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 05:59:54 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card
XCLC 27 was reseated:
Mon May 11 06:02:02 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 06:02:02 2015 Internal trap notification 60 (CardDown) card 27 type
10 Gig Ethernet Line Card Mon May 11 06:02:04 2015 Internal trap notification 7 (CardRemoved) card 27 type
10 Gig Ethernet Line Card Mon May 11 06:03:04 2015 Internal trap notification 8 (CardInserted) card 27
type 10 Gig Ethernet Line Card Mon May 11 06:03:06 2015 Internal trap notification 5 (CardUp) card 27 type 10
Gig Ethernet Line Card Mon May 11 06:03:08 2015 Internal trap notification 55 (CardActive) card 27 type 10 Gig Ethernet Line Card Mon May 11 06:03:09 2015 Internal trap notification 93 (CardStandby) card 27
type 10 Gig Ethernet Line Card Mon May 11 06:03:11 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 06:03:11 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card
The LAG was made active again and the issue was still seen.
Mon May 11 06:08:21 2015 Internal trap notification 1204 (LAGGroupDown) card:19,
port:1, partner:(007F,2C-21-72-5E-57-C0,0016) Mon May 11 06:08:21 2015 Internal trap notification 1205 (LAGGroupUp) card:19,
port:1, partner:(007F,2C-21-72-1A-B7-C0,0016) Mon May 11 06:12:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 06:13:04 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 06:14:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 06:15:05 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225 Mon May 11 06:15:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 06:16:07 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225
A PSC migration of PSC 11 (resides behind Line Card 27) to 16 clears the issue as the LAG switches to even ports (expected).
Mon May 11 06:26:03 2015 Internal trap notification 1256 (MigrateStart) from
card 11 to card 16 Mon May 11 06:26:40 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 06:26:40 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card Mon May 11 06:26:41 2015 Internal trap notification 55 (CardActive) card 16 type
Packet Services Card 3 Mon May 11 06:26:41 2015 Internal trap notification 55 (CardActive) card 40 type
Redundancy Crossbar Card Mon May 11 06:26:41 2015 Internal trap notification 55 (CardActive) card 41 type
Redundancy Crossbar Card Mon May 11 06:26:41 2015 Internal trap notification 60 (CardDown) card 11 type
Packet Services Card 3 Mon May 11 06:26:42 2015 Internal trap notification 1257 (MigrateComplete) from
card 11 to card 16 Mon May 11 06:26:42 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 06:27:55 2015 Internal trap notification 5 (CardUp) card 11 type
Packet Services Card 3 Mon May 11 06:27:55 2015 Internal trap notification 93 (CardStandby) card 11
type Packet Services Card 3
PSC 11 was reseated and then rebooted (latter should be unecessary)
Mon May 11 06:39:48 2015 Internal trap notification 60 (CardDown) card 11 type
Packet Services Card 3 Mon May 11 06:40:00 2015 Internal trap notification 7 (CardRemoved) card 11 type
Packet Services Card 3 Mon May 11 06:40:42 2015 Internal trap notification 13 (CardMismatch) card 11
type Unknown Card (0x00000000) Mon May 11 06:40:45 2015 Internal trap notification 8 (CardInserted) card 11
type Packet Services Card 3 Mon May 11 06:44:57 2015 Internal trap notification 4 (CardRebootRequest) card
11 type Packet Services Card 3 Mon May 11 06:46:44 2015 Internal trap notification 7 (CardRemoved) card 11 type
Packet Services Card 3 Mon May 11 06:46:59 2015 Internal trap notification 8 (CardInserted) card 11
type Packet Services Card 3 Mon May 11 06:50:20 2015 Internal trap notification 5 (CardUp) card 11 type
Packet Services Card 3 Mon May 11 06:50:20 2015 Internal trap notification 93 (CardStandby) card 11
type Packet Services Card 3
Migration was done back to PSC 11 and the issue started again. The problem had been seemingly isolated to PSC 11 connected to XGLC 27.
Mon May 11 06:51:55 2015 Internal trap notification 1256 (MigrateStart) from
card 16 to card 11 Mon May 11 06:52:37 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 06:52:37 2015 Internal trap notification 93 (CardStandby) card 40
type Redundancy Crossbar Card Mon May 11 06:52:37 2015 Internal trap notification 93 (CardStandby) card 41
type Redundancy Crossbar Card Mon May 11 06:52:37 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card Mon May 11 06:52:38 2015 Internal trap notification 55 (CardActive) card 11 type
Packet Services Card 3 Mon May 11 06:52:38 2015 Internal trap notification 60 (CardDown) card 16 type
Packet Services Card 3 Mon May 11 06:52:38 2015 Internal trap notification 1257 (MigrateComplete) from
card 16 to card 11 Mon May 11 06:52:38 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 06:53:42 2015 Internal trap notification 39 (AAAAuthSvrUnreachable)
server 1 ip address 209.165.200.225 Mon May 11 06:53:52 2015 Internal trap notification 5 (CardUp) card 16 type
Packet Services Card 3 Mon May 11 06:53:52 2015 Internal trap notification 93 (CardStandby) card 16 type Packet Services Card 3 Mon May 11 06:54:07 2015 Internal trap notification 40 (AAAAuthSvrReachable)
server 1 ip address 209.165.200.225
A Migration was done back to PSC 16 to clear the issue for the time being until an RMA replacement:
Mon May 11 06:56:07 2015 Internal trap notification 1256 (MigrateStart) from
card 11 to card 16 Mon May 11 06:56:43 2015 Internal trap notification 1024 (PortDown) card 27 port
1 port type 10G Ethernet Mon May 11 06:56:43 2015 Internal trap notification 55 (CardActive) card 27 type
10 Gig Ethernet Line Card Mon May 11 06:56:44 2015 Internal trap notification 55 (CardActive) card 16 type
Packet Services Card 3 Mon May 11 06:56:44 2015 Internal trap notification 55 (CardActive) card 40 type
Redundancy Crossbar Card Mon May 11 06:56:44 2015 Internal trap notification 55 (CardActive) card 41 type
Redundancy Crossbar Card Mon May 11 06:56:44 2015 Internal trap notification 60 (CardDown) card 11 type
Packet Services Card 3 Mon May 11 06:56:44 2015 Internal trap notification 1257 (MigrateComplete) from
card 11 to card 16 Mon May 11 06:56:44 2015 Internal trap notification 1025 (PortUp) card 27 port 1
port type 10G Ethernet Mon May 11 06:57:58 2015 Internal trap notification 5 (CardUp) card 11 type
Packet Services Card 3 [local]PDSN> show rct stats Monday May 11 07:08:26 UTC 2015 RCT stats Details (Last 4 Actions) Action Type From To Start Time Duration ----------------- --------- ---- ---- ------------------------ ----------
Migration Planned 11 16 2015-May-11+06:26:04.373 36.453 sec Shutdown N/A 11 0 2015-May-11+06:39:48.153 0.223 sec Migration Planned 16 11 2015-May-11+06:51:55.785 41.630 sec Migration Planned 11 16 2015-May-11+06:56:08.452 35.037 sec RCT stats Summary ----------------- Migrations = 3, Average time = 37.707 sec Switchovers = 0 [local]PDSN> show card mappings Monday May 11 07:10:22 UTC 2015 Slot Mapping Slot ----------------------------------- -------------- -------------------------- 17 None - 18 None - 19 10 Gig Ethernet Line Card <-- direct --> 3 Packet Services Card 3 20 10 Gig Ethernet Line Card <-- direct --> 4 Packet Services Card 3 21 1000 Ethernet Line Card <-- direct --> 5 Packet Services Card 3 22 None - 23 10 Gig Ethernet Line Card <-- direct --> 7 Packet Services Card 3 24 Switch Processor I/O Card <------------> 8 System Management Card 25 Switch Processor I/O Card <------------> 8 System Management Card 26 10 Gig Ethernet Line Card <-- direct --> 10 Packet Services Card 3 27 10 Gig Ethernet Line Card <--- RCCs ---> 16 Packet Services Card 3 28 10 Gig Ethernet Line Card <-- direct --> 12 Packet Services Card 3
But the RMA still did not resolve the issue.
[local]PDSN# show port utilization table verbose
Tuesday May 12 06:04:57 UTC 2015
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 333.497 331.132 345.255 347.328 354.989 358.539
20/1 10G Ethernet 0.003 0.000 0.003 0.000 0.003 0.000
23/1 10G Ethernet 361.103 334.488 353.180 354.668 363.226 363.388
26/1 10G Ethernet 0.002 0.000 0.002 0.000 0.002 0.000
27/1 10G Ethernet 309.096 1897 335.379 1892 339.740 890
28/1 10G Ethernet 0.003 0.000 0.003 0.000 0.003 0.000
37/1 1000 Ethernet 0.014 0.005 0.014 0.018 0.014 0.016
It required a chassis reload to finally resolve the issue. No root cause was ever determined. But, the point here is the troubleshooting steps taken to attempt to resolve the issue finally worked with a reload. Sometimes the results are not what originally are expected based on the troubleshooting steps taken. It was thought that the RMA was for sure going to finally solve the issue but it did not. Nonetheless the proper steps to eliminate potential culprits were taken.
LAG switchover failed to stick due to failed XGLC
A LAG switchover odd to even ports (19, 23, 27 => 20, 26, 28) would not hold and would switch back within a minute. That could imply a problem with one or more of the LAG ports not being able to maintain the connection. Note the decrease in port utilization, but the dataset is limited because of the short time the even ports would stay active:
[XGWout]XGW# show port util table
Thursday April 26 07:17:31 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 895 907 906 931 939 983
20/1 10G Ethernet 0 0 20 14 6 4
21/1 1000 Ethernet 0 0 0 3 0 3
22/1 1000 Ethernet 3 46 3 46 3 47
23/1 10G Ethernet 948 946 883 917 918 956
26/1 10G Ethernet 0 0 16 11 5 3
27/1 10G Ethernet 949 950 989 934 1029 955
28/1 10G Ethernet 0 0 4 14 1 4
[XGWout]XGW# link-aggregation port switch to 20/1
Thursday April 26 07:20:20 UTC 2012
Are you sure? [Yes|No]: yes
Thursday April 26 07:20:22 UTC 2012
2012-Apr-26+07:20:22.826 [lagmgr 179050 warning] [1/0/2337 <lagmgr:0>
lagmgr_state.c:1163] [software internal system critical-info syslog] LAG group
50 (global) with master port 19/1 has changed partner from (007F,00-26-88-8E-
4F-F0,0034) to (007F,00-26-88-A7-FF-F0,0034)
Apr 26 07:21:28 kslxmsce2.msc.vzwnet.com evlogd: [local-60sec28.393]
[lagmgr 179050 warning] [1/0/2337 <lagmgr:0> lagmgr_state.c:1163]
[software internal system critical-info syslog] LAG group 50 (global)
with master port 19/1 has changed partner from
(007F,00-26-88-A7-FF-F0,0034) to (007F,00-26-88-8E-4F-F0,0034)
[XGWout]XGW# show port util table
Thursday April 26 07:20:46 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 896 917 927 965
20/1 10G Ethernet 678 526 45 33 15 11
21/1 1000 Ethernet 0 0 0 3 0 3
22/1 1000 Ethernet 3 45 3 46 3 46
23/1 10G Ethernet 0 0 881 898 903 943
26/1 10G Ethernet 627 442 16 11 5 3
27/1 10G Ethernet 0 0 874 850 980 914
28/1 10G Ethernet 138 436 15 47 5 15
[XGWout]XGW# show port util table
Thursday April 26 07:24:58 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 847 911 742 719 860 874
20/1 10G Ethernet 0 0 137 104 52 39
21/1 1000 Ethernet 0 0 0 4 0 4
22/1 1000 Ethernet 3 48 3 47 3 47
23/1 10G Ethernet 840 804 710 718 837 862
26/1 10G Ethernet 0 0 133 95 50 35
27/1 10G Ethernet 833 814 671 697 883 856
28/1 10G Ethernet 0 0 33 92 12 35
In order to troubleshoot further, one of the LAG ports (27/1) was disabled, forcing the LAG switchover to remain in place and not switch back (the system will not switchover unless the ports to switch over to have a higher capacity than the currently active ports). As can be seen below, the port utilization goes down significantly on the EVEN ports. When the port 27/1 is re-enabled, the LAG switches back to the odd ports without intervention due to the EVEN ports having more capacity.
[local]XGW# show port util table
Thursday April 26 08:53:47 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 670 639 654 609 590 556
20/1 10G Ethernet 0 0 0 0 0 0
21/1 1000 Ethernet 0 20 0 3 0 2
22/1 1000 Ethernet 3 41 3 40 7 83
23/1 10G Ethernet 598 676 574 662 535 585
26/1 10G Ethernet 0 0 0 0 0 0
27/1 10G Ethernet 662 612 658 608 611 585
28/1 10G Ethernet 0 0 0 0 0 0
[local]XGW(config)# port ether 27/1
Thursday April 26 08:53:58 UTC 2012
[local]XGW(config-port-27/1)# shut
Thursday April 26 08:54:02 UTC 2012
Thu Apr 26 08:54:02 2012 Internal trap notification 35 (PortLinkDown) card 27
port 1 ifindex 453050368
Thu Apr 26 08:54:02 2012 Internal trap notification 1024 (PortDown) card 27 port 1 ifindex 453050368port type 10G Ethernet
Thu Apr 26 08:54:02 2012 Internal trap notification 93 (CardStandby) card 27
[local]XGW# show port util table
Thursday April 26 08:54:26 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 634 596 625 591
20/1 10G Ethernet 371 278 27 19 9 6
21/1 1000 Ethernet 0 0 0 3 0 2
22/1 1000 Ethernet 3 39 3 40 3 86
23/1 10G Ethernet 0 0 573 654 572 627
26/1 10G Ethernet 346 268 0 0 0 0
28/1 10G Ethernet 107 233 0 0 0 0
[local]XGW# show port util table
Thursday April 26 08:57:11 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 375 349 552 520
20/1 10G Ethernet 445 342 203 156 67 52
21/1 1000 Ethernet 0 0 0 3 0 2
22/1 1000 Ethernet 4 50 3 42 3 40
23/1 10G Ethernet 0 0 223 260 465 515
26/1 10G Ethernet 390 323 215 169 71 56
28/1 10G Ethernet 214 302 84 148 28 49
[local]XGW# show port util table
Thursday April 26 09:00:18 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 0 0 428 401
20/1 10G Ethernet 414 339 410 320 145 113
21/1 1000 Ethernet 0 0 0 2 0 3
22/1 1000 Ethernet 4 56 3 48 3 42
23/1 10G Ethernet 0 0 0 0 345 391
26/1 10G Ethernet 373 307 391 312 147 117
28/1 10G Ethernet 244 287 203 292 71 106
[local]XGW# show port util table
Thursday April 26 09:08:33 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 0 0 37 36
20/1 10G Ethernet 346 302 394 315 358 284
21/1 1000 Ethernet 0 11 0 4 0 3
22/1 1000 Ethernet 4 86 4 80 4 59
23/1 10G Ethernet 0 0 0 0 36 41
26/1 10G Ethernet 331 278 354 307 339 281
28/1 10G Ethernet 252 253 245 273 203 255
[local]XGW# config
Thursday April 26 09:08:43 UTC 2012
[local]XGW(config)# port ether 27/1
Thursday April 26 09:08:49 UTC 2012
[local]XGW(config-port-27/1)# no shut
Thursday April 26 09:08:53 UTC 2012
Thu Apr 26 09:08:53 2012 Internal trap notification 55 (CardActive) card 27
Thu Apr 26 09:08:53 2012 Internal trap notification 36 (PortLinkUp) card 27 port
1 ifindex 453050369
Thu Apr 26 09:08:53 2012 Internal trap notification 1025 (PortUp) card 27 port 1
ifindex 453050369port type 10G Ethernet
[local]XGW# show port util table
Thursday April 26 09:10:11 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 698 656 0 0 0 0
20/1 10G Ethernet 0 0 370 300 395 315
21/1 1000 Ethernet 0 0 0 3 0 3
22/1 1000 Ethernet 3 85 4 88 4 66
23/1 10G Ethernet 618 702 0 0 0 0
26/1 10G Ethernet 0 0 310 270 357 298
27/1 10G Ethernet 681 624 44 36 14 12
28/1 10G Ethernet 0 0 235 251 227 27
It is not obvious over which port the problem exists, and the Tx utilization is not that uneven.
"show port npu counters" clearly show a problem with error counter "Bad IPv4 header" increasing at a high rate (and it shouldn't be happening at all), but due to this being a LAG implementation, based on the current implementation, all the counters are cummulative for all the LAG ports in a LAG group, and so it cannot be determined which port is having the problem - it could be any of them. (the stats for all ports combined are found under the master port, in this case 19/1 - stats on all individual LAG ports of the LAG group have NO meaning and should be ignored).
But, tech support command "show npu stats debug all_pacs" captures NPU stats on a PSC basis, and the following shows that the problem is clearly "associated with" PSC 12 and its (default) connected XGLC 28:
******** show npu stats debug all_pacs *******
Thursday April 26 09:01:41 UTC 2012
Line 524176: debug-pkt-drop-invalid-iphdr 3601919
Line 524245: debug-pkt-drop-invalid-iphdr 265
Line 524303: debug-pkt-drop-invalid-iphdr 141
Line 524407: debug-pkt-drop-invalid-iphdr 3468928
Line 524471: debug-pkt-drop-invalid-iphdr 216
Line 524529: debug-pkt-drop-invalid-iphdr 3701708
Line 524595: debug-pkt-drop-invalid-iphdr 6501414 <= NPU debug
stats for slot 12
******** show port npu counters *******
Thursday April 26 09:01:40 UTC 2012
Counters for port 19/1
Counter Rx Frames Rx Bytes Tx Frames Tx Bytes
-------------------- ------------- --------------- ------------- ---------------
Bad IPv4 header 6493067 2820637429 n/a n/a
******** show npu stats debug all_pacs *******
Thursday April 26 09:03:36 UTC 2012
Line 985303: debug-pkt-drop-invalid-iphdr 3601919
Line 985372: debug-pkt-drop-invalid-iphdr 292
Line 985430: debug-pkt-drop-invalid-iphdr 141
Line 985534: debug-pkt-drop-invalid-iphdr 3468928
Line 985598: debug-pkt-drop-invalid-iphdr 226
Line 985656: debug-pkt-drop-invalid-iphdr 3701708
Line 985722: debug-pkt-drop-invalid-iphdr 7190387 <= NPU debug
stats for slot 12 (INCREASING)
******** show port npu counters *******
Thursday April 26 09:03:35 UTC 2012
Counters for port 19/1
Counter Rx Frames Rx Bytes Tx Frames Tx Bytes
-------------------- ------------- --------------- ------------- ---------------
Bad IPv4 header 7182088 3089244876 n/a n/a
The question still becomes what card is actually causing this issue, the PSC 12 connected to XGLC 28, or XGLC 28 itself?
Typically NPU problems would be resolved with a PSC migration of the PSC 12 connected to XGLC 28, implying an issue with the PSC. When this was attempted on a later maintenance window, it failed to resolve the issue, as did a Line Card reset as well as an npumgr reset.
Here is the troubleshooting output of npumgr reset, XGLC 28 reset, and PSC migration 12 to 16, the latter of which results in PSC 16 being connected to XGLC 28 and so eliminates PSC 12 being the issue. Checks for debug-pkt-drop-invalid-iphdr increasing were done in between each of the steps to confirm that the issue was not resolved. Shutdown of one of the LAG ports (27/1) was done to force a LAG swtichover to remain switched over for data collection purposes, and a no shut allowed for the LAG to switch back when done testing.
[local]XGW# show port util table
Saturday April 28 05:03:49 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 2311 2395 2384 2415 2384 2402
20/1 10G Ethernet 0 0 0 0 0 0
21/1 1000 Ethernet 0 9 0 9 0 9
22/1 1000 Ethernet 4 70 4 77 4 73
23/1 10G Ethernet 2230 2224 2222 2293 2202 2268
26/1 10G Ethernet 0 0 0 0 0 0
27/1 10G Ethernet 2496 2433 2505 2427 2440 2381
28/1 10G Ethernet 0 0 0 0 0 0
[local]XGW(config)# port ether 27/1
Saturday April 28 05:04:44 UTC 2012
[local]XGW(config-port-27/1)# shutdown
Saturday April 28 05:04:50 UTC 2012
Sat Apr 28 05:04:50 2012 Internal trap notification 35 (PortLinkDown) card 27
port 1 ifindex 453050368
Sat Apr 28 05:04:50 2012 Internal trap notification 1024 (PortDown) card 27 port
1 ifindex 453050368port type 10G Ethernet
Sat Apr 28 05:04:50 2012 Internal trap notification 93 (CardStandby) card 27
[local]XGW# show port table all
Saturday April 28 05:04:59 UTC 2012
Port Type Admin Oper Link State Redundant
----- ------------------------ -------- ---- ---- ---------------- -----------
19/1 10G Ethernet Enabled - Up - None ~19/1
Untagged Enabled Up - Active -
20/1 10G Ethernet Enabled Up Up Active None +19/1
[local]XGW# show port util table
Saturday April 28 05:05:42 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 2150 2182 2311 2333
20/1 10G Ethernet 1488 1064 0 0 0 0
21/1 1000 Ethernet 0 0 0 9 0 10
22/1 1000 Ethernet 4 70 4 72 4 73
23/1 10G Ethernet 0 0 2163 2225 2182 2251
26/1 10G Ethernet 1353 989 94 68 31 22
28/1 10G Ethernet 372 1042 14 41 4 13
[local]XGW# show npu stats debug all-pacs
Saturday April 28 05:07:28 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 10786357
[local]XGW# show npu stats debug all-pacs
Saturday April 28 05:07:47 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 10966718
[local]XGW# task kill facility npumgr instance 12
Saturday April 28 05:33:18 UTC 2012
Sat Apr 28 05:33:18 2012 Internal trap notification 73 (ManagerFailure) facility
npumgr instance 12 card 12 cpu 1
Sat Apr 28 05:33:18 2012 Internal trap notification 150 (TaskFailed) facility
npumgr instance 12 on card 12 cpu 1
Sat Apr 28 05:33:26 2012 Internal trap notification 35 (PortLinkDown) card 28
port 1 ifindex 469827585
Sat Apr 28 05:33:26 2012 Internal trap notification 1024 (PortDown) card 28 port
1 ifindex 469827585port type 10G Ethernet
Sat Apr 28 05:33:26 2012 Internal trap notification 36 (PortLinkUp) card 28 port
1 ifindex 469827585
Sat Apr 28 05:33:26 2012 Internal trap notification 1025 (PortUp) card 28 port 1
ifindex 469827585port type 10G Ethernet
[local]XGW# show port util table
Saturday April 28 05:34:24 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 0 0 0 0
20/1 10G Ethernet 894 723 837 661 935 728
21/1 1000 Ethernet 0 36 0 7 0 7
22/1 1000 Ethernet 4 127 4 78 4 79
23/1 10G Ethernet 0 0 0 0 0 0
26/1 10G Ethernet 906 647 780 571 865 644
28/1 10G Ethernet 356 649 0 0 0 0
[local]XGW# show npu stats debug slot 12
Saturday April 28 05:35:16 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 540273
[local]XGW# show npu stats debug slot 12
Saturday April 28 05:35:38 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 692665
Sat Apr 28 05:38:49 2012 Internal trap notification 35 (PortLinkDown) card 28
port 1 ifindex 469827584
Sat Apr 28 05:38:49 2012 Internal trap notification 1024 (PortDown) card 28 port
1 ifindex 469827584port type 10G Ethernet
Sat Apr 28 05:38:49 2012 Internal trap notification 35 (PortLinkDown) card 28
port 1 ifindex 469827585
Sat Apr 28 05:38:49 2012 Internal trap notification 60 (CardDown) card 28
Sat Apr 28 05:38:51 2012 Internal trap notification 5 (CardUp) card 28
Sat Apr 28 05:38:51 2012 Internal trap notification 4 (CardRebootRequest) card 28
Sat Apr 28 05:38:51 2012 Internal trap notification 84 (ServiceLossLC) Slots 28
and 44 has configured for card type 10 Gig Ethernet
Line Card, but neither active
Sat Apr 28 05:38:53 2012 Internal trap notification 55 (CardActive) card 28
Sat Apr 28 05:38:53 2012 Internal trap notification 1111 (ServiceLossLCClear)
Slots 28 and 44 has configured for card type 10 Gig Et
hernet Line Card, one of them is active now
Sat Apr 28 05:38:53 2012 Internal trap notification 93 (CardStandby) card 28
Sat Apr 28 05:38:55 2012 Internal trap notification 36 (PortLinkUp) card 28 port
1 ifindex 469827584
Sat Apr 28 05:38:55 2012 Internal trap notification 1025 (PortUp) card 28 port 1
ifindex 469827584port type 10G Ethernet
Sat Apr 28 05:38:55 2012 Internal trap notification 55 (CardActive) card 28
Sat Apr 28 05:38:55 2012 Internal trap notification 36 (PortLinkUp) card 28 port
1 ifindex 469827585
Sat Apr 28 05:38:55 2012 Internal trap notification 1025 (PortUp) card 28 port 1
ifindex 469827585port type 10G Ethernet
[local]XGW# show port util table
Saturday April 28 05:39:47 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 0 0 0 0
20/1 10G Ethernet 236 174 688 544 816 637
21/1 1000 Ethernet 0 17 0 7 0 7
22/1 1000 Ethernet 3 29 3 69 4 75
23/1 10G Ethernet 0 0 0 0 0 0
26/1 10G Ethernet 201 156 779 568 810 597
28/1 10G Ethernet 114 181 0 0 0 0
[local]XGW# show npu stats debug slot 12
Saturday April 28 05:40:04 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 2219078
[local]XGW# show npu stats debug slot 12
Saturday April 28 05:40:15 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 2289375
[local]XGW# show port util table
Saturday April 28 05:41:08 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 0 0 0 0
20/1 10G Ethernet 769 545 682 528 804 625
21/1 1000 Ethernet 0 0 0 6 0 6
22/1 1000 Ethernet 3 70 3 63 4 73
23/1 10G Ethernet 0 0 0 0 0 0
26/1 10G Ethernet 723 560 634 480 760 561
28/1 10G Ethernet 317 585 81 141 27 47
[local]XGW# show npu stat debug slot 12 clear
Saturday April 28 05:41:59 UTC 2012
NPU debug stats for slot 12
debug-pkt-drop-invalid-iphdr 2980554
[local]XGW# show npu stat debug slot 12 clear
Saturday April 28 05:42:10 UTC 2012
debug-pkt-drop-invalid-iphdr 60103
Sat Apr 28 05:42:43 2012 Internal trap notification 16 (PACMigrateStart) from
card 12 to card 16
Sat Apr 28 05:43:55 2012 Internal trap notification 17 (PACMigrateComplete) from
card 12 to card 16
Sat Apr 28 05:44:45 2012 Internal trap notification 5 (CardUp) card 12
Sat Apr 28 05:44:45 2012 Internal trap notification 93 (CardStandby) card 12
[local]XGW# show npu stat debug slot 16 clear
Saturday April 28 05:44:35 UTC 2012
NPU debug stats for slot 16
debug-pkt-drop-invalid-iphdr 14650
[local]XGW# show npu stat debug slot 16 clear
Saturday April 28 05:45:48 UTC 2012
NPU debug stats for slot 16
debug-pkt-drop-invalid-iphdr 70940
Sat Apr 28 05:45:20 2012 Internal trap notification 126 (SRPSwitchoverInitiated) vpn SRP ipaddr 10.209.74.164
Sat Apr 28 05:45:21 2012 Internal trap notification 121 (SRPStandby) vpn SRP
ipaddr 10.209.74.164 rtmod 2
[local]XGW(config)# port ether 27/1
Saturday April 28 05:52:27 UTC 2012
[local]XGW(config-port-27/1)# no shut
Saturday April 28 05:52:35 UTC 2012
Sat Apr 28 05:52:35 2012 Internal trap notification 36 (PortLinkUp) card 27 port
1 ifindex 453050368
Sat Apr 28 05:52:35 2012 Internal trap notification 1025 (PortUp) card 27 port 1
ifindex 453050368port type 10G Ethernet
Sat Apr 28 05:52:35 2012 Internal trap notification 55 (CardActive) card 27
Sat Apr 28 05:52:35 2012 Internal trap notification 36 (PortLinkUp) card 27 port
1 ifindex 453050369
Sat Apr 28 05:52:35 2012 Internal trap notification 1025 (PortUp) card 27 port 1
ifindex 453050369port type 10G Ethernet
[local]XGW# link-aggregation port switch to 19/1
Saturday April 28 05:56:39 UTC 2012
Are you sure? [Yes|No]: yes
Saturday April 28 05:56:42 UTC 2012
Sat Apr 28 07:09:46 2012 Internal trap notification 120 (SRPActive) vpn SRP
ipaddr 10.209.74.164 rtmod 2
[local]XGW# show card table
Saturday April 28 06:06:09 UTC 2012
Slot Card Type Oper State SPOF Attach
----------- -------------------------------- ------------- ---- ------
1: PSC Packet Services Card 2 Active No - -
2: PSC Packet Services Card 2 Active No - -
3: PSC Packet Services Card 2 Active No 19 -
4: PSC Packet Services Card 2 Active No 20 -
5: PSC Packet Services Card 2 Active No 21 37
6: PSC Packet Services Card 2 Active No 22 38
7: PSC Packet Services Card 2 Active No 23 -
8: SMC System Management Card Active No 24 25
9: SMC System Management Card Standby - - -
10: PSC Packet Services Card 2 Active No 26 -
11: PSC Packet Services Card 2 Active No 27 -
12: PSC Packet Services Card 2 Standby - - -
13: PSC Packet Services Card 2 Active No - -
14: PSC Packet Services Card 2 Active No - -
15: PSC Packet Services Card 2 Active No - -
16: PSC Packet Services Card 2 Active No 28 -
The unlikely conclusion ended up being a defective Line Card, which when replaced, resolved the issue.
Note: when XGLC 28 was replaced, the system re-attached the replacement XGLC to Demux PSC 1 instead of the previously attached PSC 16. The Card-Slot-Port task (CSP) has the right to attach an XGLC to any free PSC it desires to, in this case PSC 1 instead of PSC 16. As a result, the testing of XGLC 28 was against PSC 1 and not PSC 16 or PSC 12, but at this point based on all the testing done so far (i.e. the issue happens whether connected to PSC 12 or PSC 16), it had been concluded that the failures were due to XGLC 28 and not any PSC.
Sun Apr 29 05:17:25 2012 Internal trap notification 60 (CardDown) card 28
Sun Apr 29 05:17:25 2012 Internal trap notification 7 (CardRemoved) card 28
Sun Apr 29 05:19:56 2012 Internal trap notification 8 (CardInserted) card 28
Sun Apr 29 05:19:58 2012 Internal trap notification 5 (CardUp) card 28
Sun Apr 29 05:20:00 2012 Internal trap notification 55 (CardActive) card 28
[local]XGW# show port util table
Sunday April 29 05:23:53 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 1817 1770 1852 1868 1899 1929
20/1 10G Ethernet 0 0 0 0 0 0
21/1 1000 Ethernet 0 0 0 7 0 7
22/1 1000 Ethernet 3 55 3 58 3 59
23/1 10G Ethernet 1685 1867 1718 1858 1782 1868
26/1 10G Ethernet 0 0 0 0 0 0
27/1 10G Ethernet 1982 1866 1982 1846 2022 1927
28/1 10G Ethernet 0 0 0 0 0 0
[local]XGW# link-aggregation port switch to 20/1
Sunday April 29 05:33:18 UTC 2012
Are you sure? [Yes|No]: yes
Sunday April 29 05:33:21 UTC 2012
2012-Apr-29+05:33:21.124 [lagmgr 179050 warning] [1/0/2337 <lagmgr:0>
lagmgr_state.c:1163] [software internal system critical-info syslog] LAG group
50 (global) with master port 19/1 has changed partner from (007F,00-26-88-8E-
4F-F0,0034) to (007F,00-26-88-A7-FF-F0,0034)
[local]LENYKSCJPNR XGW# show port util table
Sunday April 29 05:34:05 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 1724 1688 1795 1783
20/1 10G Ethernet 1785 1737 112 108 37 36
21/1 1000 Ethernet 0 29 0 8 0 7
22/1 1000 Ethernet 3 55 3 56 3 57
23/1 10G Ethernet 0 0 1430 1522 1609 1720
26/1 10G Ethernet 1632 1790 89 95 29 31
27/1 10G Ethernet 0 0 1719 1669 1865 1780
28/1 10G Ethernet 1840 1738 0 0 0 0
[local]XGW# show npu stats debug slot 1
Sunday April 29 05:34:18 UTC 2012
NPU debug stats for slot 1
debug-pkt-drop-invalid-iphdr 9
[local]XGW# show card table
Sunday April 29 05:34:27 UTC 2012
Slot Card Type Oper State SPOF Attach
----------- -------------------------------- ------------- ---- ------
1: PSC Packet Services Card 2 Active No 28 -
2: PSC Packet Services Card 2 Active No - -
3: PSC Packet Services Card 2 Active No 19 -
4: PSC Packet Services Card 2 Active No 20 -
5: PSC Packet Services Card 2 Active No 21 37
6: PSC Packet Services Card 2 Active No 22 38
7: PSC Packet Services Card 2 Active No 23 -
8: SMC System Management Card Active No 24 25
9: SMC System Management Card Standby - - -
10: PSC Packet Services Card 2 Active No 26 -
11: PSC Packet Services Card 2 Active No 27 -
12: PSC Packet Services Card 2 Standby - - -
13: PSC Packet Services Card 2 Active No - -
14: PSC Packet Services Card 2 Active No - -
15: PSC Packet Services Card 2 Active No - -
16: PSC Packet Services Card 2 Active No - -
[local]LENYKSCJPNR XGW# show port npu count 28/1
Sunday April 29 05:35:39 UTC 2012
Counters for port 28/1
Counter Rx Frames Rx Bytes Tx Frames Tx Bytes
-------------------- ------------- --------------- ------------- ---------------
Bad IPv4 header 0 0 n/a n/a
[local]XGW# show npu stats debug all-pac
Sunday April 29 05:36:05 UTC 2012
NPU debug stats for slot 1
debug-pkt-drop-invalid-iphdr 32
[local]XGW# show npu stats debug all-pac | grep debug-pkt-drop-invalid-iphdr
Sunday April 29 05:36:47 UTC 2012
debug-pkt-drop-invalid-iphdr 41 <== PSC 1
debug-pkt-drop-invalid-iphdr 3722008
debug-pkt-drop-invalid-iphdr 920
debug-pkt-drop-invalid-iphdr 141
debug-pkt-drop-invalid-iphdr 3579872
debug-pkt-drop-invalid-iphdr 47
debug-pkt-drop-invalid-iphdr 3817343
[local]XGW# show port util table
Sunday April 29 05:37:52 UTC 2012
------ Average Port Utilization (in mbps) ------
Port Type Current 5min 15min
Rx Tx Rx Tx Rx Tx
----- ------------------------ ------- ------- ------- ------- ------- -------
19/1 10G Ethernet 0 0 301 297 1300 1280
20/1 10G Ethernet 1686 1603 1490 1454 496 484
21/1 1000 Ethernet 0 0 0 6 0 7
22/1 1000 Ethernet 3 53 3 55 3 55
23/1 10G Ethernet 0 0 448 475 1265 1349
26/1 10G Ethernet 1539 1692 1383 1460 461 486
27/1 10G Ethernet 0 0 252 246 1334 1288
28/1 10G Ethernet 1758 1705 1413 1390 471 463
Commentaires