On 16/05/2019 10:16, Roman Serbski wrote:
> I see occasional drops in the logs as per below:
>
> May 16 01:53:45 WEB01 kernel: IPTABLES-OUTPUT-DROP> IN= OUT=ens192
> SRC=10.9.49.52 DST=10.9.49.31 LEN=83 TOS=0x00 PREC=0x00 TTL=64
> ID=62432 DF PROTO=TCP SPT=49350 DPT=3128 WINDOW=432 RES=0x00 ACK PSH
> URGP=0
I also have some similar (or even the same) issue, but with nftables.
I'm seeing the following messages from time to time:
kernel: * OUTPUT * IN= OUT=bond0 SRC=192.168.1.150 DST=74.125.205.108 LEN=76 TOS=0x00 PREC=0x00 TTL=64 ID=26357 DF PROTO=TCP SPT=46386 DPT=993 SEQ=2541809989 ACK=3563651700 WINDOW=501 RES=0x00 ACK PSH URGP=0 OPT (0101080AC5C5BD6703BA902B) UID=1000 GID=1000
kernel: * OUTPUT * IN= OUT=bond0 SRC=192.168.1.150 DST=173.194.222.109 LEN=76 TOS=0x00 PREC=0x00 TTL=64 ID=40021 DF PROTO=TCP SPT=44006 DPT=993 SEQ=1900902695 ACK=731659087 WINDOW=501 RES=0x00 ACK PSH URGP=0 OPT (0101080AAE3C87DD9D623C3A) UID=1000 GID=1000
kernel: * OUTPUT * IN= OUT=bond0 SRC=192.168.1.150 DST=64.233.165.108 LEN=76 TOS=0x00 PREC=0x00 TTL=64 ID=8430 DF PROTO=TCP SPT=52496 DPT=993 SEQ=2684687216 ACK=1708695588 WINDOW=501 RES=0x00 ACK PSH URGP=0 OPT (0101080AAA585A0372650E64) UID=1000 GID=1000
It's also ACK PSH. Basically, at some point, the thunderbird app
gets a little bit lagy, but it seems it works in general.
At first I thought maybe this is related to some FW misconfiguration.
I'm using cgroup matching rules similar to the one below:
---------------------
create chain inet filter check-state
add rule inet filter check-state ct state { established, related } accept
add rule inet filter check-state ct state { invalid } counter drop
add rule inet filter OUTPUT jump check-state
add rule inet filter OUTPUT meta oif { "lo" } counter accept
create chain inet filter check-cgroup
add rule inet filter OUTPUT meta cgroup { 0-4095 } counter jump check-cgroup
...
add rule inet filter check-cgroup meta cgroup { 5 } tcp dport { 443, 80, 587, 465, 995, 993 } counter accept comment "mail thunderbird"
...
add rule inet filter OUTPUT limit rate 30/minute burst 1 packets log flags all prefix "* OUTPUT * " counter
add rule inet filter OUTPUT counter drop
---------------------
Cgroup works fine:
$ cat /sys/fs/cgroup/net_cls,net_prio/gui/user-apps/thunderbird/net_cls.classid
5
$ cat /sys/fs/cgroup/net_cls,net_prio/gui/user-apps/thunderbird/tasks | wc -l
75
When I start the thunderbird app, it works well:
chain check-cgroup {
...
meta cgroup { 5 } tcp dport { 80, 443, 465, 587, 993, 995 } counter packets 1079 bytes 64740 accept comment "mail thunderbird"
...
So the rule can match packets sent from the thunderbird app. But for
some reason at some point in time, the packets can't be matched
against the same rule anymore.
I noticed that when I clear the conntrack table via:
# conntrack -F
the ACK PSH messages start to flood the log. At the beginning there's
no entry related to the port 993 in the conntrack table:
# conntrack -L -p tcp --dport 993
conntrack v1.4.5 (conntrack-tools): 0 flow entries have been shown.
But in a few seconds they start to appear in that table:
# conntrack -L -p tcp --dport 993
tcp 6 43179 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33712 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33712 [ASSURED] mark=0 use=1
tcp 6 43159 ESTABLISHED src=192.168.1.150 dst=198.252.153.22 sport=45172 dport=993 src=198.252.153.22 dst=192.168.1.150 sport=993 dport=45172 [ASSURED] mark=0 use=1
tcp 6 43169 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33710 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33710 [ASSURED] mark=0 use=1
tcp 6 43199 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33760 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33760 [ASSURED] mark=0 use=1
tcp 6 43198 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33762 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33762 [ASSURED] mark=0 use=1
tcp 6 43199 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33664 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33664 [ASSURED] mark=0 use=1
tcp 6 43199 ESTABLISHED src=192.168.1.150 dst=74.125.131.109 sport=33660 dport=993 src=74.125.131.109 dst=192.168.1.150 sport=993 dport=33660 [ASSURED] mark=0 use=1
But the messages are still logged and packets are dropped:
kernel: * OUTPUT * IN= OUT=bond0 SRC=192.168.1.150 DST=198.252.153.22 LEN=98 TOS=0x00 PREC=0x00 TTL=64 ID=10251 DF PROTO=TCP SPT=42340 DPT=993 SEQ=2066039093 ACK=2743607071 WINDOW=501 RES=0x00 ACK PSH URGP=0 OPT (0101080A5090166F00FD6D1B) UID=1000 GID=1000
kernel: * OUTPUT * IN= OUT=bond0 SRC=192.168.1.150 DST=74.125.131.109 LEN=82 TOS=0x00 PREC=0x00 TTL=64 ID=5985 DF PROTO=TCP SPT=33578 DPT=993 SEQ=3751855679 ACK=4251367195 WINDOW=501 RES=0x00 ACK PSH URGP=0 OPT (0101080A0DAE337F16E76AC0) UID=1000 GID=1000
When you look closely, the source ports are different in the
conntrack table and in the log.
The only way to stop this is to restart the thunderbird app or to
wait some time, and the messages ultimately stop appear probably
because there will be some proper entry in the conntrack table or
the connection will die, or both.
Also, it looks like that only the thunderbird app has issues with it.
I have over 100 apps filtered in the OUTPUT, and I didn't see any
messages concerning their ports. So maybe some entries in the
conntract table hit their timeout while time goes by? It looks like
this problem concerns only the long lived established connections.
It's just my thoughts, correct me if I'm wrong or if you have
some better ideas. :)
Attachment:
signature.asc
Description: OpenPGP digital signature
