Need to edit OpenVPN server config after each reboot

fsutter · Mar 3, 2023, 6:51 AM

Hi,
after each reboot I need to edit my OpenVPN server config in /vpn_openvpn_server.php and click save (without making any change) to be able to connect from my clients.
Otherwise, my client cannot connect.
It's very strange, does someone have a clue?

Many thanks in advance and kind regards,

fsutter

Gertjan · Mar 3, 2023, 7:40 AM

@fsutter

Hitting the save button, or hitting restart here :

on the Service Status dashboard page, does the same thing : it starts or restarts the OpenVPN server.

But this is a no better solution of course.

The solution is available on the OpenVPN log page.
There you can find why OpenVPN doesn't wanted to start - or failed to start.
read it, act upon it, redo what has to be redone, and you'll be fine.

fsutter · Mar 3, 2023, 7:57 AM

@gertjan thanks for the tip but it doesn't help

My client is stuck here even after a restart:

After going to the config page and just hitting save button it works:

In both case, OpenVPN server is up but something prevents the connection to really happen.

regards,

Gertjan · Mar 3, 2023, 9:04 AM

@fsutter

These images look like small fragments of the entire VPN connect process, on the client side.
Probably an iPhone. That's fine, I've one also.
Here is my connection log : 1000 times smaller as your, and with all the details, from start to end (there is a 'send log to some one button on the iPone log screen ) :

[Mar 03, 2023, 09:54:31] START CONNECTION

[Mar 03, 2023, 09:54:31] ----- OpenVPN Start -----
OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 09:54:31] OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 09:54:31] Frame=512/2048/512 mssfix-ctrl=1250

[Mar 03, 2023, 09:54:31] UNUSED OPTIONS
0 [persist-tun]
1 [persist-key]
2 [data-ciphers] [AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305]
3 [data-ciphers-fallback] [AES-256-GCM]
5 [tls-client]
8 [lport] [0]
11 [explicit-exit-notify]

[Mar 03, 2023, 09:54:31] EVENT: RESOLVE

[Mar 03, 2023, 09:54:31] Contacting [64:ff9b::527f:1a6c]:1194 via UDP

[Mar 03, 2023, 09:54:31] EVENT: WAIT

[Mar 03, 2023, 09:54:31] Connecting to [82.127.226.100]:1194 (64:ff9b::527f:1a6c) via
UDPv6

[Mar 03, 2023, 09:54:31] EVENT: CONNECTING

[Mar 03, 2023, 09:54:31] Tunnel Options:V4,dev-type tun,link-mtu 1553,tun-mtu
1500,proto UDPv4,cipher BF-CBC,auth SHA256,keysize 128,key-method 2,tls-client

[Mar 03, 2023, 09:54:31] Creds: UsernameEmpty/PasswordEmpty

[Mar 03, 2023, 09:54:31] Peer Info:
IV_VER=3.git::081bfebe
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:BF-CBC
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086
IV_SSO=webauth,openurl,crtext
IV_BS64DL=1


[Mar 03, 2023, 09:54:31] VERIFY OK: depth=1, /C=FR/ST=LG/L=Cuzorn/O=My
Comp/emailAddress=gertjan@my-domain.tld/CN=ca-openvpn/OU=My Dept, signature: RSA-SHA256

[Mar 03, 2023, 09:54:31] VERIFY OK: depth=0, /C=FR/ST=LG/L=Cuzorn/O=My
Comp/emailAddress=gertjan@my-domain.tld/CN=my-domain.tld/OU=My Dept, signature:
RSA-SHA256

[Mar 03, 2023, 09:54:32] SSL Handshake: peer certificate: CN=my-domain.tld,
2048 bit RSA, cipher: TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256)
Mac=AEAD


[Mar 03, 2023, 09:54:32] Session is ACTIVE

[Mar 03, 2023, 09:54:32] EVENT: GET_CONFIG

[Mar 03, 2023, 09:54:32] Sending PUSH_REQUEST to server...

[Mar 03, 2023, 09:54:32] OPTIONS:
0 [dhcp-option] [DOMAIN] [my-domain.tld]
1 [dhcp-option] [DNS] [192.168.3.1]
2 [block-outside-dns]
3 [register-dns]
4 [dhcp-option] [NTP] [192.168.1.1]
5 [redirect-gateway] [def1]
6 [route-gateway] [192.168.3.1]
7 [topology] [subnet]
8 [ping] [10]
9 [ping-restart] [60]
10 [ifconfig] [192.168.3.2] [255.255.255.0]
11 [peer-id] [0]
12 [cipher] [AES-256-GCM]
13 [key-derivation] [tls-ekm]


[Mar 03, 2023, 09:54:32] PROTOCOL OPTIONS:
cipher: AES-256-GCM
digest: NONE
key-derivation: TLS Keying Material Exporter [RFC5705]
compress: NONE
peer ID: 0
control channel: tls-crypt enabled

[Mar 03, 2023, 09:54:32] EVENT: ASSIGN_IP

[Mar 03, 2023, 09:54:32] NIP: preparing TUN network settings

[Mar 03, 2023, 09:54:32] NIP: init TUN network settings with endpoint:
64:ff9b::527f:1a6c

[Mar 03, 2023, 09:54:32] NIP: adding IPv4 address to network settings
192.168.3.2/255.255.255.0

[Mar 03, 2023, 09:54:32] NIP: adding (included) IPv4 route 192.168.3.0/24

[Mar 03, 2023, 09:54:32] NIP: redirecting all IPv4 traffic to TUN interface

[Mar 03, 2023, 09:54:32] NIP: adding match domain my-domain.tld

[Mar 03, 2023, 09:54:32] NIP: adding DNS 192.168.3.1

[Mar 03, 2023, 09:54:32] Connected via NetworkExtensionTUN

[Mar 03, 2023, 09:54:32] EVENT: CONNECTED 82.127.226.100:1194 (64:ff9b::527f:1a6c)
via /UDPv6 on NetworkExtensionTUN/192.168.3.2/ gw=[/]


————-
Envoyé de mon iPhone

I didn't saw any lines that could indicate an error.

But this client log is just half of the story.
What about the other side ?
Where is the pfSense admin ??
Why doesn't he post his OpenVPN server side of the log ????
No images pleace : text, like what I did above.
Take out the private stuff with search/replace.

fsutter · Mar 3, 2023, 1:08 PM

@gertjan Fair enough,

here is the client log at reboot:

[Mar 03, 2023, 14:02:44] START CONNECTION

[Mar 03, 2023, 14:02:44] ----- OpenVPN Start -----
OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 14:02:44] OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 14:02:44] Frame=512/2048/512 mssfix-ctrl=1250

[Mar 03, 2023, 14:02:44] UNUSED OPTIONS
4 [auth-nocache]
7 [resolv-retry] [infinite]
8 [user] [nobody]
9 [group] [nobody]
10 [persist-key]
11 [persist-tun]
13 [verb] [3]

[Mar 03, 2023, 14:02:44] EVENT: RESOLVE

[Mar 03, 2023, 14:02:44] Contacting X.X.X.X:1194 via UDP

[Mar 03, 2023, 14:02:44] EVENT: WAIT

[Mar 03, 2023, 14:02:44] Connecting to [vpn.domain.com]:1194 (X.X.X.X) via UDPv4

[Mar 03, 2023, 14:02:44] EVENT: CONNECTING

[Mar 03, 2023, 14:02:44] Tunnel Options:V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client

[Mar 03, 2023, 14:02:44] Creds: UsernameEmpty/PasswordEmpty

[Mar 03, 2023, 14:02:44] Peer Info:
IV_VER=3.git::081bfebe
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086
IV_SSO=webauth,openurl,crtext


[Mar 03, 2023, 14:02:45] VERIFY OK: depth=1, /C=FR/ST=Haut-Rhin/L=Rosenau/O=Root Certification Authority/CN=XXXXX Root CA ECC, signature: ecdsa-with-SHA512

[Mar 03, 2023, 14:02:45] VERIFY OK: depth=0, /CN=server/ST=Haut-Rhin/C=FR/emailAddress=openvpn@domain.com/O=Sutter/OU=OpenVPN, signature: ecdsa-with-SHA512

Here is the client log after save button was clicked:

[Mar 03, 2023, 10:29:33] START CONNECTION

[Mar 03, 2023, 10:29:33] ----- OpenVPN Start -----
OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 10:29:33] OpenVPN core 3.git::081bfebe ios arm64 64-bit

[Mar 03, 2023, 10:29:33] Frame=512/2048/512 mssfix-ctrl=1250

[Mar 03, 2023, 10:29:33] UNUSED OPTIONS
4 [auth-nocache]
7 [resolv-retry] [infinite]
8 [user] [nobody]
9 [group] [nobody]
10 [persist-key]
11 [persist-tun]
13 [verb] [3]

[Mar 03, 2023, 10:29:33] EVENT: RESOLVE

[Mar 03, 2023, 10:29:34] Contacting X.X.X.X:1194 via UDP

[Mar 03, 2023, 10:29:34] EVENT: WAIT

[Mar 03, 2023, 10:29:34] Connecting to [vpn.domain.com]:1194 (X.X.X.X) via UDPv4

[Mar 03, 2023, 10:29:34] EVENT: CONNECTING

[Mar 03, 2023, 10:29:34] Tunnel Options:V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client

[Mar 03, 2023, 10:29:34] Creds: UsernameEmpty/PasswordEmpty

[Mar 03, 2023, 10:29:34] Peer Info:
IV_VER=3.git::081bfebe
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086
IV_SSO=webauth,openurl,crtext


[Mar 03, 2023, 10:29:34] VERIFY OK: depth=1, /C=FR/ST=Haut-Rhin/L=Rosenau/O=Root Certification Authority/CN=XXXX Root CA ECC, signature: ecdsa-with-SHA512

[Mar 03, 2023, 10:29:34] VERIFY OK: depth=0, /CN=server/ST=Haut-Rhin/C=FR/emailAddress=openvpn@domain.com/O=XXXXX/OU=OpenVPN, signature: ecdsa-with-SHA512

[Mar 03, 2023, 10:29:36] SSL Handshake: peer certificate: CN=server, 384 bit EC, curve:secp384r1, cipher: TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD


[Mar 03, 2023, 10:29:36] Session is ACTIVE

[Mar 03, 2023, 10:29:36] EVENT: GET_CONFIG

[Mar 03, 2023, 10:29:36] Sending PUSH_REQUEST to server...

[Mar 03, 2023, 10:29:36] OPTIONS:
0 [redirect-gateway] [def1]
1 [redirect-gateway] [ipv6]
2 [dhcp-option] [DNS] [192.168.1.1]
3 [tun-ipv6]
4 [route-gateway] [172.24.7.1]
5 [topology] [subnet]
6 [ping] [10]
7 [ping-restart] [60]
8 [ifconfig-ipv6] [2a01:AAA:AAA:XXXX::1000/64] [2a01:e0a:CCC:CCC:1]
9 [ifconfig] [172.24.7.2] [255.255.255.0]
10 [peer-id] [0]
11 [cipher] [AES-256-GCM]


[Mar 03, 2023, 10:29:36] PROTOCOL OPTIONS:
cipher: AES-256-GCM
digest: NONE
key-derivation: OpenVPN PRF
compress: NONE
peer ID: 0
control channel: tls-auth enabled

[Mar 03, 2023, 10:29:36] EVENT: ASSIGN_IP

[Mar 03, 2023, 10:29:36] NIP: preparing TUN network settings

[Mar 03, 2023, 10:29:36] NIP: init TUN network settings with endpoint: X.X.X.X

[Mar 03, 2023, 10:29:36] NIP: adding IPv4 address to network settings 172.24.7.2/255.255.255.0

[Mar 03, 2023, 10:29:36] NIP: adding (included) IPv4 route 172.24.7.0/24

[Mar 03, 2023, 10:29:36] NIP: adding IPv6 address to network settings 2a01:EEE:AAA:XXXX::1000/64

[Mar 03, 2023, 10:29:36] NIP: adding (included) IPv6 route 2a01:EEE:AAA:XXX::/64

[Mar 03, 2023, 10:29:36] NIP: redirecting all IPv4 traffic to TUN interface

[Mar 03, 2023, 10:29:36] NIP: redirecting all IPv6 traffic to TUN interface

[Mar 03, 2023, 10:29:36] NIP: adding DNS 192.168.1.1

[Mar 03, 2023, 10:29:36] Connected via NetworkExtensionTUN

[Mar 03, 2023, 10:29:36] EVENT: CONNECTED vpn.domain.com:1194 (X.X.X.X) via /UDPv4 on NetworkExtensionTUN/172.24.7.2/2a01:EEE:AAA:XXX::1000 gw=[/]

[Mar 03, 2023, 10:29:39] EVENT: DISCONNECTED

[Mar 03, 2023, 10:29:39] EVENT: CORE_THREAD_DONE

[Mar 03, 2023, 10:29:39] EVENT: DISCONNECT_PENDING

[Mar 03, 2023, 10:29:39] Raw stats on disconnect:
BYTES_IN : 38657
BYTES_OUT : 14883
PACKETS_IN : 76
PACKETS_OUT : 80
TUN_BYTES_IN : 5728
TUN_BYTES_OUT : 33529
TUN_PACKETS_IN : 65
TUN_PACKETS_OUT : 67


[Mar 03, 2023, 10:29:39] Performance stats on disconnect:
CPU usage (microseconds): 95484
Tunnel compression ratio (uplink): 2.59829
Tunnel compression ratio (downlink): 1.15294
Network bytes per CPU second: 560722
Tunnel bytes per CPU second: 411136

As described before at reboot, the connection is stuck at:
[Mar 03, 2023, 14:02:45] VERIFY OK: depth=0, /CN=server/ST=Haut-Rhin/C=FR/emailAddress=openvpn@domain.com/O=Sutter/OU=OpenVPN, signature: ecdsa-with-SHA512

Do I need also to post the Server logs?

Many thanks in advance and kind regards,

fsutter

Gertjan · Mar 3, 2023, 4:01 PM

@fsutter said in Need to edit OpenVPN server config after each reboot:

As described before at reboot, the connection is stuck at:

Reboot of the phone ?

But I have something else - and .... my connections works (using iPhone also, same OpenVPN app as you).

[dhcp-option] [DNS] [192.168.1.1] => Are you sure that the LAN IP is your VPN DNS ? Why not - see my options in my log ?

4 [route-gateway] [172.24.7.1] : just checking : why not 192.168.2.1 ? (I've nothing against 172.24.7.1, just that it doesn't look and feel like RFC1918, but I might be mistaken)

3 [tun-ipv6] : I used IPv6 also for my tunnel before. Why not, but better have your IPv6 act together. All OSs prefer IPv6 and if you announce it 'exists' but doesn't 'work', then it's fail time.

Also compare
Me :
Tunnel Options:.... link-mtu 1553,.........,cipher BF-CBC,auth SHA256,keysize 128,......
You :
Tunnel Options:.....,link-mtu 1601,.........,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,.....

@fsutter said in Need to edit OpenVPN server config after each reboot:

Do I need also to post the Server logs?

If there is nothing suspicious, well no.
But : I can't post without info.

And the fact is : after certs are send by the client, and certs IS the authentication you are using, the server stays silent.
Like it did not accept the 'login' (by cert).
Check server side.

fsutter · Mar 6, 2023, 1:34 PM

@gertjan

Here are the logs from the server:

After a reboot (when the connection doesn't work):

Last 5 OpenVPN Log Entries. (Maximum 500)
Mar 6 12:34:02 	openvpn 	7436 	77.131.11.51:62217 Certificate does not have key usage extension
Mar 6 12:34:02 	openvpn 	7436 	77.131.11.51:62217 OpenSSL: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
Mar 6 12:34:02 	openvpn 	7436 	77.131.11.51:62217 TLS_ERROR: BIO read tls_read_plaintext error
Mar 6 12:34:02 	openvpn 	7436 	77.131.11.51:62217 TLS Error: TLS object -> incoming plaintext read error
Mar 6 12:34:02 	openvpn 	7436 	77.131.11.51:62217 TLS Error: TLS handshake failed

After just clicked on the save button in the OpenVPN server config:

Last 23 OpenVPN Log Entries. (Maximum 500)
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_VER=3.git::081bfebe
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_PLAT=ios
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_NCP=2
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_TCPNL=1
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_PROTO=30
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_AUTO_SESS=1
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 peer info: IV_SSO=webauth,openurl,crtext
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1549', remote='link-mtu 1601'
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA512'
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #5 / time = (1678102545) 2023-03-06 12:35:45 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 TLS Error: incoming packet authentication failed from [AF_INET]77.131.11.51:53542
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #6 / time = (1678102545) 2023-03-06 12:35:45 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 TLS Error: incoming packet authentication failed from [AF_INET]77.131.11.51:53542
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #5 / time = (1678102545) 2023-03-06 12:35:45 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 TLS Error: incoming packet authentication failed from [AF_INET]77.131.11.51:53542
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #6 / time = (1678102545) 2023-03-06 12:35:45 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 TLS Error: incoming packet authentication failed from [AF_INET]77.131.11.51:53542
Mar 6 12:35:49 	openvpn 	27206 	77.131.11.51:53542 [iPhone6sFred] Peer Connection Initiated with [AF_INET]77.131.11.51:53542
Mar 6 12:35:49 	openvpn 	27206 	iPhone/77.131.11.51:53542 MULTI_sva: pool returned IPv4=172.24.7.2, IPv6=2a01:AAA:BBB:FFFF::1000
Mar 6 12:35:49 	openvpn 	4478 	openvpn server 'ovpns1' user cert CN 'iPhone' address '77.131.11.51' - connected
Mar 6 12:36:02 	openvpn 	55729 	openvpn server 'ovpns1' user cert CN 'iPhone' address '77.131.11.51' - disconnected

I have no explanation at all

If I reboot I'm in case 1 again.

Thanks and kind regards,

fsutter

Gertjan · Mar 6, 2023, 1:34 PM

@fsutter said in Need to edit OpenVPN server config after each reboot:

(may be a replay)

About the replay : server and client have a 10 seconds diffrence.
That's strange, as both, iPhHone and pfSense, use ntp 'atomic clock' syncing.

@fsutter said in Need to edit OpenVPN server config after each reboot:

Certificate does not have key usage extension

You see this message when pfSense starts ?

I have these :

The CA is :

and the ca-server-openvpn cert is :

fsutter · Mar 6, 2023, 2:02 PM

@gertjan

Yes, you're right the problem was Certificate does not have key usage extension!

I have my own script for generating my PKI infrastructure.
Previously I had that in openssl.cnf:

[ certificate_extensions ]
basicConstraints                = CA:false

Now:

[ certificate_extensions ]
basicConstraints                = CA:false
subjectKeyIdentifier            = hash
authorityKeyIdentifier          = keyid,issuer:always
extendedKeyUsage                = clientAuth
keyUsage                        = digitalSignature

And it works even after a reboot!

Thanks again for the support and have a great day.

fsutter

fsutter · Mar 6, 2023, 2:18 PM

Regarding the time difference, it's strange because I've compared both times and they are equal