N2N OpenVPN not working after CU 182 upgrade

barkingdoggy · 31 January 2024 16:50

The connection is dropped immediately by the “client.” Here’s the connection log on the “client-side” ipFire machine:

Jan 31 10:18:13 MVPipfire MVP2024n2n[12021]: Cipher negotiation is disabled since neither P2MP client nor server mode is enabled
Jan 31 10:18:13 MVPipfire MVP2024n2n[12021]: WARNING: Using --management on a TCP port WITHOUT passwords is STRONGLY discouraged and considered insecure
Jan 31 10:18:13 MVPipfire MVP2024n2n[12021]: OpenVPN 2.5.9 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Sep 19 2023
Jan 31 10:18:13 MVPipfire MVP2024n2n[12021]: library versions: OpenSSL 3.1.4 24 Oct 2023, LZO 2.10
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:51001
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: ROUTE_GATEWAY ggg.ggg.ggg.ggg
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: TUN/TAP device tun1 opened
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: /sbin/ip link set dev tun1 up mtu 1500
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: /sbin/ip link set dev tun1 up
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: /sbin/ip addr add dev tun1 local 10.1.251.2 peer 10.1.251.1
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: /etc/init.d/static-routes start tun1 1500 1605 10.1.251.2 10.1.251.1 init
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: /sbin/ip route add 10.199.251.0/24 via 10.1.251.1
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: TCP/UDP: Preserving recently used remote address: [AF_INET]sss.sss.sss.sss:51001
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: UDPv4 link local (bound): [AF_INET]ccc.ccc.ccc.ccc:51001
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: UDPv4 link remote: [AF_INET]sss.sss.sss.sss:51001
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: GID set to nobody
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: UID set to nobody
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: TLS: Initial packet from [AF_INET]sss.sss.sss.sss:51001, sid=22834ec5 a1d52199
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: VERIFY OK: depth=1, C=US, ST=OH, L=New York, O=Test Corp, CN=Test Corp CA, emailAddress=jredmond@testcorp.com
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: VERIFY KU OK
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Validating certificate extended key usage
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: VERIFY EKU OK
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: VERIFY OK: depth=0, C=US, ST=VA, O=Test Corp, CN=70-88-234-69-BusName-md.hfc.comcastbusiness.net
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256
Jan 31 10:18:13 MVPipfire MVP2024n2n[12022]: [serverhostname] Peer Connection Initiated with [AF_INET]sss.sss.sss.sss:51001
Jan 31 10:18:14 MVPipfire MVP2024n2n[12022]: Initialization Sequence Completed
Jan 31 10:18:15 MVPipfire MVP2024n2n[12022]: MANAGEMENT: Client connected from [AF_INET]127.0.0.1:51001
Jan 31 10:18:15 MVPipfire MVP2024n2n[12022]: MANAGEMENT: CMD 'state'
Jan 31 10:18:15 MVPipfire MVP2024n2n[12022]: MANAGEMENT: Client disconnected

Here’s what’s happening on the server side:

Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Preserving previous TUN/TAP instance: tun0
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: TCP/UDP: Preserving recently used remote address: [AF_INET]ccc.ccc.ccc.ccc:51001
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: UDPv4 link local (bound): [AF_INET]sss.sss.sss.sss:51001
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: UDPv4 link remote: [AF_INET]ccc.ccc.ccc.ccc:51001
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: TLS: Initial packet from [AF_INET]ccc.ccc.ccc.ccc:51001, sid=70b7b96d d33563c0
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: VERIFY OK: depth=1, C=US, ST=OH, L=New York, O=Test Corp, CN=Test Corp CA, emailAddress=jredmond@testcorp.com
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: VERIFY OK: depth=0, C=US, ST=VA, O=Test Corp, OU=Enforcement, CN=70-88-234-69-BusName-md.hfc.comcastbusiness.net
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA256
Jan 31 10:18:13 ServeripFire MVP2024n2n[11033]: [serverhost] Peer Connection Initiated with [AF_INET]ccc.ccc.ccc.ccc:51001
Jan 31 10:18:14 ServeripFire MVP2024n2n[11033]: Initialization Sequence Completed
Jan 31 11:14:01 ServeripFire MVP2024n2n[11033]: MANAGEMENT: Client connected from [AF_INET]127.0.0.1:51001
Jan 31 11:14:01 ServeripFire MVP2024n2n[11033]: MANAGEMENT: CMD 'state'
Jan 31 11:14:01 ServeripFire MVP2024n2n[11033]: MANAGEMENT: Client disconnected

Note: IP addresses “sss.sss.sss.sss” are the server ipFire machine. c’s are the client ipFire addresses. g’s the client gateway. Thanks.

bonnietwin · 31 January 2024 17:43

That is very peculiar. My CU182 and CU183 have not had any problems with the n2n connections at all.

Both the “client” and the “server” end reach the

Initialization Sequence Completed

message meaning that the whole N2N connection was successfully made but then a second later there is the

MANAGEMENT: Client disconnected

message.

We need more verbosity in the logs.

Can you change the verb level in the conf files at both ends from 3 to 6 and see what more detail occurs when you try to make the connection, especially around those MANAGEMENT commands. You can try higher numbers, up to 11 is the max I believe, if there is still not enough verbosity.

The files are in

/var/ipfire/ovpn/n2nconf/n2n-name-directory/n2n-name.conf-file

After making the changes at both ends you should disconnect and re-connect the n2n ends to make sure they are using the modified conf files.

bonnietwin · 31 January 2024 18:01

I just checked my n2n connection logs.

I also get those three lines of MANAGEMENT

18:53:06	ipfirenet2netn2n[8263]: 	MANAGEMENT: Client disconnected
18:53:06	ipfirenet2netn2n[8263]: 	MANAGEMENT: CMD 'state'
18:53:06	ipfirenet2netn2n[8263]: 	MANAGEMENT: Client connected from [AF_INET]127.0.0.1:3120
18:53:04	ipfirenet2netn2n[8263]: 	Initialization Sequence Completed

Those MANAGEMENT messages are obviously nothing to do with the actual connection because although I got those messages I have got a working connection between PC’s on both ends of the n2n tunnel.

I am still able to ping from one to the other and connect into a machine on the other end via ssh and then transfer files across the tunnel.

When you say

Is that based on the messages in your logs or are you unable to ping and ssh etc to a machine at the opposite end or do you get some other error message telling you the connection has been lost?

Do they show up as CONNECTED in green colour on the OpenVPN WUI page or as DISCONNECTED and in a blue colour?

barkingdoggy · 31 January 2024 18:11

Ok. It’s working now. Before, I was not able to ping from one net to the other. Now I can. The client-side ipFire OpenVPN GUI is messed up. See:

Although on the home page it’s indcating connected. Thanks for looking into this.

bonnietwin · 31 January 2024 18:16

That second line is where you have created a new n2n connection since CU181.

That is due to a bug in a bug fix I submitted. I only just found that in my testing of CU183 but realised it was present since CU181.

I have raised a bug for what you have seen there and will be working to get it fixed.
https://bugzilla.ipfire.org/show_bug.cgi?id=13548

It is not nice because the Status is missing but the connection actually does get made. You just can’t confirm the status except by doing something like pinging.

barkingdoggy · 31 January 2024 18:24

And/or by looking at the home page. This was saying reconnecting earlier today…

bonnietwin · 1 February 2024 11:52

I now have a fix for the bug which will be submitted and probably get into CU184.

However a workaround to fix it on your current machine is to edit the

/var/ipfire/ovpn/ovpnconfig
file.
At the end of the line with the name MVP2024 you will find that there is the word disabled. This should be replaced by no-pass.
Then if you reopen the openvpn WUI page the problem should be fixed.

I just tested this out on my vm testbed and confirmed it.

barkingdoggy · 1 February 2024 13:59

I confirm that your instruction for editing the ovpnconfig works to fix that bug. Thanks!