Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 5 Jul 2011 18:17:56 +0200
From:      =?ISO-8859-1?Q?Ermal_Lu=E7i?= <eri@freebsd.org>
To:        Fabian Keil <freebsd-listen@fabiankeil.de>
Cc:        freebsd-pf@freebsd.org
Subject:   Re: svn commit: r223637 - in head: . contrib/pf/authpf contrib/pf/ftp-proxy contrib/pf/man contrib/pf/pfctl contrib/pf/pflogd sbin/pflogd sys/conf sys/contrib/altq/altq sys/contrib/pf/net sys/modules s...
Message-ID:  <BANLkTikoJV5gGkub-z_WF2cmFzHnQbxpkA@mail.gmail.com>
In-Reply-To: <20110705154747.547ac919@fabiankeil.de>
References:  <201106281157.p5SBvP5g048097@svn.freebsd.org> <EA6E6909-A42B-4CF2-891A-B8A80E2B8476@FreeBSD.org> <20110629192224.2283efc8@fabiankeil.de> <4E0F3A2D.60409@userid.org> <BANLkTi=Bu8yRVKU7XxEwjS3%2B8Kryn7WQbQ@mail.gmail.com> <20110705154747.547ac919@fabiankeil.de>

next in thread | previous in thread | raw e-mail | index | archive | help
On Tue, Jul 5, 2011 at 3:47 PM, Fabian Keil
<freebsd-listen@fabiankeil.de> wrote:
> Ermal Lu=E7i <eri@freebsd.org> wrote:
>
>> On Sat, Jul 2, 2011 at 5:33 PM, Pierre Lamy <pierre@userid.org> wrote:
>> >
>> >
>> > On 6/29/2011 1:22 PM, Fabian Keil wrote:
>> >>
>> >> "Bjoern A. Zeeb"<bz@FreeBSD.org> =A0wrote:
>> >>
>> >>> Begin forwarded message:
>> >>>
>> >>>> From: "Bjoern A. Zeeb"<bz@FreeBSD.org>
>> >>>> Date: June 28, 2011 11:57:25 AM GMT+00:00
>> >>>> To: src-committers@freebsd.org, svn-src-all@freebsd.org,
>> >>>> svn-src-head@freebsd.org
>> >>>> Subject: svn commit: r223637 - in head: . contrib/pf/authpf
>> >>>> contrib/pf/ftp-proxy contrib/pf/man contrib/pf/pfctl contrib/pf/pfl=
ogd
>> >>>> sbin/pflogd sys/conf sys/contrib/altq/altq sys/contrib/pf/net sys/m=
odules
>> >>>> s...
>> >>>>
>> >>>> Author: bz
>> >>>> Date: Tue Jun 28 11:57:25 2011
>> >>>> New Revision: 223637
>> >>>> URL: http://svn.freebsd.org/changeset/base/223637
>> >>>>
>> >>>> Log:
>> >>>> =A0Update packet filter (pf) code to OpenBSD 4.5.
>> >>
>> >> Thanks!
>> >>
>> >>> In short; please test!
>> >>
>> >> I didn't experience any real problems yet, but running
>> >> Privoxy-Regression-Test, I reproducible got this log message
>> >> for one of the tests:
>> >>
>> >> Jun 29 18:26:19 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo1, stored af=3D2, a0: 10.0.0.1:50722, a1: 10.0.0.1:12345, prot=
o=3D6, found
>> >> af=3D2, a0: 10.0.0.1:50722, a1: 10.0.0.1:12345, proto=3D6.
>> >>
>> >> This didn't happen with the previous pf version.
>> >>
>> >> I tracked it down to a test that does a connect()
>> >> to a local unbound port.
>> >>
>> >> It's also reproducible for every address on the system with:
>> >>
>> >> ifconfig -a | awk '/inet / {system("telnet "$2" 12345")}'
>> >>
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo0, stored af=3D2, a0: 192.168.5.49:61512, a1: 192.168.5.49:123=
45,
>> >> proto=3D6, found af=3D2, a0: 192.168.5.49:61512, a1: 192.168.5.49:123=
45,
>> >> proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo0, stored af=3D2, a0: 127.0.0.1:44717, a1: 127.0.0.1:12345, pr=
oto=3D6,
>> >> found af=3D2, a0: 127.0.0.1:44717, a1: 127.0.0.1:12345, proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo1, stored af=3D2, a0: 192.168.6.100:31600, a1: 192.168.6.100:1=
2345,
>> >> proto=3D6, found af=3D2, a0: 192.168.6.100:31600, a1: 192.168.6.100:1=
2345,
>> >> proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo1, stored af=3D2, a0: 10.0.0.1:20126, a1: 10.0.0.1:12345, prot=
o=3D6, found
>> >> af=3D2, a0: 10.0.0.1:20126, a1: 10.0.0.1:12345, proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo1, stored af=3D2, a0: 10.0.0.1:10895, a1: 10.0.0.2:12345, prot=
o=3D6, found
>> >> af=3D2, a0: 10.0.0.1:10895, a1: 10.0.0.2:12345, proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo1, stored af=3D2, a0: 10.0.0.1:25081, a1: 10.0.0.3:12345, prot=
o=3D6, found
>> >> af=3D2, a0: 10.0.0.1:25081, a1: 10.0.0.3:12345, proto=3D6.
>> >> Jun 29 18:30:49 r500 kernel: pf: state key linking mismatch! dir=3DOU=
T,
>> >> if=3Dlo0, stored af=3D2, a0: 192.168.0.106:32448, a1: 192.168.0.106:1=
2345,
>> >> proto=3D6, found af=3D2, a0: 192.168.0.106:32448, a1: 192.168.0.106:1=
2345,
>> >> proto=3D6.
>> >>
>> >> 12345 can be replaced with any unbound port it seems.
>> >>
>> >> I'm additionally occasionally seeing the message for successfully
>> >> established connections (both internal and outgoing) but don't
>> >> know how to reproduce it.
>> >>
>> >> Fabian
>> >
>> > I also get the state key mismatch problem, it seems that pf is leaking
>> > states (I assume this is the same problem). I also see a strange NAT i=
ssue,
>> > internal IPs leak somewhat on the outside int. Eventually the system r=
uns
>> > out of state entry slots and connectivity is lost. This is on a -curre=
nt
>> > kernel from ~Jun 30, after the 4.5 import.
>> >
>> > tun0: flags=3D8151<UP,POINTOPOINT,RUNNING,PROMISC,MULTICAST> metric 0 =
mtu 1492
>> > =A0 =A0 =A0 =A0options=3D80000<LINKSTATE>
>> > =A0 =A0 =A0 =A0inet6 fe80::290:bff:fe1a:a674%tun0 prefixlen 64 scopeid=
 0xf
>> > =A0 =A0 =A0 =A0inet6 2607:f0b0:0:1:290:bff:fe1a:a674 prefixlen 64 auto=
conf
>> > =A0 =A0 =A0 =A0inet 216.106.102.33 --> 209.87.255.1 netmask 0xffffffff
>> > =A0 =A0 =A0 =A0nd6 options=3D23<PERFORMNUD,ACCEPT_RTADV,AUTO_LINKLOCAL=
>
>> > =A0 =A0 =A0 =A0Opened by PID 3446
>> >
>> > em0 is on the 192.168.3/24 network
>> >
>> > <root.wheel@pyr7535> [/var/preserve/root] # tcpdump -i tun0 net 192.16=
8.3.0
>> > mask 255.255.255.0
>> > tcpdump: verbose output suppressed, use -v or -vv for full protocol de=
code
>> > listening on tun0, link-type NULL (BSD loopback), capture size 65535 b=
ytes
>> > 11:22:37.030244 IP 192.168.3.99 > 190.252.34.186: ICMP pandora.userid.=
org
>> > udp port 16881 unreachable, length 134
>> > 11:24:03.137016 IP 192.168.3.99 > 190.252.34.186: ICMP pandora.userid.=
org
>> > udp port 16881 unreachable, length 98
>> >
>> > Relevant pf.conf lines:
>> > int_if =3D "em0"
>> > ext_if =3D "tun0"
>> > # NAT
>> > nat on $ext_if from $int_if:network to any -> ($ext_if)
>> >
>> > Here is the info about states leaking:
>> >
>> > State Table =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Total =
=A0 =A0 =A0 =A0 =A0 =A0 Rate
>> > =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 108488
>> >
>> > <root.wheel@pyr7535> [/var/preserve/root] # pfctl -F states
>> > 1003 states cleared
>> > <root.wheel@pyr7535> [/var/preserve/root] # pfctl -s info
>> > Status: Enabled for 0 days 02:21:18 =A0 =A0 =A0 =A0 =A0 Debug: Urgent
>> >
>> > Interface Stats for tun0 =A0 =A0 =A0 =A0 =A0 =A0 =A0IPv4 =A0 =A0 =A0 =
=A0 =A0 =A0 IPv6
>> > =A0Bytes In =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A01252327614 =A0 =
=A0 =A0 =A0 =A01907903
>> > =A0Bytes Out =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0373783492 =A0 =
=A0 =A0 =A0 =A01429003
>> > =A0Packets In
>> > =A0 =A0Passed =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1341017 =
=A0 =A0 =A0 =A0 =A0 =A012360
>> > =A0 =A0Blocked =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A04543=
7 =A0 =A0 =A0 =A0 =A0 =A0 =A0831
>> > =A0Packets Out
>> > =A0 =A0Passed =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1186359 =
=A0 =A0 =A0 =A0 =A0 =A013441
>> > =A0 =A0Blocked =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 164=
1 =A0 =A0 =A0 =A0 =A0 =A0 3724
>> >
>> > State Table =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Total =
=A0 =A0 =A0 =A0 =A0 =A0 Rate
>> > =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 125127
>> >
>> > States aren't getting cleared properly. Below is a sample of the state=
 key
>> > linking mismatch problem:
>> >
>> > Jul =A02 11:28:17 pyr7535 kernel: pf: state key linking mismatch! dir=
=3DOUT,
>> > if=3Dem0, stored af=3D2, a0:
>>
>> I just committed a fix for the state key linking mismatch issue.
>> Can you test with the latest HEAD sources?
>
> Works for me, at least the error messages are gone. Thanks a lot.
>
> I never experienced the "state leak issue" Pierre described above,
> but it does seem to take a while until cleared states are reported
> as such:

It is normal the GC thread used for this takes only a bunch at a time.
Though you want see those states in the output of pfctl -vss since
they are masked out.

>
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1556
> fk@r500 ~ $sudo pfctl -F states
> 1556 states cleared
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1259
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1133
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 1019
> fk@r500 ~ $sudo pfctl -F states
> 0 states cleared
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0742
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0667
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0667
> fk@r500 ~ $sudo pfctl -F states
> 0 states cleared
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0436
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0436
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0352
> fk@r500 ~ $sudo pfctl -F states
> 0 states cleared
> fk@r500 ~ $sudo pfctl -s all | grep current
> =A0current entries =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0185
>
> I never looked at this before, so it might have always behaved that way.
>
> Fabian
>



--=20
Ermal



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?BANLkTikoJV5gGkub-z_WF2cmFzHnQbxpkA>