Tips & Tricks: Flow Basic Debugging

cancel
Showing results for 
Show  only  | Search instead for 
Did you mean: 
Announcements
Please sign in to see details of an important advisory in our Customer Advisories area.
Community Team Member
100% helpful (4/4)

You can use debug filters to enable the Palo Alto Networks firewall to collect packet captures for troubleshooting purposes.

 

However, there are situations where you may require a more in-depth understanding of the firewall's internal operations.

 

Flow basic provides an extensive view into every stage of the firewall process, including packet reception, security decision-making, and the application of features such as NAT and App-ID. This feature makes it an incredibly powerful tool.

 

IMPORTANT: it's important to exercise caution when using this capability, as it can impose a heavy load on the CPU, especially if you have broad filter settings or need to capture a large amount of traffic.

 

Before diving in, ensure that the dataplane is not overwhelmed or overloaded to ensure optimal performance:

 

> show running resource-monitor minute 

Resource monitoring sampling data (per minute):

CPU load (%) during last 60 minutes:
core    0       1       2       3       4       5   
     avg max avg max avg max avg max avg max avg max
       0   0   0   1   0   0   0   0   0   0   0   0
       0   0   0   1   0   0   0   0   0   0   0   0
       0   0   0   0   0   0   0   0   0   0   0   0
       0   0   0   0   0   0   0   0   0   0   0   0

 

Before you begin, you should configure the filters, but first one should confirm whether any existing configurations might potentially disrupt our new settings:

 

> debug dataplane packet-diag show setting 

--------------------------------------------------------------------------------
Packet diagnosis setting:
--------------------------------------------------------------------------------
Packet filter
  Enabled:                   no
  Match pre-parsed packet:   no            
--------------------------------------------------------------------------------
Logging
  Enabled:                   no
  Log-throttle:              no
  Sync-log-by-ticks:         yes            
  Features:
  Counters:
--------------------------------------------------------------------------------
Packet capture
  Enabled:                   no
  Snaplen:                   0            
--------------------------------------------------------------------------------

 

In case there are any remaining configurations, we can remove all filters and previous flow basic logs by executing the following commands:

 

> debug dataplane packet-diag clear all
> debug dataplane packet-diag clear log log

 

Now, we can proceed with creating and enabling the filters while ensuring that pre-parse is disabled (If pre-parse match is enabled, some traffic that does not match the packet-filter may be captured. This option should only be used for advanced troubleshooting).

 

Additionally, setting up a second filter from the server to the NAT IP on the external interface of the firewall will assist in capturing returning packets before they undergo NAT in the 'ingress stage'.

 

I'll provide further details on this topic below:

 

> debug dataplane packet-diag set filter match source 192.168.0.34 destination 198.51.100.97 destination-port 80 protocol 6 non-ip exclude 
> debug dataplane packet-diag set filter match source 198.51.100.97 destination 198.51.100.230 source-port 80 protocol 6 non-ip exclude 
> debug dataplane packet-diag set filter on

> debug dataplane packet-diag show setting -------------------------------------------------------------------------------- Packet diagnosis setting: -------------------------------------------------------------------------------- Packet filter Enabled: yes Match pre-parsed packet: no Index 1: 192.168.0.34[0]->198.51.100.97[80], proto 6 ingress-interface any, egress-interface any, exclude non-IP Index 2: 198.51.100.97[80]->198.51.100.230[0], proto 6 ingress-interface any, egress-interface any, exclude non-IP -------------------------------------------------------------------------------- Logging Enabled: no Log-throttle: no Sync-log-by-ticks: yes Features: Counters: -------------------------------------------------------------------------------- Packet capture Enabled: no Snaplen: 0 --------------------------------------------------------------------------------

 

Once you're ready to activate logging, you'll notice several features that you can enable. Each feature initiates a capturing process on a specific engine or daemon, which can provide further insights. For example, enabling 'appid' can assist in troubleshooting scenarios where a particular application is not being identified correctly within a flow. On the other hand, enabling 'ctd' can aid in the troubleshooting of vulnerability signatures. There are various features available, each offering valuable assistance in different aspects of analysis and diagnosis.

 

> debug dataplane packet-diag set log feature 
 > all        all 
 > appid      appid 
> base base > cfg cfg > ctd ctd > flow flow
> http2. http2 > misc misc > module module > pow pow > proxy proxy > ssl ssl > tcp tcp
> tdb. tdb > tunnel tunnel > url_trie Do NOT enable > zip zip

 

For starters, let's begin with the 'flow' feature, which encompasses fundamental operations such as examining the TCP handshake, establishing sessions on the firewall, and executing NAT. Within each feature, there are additional subsections that can be enabled to delve into even more specific details. However, for now, we will focus on the basic settings to keep things simple.

 

> debug dataplane packet-diag set log feature flow 
  ager          ager 
  all           all 
  arp           arp 
  basic         basic 
cluster cluster
fbo fbo ha ha log log nd nd
netx netx np np receive receive
sdwan sdwan
sdwan_probe sdwan_probe track track

> debug dataplane packet-diag set log feature flow basic 
> debug dataplane packet-diag show setting 

--------------------------------------------------------------------------------
Packet diagnosis setting:
--------------------------------------------------------------------------------
Packet filter
  Enabled:                   yes
  Match pre-parsed packet:   no            
  Index 1: 192.168.0.34[0]->198.51.100.97[80], proto 6
           ingress-interface any, egress-interface any, exclude non-IP
  Index 2: 198.51.100.97[80]->198.51.100.230[0], proto 6
           ingress-interface any, egress-interface any, exclude non-IP
--------------------------------------------------------------------------------
Logging
  Enabled:                   no
  Log-throttle:              no
  Sync-log-by-ticks:         yes            
  Features:
    flow    : basic 
  Counters:
--------------------------------------------------------------------------------
Packet capture
  Enabled:                   no
  Snaplen:                   0            
--------------------------------------------------------------------------------

 

Before you start generating traffic, it's important to ensure that any existing sessions have been terminated. Additionally, disabling session offloading is necessary to capture all packets, even if they would typically be offloaded into hardware for processing. Once these precautions are taken care of, you can proceed to enable the logging feature and begin capturing the desired data.

 

> show session all filter source 192.168.0.34 destination 198.51.100.97

No Active Sessions

 

If there are any active sessions remaining, you can clear them by utilizing the "clear session" command. This will effectively remove any existing sessions and provide a clean slate for capturing new data:

 

> clear session all filter source 192.168.0.34 destination 198.51.100.97

 

> set session offload no

> debug dataplane packet-diag set log on

 

You can now start the session you'd like to capture,  wait for it to end gracefully, and then you can turn off logging:

 

> show session all filter source 192.168.0.34 destination 198.51.100.97

--------------------------------------------------------------------------------
ID          Application    State   Type Flag  Src[Sport]/Zone/Proto (translated IP[Port])
Vsys                                          Dst[Dport]/Zone (translated IP[Port])
--------------------------------------------------------------------------------
51187        web-browsing   ACTIVE  FLOW  NS   192.168.0.34[64969]/trust/6  (198.51.100.230[42882])
vsys1                                          198.51.100.97[80]/ISP1  (198.51.100.97[80])
> show session id 51187

Session           51187

        c2s flow:
                source:      192.168.0.34 [trust]
                dst:         198.51.100.97
                proto:       6
                sport:       64969           dport:      80
                state:       INIT            type:       FLOW
                src user:    pantac\tpiens
                dst user:    unknown

        s2c flow:
                source:      198.51.100.97 [ISP1]
                dst:         198.51.100.230
                proto:       6
                sport:       80              dport:      42882
                state:       INIT            type:       FLOW
                src user:    unknown
                dst user:    pantac\tpiens

        start time                           : Wed Feb 10 13:43:27 2016
        timeout                              : 15 sec
        total byte count(c2s)                : 644
        total byte count(s2c)                : 308
        layer7 packet count(c2s)             : 5
        layer7 packet count(s2c)             : 2
        vsys                                 : vsys1
        application                          : web-browsing  
        rule                                 : web-out
        session to be logged at end          : False
        session in session ager              : False
        session updated by HA peer           : False
        address/port translation             : source
        nat-rule                             : outbound-nat(vsys1)
        layer7 processing                    : enabled
        URL filtering enabled                : False
        session via syn-cookies              : False
        session terminated on host           : False
        session traverses tunnel             : False
        captive portal session               : False
        ingress interface                    : ethernet1/3
        egress interface                     : ethernet1/1
        session QoS rule                     : N/A (class 4)
        tracker stage firewall               : TCP RST - client
        end-reason                           : tcp-rst-from-client
> show session all filter source 192.168.0.34 destination 198.51.100.97

No Active Sessions
> debug dataplane packet-diag set log off

Packet log is disabled

> set session offload yes

 

Each CPU in the dataplane will generate its own flow log. So, depending on the traffic volume, session types, and quantity, you might come across multiple files on the dataplane. If a CPU was involved in the capture, you'll find an entry called pan_task_X.log for that specific CPU:

 

> less dp-log 
bfd.log             brdagent.log        dp-monitor.log      dp-monitor.log.1    
dp-monitor.log.2    dp-monitor.log.3    dp-monitor.log.4    masterd.log         
masterd_apps.log    masterd_detail.log  mprelay.log         pan_comm_0.log      
pan_dha.log         pan_task_1.log      pan_task_10.log     pan_task_11.log     
pan_task_2.log      pan_task_3.log      pan_task_4.log      pan_task_5.log      
pan_task_6.log      pan_task_7.log      pan_task_8.log      pan_task_9.log      
panio.log           panio.log.old       pdtrc.log           supervisor.log      
sysdagent.log       

 

You can of course combine all these files into a single file:

 

> debug dataplane packet-diag aggregate-logs 

packet-diag.log is aggregated

 

Once the aggregation is complete, the resulting file is saved as pan_packet_diag.log on the management plane.

 

> less dp-log pan_packet_diag.log for platforms with separate/multiple dataplanes
> less mp-log pan_packet_diag.log for vm and platforms with integrated dataplane

 

Let's take a look at the stages a packet goes through as it is seen in flow basic:

 

When a packet arrives on the ingress interface, it undergoes a check to determine if it matches an existing session. If there's no match, the packet is then directed to 'slowpath' for session creation.

 

== 2016-02-10 14:53:09.977 -0800 ==
Packet received at ingress stage
Packet info: len 66 port 18 interface 18 vsys 1
  wqe index 208735 packet 0x0x80000000b4d600c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 52,
        id 93, frag_off 0x4000, ttl 128, checksum 3848
TCP:    sport 64984, dport 80, seq 2270663711, ack 0,
        reserved 0, offset 8, window 8192, checksum 18967,
        flags 0x0002 ( SYN), urgent data 0
TCP option:
00000000: 02 04 05 b4 01 03 03 02  01 01 04 02                ........ ....
Flow lookup, key word0 0xfdd8005000010600 word1 0
Session setup: vsys 1
No active flow found, enqueue to create session
           

 

Next, the packet proceeds to slowpath. Here, several checks are performed on the packet. This includes verifying the source and destination zones based on routes or PBF entries. Additionally, the packet is inspected to determine if there are applicable security rules for this session based on the 5 tuples(source zone, source IP subnet, destination zone, destination IP subnet and destination port). NAT operations are also evaluated. Assuming all conditions pass, a session is then established.

 

== 2016-02-10 14:53:09.978 -0800 ==
Packet received at slowpath stage
Packet info: len 66 port 18 interface 18 vsys 1
  wqe index 208735 packet 0x0x80000000b4d600c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 52,
        id 93, frag_off 0x4000, ttl 128, checksum 3848
TCP:    sport 64984, dport 80, seq 2270663711, ack 0,
        reserved 0, offset 8, window 8192, checksum 18967,
        flags 0x0002 ( SYN), urgent data 0
TCP option:
00000000: 02 04 05 b4 01 03 03 02  01 01 04 02                ........ ....
Session setup: vsys 1
PBF lookup (vsys 1) with application web-browsing
Session setup: ingress interface ethernet1/3 egress interface ethernet1/1 (zone 5)
NAT policy lookup, matched rule index 0
Policy lookup, matched rule index 0, 
Allocated new session 51187.
Packet matched vsys 1 NAT rule 'outbound-nat' (index 1),
source translation 192.168.0.34/64984 => 198.51.100.230/52924
Created session, enqueue to install

 

The packet is forwarded to fastpath where NAT translation is applied. Once the packet is translated, it is then sent out of the egress interface towards the next hop.

 

== 2016-02-10 14:53:09.978 -0800 ==
Packet received at fastpath stage
Packet info: len 66 port 18 interface 18 vsys 1
  wqe index 208735 packet 0x0x80000000b4d600c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 52,
        id 93, frag_off 0x4000, ttl 128, checksum 3848
TCP:    sport 64984, dport 80, seq 2270663711, ack 0,
        reserved 0, offset 8, window 8192, checksum 18967,
        flags 0x0002 ( SYN), urgent data 0
TCP option:
00000000: 02 04 05 b4 01 03 03 02  01 01 04 02                ........ ....
Flow fastpath, session 51187
2016-02-10 14:53:09.978 -0800  pan_flow_process_fastpath(src/pan_flow_proc.c:1414): SESSION-DSCP: set se
ssion DSCP: 0x00
NAT session, run address/port translation
Syn Cookie: pan_reass(Init statete): c2s:0 c2s:nxtseq 2270663712 c2s:startseq 2270663712 c2s:win 0 c2s:s
t 3 c2s:newsyn 0 :: s2c:nxtseq 0 s2c:startseq 0 s2c:win 8192 s2c:st 0 s2c:newsyn 0 ack 0 nosyn 0 plen 0
Forwarding lookup, ingress interface 18
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP 198.51.100.97
Route found, interface ethernet1/1, zone 5
Resolve ARP for IP 198.51.100.97 on interface ethernet1/1
ARP entry found on interface 16
Transmit packet on port 16


 

When the returning SYN/ACK packet arrives at the ingress stage, it is matched with the corresponding existing session. Afterwards, it is forwarded to the fastpath stage. Reverse NAT is then applied to the packet, and it is sent back to the client through the internal interface:

 

== 2016-02-10 14:53:09.978 -0800 ==
Packet received at ingress stage
Packet info: len 66 port 16 interface 16 vsys 1
  wqe index 206169 packet 0x0x80000000b72c28c6
Packet decoded dump:
L2:     00:0c:29:de:25:fa->b4:0c:25:ed:37:10, type 0x0800
IP:     198.51.100.97->198.51.100.230, protocol 6
        version 4, ihl 5, tos 0x00, len 52,
        id 10919, frag_off 0x4000, ttl 128, checksum 31342
TCP:    sport 80, dport 52924, seq 3191786586, ack 2270663712,
        reserved 0, offset 8, window 8192, checksum 33843,
        flags 0x0012 ( SYN ACK), urgent data 0
TCP option:
00000000: 02 04 05 b4 01 03 03 08  01 01 04 02                ........ ....
Flow lookup, key word0 0x50cebc00050600 word1 0
Flow 102375 found, state 2, HA 0
Active flow, enqueue to fastpath process


== 2016-02-10 14:53:09.979 -0800 ==
Packet received at fastpath stage
Packet info: len 66 port 16 interface 16 vsys 1
  wqe index 206169 packet 0x0x80000000b72c28c6
Packet decoded dump:
L2:     00:0c:29:de:25:fa->b4:0c:25:ed:37:10, type 0x0800
IP:     198.51.100.97->198.51.100.230, protocol 6
        version 4, ihl 5, tos 0x00, len 52,
        id 10919, frag_off 0x4000, ttl 128, checksum 31342
TCP:    sport 80, dport 52924, seq 3191786586, ack 2270663712,
        reserved 0, offset 8, window 8192, checksum 33843,
        flags 0x0012 ( SYN ACK), urgent data 0
TCP option:
00000000: 02 04 05 b4 01 03 03 08  01 01 04 02                ........ ....
Flow fastpath, session 51187
NAT session, run address/port translation
Syn Cookie: pan_reass(Init statete): c2s:1 c2s:nxtseq 2270663712 c2s:startseq 2270663712 c2s:win 8192 c2
s:st 3 c2s:newsyn 0 :: s2c:nxtseq 3191786587 s2c:startseq 3191786587 s2c:win 8192 s2c:st 3 s2c:newsyn 0 
ack 2270663712 nosyn 0 plen 0
Forwarding lookup, ingress interface 16
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP 192.168.0.34
Route found, interface ethernet1/3, zone 1
Resolve ARP for IP 192.168.0.34 on interface ethernet1/3
ARP entry found on interface 18
Transmit packet on port 18



 

Once the final ACK to complete the handshake is received, it acts as a trigger for the session to be registered and the flow to be established within the fastpath stage. From this point onward, the firewall won't need to conduct any additional route or NAT lookups:

 

== 2016-02-10 14:53:09.979 -0800 ==
Packet received at ingress stage
Packet info: len 60 port 18 interface 18 vsys 1
  wqe index 193163 packet 0x0x80000000b49c60c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 40,
        id 94, frag_off 0x4000, ttl 128, checksum 3859
TCP:    sport 64984, dport 80, seq 2270663712, ack 3191786587,
        reserved 0, offset 5, window 16425, checksum 57360,
        flags 0x0010 ( ACK), urgent data 0
TCP option:
Flow lookup, key word0 0xfdd8005000010600 word1 0
Flow 102374 found, state 2, HA 0
Active flow, enqueue to fastpath process


== 2016-02-10 14:53:09.979 -0800 ==
Packet received at fastpath stage
Packet info: len 60 port 18 interface 18 vsys 1
  wqe index 193163 packet 0x0x80000000b49c60c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 40,
        id 94, frag_off 0x4000, ttl 128, checksum 3859
TCP:    sport 64984, dport 80, seq 2270663712, ack 3191786587,
        reserved 0, offset 5, window 16425, checksum 57360,
        flags 0x0010 ( ACK), urgent data 0
TCP option:
Flow fastpath, session 51187
NAT session, run address/port translation
Forwarding lookup, ingress interface 18
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP 198.51.100.97
Route found, interface ethernet1/1, zone 5
Resolve ARP for IP 198.51.100.97 on interface ethernet1/1
ARP entry found on interface 16
Transmit packet on port 16


 

At this point, the client and server are free to start communicating:

 

== 2016-02-10 14:53:09.980 -0800 ==
Packet received at ingress stage
Packet info: len 398 port 18 interface 18 vsys 1
  wqe index 202239 packet 0x0x80000000b341e8c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 384,
        id 95, frag_off 0x4000, ttl 128, checksum 3514
TCP:    sport 64984, dport 80, seq 2270663712, ack 3191786587,
        reserved 0, offset 5, window 16425, checksum 24524,
        flags 0x0018 ( ACK PSH), urgent data 0
TCP option:
Flow lookup, key word0 0xfdd8005000010600 word1 0
Flow 102374 found, state 2, HA 0
Active flow, enqueue to fastpath process


== 2016-02-10 14:53:09.980 -0800 ==
Packet received at fastpath stage
Packet info: len 398 port 18 interface 18 vsys 1
  wqe index 202239 packet 0x0x80000000b341e8c6
Packet decoded dump:
L2:     00:0c:29:1e:9c:8c->b4:0c:25:ed:37:12, type 0x0800
IP:     192.168.0.34->198.51.100.97, protocol 6
        version 4, ihl 5, tos 0x00, len 384,
        id 95, frag_off 0x4000, ttl 128, checksum 3514
TCP:    sport 64984, dport 80, seq 2270663712, ack 3191786587,
        reserved 0, offset 5, window 16425, checksum 24524,
        flags 0x0018 ( ACK PSH), urgent data 0
TCP option:
Flow fastpath, session 51187
NAT session, run address/port translation
session 51187 packet sequeunce old 0 new 1

Forwarding lookup, ingress interface 18
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP 198.51.100.97
Route found, interface ethernet1/1, zone 5
Resolve ARP for IP 198.51.100.97 on interface ethernet1/1
ARP entry found on interface 16
Transmit packet on port 16


== 2016-02-10 14:53:09.981 -0800 ==
Packet received at ingress stage
Packet info: len 242 port 16 interface 16 vsys 1
  wqe index 211483 packet 0x0x80000000b58550c6
Packet decoded dump:
L2:     00:0c:29:de:25:fa->b4:0c:25:ed:37:10, type 0x0800
IP:     198.51.100.97->198.51.100.230, protocol 6
        version 4, ihl 5, tos 0x00, len 228,
        id 10920, frag_off 0x4000, ttl 128, checksum 31165
TCP:    sport 80, dport 52924, seq 3191786587, ack 2270664056,
        reserved 0, offset 5, window 256, checksum 13539,
        flags 0x0018 ( ACK PSH), urgent data 0
TCP option:
Flow lookup, key word0 0x50cebc00050600 word1 0
Flow 102375 found, state 2, HA 0
Active flow, enqueue to fastpath process


== 2016-02-10 14:53:09.981 -0800 ==
Packet received at fastpath stage
Packet info: len 242 port 16 interface 16 vsys 1
  wqe index 211483 packet 0x0x80000000b58550c6
Packet decoded dump:
L2:     00:0c:29:de:25:fa->b4:0c:25:ed:37:10, type 0x0800
IP:     198.51.100.97->198.51.100.230, protocol 6
        version 4, ihl 5, tos 0x00, len 228,
        id 10920, frag_off 0x4000, ttl 128, checksum 31165
TCP:    sport 80, dport 52924, seq 3191786587, ack 2270664056,
        reserved 0, offset 5, window 256, checksum 13539,
        flags 0x0018 ( ACK PSH), urgent data 0
TCP option:
Flow fastpath, session 51187
NAT session, run address/port translation
session 51187 packet sequeunce old 1 new 2

Forwarding lookup, ingress interface 16
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP 192.168.0.34
Route found, interface ethernet1/3, zone 1
Resolve ARP for IP 192.168.0.34 on interface ethernet1/3
ARP entry found on interface 18
Transmit packet on port 18


 

With this, you have the option to utilize flow basic and track the packets as they traverse the Palo Alto Networks firewall. This will provide you with a comprehensive understanding of the various stages a packet undergoes. Additionally, I recommend checking out this informative article, "Packet Flow Sequence in PAN-OS" which delves into the topic with more depth.

 

Once you feel comfortable, feel free to incorporate additional features such as 'appid' to gain more detailed insights. That being said, it's important to monitor the dataplane resource-monitor closely to ensure that the dataplane isn't being overloaded.

 

Rate this article:
(3)
  • 15616 Views
  • 0 comments
  • 9 Likes
Register or Sign-in
Labels
Article Dashboard
Version history
Last Updated:
‎07-06-2023 09:56 AM
Updated by: