Why does the firewall sometimes flag blocked packets that are actually allowed?

[allebone]

Hi,

Unsure why sometimes the firewall logs show that packets are blocked when I have a rule that allows these packets outbound (443 is allowed outbound from any source on my network, and indeed i can browse https sites )

I have attached a screenshot of an example. I have a rule that allows 443 outbound and am 100% sure it is working as this only happens very infrequently that I see these packets. I dont detect anything not working and can browse sites on https anytime without issue so am not clear what it is blocking.

Here is the detail of 1 of the packets in the below screenshot:

__timestamp__   Nov 25 09:27:05
ack   3986972122
action   [block]
anchorname   
datalen   1395
dir   [in]
dst   13.107.42.12
dstport   443
ecn   
id   0
interface   vtnet1
interface_name   lan
ipflags   DF
label   Default block LAN to any rule
length   1435
offset   0
proto   6
protoname   tcp
reason   match
rid   da7b834f8d727a70d52f48cc6b111da3
ridentifier   0
rulenr   324
seq   3973428692:3973430087
src   192.168.2.53
srcport   56922
subrulenr   
tcpflags   PA
tcpopts   
tos   0x0
ttl   64
urp   4096
version   4

[Der Stefan]

Well I see the same thing.

I am pretty sure it did NOT happen before the 20.7.5 upgrade.
This is my backup machine trying to sync to the cloud (via p443).
For whatever reason default deny rule kicks in. Then after a few mins traffic gets through.

I am a bit puzzled but glad I just saw this post.


No changes in ruset...here is a block

Code: [Select]

__timestamp__ Nov 26 13:54:40
ack 4159507402
action [block]
anchorname
datalen 0
dir [in]
dst 185.179.130.30
dstport 443
ecn
id 30707
interface lagg0_vlan1
interface_name INT_MgmtVLAN_VL1
ipflags none
label Default deny rule
length 52
offset 0
proto 6
protoname tcp
reason match
rid 7ca0bdbea8e636fba2e984923ed67866
ridentifier 0
rulenr 38
seq
src 10.0.1.243
srcport 35072
subrulenr
tcpflags A
tcpopts
tos 0x0
ttl 64
urp 501
version 4

this one passes

Code: [Select]

_timestamp__ Nov 26 14:01:55
ack
action [pass]
anchorname
datalen 0
dir [in]
dst 185.179.130.30
dstport 443
ecn
id 54761
interface lagg0_vlan1
interface_name INT_MgmtVLAN_VL1
ipflags none
label Allow HTTPS VL1
length 60
offset 0
proto 6
protoname tcp
reason match
rid deb4772f1e71b5c6ccd7ce018eb36304
ridentifier 0
rulenr 176
seq 3208949710
src 10.0.1.243
srcport 44558
subrulenr
tcpflags S
tcpopts
tos 0x0
ttl 64
urp 64240
version 4

[Fright]

Gets the feeling that a separate post about the work of the stateful firewalls is needed to refer to it once a month )

https://learningnetwork.cisco.com/s/question/0D53i00000Ksup8/stateful-firewall-overview

can also google "out of state packet" (the results will be about checkpoint firewall. but general principles are true for every stateful firewall. including pf)

[allebone]

Thank you for your reply. I do not understand why this is an answer. Can you help me to understand what you are pointing out and in addition how you know the example packet I posted relates to this? I am not able to do this on my own.

Kind regards,
Peter

[Fright]

The answer is: in the vast majority of cases, this is normal firewall operation.
When the first packet from client to server passes through the firewall, a state table entry is created.
Using the state table allows to: a) speed up packet processing b) additionally control the security of connections (control the allowed flags, packets order etc.).
For example, @Der Stefan tcp connections: in example of a successful connection, you can see that the SYN flag is set ("tcpflags S"). From this tcp flag tcp connection is starting. Therefore, the firewall allows this connection and creates a record for it in the table. (pf use "flags S/SA" by default for stateful connections*)
In the blocked packet, you can see that the ACK flag is set ("tcpflags A"). By deafult pf firewall logs only first packet that establishes a connection. Therefore, this entry, most likely, indicates that the connection is no longer in the state table (for example, you applied some new rule in the firewall and the connection table was cleared . or the connection was closed by timeout). To the firewall, this looks like a new connection attempt, but with the tcp ACK flag set, which is unacceptable. Packet is droped.
Therefore, sporadic records with blocking of "allowed" connections are absolutely normal.

*from pf man:
      Because flags S/SA is applied by default (unless no state is   speci-
      fied), only the initial SYN packet of a TCP handshake will create a
      state for a TCP connection.   It is possible to be less restrictive,
      and allow state creation from intermediate (non-SYN)   packets, by
      specifying flags any.  This will cause pf(4)   to synchronize to ex-
      isting connections, for instance if one flushes the state table.
      However, states created from   such intermediate packets may be miss-
      ing connection details such as the TCP window scaling factor.
      States which   modify the packet flow,   such as   those affected by nat,
      binat or rdr   rules, modulate   or synproxy state options, or scrubbed
      with   reassemble tcp will also not be   recoverable from intermediate
      packets.  Such connections will stall and time out.

[allebone]

This is very interesting. Thank you. This information is very valuable to me and appreciate the time you took to reply.

Can I also ask what tcpflags   PA (I have a P in my packet).

Kind regards
Peter

[Fright]

https://serverfault.com/questions/1008268/what-do-the-following-mean-tcpra-tcpfa-tcppa-tcps-tcpsec
if link will break someday:
TCP:A = ACK
TCP:RA = RST, ACK
TCP:FA = FIN, ACK
TCP:PA = PSH, ACK
TCP:S = SYN
TCP:SEC = SYN, ECE, CWR

[allebone]

Thank you

[eth0]

I think I may have been seeing something similar. Sometimes a connection to [somewhere]:443 would get randomly blocked, sometimes also :993. I don't think I had edited firewall rules, at least not every time, and the IMAPS connections likely not closed for timeout either (if I understand correctly what kind of timeout was meant here).

However today I also saw an SSH connection between my VLANs hang, with logs looking like this:

Code: [Select]

2020-11-28T19:10:55 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,92,192.168.0.104,10.10.20.100,51266,22,52,PA,741519746:741519798,2878760399,65535,,
2020-11-28T19:10:55 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,328,192.168.0.104,10.10.20.100,51266,22,288,PA,741519458:741519746,2878760399,65535,,
2020-11-28T19:10:54 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519710:741519746,2878760399,65535,,
2020-11-28T19:10:54 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519674:741519710,2878760399,65535,,
2020-11-28T19:10:54 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519638:741519674,2878760399,65535,,
2020-11-28T19:10:54 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,220,192.168.0.104,10.10.20.100,51266,22,180,PA,741519458:741519638,2878760399,65535,,
2020-11-28T19:10:54 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519602:741519638,2878760399,65535,,
2020-11-28T19:10:53 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,184,192.168.0.104,10.10.20.100,51266,22,144,PA,741519458:741519602,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,184,192.168.0.104,10.10.20.100,51266,22,144,PA,741519458:741519602,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,184,192.168.0.104,10.10.20.100,51266,22,144,PA,741519458:741519602,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519566:741519602,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519530:741519566,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,112,192.168.0.104,10.10.20.100,51266,22,72,PA,741519458:741519530,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519494:741519530,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519458:741519494,2878760399,65535,,
2020-11-28T19:10:52 filterlog[58643] 20,,,0,igb1_vlan10,match,block,in,4,0x48,,64,0,0,DF,6,tcp,76,192.168.0.104,10.10.20.100,51266,22,36,PA,741519458:741519494,2878760399,65535,,

This went on for a while, until after a minute or so the connection was closed with rst-ack (RA).

Not sure if this is the same issue, but I don't see how state should have been reset/lost in this case. I wonder what's up here? I note the TCP sequence number/ack fields seem to have several numbers and combinations repeating in some pattern, but I don't know how to interpret that. Does this give any clue?

This could of course be caused by something in the machine I'm connecting to, but haven't seen it before.

Actually, the same thing just happened again while I was typing this. Running 20.7.4

[eth0]

...Also, while looking at the logs of a new connection after that, I see one packet also blocked in the opposite direction:

Code: [Select]

2020-11-28T19:49:31 filterlog[58643] 20,,,0,igb1_vlan20,match,block,in,4,0x10,,64,15604,0,DF,6,tcp,280,10.10.20.100,192.168.0.104,22,51534,228,PA,2589767952:2589768180,2806836895,501,,nop;nop;TS
That was just one packet though (and the connection survived it).

[Fright]

I think I may have been seeing something similar

yes. PA packets are "out of state" packets.
droped client packets looks like tcp retransmissions on closed connection.
then the client realized that the server would not respond and sent RA

but I don't see how state should have been reset/lost in this case

this cannot be understood from the firewall logs alone. you need to look at the logs on the server side, system logs, etc. it is possible that there was a dynamic address renew and the state table was flushed.
anyway, there was no entry for this connection in the table.

That was just one packet though (and the connection survived it).

technically its not the same connection. again, (by deafult) if you see any packet (allowed or droped) in pf log - its new connection attempt

[eth0]

yes. PA packets are "out of state" packets.
droped client packets looks like tcp retransmissions on closed connection.
then the client realized that the server would not respond and sent RA

Hm. Ok, this makes sense, thanks for the explanation. I'll try to double check this in server side logs if I still see it again.

technically its not the same connection. again, (by deafult) if you see any packet (allowed or droped) in pf log - its new connection attempt

I'm not sure if I understood now – it was a new connection that I opened after the previous one hanged, but (unless I did something strange without realizing it) it was still a connection from vlan10 to vlan20. But the firewall logged it as if vlan20 was the initiator.

[Fright]

it was still a connection from vlan10 to vlan20. But the firewall logged it as if vlan20 was the initiator.

perhaps this package was somehow related to the previous ssh session (some keep-alive packet frome server or some. need to trace packets to tell more). but definitely not with a new one.
Once again: if a session is established, then (by default) the packets inside this session cannot be displayed in the log (or you need to set the "log (all)" directive or not use states). moreover, if the packet matches an entry in the state table, then the rules are not evaluated: packet is passed with the parameters of the rule that established this session - quick and easy

from pf man:
     By   default   pf(4) filters packets statefully; the first time a packet
     matches a pass rule, a state entry   is created; for   subsequent packets the
     filter checks whether the packet matches any state.  If it   does, the
     packet is passed without evaluation of any   rules.   After the connection
     is   closed or times   out, the state entry is   automatically removed.