Identifying and Resolving High Dataplane CPU caused by packet-diag logging

95642

Created On 03/07/19 05:18 AM - Last Modified 04/02/20 02:42 AM

Packet Capture

Analysis

PAN-OS

Symptom

One or more of the following symptoms are observed:

High dataplane (DP) CPU reaching 99 to 100%
High packet descriptor up to 90% or higher

admin@FW1(active)> show running resource-monitor
DP s1dp0:

Resource monitoring sampling data (per second):

CPU load sampling by group:
flow_lookup : 99%
flow_fastpath : 99%
flow_slowpath : 99%
flow_forwarding : 99%
flow_mgmt : 99%
flow_ctrl : 99%
nac_result : 99%
flow_np : 99%
dfa_result : 99%
module_internal : 99%
aho_result : 99%
zip_result : 99%
pktlog_forwarding : 99%
lwm : 0%
flow_host : 99%

CPU load (%) during last 60 seconds:
core 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15
* 96 97 98 98 98 97 97 97 97 98 97 97 97 97 98
* 100 100 100 100 100 100 100 100 100 100 100 100 100 100 100

Resource utilization (%) during last 60 seconds:
packet descriptor (on-chip):
75 90 90 91 56 40 91 90 72 6 24 90 92 91 94
89 11 92 5 87 93 91 89 24 6 71 92 53 65 56
57 89 52 4 5 43 94 94 64 9 37 89 89 70 9
7 30 89 91 91 91 39 12 5 9 10 70 40 59 93

System log generating heavy DP load messages

admin@FW1(active)> show log system direction equal backward
2019/03/05 12:39:38 high     general        general 0  Dataplane under severe load
2019/03/05 12:39:32 high     general        general 0  Dataplane under severe load

Global counters displaying large value for "log_pkt_diag_us" and increments at a high rate

admin@FW1(active)> show counter global filter delta yes
log_pkt_diag_us                     49998362 48947116 info      log       system    Time (us) spend on writing packet-diag logs

Traffic will be sluggish through the firewall and CLI has delayed input/output
DP monitor show average Load to be high

admin@FW1(active)> less mp-log dp-monitor.log 
2019-03-05 12:42:55.304 -0700  --- cpu
2019-03-05 12:42:55   Last 180 seconds
2019-03-05 12:42:55   Avg (%)    Max (%)
2019-03-05 12:42:55   29         72     
2019-03-05 12:42:55   Load Avg:
2019-03-05 12:42:55   31.22 31.33 31.31 31/280 13449

HTTP/HTTPS connections to website disconnect intermittently
From Auto Assist:

2 (2019-03-05 12:05:17)    Warning    Panio Function    urlcache_lru max

admin@FW1(active)> debug dataplane pow performance all
urlcache_lookup 4142 110 26813

Traffic is normal during off peak hours when less users are accessing the Firewall.
Root directory may full up and run high

admin@Lab196-118-PA-VM1> show system disk-space

Filesystem      Size  Used Avail Use% Mounted on
/dev/root       4.0G  3.8G  220M  95% /
none            3.2G   60K  3.2G   1% /dev
/dev/sda5       8.0G  4.4G  3.2G  59% /opt/pancfg
/dev/sda6       4.0G  2.1G  1.7G  55% /opt/panrepo
tmpfs           2.8G  2.3G  566M  81% /dev/shm
/dev/sda8        16G  6.7G  8.4G  45% /opt/panlogs
tmpfs            12M     0   12M   0% /opt/pancfg/mgmt/lcaas/ssl/private

Environment

Any PAN-OS.
Pao Ato Firewall.

Cause

This is caused by an "any any" filter being defined for the packet-diag which, results in all traffic being logged

admin@FW1(active)> debug dataplane packet-diag show setting
--------------------------------------------------------------------------------
Packet diagnosis setting:
--------------------------------------------------------------------------------
Packet filter
  Enabled:                   yes                            <<filter is enabled
  Match pre-parsed packet:   no            
--------------------------------------------------------------------------------
Logging
  Enabled:                   yes                          <<logging is enabled
  Log-throttle:              no
  Sync-log-by-ticks:         yes            

flow    : basic 
  Counters:
--------------------------------------------------------------------------------
Packet capture
  Enabled:                   no
  Snaplen:                   0
  Username:                              
  Stage receive           :  file rc1
    Captured:     packets - 50437      bytes - 44140473    
    Maximum:      packets - 0          bytes - 0           
  Stage firewall          :  file fw1
    Captured:     packets - 9753       bytes - 3917310     
    Maximum:      packets - 0          bytes - 0           
  Stage transmit          :  file tr1
    Captured:     packets - 8389       bytes - 3745793     
    Maximum:      packets - 0          bytes - 0           
  Stage drop              :  file dr1
    Captured:     packets - 1608       bytes - 145761      
    Maximum:      packets - 0          bytes - 0

Resolution

If a majority of the symptoms match up then it may be possible that a packet-diag is on

To turn off the logging and filtering:

admin@FW1(active)> debug dataplane packet-diag set log off
admin@FW1(active)> debug dataplane packet-diag set filter off

To confirm the feature has been disabled:

admin@FW1(active)> debug dataplane packet-diag show setting
--------------------------------------------------------------------------------
Packet diagnosis setting:
--------------------------------------------------------------------------------
Packet filter
  Enabled:                   no                          <<filter is off
  Match pre-parsed packet:   no            
--------------------------------------------------------------------------------
Logging
  Enabled:                   no                          <<logging is off
  Log-throttle:              no
  Sync-log-by-ticks:      yes

If root directory is high or full, delete the "pan_packet_diag.log" file

admin@FW1(active)> debug dataplane packet-diag clear log log

Additional Information