Policy action is allow, but session-end-reason is "policy-deny" PAN 8.1.12

[STHONG]

Hi, All

The action of security policy is set to allow, but session-end-reason is shown as "policy-deny" in traffic monitor.

The PAN-OS version is 8.1.12 and SSL decryption is enabled.
Could someone please explain this to me?
If you need more information, please let me know.

[reaper]

there's several layers where sessions are inspected and where a poliy decission can be taken to drop connections

The session is first processed at layer 3 where it is allowed or denied based on source/destination IP, source/destination zone and destination port and protocol. Once a connection is allowed based on the 6tuple, the traffic log will be an allow action, but the session may later be dropped due to an expired certificate (if ssl decryption is enabled) or an application switch or a threat profile that simply drops the connection

at the far-left of the log entry there's a log details icon that will show you more details and any related logs. this may shed some light on the reason for the session to get ended

[STHONG]

Hi,

Thank you for your reply.
I checked the detailed log and found that the destination address is https://api.snapcraft.io, and the certificate of this address is not expired but normal.

And there were no blocked or denied sessions in the threat log.

Is there anything else I need to check?

Thanks in advance.

/STHONG

[Abdalhakeem]

Any Update

[AmitKa79]

Hi,

We are facing something similar.

A client trying to access from the internet side to our website and our FW for some reason deny the traffic.

This happens only to one client while all other clients able to access the site normally. 

we also see a traffic log with action ALLOW and session end reason POLICY-DENY.

In the rule we only have VP profile but we don't see any threat log.

we did see from the output of the command "show counter global filter delta yes packet-filter yes severity drop":

flow_acion_close >> TCP sessions closed via injecting RST.

we ran a flow basic debug:

== 2022-12-28 14:15:30.994 +0200 ==
Packet received at ingress stage, tag 0, type ORDERED
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 544734 packet 0x0x80000003942f40f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19914, frag_off 0x4000, ttl 119, checksum 1599(0x63f)
TCP: sport 58420, dport 443, seq 4187513754, ack 0,
reserved 0, offset 8, window 64240, checksum 33105,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 129
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Server-IP
Route found, interface ae1.89, zone 5
Resolve ARP for IP Server-IP on interface ae1.89
ARP entry found on interface 190
Transmit packet size 52 on port 16

== 2022-12-28 14:15:30.959 +0200 ==
Packet received at fastpath stage, tag 548459, type ATOMIC
Packet info: len 70 port 80 interface 190 vsys 1
wqe index 545439 packet 0x0x80000003940430e4, HA: 0, IC: 0
Packet decoded dump:
L2: 00:94:a1:56:25:8a->b4:0c:25:e0:40:10, VLAN 89 (0x8100 0x0059), type 0x0800
IP: Server-IP->Client-IP, protocol 6
version 4, ihl 5, tos 0x00, len 52,
id 37496, frag_off 0x4000, ttl 255, checksum 14744(0x3998)
TCP: sport 443, dport 58417, seq 1707377135, ack 3880782354,
reserved 0, offset 8, window 14520, checksum 51352,
flags 0x12 ( SYN ACK), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 b4 01 03 03 02 04 02 00 00 ........ ....
Flow fastpath, session 548459 s2c (set work 0x800000038f346e80 exclude_video 0 from sp 0x80000002aa7d5e80 exclude_video 0)
* Dos Profile NULL (NO) Index (0/0) *
Syn Cookie: pan_reass(Init statete): c2s:1 c2s:nxtseq 3880782354 c2s:startseq 3880782354 c2s:win 14520 c2s:st 3 c2s:newsyn 0 :: s2c:nxtseq 1707377136 s2c:startseq 1707377136 s2c
:win 64240 s2c:st 3 s2c:newsyn 0 ack 3880782354 nosyn 0 plen 0
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 190
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Client-IP
Route found, interface ae2.3010, zone 6, nexthop LinkProof-Float
Resolve ARP for IP LinkProof-Float on interface ae2.3010
ARP entry found on interface 129
Transmit packet size 52 on port 17

Any advice on what might be the reason for the traffic being dropped?

[Arnesh]

Hi @AmitKa79 

In the scenarios where the traffic is denied even after the policy action is "Allow", the traffic is denied after the 3-way handshake (if not in all cases). You would have to share further flow basic so that it is identified as to why this traffic is denied?

I agree with @reaper as the traffic can be denied due to many factors as suggested previously even after the initial 3-way handshake is allowed.

Regards, 

[AmitKa79]

== 2022-12-28 14:15:30.994 +0200 ==
Packet received at ingress stage, tag 0, type ORDERED
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 544734 packet 0x0x80000003942f40f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19914, frag_off 0x4000, ttl 119, checksum 1599(0x63f)
TCP: sport 58420, dport 443, seq 4187513754, ack 0,
reserved 0, offset 8, window 64240, checksum 33105,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 129
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Server-IP
Route found, interface ae1.89, zone 5
Resolve ARP for IP Server-IP on interface ae1.89
ARP entry found on interface 190
Transmit packet size 52 on port 16

== 2022-12-28 14:15:30.959 +0200 ==
Packet received at fastpath stage, tag 548459, type ATOMIC
Packet info: len 70 port 80 interface 190 vsys 1
wqe index 545439 packet 0x0x80000003940430e4, HA: 0, IC: 0
Packet decoded dump:
L2: 00:94:a1:56:25:8a->b4:0c:25:e0:40:10, VLAN 89 (0x8100 0x0059), type 0x0800
IP: Server-IP->Client-IP, protocol 6
version 4, ihl 5, tos 0x00, len 52,
id 37496, frag_off 0x4000, ttl 255, checksum 14744(0x3998)
TCP: sport 443, dport 58417, seq 1707377135, ack 3880782354,
reserved 0, offset 8, window 14520, checksum 51352,
flags 0x12 ( SYN ACK), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 b4 01 03 03 02 04 02 00 00 ........ ....
Flow fastpath, session 548459 s2c (set work 0x800000038f346e80 exclude_video 0 from sp 0x80000002aa7d5e80 exclude_video 0)
* Dos Profile NULL (NO) Index (0/0) *
Syn Cookie: pan_reass(Init statete): c2s:1 c2s:nxtseq 3880782354 c2s:startseq 3880782354 c2s:win 14520 c2s:st 3 c2s:newsyn 0 :: s2c:nxtseq 1707377136 s2c:startseq 1707377136 s2c
:win 64240 s2c:st 3 s2c:newsyn 0 ack 3880782354 nosyn 0 plen 0
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 190
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Client-IP
Route found, interface ae2.3010, zone 6, nexthop LinkProof-Float
Resolve ARP for IP LinkProof-Float on interface ae2.3010
ARP entry found on interface 129
Transmit packet size 52 on port 17

== 2022-12-28 14:15:30.959 +0200 ==
Packet received at fastpath stage, tag 103101, type ATOMIC
Packet info: len 70 port 81 interface 190 vsys 1
wqe index 548027 packet 0x0x80000003958c78e4, HA: 0, IC: 0
Packet decoded dump:
L2: 00:94:a1:56:25:8a->b4:0c:25:e0:40:10, VLAN 89 (0x8100 0x0059), type 0x0800
IP: Server-IP->Client-IP, protocol 6
version 4, ihl 5, tos 0x00, len 52,
id 49846, frag_off 0x4000, ttl 255, checksum 2394(0x95a)
TCP: sport 443, dport 58418, seq 2764533183, ack 577938220,
reserved 0, offset 8, window 14520, checksum 51592,
flags 0x12 ( SYN ACK), urgent data 0, l4 data len 0
TCP option:
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 129
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Server-IP
Route found, interface ae1.89, zone 5
Resolve ARP for IP Server-IP on interface ae1.89
ARP entry found on interface 190
Transmit packet size 52 on port 16

== 2022-12-28 14:15:30.958 +0200 ==
Packet received at slowpath stage, tag 1465060809, type ATOMIC
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 548013 packet 0x0x80000003949218f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19907, frag_off 0x4000, ttl 119, checksum 1606(0x646)
TCP: sport 58417, dport 443, seq 3880782353, ack 0,
reserved 0, offset 8, window 64240, checksum 60709,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 ac 01 03 03 08 01 01 04 02 ........ ....
Session setup: vsys 1
PBF lookup (vsys 1) with application ssl
Session setup: ingress interface ae2.3010 egress interface ae1.89 (zone 5)
Policy lookup, matched rule index 42,
TCI_INSPECT: Do TCI lookup policy - appid 0
Allocated new session 548459.
set exclude_video in session 548459 0x80000002aa7d5e80 0 from work 0x800000038f397580 0
Created session, enqueue to install. work 0x800000038f397580 exclude_video 0,session 548459 0x80000002aa7d5e80 exclude_video 0

== 2022-12-28 14:15:30.958 +0200 ==
Packet received at ingress stage, tag 0, type ORDERED
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 547400 packet 0x0x8000000393e338f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19908, frag_off 0x4000, ttl 119, checksum 1605(0x645)
TCP: sport 58418, dport 443, seq 577938219, ack 0,
reserved 0, offset 8, window 64240, checksum 6377,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 ac 01 03 03 08 01 01 04 02 ........ ....
Flow lookup, key word0 0xe43201bb00060600 word1 0 word2 0xffff956aff80 word3 0x0 word4 0xffffc1a9591e
* Dos Profile NULL (NO) Index (0/0) *
Flow not found, HA 0
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 129
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Server-IP
Route found, interface ae1.89, zone 5
Resolve ARP for IP Server-IP on interface ae1.89
ARP entry found on interface 190
Transmit packet size 40 on port 16

== 2022-12-28 14:15:25.895 +0200 ==
Packet received at fastpath stage, tag 300232, type ATOMIC
Packet info: len 64 port 82 interface 129 vsys 1
wqe index 543791 packet 0x0x8000000394ac70e4, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 46,
id 19906, frag_off 0x4000, ttl 119, checksum 1613(0x64d)
TCP: sport 58415, dport 443, seq 1170268787, ack 3301540227,
reserved 0, offset 5, window 516, checksum 37541,
flags 0x10 ( ACK), urgent data 0, l4 data len 6
TCP option:
Flow fastpath, session 300232 c2s (set work 0x800000038f313680 exclude_video 0 from sp 0x80000002a6b3bb80 exclude_video 0)
session 300232 packet sequeunce old 0 new 1
Flow action close for session 300232, option 3
2022-12-28 14:15:25.895 +0200 Warning: pan_ctd_start_session_can_be_decrypted(pan_ctd.c:3471): pan_proxy_proc_session() failed: -1

== 2022-12-28 14:15:25.895 +0200 ==
Packet received at forwarding stage, tag 300232, type ATOMIC
Packet info: len 58 port 82 interface 190 vsys 1
wqe index 545722 packet 0x0x8000000393e338c0, HA: 0, IC: 0
Packet decoded dump:
L2: b4:0c:25:e0:40:11->2c:b6:93:56:07:00, type 0x0800
IP: Server-IP->Client-IP, protocol 6
version 4, ihl 5, tos 0x00, len 40,
id 15260, frag_off 0x0000, ttl 64, checksum 36737(0x8f81)
TCP: sport 443, dport 58415, seq 3301540227, ack 1170268793,
reserved 0, offset 5, window 516, checksum 43431,
flags 0x14 ( ACK RST), urgent data 0, l4 data len 0
TCP option:
Forwarding lookup, ingress interface 190
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Client-IP
Route found, interface ae2.3010, zone 6, nexthop LinkProof-Float
Resolve ARP for IP LinkProof-Float on interface ae2.3010
ARP entry found on interface 129
Transmit packet size 40 on port 17
CP-DENY TCP non data packet getting through
Forwarding lookup, ingress interface 190
L3 mode, virtual-router 1
Route lookup in virtual-router 1, IP Client-IP
Route found, interface ae2.3010, zone 6, nexthop LinkProof-Float
Resolve ARP for IP LinkProof-Float on interface ae2.3010
ARP entry found on interface 129
Transmit packet size 52 on port 17

== 2022-12-28 14:15:25.879 +0200 ==
Packet received at ingress stage, tag 0, type ORDERED
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 551288 packet 0x0x80000003946968f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19902, frag_off 0x4000, ttl 119, checksum 1611(0x64b)
TCP: sport 58415, dport 443, seq 1170268786, ack 0,
reserved 0, offset 8, window 64240, checksum 46678,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 ac 01 03 03 08 01 01 04 02 ........ ....
Flow lookup, key word0 0xe42f01bb00060600 word1 0 word2 0xffff956aff80 word3 0x0 word4 0xffffc1a9591e
* Dos Profile NULL (NO) Index (0/0) *
Flow not found, HA 0
Session setup: vsys 1
No active flow found, enqueue to create session

== 2022-12-28 14:15:25.879 +0200 ==
Packet received at slowpath stage, tag 1610831203, type ATOMIC
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 551288 packet 0x0x80000003946968f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19902, frag_off 0x4000, ttl 119, checksum 1611(0x64b)
TCP: sport 58415, dport 443, seq 1170268786, ack 0,
reserved 0, offset 8, window 64240, checksum 46678,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 ac 01 03 03 08 01 01 04 02 ........ ....
Session setup: vsys 1
PBF lookup (vsys 1) with application ssl
Session setup: ingress interface ae2.3010 egress interface ae1.89 (zone 5)
Policy lookup, matched rule index 42,
TCI_INSPECT: Do TCI lookup policy - appid 0
Allocated new session 300232.
set exclude_video in session 300232 0x80000002a6b3bb80 0 from work 0x800000038f3fdb00 0
Created session, enqueue to install. work 0x800000038f3fdb00 exclude_video 0,session 300232 0x80000002a6b3bb80 exclude_video 0

== 2022-12-28 14:15:25.879 +0200 ==
Packet received at fastpath stage, tag 300232, type ATOMIC
Packet info: len 70 port 82 interface 129 vsys 1
wqe index 551288 packet 0x0x80000003946968f8, HA: 0, IC: 0
Packet decoded dump:
L2: 2c:b6:93:56:07:00->b4:0c:25:e0:40:11, VLAN 3010 (0x8100 0x0bc2), type 0x0800
IP: Client-IP->Server-IP, protocol 6
version 4, ihl 5, tos 0x08, len 52,
id 19902, frag_off 0x4000, ttl 119, checksum 1611(0x64b)
TCP: sport 58415, dport 443, seq 1170268786, ack 0,
reserved 0, offset 8, window 64240, checksum 46678,
flags 0x02 ( SYN), urgent data 0, l4 data len 0
TCP option:
00000000: 02 04 05 ac 01 03 03 08 01 01 04 02 ........ ....
57%

[TomYoung]

Hi @AmitKa79 ,

The most common reason I have seen for the apparent oxymoron of allow and policy-deny is the traffic is denied due to decryption policy.  Please see this thread https://live.paloaltonetworks.com/t5/general-topics/security-policy-action-is-quot-allow-quot-but-se....

The logs actually make sense because the traffic is allowed by security policy, but denied by another policy.  Do you have decryption enabled?  If so, please check the decryption logs.  If not, please let us know.

Thanks,

Tom

[AmitKa79]

we are not applying decryption policy for that traffic.

[Arnesh]

Thanks @TomYoung.
@AmitKa79 Although the session does not seem to be complete in the logs for any particular session (I traced via sport). I can see the below log which seems to be due to decryption failing.

2022-12-28 14:15:25.895 +0200 Warning: pan_ctd_start_session_can_be_decrypted(pan_ctd.c:3471): pan_proxy_proc_session() failed: -1

Is this the only site which is facing the issue? What is the website you are accessing and the PAN-OS of the firewall?

Regards,

[AmitKa79]

we are not applying decryption policy for that traffic.

in the traffic logs we see in the application - ssl.

[AmitKa79]

[TomYoung]

Hi @AmitKa79 ,

Do you have a "no-decrypt" rule?  If so, the decryption profile can still be applied and deny traffic even it it is not decrypted.

Is there anything in the decryption logs?

Thanks,

Tom

[Raido_Rattameister]

In first screenshot "Decrypted" column is "yes".

It means you are decrypting this traffic.

[AmitKa79]

The first image relates to someone elses issue which is similar to ours.

This  is our logs