ARP Age time is Zero n 6509-e

mohammad saeed · ‎03-09-2017

Hi Guys,

I have an issue related to ARP request in my network, I have CCTV Cameras and IP telephones and RCUs for Room controllers and all of them the ARP age time near to Zero! and that make my network busy for ARP process which I didn't like it hich make my Core 6509 CPU usage reach to 90-100% sometimes.

Internet 10.30.1.37 18 ccef.488d.2245 ARPA Vlan120
Internet 10.30.1.40 11 ccef.488d.2249 ARPA Vlan120
Internet 10.30.1.44 8 7081.0585.d428 ARPA Vlan120
Internet 10.30.1.46 8 7081.0585.d437 ARPA Vlan120
Internet 10.30.1.60 18 ccef.488d.82b5 ARPA Vlan120
Internet 10.30.1.61 15 ccef.488d.4a24 ARPA Vlan120
Internet 10.30.1.62 7 ccef.488d.82b0 ARPA Vlan120
Internet 10.30.1.66 16 ccef.488d.7ea1 ARPA Vlan120
Internet 10.30.1.74 9 ccef.488d.82de ARPA Vlan120
Internet 10.30.1.76 2 ccef.488d.82b4 ARPA Vlan120
Internet 10.30.1.78 17 ccef.488d.80bf ARPA Vlan120
Internet 10.30.1.86 79 ccef.488d.82db ARPA Vlan120
Internet 10.30.1.87 18 ccef.488d.80d6 ARPA Vlan120
Internet 10.30.1.88 19 ccef.488d.82cb ARPA Vlan120
Internet 10.30.1.98 11 ccef.488d.37b4 ARPA Vlan120
Internet 10.30.1.100 0 34a8.4ea7.421d ARPA Vlan120
Internet 10.30.1.101 11 ccef.488d.3a1b ARPA Vlan120

How can I solve this issue ?

Thanks for all

Mohammad

Seb Rupik · ‎03-09-2017

Hi Mohammad,

The age value you are seeing relates to the time in minutes since the entry was entered into the table. Low values are simply an indicator of a chatty device.

If the ARP entry is timed-out (default 4 hours) then it will be removed from the table.

cheers,

Seb.

mohammad saeed · ‎03-09-2017

Hi Seb.

Yes I know the ARP time-out is 4 hours but some IP addresses showed time in min: 40, 100,.... but most of the IP addresses is 0

Core_SW#show arp 10.60.131.145
Protocol Address Age (min) Hardware Addr Type Interface
Internet 10.60.131.145 0 0201.0408.032a ARPA Vlan130

I did debug command for ARP process I got ARP requist and reply always generating without stop!

Core_SW#
Mar 8 05:47:04.525: IP ARP: arp_process_request: 10.60.127.87, hw: 9002.a932.ae49; rc: 3
Mar 8 05:47:04.525: IP ARP: rcvd req src 10.60.127.87 9002.a932.ae49, dst 10.60.127.193 Vlan127
Mar 8 05:47:04.565: IP ARP: arp_process_request: 10.30.4.119, hw: 34a8.4ea7.3d3c; rc: 3
Mar 8 05:47:04.565: IP ARP: rcvd req src 10.30.4.119 34a8.4ea7.3d3c, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.565: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.4.119 34a8.4ea7.3d3c Vlan120
Mar 8 05:47:04.569: IP ARP: arp_process_request: 10.30.3.169, hw: 5478.1a1c.6c16; rc: 3
Mar 8 05:47:04.569: IP ARP: rcvd req src 10.30.3.169 5478.1a1c.6c16, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.569: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.3.169 5478.1a1c.6c16 Vlan120
Mar 8 05:47:04.597: IP ARP: arp_process_request: 10.30.4.245, hw: 34a8.4ea7.3ccc; rc: 3
Mar 8 05:47:04.597: IP ARP: rcvd req src 10.30.4.245 34a8.4ea7.3ccc, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.597: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.4.245 34a8.4ea7.3ccc Vlan120
Mar 8 05:47:04.597: IP ARP: arp_process_request: 10.30.2.144, hw: 34a8.4ea7.421c; rc: 3
Mar 8 05:47:04.597: IP ARP: rcvd req src 10.30.2.144 34a8.4ea7.421c, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.597: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.2.144 34a8.4ea7.421c Vlan120
Mar 8 05:47:04.625: IP ARP: arp_process_request: 10.60.176.2, hw: 30f7.0d31.2c00; rc: 3
Mar 8 05:47:04.625: IP ARP: rcvd req src 10.60.176.2 30f7.0d31.2c00, dst 10.60.176.1 Vlan122
Mar 8 05:47:04.625: IP ARP: sent rep src 10.60.176.1 c8f9.f959.a140,
dst 10.60.176.2 30f7.0d31.2c00 Vlan122
Mar 8 05:47:04.673: IP ARP: arp_process_request: 10.60.1.110, hw: 0050.56ab.1cd1; rc: 3
Mar 8 05:47:04.673: IP ARP: rcvd req src 10.60.1.110 0050.56ab.1cd1, dst 10.60.1.112 Vlan101
Mar 8 05:47:04.685: IP ARP: arp_process_request: 10.30.3.159, hw: 34a8.4ea7.41b7; rc: 3
Mar 8 05:47:04.685: IP ARP: rcvd req src 10.30.3.159 34a8.4ea7.41b7, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.685: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.3.159 34a8.4ea7.41b7 Vlan120
Mar 8 05:47:04.745: IP ARP: arp_process_request: 10.30.4.113, hw: 34a8.4ea7.40f0; rc: 3
Mar 8 05:47:04.745: IP ARP: rcvd req src 10.30.4.113 34a8.4ea7.40f0, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.745: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.4.113 34a8.4ea7.40f0 Vlan120
Mar 8 05:47:04.753: IP ARP: arp_process_request: 192.168.1.112, hw: 300e.d5c0.d1f6; rc: 3
Mar 8 05:47:04.753: IP ARP req filtered src 192.168.1.112 300e.d5c0.d1f6, dst 192.168.1.99 0000.0000.0000 wrong cable, interface Vlan121
Mar 8 05:47:04.773: IP ARP: arp_process_request: 10.60.5.52, hw: 6451.065a.33b8; rc: 3
Mar 8 05:47:04.773: IP ARP: rcvd req src 10.60.5.52 6451.065a.33b8, dst 10.60.5.15 Vlan105
Mar 8 05:47:04.809: IP ARP: arp_process_request: 10.30.8.212, hw: 5478.1a6a.b0ad; rc: 3
Mar 8 05:47:04.809: IP ARP: rcvd req src 10.30.8.212 5478.1a6a.b0ad, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.809: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.8.212 5478.1a6a.b0ad Vlan120
Mar 8 05:47:04.825: IP ARP: arp_process_request: 10.30.8.103, hw: 5478.1a6a.ab31; rc: 3
Mar 8 05:47:04.825: IP ARP: rcvd req src 10.30.8.103 5478.1a6a.ab31, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.825: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.8.103 5478.1a6a.ab31 Vlan120
Mar 8 05:47:04.857: IP ARP: arp_process_request: 10.30.8.230, hw: 5478.1a6a.ae63; rc: 3
Mar 8 05:47:04.857: IP ARP: rcvd req src 10.30.8.230 5478.1a6a.ae63, dst 10.30.0.1 Vlan120
Mar 8 05:47:04.857: IP ARP: sent rep src 10.30.0.1 c8f9.f959.a140,
dst 10.30.8.230 5478.1a6a.ae63 Vlan120
Mar 8 05:47:04.901: IP ARP: arp_process_request: 10.30.3.197, hw: 34a8.4ea7.3e2d; rc: 3
Mar 8 05:47:04.901: IP ARP: rcvd req src 10.30.3.197 34a8.4ea7.3e2d, dst 10.30.0.1 Vlan12

without stop! if the time out is 4 hours why Core switch still has ARP process ?

BR

Mohammad

Seb Rupik · ‎03-09-2017

This ARP requests are coming from devices out in the network which are trying to reach devices in different subnets. The switch is sending out it's MAC address for the destination IP as it is the GW. This is normal proxy arp behavior. Do the source IP devices have a GW configured and correct netmask?

Looking at your process graph in the other reply, I think something more serious is occurring. Please post the output of running the command Reza suggests.

cheers,

Seb.

mohammad saeed · ‎03-09-2017

Yes here I want to know exactly! ARP is mainly generated from Hosts to recognize their servers! not related to core sw!

Yes they have correct GW and netmask as well !

Seb Rupik · ‎03-09-2017

...except when the core switch is configured for proxy-arp.

What is the output for:

sh cef summary

sh cef not-cef-switched

mohammad saeed · ‎03-09-2017

Core_SW#show cef not-cef-switched
% Command accepted but obsolete, see 'show (ip|ipv6) cef switching statistics [feature]'

IPv4 CEF Packets passed on to next switching layer
Slot No_adj No_encap Unsupp'ted Redirect Receive Options Access Frag
RP 0 0 58923663 8393283 1139793165 0 21098020 0
34/0 0 0 0 0 0 0 0 0
33/0 0 0 0 0 0 0 0 0
35/0 0 0 0 0 0 0 0 0
36/0 0 0 0 0 0 0 0 0
21/0 0 0 0 0 0 0 0 0
17/0 0 0 0 0 0 0 0 0
19/0 0 0 0 0 0 0 0 0
18/0 0 0 0 0 0 0 0 0
20/0 0 0 0 0 0 0 0 0
Core_SW#

there is no show cef summary command!

Core_SW#show cef st
Core_SW#show cef state
CEF Status:
RP instance
common CEF enabled
IPv4 CEF Status:
CEF enabled/running
dCEF enabled/running
CEF switching enabled/running
universal per-destination load sharing algorithm, id D84C3389
IPv6 CEF Status:
CEF disabled/not running
dCEF disabled/not running
universal per-destination load sharing algorithm, id D84C3389
RRP state:
I am standby RRP: no
RF Peer Presence: yes
RF PeerComm reached: yes
RF Progression blocked: unblocked (blocked for 00:00:00.836)
Redundancy mode: sso(3)
CEF NSF sync: enabled/running

CEF ISSU Status:
FIBHWIDB broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
FIBIDB broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
FIBHWIDB Subblock broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
FIBIDB Subblock broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
Adjacency update
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
IPv4 table broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
IPv6 table broker
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.
CEF push
Slot(s): 17/0-21/0 33/0-36/0 (0x1E003E0000) (grp 0x17824BF0) - Nego compatible.

Core_SW#

Seb Rupik · ‎03-10-2017

Your CPU process stats show very high CPU interrupt values which could account for the spikes you are seeing in the CPU histogram. Can you provide the output for:

sh ip cef switching statistics

sh ip cef switching statistics feature

cheers,

Seb.

mohammad saeed · ‎03-10-2017

Core_SW#sh ip cef switching statistics

Reason Drop Punt Punt2Host
RP LES No route 426218 0 167373
RP LES Packet destined for us 0 1142605503 0
RP LES No adjacency 15227783 0 0
RP LES Incomplete adjacency 28894 0 0
RP LES Bad checksum 193 0 0
RP LES TTL expired 0 0 29430828
RP LES Features 25647728 0 21143542
RP LES IP redirects 0 0 8393286
RP LES Neighbor resolution req 10958583 871 0
RP LES Bad IP packet header leng 1 0 0
RP LES Total 52289400 1142606374 59135029

All Total 52289400 1142606374 59135029
Core_SW#
Core_SW#sh ip cef switching statistics feature
IPv4 CEF input features:
Feature Drop Consume Punt Punt2Host Gave route
Access List 1 0 0 392 0
NAT Outside 0 0 0 21240 0
Total 1 0 0 21632 0

IPv4 CEF output features:
Feature Drop Consume Punt Punt2Host New i/f
Post-routing NAT 0 0 0 24282 0
IPsec or interfa 25647727 0 0 21097628 0
Total 25647727 0 0 21121910 0

IPv4 CEF post-encap features:
Feature Drop Consume Punt Punt2Host New i/f
Total 0 0 0 0 0

IPv4 CEF for us features:
Feature Drop Consume Punt Punt2Host New i/f
Total 0 0 0 0 0

IPv4 CEF punt features:
Feature Drop Consume Punt Punt2Host New i/f
Total 0 0 0 0 0

IPv4 CEF local features:
Feature Drop Consume Punt Punt2Host Gave route
Total 0 0 0 0 0

Thanks :)

mohammad saeed · ‎03-10-2017

Any Idea :)

Reza Sharifi · ‎03-09-2017

Hi,

How do you know its near 0 and how do you know that is causing high CPU? The default arp table aging time is 4 hours.

see this document

http://www.cisco.com/c/en/us/support/docs/switches/catalyst-6500-series-switches/71079-arp-cam-tableissues.html

What is the output of "sh process cpu sort | ex 0.00"?

HTH

mohammad saeed · ‎03-09-2017

Take it easy my friend ;) I am just wondering why this happened?

could you check the CPU history!

i know the average is around 40% but sometimes reach into 100%

9087908999799770879097097799899790870790770999780979790890990779979980
9004800999599750449083087599499190430480790889380939380410980899828910
100 ** ** *** ** * *** ** ** ** ** * ** **** ** * ** **** ** ** *
90 ** ** *** ** * *** ** ** ** ** * ** **** *** * ** ***** ** ** *
80 *** ************* *** ********* *** * ******** *** * ************ ****
70 **********************************************************************
60 **********************************************************************
50 **********************************************************************
40 ######################################################################
30 ######################################################################
20 ######################################################################
10 ######################################################################
0....5....1....1....2....2....3....3....4....4....5....5....6....6....7.
0 5 0 5 0 5 0 5 0 5 0 5 0
CPU% per hour (last 72 hours)
* = maximum CPU% # = average CPU%

Reza Sharifi · ‎03-09-2017

Mohammad,

The CPU is running high on this device. Can you provide the output of "sh process cpu sort | ex 0.00"?

Also, maybe a good idea to open a ticket with TAC, so they can analyze the issue.

HTH

mohammad saeed · ‎03-09-2017

Hi Reza,

Core_SW#sh process cpu sort | ex 0.00
CPU utilization for five seconds: 67%/51%; one minute: 58%; five minutes: 44%
PID Runtime(ms) Invoked uSecs 5Sec 1Min 5Min TTY Process
819 19398741922274307903 0 8.55% 7.17% 6.72% 0 MFIB_mrib_read
36 31697103043719394900 0 4.47% 7.31% 9.35% 0 IPC Seat Manager
167 8435967923160319989 0 0.55% 2.23% 2.31% 0 slcp process
583 1647071521187035063 138 0.39% 0.46% 0.52% 0 cmfib
675 2613689882094976865 124 0.31% 0.63% 0.79% 0 Port manager per
450 69880776 225197754 310 0.15% 0.26% 0.29% 0 Spanning Tree
357 211270881488529620 14 0.07% 0.06% 0.06% 0 MRIB RP Proxy
352 14564237203453758822 0 0.07% 8.82% 6.49% 0 IP Input
87 201310121643892752 12 0.07% 0.07% 0.06% 0 VSIBC process
814 4224758642893896645 0 0.07% 0.68% 1.02% 0 MRIB Trans
197 11787548 25175700 468 0.07% 0.02% 0.01% 0 XDR mcast rcv
315 7572580 108747859 69 0.07% 0.02% 0.01% 0 CDP Protocol
Core_SW#

This is the output!

Thanks,

Mohammad

Reza Sharifi · ‎03-09-2017

Mohammad,

So, the first 3 processes consume about 17% of the total CPU and I am not sure what they are for. I recommend you open a ticket with TAC, so they can investigate and find the root cause of high CPU.

HTH