OpenVPN peer2peer broken after update to 23.7.5

[daudo]

Hi,

after doing a minor update from 23.7.x to 23.7.5, one of our firewalls fails to establish a previously working OpenVPN peer-to-peer connection to another firewall. No setting has been changed and looking at the logs, I don't see much of a difference, except that after the upgrade I see a "FreeBSD ifconfig failed: external program exited with error status: 1", but have a look for yourself (IP addresses and host names etc redacted):

logs from before the upgrade:

Code Select Expand

<28>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48537 - [meta sequenceId="26"] WARNING: Compression for receiving enabled. Compression has been used in the past to break encryption. Sent packets are not compressed unless "allow-compression yes" is also set.
<28>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48537 - [meta sequenceId="27"] DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations.
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48537 - [meta sequenceId="28"] OpenVPN 2.6.6 amd64-portbld-freebsd13.2 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD]
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48537 - [meta sequenceId="29"] library versions: OpenSSL 1.1.1v  1 Aug 2023, LZO 2.10
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="30"] MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client1.sock
<28>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="31"] WARNING: using --pull/--client and --ifconfig together is probably not what you want
<28>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="32"] WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
<28>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="33"] NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="34"] TCP/UDP: Preserving recently used remote address: [AF_INET]233.252.0.237:1195
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="35"] Socket Buffers: R=[42080->42080] S=[57344->57344]
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="36"] UDPv4 link local (bound): [AF_INET]233.252.0.103:0
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="37"] UDPv4 link remote: [AF_INET]233.252.0.237:1195
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="38"] TLS: Initial packet from [AF_INET]233.252.0.237:1195, sid=74dd58be 5cba6ac3
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="39"] VERIFY OK: depth=2, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=Example.com CA 2022, emailAddress=foobar@example.com
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="39"] VERIFY OK: depth=1, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=Example.com HTTPS CA 2022, emailAddress=foobar@example.com
<29>1 2023-09-09T19:54:17+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="39"] VERIFY OK: depth=0, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=peera.example.com, emailAddress=foobar@example.com
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="58"] Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA256
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="59"] [peera.example.com] Peer Connection Initiated with [AF_INET]233.252.0.237:1195
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="60"] TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="61"] TLS: tls_multi_process: initial untrusted session promoted to trusted
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="62"] PUSH: Received control message: 'PUSH_REPLY,route 172.21.1.0 255.255.255.0,route 172.21.254.0 255.255.255.0,route 172.16.5.0 255.255.255.0,route 172.21.7.0 255.255.255.0,route 172.22.0.0 255.255.255.0,route 172.22.1.0 255.255.255.0,route 172.21.253.0 255.255.255.0,route 10.9.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.19.0.6 10.19.0.5,peer-id 0,cipher AES-256-GCM'
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="63"] OPTIONS IMPORT: --ifconfig/up options modified
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="64"] OPTIONS IMPORT: route options modified
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="65"] ROUTE_GATEWAY 233.252.0.242/255.255.255.255 IFACE=pppoe0 HWADDR=00:00:00:00:00:00
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="66"] TUN/TAP device ovpnc1 exists previously, keep at program end
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="67"] TUN/TAP device /dev/tun1 opened
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="68"] /sbin/ifconfig ovpnc1 10.19.0.6 10.19.0.5 mtu 1500 netmask 255.255.255.255 up
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="69"] /usr/local/etc/inc/plugins.inc.d/openvpn/ovpn-linkup ovpnc1 1500 0 10.19.0.6 10.19.0.5 init
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="70"] /sbin/route add -net 172.21.251.0 10.9.0.5 255.255.255.0
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="71"] /sbin/route add -net 172.16.5.0 10.9.0.5 255.255.255.0
<29>1 2023-09-09T19:54:18+02:00 peerb.example.com openvpn_client1 48688 - [meta sequenceId="72"] /sbin/route add -net 172.21.1.0 10.9.0.5 255.255.255.0
[...]


logs from after the upgrade with the failing connection:

Code Select Expand


<28>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81021 - [meta sequenceId="26"] WARNING: Compression for receiving enabled. Compression has been used in the past to break encryption. Sent packets are not compressed unless "allow-compression yes" is also set.
<28>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81021 - [meta sequenceId="27"] DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations.
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81021 - [meta sequenceId="28"] OpenVPN 2.6.6 amd64-portbld-freebsd13.2 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD]
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81021 - [meta sequenceId="29"] library versions: OpenSSL 1.1.1w  11 Sep 2023, LZO 2.10
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="30"] MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client1.sock
<28>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="31"] WARNING: using --pull/--client and --ifconfig together is probably not what you want
<28>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="32"] WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
<28>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="33"] NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="34"] TCP/UDP: Preserving recently used remote address: [AF_INET]233.252.0.237:1195
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="35"] Socket Buffers: R=[42080->42080] S=[57344->57344]
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="36"] UDPv4 link local (bound): [AF_INET]233.252.0.103:0
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="37"] UDPv4 link remote: [AF_INET]233.252.0.237:1195
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="38"] TLS: Initial packet from [AF_INET]233.252.0.237:1195, sid=ece7d1b9 47113c63
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="39"] VERIFY OK: depth=2, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=Example.com CA 2022, emailAddress=foobar@example.com
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="40"] VERIFY OK: depth=1, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=Example.com HTTPS CA 2022, emailAddress=foobar@example.com
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="41"] VERIFY OK: depth=0, C=AT, ST=Tirol, L=Innsbruck, O=Example.com, OU=sysops team, CN=peera.example.com, emailAddress=foobar@example.com
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="58"] Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA256
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="59"] [peera.example.com] Peer Connection Initiated with [AF_INET]233.252.0.237:1195
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="60"] TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="61"] TLS: tls_multi_process: initial untrusted session promoted to trusted
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="62"] PUSH: Received control message: 'PUSH_REPLY,route 172.21.1.0 255.255.255.0,route 172.21.254.0 255.255.255.0,route 172.16.5.0 255.255.255.0,route 172.21.7.0 255.255.255.0,route 172.22.0.0 255.255.255.0,route 172.22.1.0 255.255.255.0,route 172.21.253.0 255.255.255.0,route 10.9.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.19.0.6 10.19.0.5,peer-id 0,cipher AES-256-GCM'
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="63"] OPTIONS IMPORT: --ifconfig/up options modified
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="64"] OPTIONS IMPORT: route options modified
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="65"] ROUTE_GATEWAY 233.252.0.242/255.255.255.255 IFACE=pppoe0 HWADDR=00:00:00:00:00:00
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="66"] TUN/TAP device ovpnc1 exists previously, keep at program end
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="67"] TUN/TAP device /dev/tun1 opened
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="68"] /sbin/ifconfig ovpnc1 10.19.0.6 10.19.0.5 mtu 1500 netmask 255.255.255.255 up
<27>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="69"] FreeBSD ifconfig failed: external program exited with error status: 1
<29>1 2023-10-06T17:52:04+02:00 peerb.example.com openvpn_client1 81047 - [meta sequenceId="70"] Exiting due to fatal error


In the meantime, I've tried all kinds of things (like recreating the connection in new "Instances" page), but all to no avail unfortunately.

little update: when trying to initiate the connection directly on the shell, I see that ifconfig fails with "ifconfig: ioctl (SIOCAIFADDR): File exists":

Code Select Expand

# /usr/local/sbin/openvpn --log /var/log/foobar.log --errors-to-stderr --config /var/etc/openvpn/client1.conf
root@peerb:/usr/local # tail -5 /var/log/foobar.log
2023-10-07 12:46:27 TUN/TAP device /dev/tun1 opened
2023-10-07 12:46:27 /sbin/ifconfig ovpnc1 10.19.0.6 10.19.0.5 mtu 1500 netmask 255.255.255.255 up
ifconfig: ioctl (SIOCAIFADDR): File exists
2023-10-07 12:46:27 FreeBSD ifconfig failed: external program exited with error status: 1
2023-10-07 12:46:27 Exiting due to fatal error


Any ideas?

[Monviech (Cedrik)]

I don't know OpenVPN in depth, but that error looks like the IP address you're trying to assign to your TUN/TAP interface already exists.

Can you try to create an interface with a different IP? Maybe a ovpnc2?

[daudo]

thanks for that idea. From a network POV, I should be able to assign the same IP address to multiple interfaces (for very exotic configurations), but that isn't the case here anyways:

Code Select Expand

root@peerb:~ # ifconfig | grep -2 '10.19'
root@peerb:~ #
root@peerb:~ # ifconfig ovpnc1
ovpnc1: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1500
options=80000<LINKSTATE>
groups: tun openvpn
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
root@peerb:~ # /sbin/ifconfig ovpnc1 10.19.0.6 10.19.0.5 mtu 1500 netmask 255.255.255.255 up
ifconfig: ioctl (SIOCAIFADDR): File exists
root@peerb:~ #
root@peerb:~ # /sbin/ifconfig ovpnc1 10.19.0.16 10.19.0.15 mtu 1500 netmask 255.255.255.255 up
root@peerb:~ # ifconfig ovpnc1
ovpnc1: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1500
options=80000<LINKSTATE>
inet 10.19.0.16 --> 10.19.0.15 netmask 0xffffffff
groups: tun openvpn
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
root@peerb:/var/etc/openvpn #


... so how weird is that ... I cannot assign 10.19.0.6, but I can assign 10.19.0.16 ...

[daudo]

Alright, so after a day of debugging and trying to figure out what was doing on I also investigated the remote firewall settings that I was trying to connect to.

What helped there was to disable the OpenVPN address pool that was configured at the server side to keep client IP tunnel addresses stable over disconnects.

After disabling the pool on the server side (peera.example.com in my example), I could connect to the server from peerb.example.com as a client, now assigned a new peer to peer tunnel address.

So for the time being, things are working again, but I am still flabbergasted what went wrong after the update in the first place ...