DATAPATH-0-2065 in ASA 5545 HA infrastructure

[bensonlei]

Today, we found below:

fwcore/sec/act# sh proc u cpu-us non
PC         Thread       5Sec     1Min     5Min   Process
0x0000000000c0256c   0x00007fffdb3233a0     0.1%     0.1%     0.1%   ARP Thread
   -          -        36.7%    35.5%     38%   DATAPATH-0-2065

CPU utilization wss so high today, caused network slowness ( normal CPU is around 10% ), Any hints of this strange thread "DATAPATH-0-2065" ?

We have a pair of ASA5545-x in HA configuration in the LAN network, thx a lot

[balaji.bandi]

This means it is over utilizing the data path, Do you have VPN Terminating in this box

BB

[bensonlei]

Thx, Bandi,

Our ASA 5545-x pair runs on ASA Version 9.4(4)5 

We do not have any VPN tunnel, but with following functions:

1. normal firewall function, packet inspection. 

2. No firepower installation in it.

3. With static and OSPF routing protocols, but only around totally 150 routes in whole the network.

4. Around 18 subnets are configured in interface 1/1 ( as below) and used as default gateway, which 

    means this asa firewall also as the router for these VLANs

For normal situation, or daily operation; we find just this thread ( quite quiet in fact ):

fwcore/sec/act# show proc cpu-usage non
PC         Thread       5Sec     1Min     5Min   Process
0x0000000000c0256c   0x00007fffdb3233a0     0.1%     0.1%     0.1%   ARP Thread
   -          -        13.6%    14.1%    13.5%   DATAPATH-0-2065

But I find some errors in ASA interfaces, like the following:

-------------------------------------------------
Interface GigabitEthernet1/1 "vlan1", is up, line protocol is up
  Hardware is i82576F rev01, BW 1000 Mbps, DLY 1000 usec
 Description: OA Servers
 4702946706 packets input, 5652749617806 bytes, 0 no buffer
 Received 3712258 broadcasts, 0 runts, 0 giants
 29130 L2 decode drops
 4624741186 packets output, 5341715641524 bytes, 320 underruns
 Traffic Statistics for "vlan1":
 22737451 packets input, 15113473630 bytes
 19505830 packets output, 6151785432 bytes
 37168 packets dropped
      1 minute input rate 177 pkts/sec,  69761 bytes/sec
      1 minute output rate 196 pkts/sec,  67631 bytes/sec
      1 minute drop rate, 0 pkts/sec
      5 minute input rate 169 pkts/sec,  75643 bytes/sec
      5 minute output rate 180 pkts/sec,  56364 bytes/sec

Interface GigabitEthernet1/2 "", is up, line protocol is up
  Hardware is i82576F rev01, BW 1000 Mbps, DLY 1000 usec
  98542707 packets input, 9301091110 bytes, 0 no buffer
 Received 1257043 broadcasts, 0 runts, 0 giants
 61177 L2 decode drops
 489922662 packets output, 695500509654 bytes, 0 underruns

---------------------------------------------

fwcore/sec/act#show asp event dp-cp
DP-CP EVENT QUEUE                  QUEUE-LEN  HIGH-WATER
Punt Event Queue                           0         190
Routing Event Queue                        0           2
Identity-Traffic Event Queue               0         159
General Event Queue                        0         112
Syslog Event Queue                         0          84
Non-Blocking Event Queue                   0           6
Midpath High Event Queue                   0           1
Midpath Norm Event Queue                   0           3
Crypto Event Queue                         0         114
HA Event Queue                             0          12
Threat-Detection Event Queue               0           4
SCP Event Queue                            0           0
ARP Event Queue                            0         172
IDFW Event Queue                           0           0
CXSC Event Queue                           0           0

EVENT-TYPE          ALLOC ALLOC-FAIL ENQUEUED ENQ-FAIL  RETIRED 15SEC-RATE
punt             82041948          0 82041948        0 82041948          3
  inspect-ftp      136842          0   136842        0   136842          0
  inspect-netbi    250280          0   250280        0   250280          0
  inspect-sunrp      4076          0     4076        0     4076          0
  inspect-rsh          84          0       84        0       84          0
  inspect-smtp   19795549          0 19795549        0 19795549          0
  inspect-sqlne  61851926          0 61851926        0 61851926          3
  inspect-tftp       3191          0     3191        0     3191          0
routing            502788          0   502788        0   502788          0
drop-flow               0          0   868006        0   868006          0
midpath-high         3132          0     3132        0     3132          0
midpath-norm       109327          0   109327        0   109327          0
crypto-msg          28287          0    28287        0    28287          0
adj-absent       554322420         0 554322420        0 554322420        103
arp-in           50908100          0 50908100        0 50908100         15
identity-traffic 83835360          0 83835360        0 83835360         19
syslog           46696496          0 46696496        0 46696496         18
scheduler             133          0      133        0      133          0
threat-detection   246741          0   246741        0   246741          0
ha-msg            9077798          0  9077798        0  9077798          2

any problem of the firewall pair , thx ?

[patoberli]

Might be a bug in your interims version.
For security reasons (and all other fixed bugs) I'd update to the latest version:
https://www.cisco.com/web/software/280775065/137125/ASA-944-Interim-Release-Notes.html

[bensonlei]

Thx guys,

Any body knows what is the event "adj-absent" ? I found it is so high among the events.

Cisco can not identify anything from my event logs sent to them, need wait until next time....so bad.

[patoberli]

Can you post such one event? Would like to see the full line.

[bensonlei]

Thx for the help,

As my previous post, the event "adj-absent" is so high compared to the other events:

fwcore/sec/act#show asp event dp-cp
…….

EVENT-TYPE     ALLOC       ALLOC-FAIL  ENQUEUED ENQ-FAIL  RETIRED        15SEC-RATE

 adj-absent       554322420         0            554322420        0        554322420        103

or which event logs you would like to view, thx ?

[patoberli]

Not finding anything with this event.
What do you get if you run 'show asp drop'?
What are the highest counters there?
Check if you have a high number of 'no-adjacency', that's the closest I could find, which would point to a wrong routing configuration on the ASA.

[bensonlei]

Hi, Pat

Highest counters for the following command output:

fwcore/sec/act# show asp drop

Frame drop:

 Reverse-path verify failed (rpf-violated)                             21681802
 Flow is denied by configured rule (acl-drop)                      31961143
 First TCP packet not SYN (tcp-not-syn)                             23209599

 FP L2 rule drop (l2_acl)                                                    157224543

fwcore/sec/act# show asp event dp-cp
DP-CP EVENT QUEUE                  QUEUE-LEN  HIGH-WATER

Punt Event Queue                           0                190

Identity-Traffic Event Queue            0               159

ARP Event Queue                            0               172

EVENT-TYPE    ALLOC ALLOC-FAIL ENQUEUED ENQ-FAIL  RETIRED 15SEC-RATE

adj-absent       591481627          0 591481627        0 591481627        145

fwcore/sec/act# sh proc cpu-hog

Process:      Unicorn Admin Handler, NUMHOG: 46, MAXHOG: 6, LASTHOG: 6
LASTHOG At:   09:30:56 HKST Jun 20 2018
PC:           0x00000000004f56d5 (suspend)
Call stack:   0x00007ffff7ad7ea0  0x00007fffd3d40a91  0x223d646920696c63
           

Process:      Unicorn Admin Handler, NUMHOG: 18, MAXHOG: 6, LASTHOG: 6
LASTHOG At:   16:07:12 HKST Jun 20 2018
PC:           0x00000000004f56d5 (suspend)
Call stack:   0x00007ffff7ad7ea0  0x00007fffd3b35951  0x223d646920696c63
           

Process:      Unicorn Admin Handler, NUMHOG: 3, MAXHOG: 6, LASTHOG: 6
LASTHOG At:   16:29:56 HKST Jun 20 2018
PC:           0x00000000004f56d5 (suspend)
Call stack:   0x00007ffff7ad7ea0  0x00007fffa564b761  0x223d646920696c63

Any findings ?

Is it really DATAPATH oversubscribed as Bandi 's observation/conclusion ? if so, flow control configuration in ASA interface is a useful configuration ?

[patoberli · Accepted solution]

This is probably the main problem:

Reverse-path verify failed (rpf-violated)                             21681802

It seems you have a routing misconfiguration. You have packets hitting an interface, with an IP address that isn't configured on that interface.

Check here for some details: https://www.cisco.com/c/en/us/about/security-center/unicast-reverse-path-forwarding.html

In any case I suggest you draw a L3 map with your ASA in the middle and all configured (virtual) interfaces with the IP addresses on the interfaces and afterwards compare it with your actual configuration.

[bensonlei · Accepted solution]

Hi, Pat,

Network issue occurred on 20June, I felt the network connectivity slow/degraded gradually, and after around 15 minutes later, I almost lost any network connection, and around another 20 minutes later, the CPU utilization of ASA firewall dropped to 10% from 40% (nothing done), the network resumed to normal automatically.

If so I shall check the ASA configuration.

Thanks so much for your precious time and professional advice.

[patoberli · Accepted solution]

Yes check the configuration. You might have the feature reverse path check active on the outside interface, that's not recommended. Or maybe a combination of NAT and RPF, which needs some special configuration.

[bensonlei]

Hi, Pat,

Thanks for your great advice.