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

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

• Any PAN-OS.
• Pao Ato Firewall.

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

If a majority of the symptoms match up then it may be possible that a packet-diag is on
The sequence of commands to turn off packet-diag plays a key role, always turn the log off first, otherwise ALL packets through FW will be logged, which would for sure impose heavy burdens to DP CPUs, affecting traffic (including LACP processing).

It is recommended to do it the other way: stop logging first, then clear filter.

 
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
admin@FW1(active)> debug dataplane packet-diag set capture 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