Re: NAT with PF over umb(4) and wireguard traffic from a client blackholed

Tue, 18 May 2021 23:57:42 -0700

This can happen with any long lived UDP-based protocol that is natted to a dynamically configured address. I think this is not a bug; PF is doing exactly what you have asked it to.
The issue is that you're sending packets frequently (due to the fairly low keepalive timer) which refreshes the PF state and keeping the NAT mapping alive. Normally this is what you want, it's the whole point of the keepalive, but it falls apart when the address changes. 


As you've said, flushing all states does the trick (and it's obvious why); 
this could possibly be automated via ifstated. It's a bit heavy handed to 
flush all states when only those involving one natted IP address actually 
need it but pf doesn't have a more targetted way for states using a certain 
NAT address, short of parsing pfctl -ss and killing the individual states 
by id. Alternatively, not a generic solution but might work in your case is 
to use ifstated to run pfctl -k to delete states from the known address of 
the rpi to the known wireguard endpoint address. I'm hoping that the change 
of address would also involve a link state change so that ifstated can 
trigger on this. However the interface used by pfctl -k is buggy and I 
can't remember if this use will run into a problem or not...



I don't know if it might make sense to handle automatically in the kernel; 
it would be convenient for the user but would I think be delicate work, 
especially regarding MP locking.


--
 Sent from a phone, apologies for poor formatting.
On 19 May 2021 01:16:06 Mikolaj Kucharski <miko...@kucharski.name> wrote:


Forgot to also show PF rules:

pce-0035# grep -ve '^$' -e '^#' /etc/pf.conf
set skip on lo
set limit states 25000
queue q_umb0 on umb0 flows 1024 qlimit 50 quantum 300 default
queue q_athn0 on athn0 flows 1024 qlimit 100 quantum 300 default
match out on umb0 inet from !(umb0) nat-to (umb0:0)
match on umb0 inet all scrub (no-df random-id max-mss 1460)
block return
pass quick proto icmp all
pass quick proto icmp6 all
pass quick on tun0 from (tun0:network) to any keep state (if-bound)
pass in quick proto tcp from any to (self) port ssh
pass in quick proto udp from any to (self) port 51820
pass quick on { athn0 em0 em1 em2 }
pass out


On Wed, May 19, 2021 at 12:10:45AM +0000, miko...@kucharski.name wrote:

Synopsis: wireguard traffic blackholed after umb(4) changes ip addr
Category: kernel
Environment:

System      : OpenBSD 6.9

Details     : OpenBSD 6.9-current (GENERIC.MP) #14: Tue May 11 18:41:12 UTC 
2021

r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP

Architecture: OpenBSD.amd64
Machine     : amd64

Description:

This also occurs on vanilla kernel, but at present I'm running
custom kernel, with some athn(4) related changes.

Once in a while umb(4) disconnects from network and reconnects with new
IP address. OpenBSD machine, from this bug report has a wg0 interface
and when umb(4) changes IP address wireguard tunnel from OpenBSD to
external peer klMOiaGJpjMM1bqJouUirOIJRRqcQ8J5QdWOErfj5UM= is NOT
affected:

pce-0035# ifconfig wg0
wg0: flags=80c3<UP,BROADCAST,RUNNING,NOARP,MULTICAST> mtu 1420
index 9 priority 0 llprio 3
wgport 51820
wgpubkey BvWfmzqI94CkkI5TygWcmT10de8+7DUA2cxsl3jPeyo=
wgpeer klMOiaGJpjMM1bqJouUirOIJRRqcQ8J5QdWOErfj5UM=
       wgpsk (present)
       wgpka 25 (sec)
       wgendpoint 5.135.165.132 51820
       tx: 19396164, rx: 2960456
       last handshake: 57 seconds ago
       wgaip fde4:f456:48c2:13c0::/64
groups: wg
inet6 fde4:f456:48c2:13c0::cc35 prefixlen 64

Per above output last handshake is pretty recent. However, over em(1)
device there is RPi connected with Linux, which also has wireguard
tunnel configured to the same endpoint:

rpi-0058:~# wg
interface: wg0
public key: QLG8RSrYJ/MUmIo2NJcgwleAnPFnl843HwNDgcd9u0c=
private key: (hidden)
listening port: 51820

peer: klMOiaGJpjMM1bqJouUirOIJRRqcQ8J5QdWOErfj5UM=
preshared key: (hidden)
endpoint: 5.135.165.132:51820
allowed ips: fde4:f456:48c2:13c0::/64
latest handshake: 1 day, 29 minutes, 14 seconds ago
transfer: 424.79 KiB received, 3.09 MiB sent
persistent keepalive: every 25 seconds

Per above output, we see that latest handshake was more than a day ago.
When I look tcpdump on em(4) which is connected to RPi I see following:

pce-0035# tcpdump -c5 -ni em1 host 5.135.165.132 and port 51820
tcpdump: listening on em1, link-type EN10MB

23:22:03.803721 192.168.1.58.51820 > 5.135.165.132.51820: [wg] initiation 
from 0xec39d550 [tos 0x88]
23:22:08.923739 192.168.1.58.51820 > 5.135.165.132.51820: [wg] initiation 
from 0x13821437 [tos 0x88]
23:22:14.043830 192.168.1.58.51820 > 5.135.165.132.51820: [wg] initiation 
from 0x3fda1931 [tos 0x88]
23:22:19.803752 192.168.1.58.51820 > 5.135.165.132.51820: [wg] initiation 
from 0x1537a4da [tos 0x88]
23:22:25.083788 192.168.1.58.51820 > 5.135.165.132.51820: [wg] initiation 
from 0x93343c5f [tos 0x88]


Then when I look at tcpdmump on umb(4) I see traffic from local machine,
which works fine, but also we see above initiation traffic from RPi,
which uses wrong (old) IP address (TWO wrong IP addresses):

pce-0035# tcpdump -c50 -ni umb0 host 5.135.165.132 and port 51820
tcpdump: listening on umb0, link-type LOOP

23:23:30.355499 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 160 to 0x12b4877c nonce 6
23:23:30.355695 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 160 to 0x12b4877c nonce 7
23:23:30.421959 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 7
23:23:30.614535 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 8
23:23:31.360393 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 8
23:23:31.360398 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 256 to 0x12b4877c nonce 9
23:23:31.431873 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 9
23:23:32.369725 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 10
23:23:32.683202 100.102.59.145.52422 > 5.135.165.132.51820: [wg] initiation 
from 0x3007810a [tos 0x88]
23:23:32.744484 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 10
23:23:33.379929 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 256 to 0x12b4877c nonce 11
23:23:33.380107 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 12
23:23:33.518203 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 11
23:23:34.389827 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 13
23:23:34.753559 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 12
23:23:35.399748 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 14
23:23:35.774192 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 13
23:23:35.903086 100.100.10.26.55426 > 5.135.165.132.51820: [wg] initiation 
from 0xa30f0817 [tos 0x88]
23:23:36.409833 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 15
23:23:36.409838 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 256 to 0x12b4877c nonce 16
23:23:36.550602 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 14
23:23:37.419936 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 17
23:23:37.712890 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 15
23:23:37.882966 100.102.59.145.52422 > 5.135.165.132.51820: [wg] initiation 
from 0x293df129 [tos 0x88]
23:23:38.429823 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 18
23:23:38.834033 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 16
23:23:39.439863 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 19
23:23:39.801909 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 17
23:23:40.449874 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 20
23:23:40.833360 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 18
23:23:41.279245 100.100.10.26.55426 > 5.135.165.132.51820: [wg] initiation 
from 0xe9cf88d8 [tos 0x88]
23:23:41.459919 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 21
23:23:41.794501 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 19
23:23:42.469957 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 22
23:23:42.833630 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 20
23:23:43.082901 100.102.59.145.52422 > 5.135.165.132.51820: [wg] initiation 
from 0x41dfd760 [tos 0x88]
23:23:43.479931 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 23
23:23:43.873761 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 21
23:23:44.489891 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 24
23:23:44.833901 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 22
23:23:45.500016 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 25
23:23:45.874031 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 23
23:23:46.398752 100.100.10.26.55426 > 5.135.165.132.51820: [wg] initiation 
from 0x2aaeec29 [tos 0x88]
23:23:46.510138 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 480 to 0x12b4877c nonce 26
23:23:46.782331 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 24
23:23:47.520027 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 27
23:23:47.794006 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 25
23:23:48.530003 100.125.241.79.51820 > 5.135.165.132.51820: [wg] data 
length 368 to 0x12b4877c nonce 28
23:23:48.762716 100.102.59.145.52422 > 5.135.165.132.51820: [wg] initiation 
from 0xa0dadeeb [tos 0x88]
23:23:48.904684 5.135.165.132.51820 > 100.125.241.79.51820: [wg] data 
length 80 to 0xb8f89c82 nonce 26


Above grep for `initiation from`.

See IP addr 100.125.241.79 (working) versus 100.100.10.26 (not working),
100.102.59.145 (another not working) and states in PF:

pce-0035# pfctl -ss | grep -F 5.135.165.132:51820
all udp 5.135.165.132:51820 <- 192.168.1.58:51820       MULTIPLE:MULTIPLE

all udp 100.102.59.145:52422 (192.168.1.58:51820) -> 5.135.165.132:51820    
   MULTIPLE:MULTIPLE

all udp 5.135.165.132:51820 <- 192.168.5.189:51820       MULTIPLE:MULTIPLE

all udp 100.100.10.26:55426 (192.168.5.189:51820) -> 5.135.165.132:51820    
   MULTIPLE:MULTIPLE

all udp 100.125.241.79:51820 -> 5.135.165.132:51820       MULTIPLE:MULTIPLE

Current IP address on umb(4) is 100.125.241.79:

pce-0035# ifconfig umb0
umb0: flags=8855<UP,DEBUG,POINTOPOINT,RUNNING,SIMPLEX,MULTICAST> mtu 1500
index 7 priority 6 llprio 3
roaming disabled registration home network
state up cell-class LTE rssi -101dBm speed 47.7Mbps up 286Mbps down
SIM initialized PIN valid (3 attempts left)
subscriber-id 000000000000000 ICC-id 00000000000000000000 provider PLAY
device MC7455 IMEI 000000000000000 firmware SWI9X30C_02.33.03.00
APN internet
dns 89.108.202.20 185.89.185.1
groups: egress
status: active
inet 100.125.241.79 --> 100.125.241.80 netmask 0xffffffe0

I do periodic ifconfig(8) and send it to syslog, so I see IP address
changed twice during uptime of this machine:

# zgrep -F 'inet 100' /var/log/messages...
...

2021-05-17T23:21:01.528Z pce-0035 ifconfig[80523]:      inet 100.102.59.145 
--> 100.102.59.146 netmask 0xfffffffc
2021-05-17T23:32:47.049Z pce-0035 ifconfig[43011]:      inet 100.102.59.145 
--> 100.102.59.146 netmask 0xfffffffc
2021-05-17T23:32:47.049Z pce-0035 ifconfig[43011]:      inet 100.100.10.26 
--> 100.100.10.25 netmask 0xfffffffc
2021-05-18T00:21:01.195Z pce-0035 ifconfig[96823]:      inet 100.100.10.26 
--> 100.100.10.25 netmask 0xfffffffc

...

2021-05-18T16:21:01.975Z pce-0035 ifconfig[21612]:      inet 100.100.10.26 
--> 100.100.10.25 netmask 0xfffffffc
2021-05-18T16:38:15.484Z pce-0035 ifconfig[43011]:      inet 100.100.10.26 
--> 100.100.10.25 netmask 0xfffffffc
2021-05-18T16:38:15.484Z pce-0035 ifconfig[43011]:      inet 100.125.241.79 
--> 100.125.241.80 netmask 0xffffffe0
2021-05-18T17:21:01.649Z pce-0035 ifconfig[27235]:      inet 100.125.241.79 
--> 100.125.241.80 netmask 0xffffffe0

...


How-To-Repeat:

Setup NAT with PF, connect wireguard client over internal
network, which goes over external interface which changes IP address
once in a while, in my case it's umb(4).


Fix:

Unknown. Many workarounds, pfctl -Fs, seems the simplest?

After pfctl -Fs, wireguard tunnel works straightaway:

rpi-0058:~# ping6 -n -c5 fde4:f456:48c2:13c0::1
PING fde4:f456:48c2:13c0::1(fde4:f456:48c2:13c0::1) 56 data bytes
64 bytes from fde4:f456:48c2:13c0::1: icmp_seq=2 ttl=64 time=54.3 ms
64 bytes from fde4:f456:48c2:13c0::1: icmp_seq=3 ttl=64 time=58.7 ms
64 bytes from fde4:f456:48c2:13c0::1: icmp_seq=4 ttl=64 time=60.9 ms
64 bytes from fde4:f456:48c2:13c0::1: icmp_seq=5 ttl=64 time=70.7 ms

--- fde4:f456:48c2:13c0::1 ping statistics ---
5 packets transmitted, 4 received, 20% packet loss, time 15ms
rtt min/avg/max/mdev = 54.346/61.151/70.704/5.993 ms


Latest handshake obviously drops to a recent value:

rpi-0058:~# wg
interface: wg0
public key: QLG8RSrYJ/MUmIo2NJcgwleAnPFnl843HwNDgcd9u0c=
private key: (hidden)
listening port: 51820

peer: klMOiaGJpjMM1bqJouUirOIJRRqcQ8J5QdWOErfj5UM=
preshared key: (hidden)
endpoint: 5.135.165.132:51820
allowed ips: fde4:f456:48c2:13c0::/64
latest handshake: 1 minute, 20 seconds ago
transfer: 429.69 KiB received, 3.12 MiB sent
persistent keepalive: every 25 seconds


--
Regards,
Mikolaj
























					Reply via email to