[Mint 21.1] OpenVPN failure with strange behaviorS

Questions about Wi-Fi and other network devices, file sharing, firewalls, connection sharing etc
Forum rules
Before you post read how to get help. Topics in this forum are automatically closed 6 months after creation.
Locked
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

[Mint 21.1] OpenVPN failure with strange behaviorS

Post by Charlymint »

Hello all

I just upgraded my workstation from Mint 20.3 to 21.1. Everything went smoothly at first sight.
Bet when trying to use my OpenVPN from the network manager, it fails.

First, in the status bar, you see that the process tries to reconnect every 3 or 4 seconds. after 5 retries, it asks for my VPN password, and then makes the retries as a loop... No success.

From the syslog I can read this :

Code: Select all

    [...]
    Mar 22 15:15:38 DZ-32 NetworkManager[619]: <info>  [1679494538.6213] vpn[0x56456b1625b0,bc1281d1-5763-4487-8a24-597bb8802aef,"VPN Home (old)"]: starting openvpn
    Mar 22 15:15:38 DZ-32 NetworkManager[619]: <info>  [1679494538.6218] audit: op="connection-activate" uuid="bc1281d1-5763-4487-8a24-597bb8802aef" name="VPN Home (old)" pid=1626 uid=1000 result="success"
    Mar 22 15:15:38 DZ-32 nm-openvpn[5290]: DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
    Mar 22 15:15:38 DZ-32 nm-openvpn[5290]: OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
    Mar 22 15:15:38 DZ-32 nm-openvpn[5290]: library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
    Mar 22 15:15:38 DZ-32 nm-openvpn[5290]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: RESOLVE: Cannot resolve host address: 6272f7f0a623.my.vpn.server:pp (Name or service not known)
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: RESOLVE: Cannot resolve host address: 8dcc0076ea57.my.vpn.server:pp (Name or service not known)
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: Could not determine IPv4/IPv6 protocol
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
    Mar 22 15:15:40 DZ-32 nm-openvpn[5290]: SIGUSR1[soft,init_instance] received, process restarting
    [...]
Above here the FQDN "my.vpn.server" is replacing in this message the real FQDN of my server.
With the error "RESOLVE: Cannot resolve host address: 6272f7f0a623.my.vpn.server:pp (Name or service not known)" why do we have "6272f7f0a623" ? It is not set in my configuration...

I retrieved the original ovpn file used to set the VPN in the network manager, so I could try it from the command line.
Here is what happens :

Code: Select all

    2023-03-22 15:25:34 DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
    2023-03-22 15:25:34 OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
    2023-03-22 15:25:34 library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
    Enter Auth Username: <username>
    ?? Enter Auth Password: **********              
    2023-03-22 15:25:41 Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
    2023-03-22 15:25:41 Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
    2023-03-22 15:25:41 Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
    2023-03-22 15:25:41 Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
    2023-03-22 15:25:41 TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
    2023-03-22 15:25:41 Socket Buffers: R=[212992->212992] S=[212992->212992]
    2023-03-22 15:25:41 UDP link local: (not bound)
    2023-03-22 15:25:41 UDP link remote: [AF_INET]xx.xx.xx.xx:pp
    2023-03-22 15:25:41 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:pp, sid=67108659 72fc061c
    2023-03-22 15:25:41 net_route_v4_best_gw query: dst 0.0.0.0
    2023-03-22 15:25:41 net_route_v4_best_gw result: via 192.168.12.76 dev wlx34e894caa16b
    2023-03-22 15:25:42 VERIFY OK: depth=1, CN=OpenVPN CA
    2023-03-22 15:25:42 VERIFY KU OK
    2023-03-22 15:25:42 Validating certificate extended key usage
    2023-03-22 15:25:42 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
    2023-03-22 15:25:42 VERIFY EKU OK
    2023-03-22 15:25:42 VERIFY OK: depth=0, CN=OpenVPN Server
    2023-03-22 15:25:42 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256
    2023-03-22 15:25:42 [OpenVPN Server] Peer Connection Initiated with [AF_INET]xx.xx.xx.xx:pp
    2023-03-22 15:25:42 PUSH: Received control message: 'PUSH_REPLY,explicit-exit-notify,topology subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 12,ping-restart 50,redirect-gateway def1,redirect-gateway bypass-dhcp,redirect-gateway autolocal,route-gateway 10.3.0.129,dhcp-option DNS 192.168.1.249,dhcp-option DNS 192.168.1.254,register-dns,block-ipv6,ifconfig 10.3.0.137 255.255.255.192,peer-id 0,auth-tokenSESS_ID,cipher AES-256-GCM'
    2023-03-22 15:25:42 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:4: dhcp-pre-release (2.5.5)
    2023-03-22 15:25:42 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:5: dhcp-renew (2.5.5)
    2023-03-22 15:25:42 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:6: dhcp-release (2.5.5)
    2023-03-22 15:25:42 WARNING: You have specified redirect-gateway and redirect-private at the same time (or the same option multiple times). This is not well supported and may lead to unexpected results
    2023-03-22 15:25:42 WARNING: You have specified redirect-gateway and redirect-private at the same time (or the same option multiple times). This is not well supported and may lead to unexpected results
    2023-03-22 15:25:42 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:16: register-dns (2.5.5)
    2023-03-22 15:25:42 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
    2023-03-22 15:25:42 OPTIONS IMPORT: timers and/or timeouts modified
    2023-03-22 15:25:42 OPTIONS IMPORT: explicit notify parm(s) modified
    2023-03-22 15:25:42 OPTIONS IMPORT: --ifconfig/up options modified
    2023-03-22 15:25:42 OPTIONS IMPORT: route options modified
    2023-03-22 15:25:42 OPTIONS IMPORT: route-related options modified
    2023-03-22 15:25:42 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
    2023-03-22 15:25:42 OPTIONS IMPORT: peer-id set
    2023-03-22 15:25:42 OPTIONS IMPORT: adjusting link_mtu to 1624
    2023-03-22 15:25:42 OPTIONS IMPORT: data channel crypto options modified
    2023-03-22 15:25:42 Data Channel: using negotiated cipher 'AES-256-GCM'
    2023-03-22 15:25:42 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
    2023-03-22 15:25:42 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
    2023-03-22 15:25:42 net_route_v4_best_gw query: dst 0.0.0.0
    2023-03-22 15:25:42 net_route_v4_best_gw result: via 192.168.12.76 dev wlx34e894caa16b
    2023-03-22 15:25:42 ROUTE_GATEWAY 192.168.12.76/255.255.255.0 IFACE=wlx34e894caa16b HWADDR=34:e8:94:ca:a1:6b
    2023-03-22 15:25:42 ERROR: Cannot ioctl TUNSETIFF tun: Operation not permitted (errno=1)
    2023-03-22 15:25:42 Exiting due to fatal error
The same command run with root priviege works perfectly.

I don't know how to diagnose this. Each method gives a different error and I don't know where I should look to solve this.
I've read many discussions, here and elsewhere on the web, without finding a working solution.

If you have any hint please advise...

Thanks in advance,

Charly
Last edited by LockBot on Fri Sep 22, 2023 10:00 pm, edited 3 times in total.
Reason: Topic automatically closed 6 months after creation. New replies are no longer allowed.
Top
rene
Level 20
Level 20
Posts: 12212
Joined: Sun Mar 27, 2016 6:58 pm

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by rene »

Not much of a clue but you say to "have upgraded". I take it that was an in-place upgrade? Can you just remove the VPN connection and add it again new?
Top
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by Charlymint »

Hello

Thanks for your advice. Unfortunately, I did that already (and I should have mentioned it, sorry) : it fails as well with the same behavior.

Charly
Top
rene
Level 20
Level 20
Posts: 12212
Joined: Sun Mar 27, 2016 6:58 pm

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by rene »

OK, in that case no idea I'm afraid. It's not the "normal" 20 -> 21 VPN issue with cipher; looked like an incompatibility between 21 infrastructure and 20 configuration -- but if not that, no idea.
Top
t42
Level 11
Level 11
Posts: 3747
Joined: Mon Jan 20, 2014 6:48 pm

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by t42 »

In the first code snippet there is the current --script-security setting may allow this configuration to call user-defined scripts what points to script-security 2 which is potentially dangerous and subject to be blocked by NetworkManager (though it will not be blocked by OpenVPN per se.
-=t42=-
Top
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by Charlymint »

Hello t42,

Thanks, I will try that tomorrow morning...

My other choices are :
- downgrade (go back to) Mint 20 on the client,
or
- upgrade the server running OpenVPN (it's mine) from Ubuntu 20.04 to 22.04 ?

Currently on the client (Mint 21.3) side I have :
openvpn/jammy-updates,now 2.5.5-1ubuntu3.1 amd64 [installed]
openvpn/jammy 2.5.5-1ubuntu3 amd64

and on the server side (Ubunto 20.04) I have :
openvpn/focal-updates,focal-security 2.4.7-1ubuntu2.20.04.4 amd64
openvpn/focal 2.4.7-1ubuntu2 amd64

Perhaps having the same versions of openvpn on both side could help... :wink:

Charly
Top
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

Re: [Mint 21.1] OpenVPN failure with strange behaviorS

Post by Charlymint »

Hello

I've added an 'S' to "behavior" in the topic's title, because depending on the workstation I got different behaviors... :?

I already reported a first client with VPN error.

In fact that week I've upgraded several workstation (2 VMs and 2 laptops). All machines received the same "ovpn" configuration file, imported into the Network Manager.

Here are the results :
  1. VM #1 is the one reported above. It fails.
  2. VM #2 is almost similar (same origin, in fact it is an old "duplicate" of the #1 living it's own life since then). And surprisingly VPN works fine with the Network Manager !
  3. Then I have an HP Pavilion laptop : VPN OK !!
  4. And finally this older HP ProBook laptop : VPN KO !
So we have 50% of failure and 50% of success among this small sample.

But today I'm not at the same location for my tests and VM #1 did give a different error !!! Below is the syslog lines captured between the 'switch ON' and 'switch OFF' of the VPN :

Code: Select all

Mar 23 11:33:40 DZ-32 NetworkManager[586]: <info>  [1679567620.0503] vpn[0x55797833a330,bc1281d1-5763-4487-8a24-597bb8802aef,"VPN Home"]: starting openvpn
Mar 23 11:33:40 DZ-32 NetworkManager[586]: <info>  [1679567620.0507] audit: op="connection-activate" uuid="bc1281d1-5763-4487-8a24-597bb8802aef" name="VPN Home" pid=1511 uid=1000 result="success"
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: UDP link local: (not bound)
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
Mar 23 11:33:40 DZ-32 nm-openvpn[2330]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: Server poll timeout, restarting
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: UDP link local: (not bound)
Mar 23 11:33:48 DZ-32 nm-openvpn[2330]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: Server poll timeout, restarting
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: UDP link local: (not bound)
Mar 23 11:33:56 DZ-32 nm-openvpn[2330]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:34:04 DZ-32 nm-openvpn[2330]: Server poll timeout, restarting
Mar 23 11:34:04 DZ-32 nm-openvpn[2330]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 11:34:04 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:34:05 DZ-32 nm-openvpn[2330]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:34:05 DZ-32 nm-openvpn[2330]: UDP link local: (not bound)
Mar 23 11:34:05 DZ-32 nm-openvpn[2330]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: Server poll timeout, restarting
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: UDP link local: (not bound)
Mar 23 11:34:13 DZ-32 nm-openvpn[2330]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:34:22 DZ-32 nm-openvpn[2330]: Server poll timeout, restarting
Mar 23 11:34:22 DZ-32 nm-openvpn[2330]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 11:34:22 DZ-32 nm-openvpn[2330]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:34:25 DZ-32 NetworkManager[586]: <info>  [1679567665.2292] audit: op="connection-deactivate" uuid="bc1281d1-5763-4487-8a24-597bb8802aef" name="VPN Home" pid=1511 uid=1000 result="success"
Mar 23 11:34:25 DZ-32 dbus-daemon[585]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=586 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Mar 23 11:34:25 DZ-32 systemd[1]: Starting Network Manager Script Dispatcher Service...
Mar 23 11:34:25 DZ-32 dbus-daemon[585]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 23 11:34:25 DZ-32 systemd[1]: Started Network Manager Script Dispatcher Service.
Mar 23 11:34:31 DZ-32 wpa_supplicant[629]: wlx000fb5d8cc35: CTRL-EVENT-BEACON-LOSS
And for the ProBook laptop i have this in sylog :

Code: Select all

Mar 23 12:59:37 ProBook NetworkManager[529]: <info>  [1679572777.8544] vpn[0x5580974a83d0,1bce2208-cf10-4646-abea-a0f0dee4ce0e,"VPN Home"]: starting openvpn
Mar 23 12:59:37 ProBook NetworkManager[529]: <info>  [1679572777.8569] audit: op="connection-activate" uuid="1bce2208-cf10-4646-abea-a0f0dee4ce0e" name="VPN Home" pid=2389 uid=1000 result="success"
Mar 23 12:59:37 ProBook nm-openvpn[8268]: DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
Mar 23 12:59:37 ProBook nm-openvpn[8268]: OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
Mar 23 12:59:37 ProBook nm-openvpn[8268]: library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
Mar 23 12:59:38 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:39 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 12:59:39 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 12:59:39 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 12:59:39 ProBook nm-openvpn[8268]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
Mar 23 12:59:39 ProBook nm-openvpn[8268]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Mar 23 12:59:43 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 12:59:43 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 12:59:43 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:43 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 12:59:43 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 12:59:43 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 12:59:47 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 12:59:47 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 12:59:47 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:47 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 12:59:47 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 12:59:47 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 12:59:51 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 12:59:51 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 12:59:51 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:51 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 12:59:51 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 12:59:51 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 12:59:55 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 12:59:55 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 12:59:55 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:55 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET6]64:ff9b::527c:a592:443
Mar 23 12:59:55 ProBook nm-openvpn[8268]: Attempting to establish TCP connection with [AF_INET6]64:ff9b::527c:a592:443 [nonblock]
Mar 23 12:59:55 ProBook nm-openvpn[8268]: TCP connection established with [AF_INET6]64:ff9b::527c:a592:443
Mar 23 12:59:55 ProBook nm-openvpn[8268]: TCP_CLIENT link local: (not bound)
Mar 23 12:59:55 ProBook nm-openvpn[8268]: TCP_CLIENT link remote: [AF_INET6]64:ff9b::527c:a592:443
Mar 23 12:59:59 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 12:59:59 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 12:59:59 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 12:59:59 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:ppp
Mar 23 12:59:59 ProBook nm-openvpn[8268]: Attempting to establish TCP connection with [AF_INET]xx.xx.xx.xx:ppp [nonblock]
Mar 23 12:59:59 ProBook nm-openvpn[8268]: TCP connection established with [AF_INET]xx.xx.xx.xx:ppp
Mar 23 12:59:59 ProBook nm-openvpn[8268]: TCP_CLIENT link local: (not bound)
Mar 23 12:59:59 ProBook nm-openvpn[8268]: TCP_CLIENT link remote: [AF_INET]xx.xx.xx.xx:ppp
Mar 23 13:00:03 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 13:00:03 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 13:00:03 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 13:00:03 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 13:00:03 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 13:00:03 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET6]xxxxx:xxxx:xxxx:xxxx:pppp
Mar 23 13:00:07 ProBook nm-openvpn[8268]: Server poll timeout, restarting
Mar 23 13:00:07 ProBook nm-openvpn[8268]: SIGUSR1[soft,server_poll] received, process restarting
Mar 23 13:00:07 ProBook nm-openvpn[8268]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 13:00:07 ProBook nm-openvpn[8268]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 13:00:07 ProBook nm-openvpn[8268]: UDP link local: (not bound)
Mar 23 13:00:07 ProBook nm-openvpn[8268]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 13:00:10 ProBook NetworkManager[529]: <info>  [1679572810.1787] audit: op="connection-deactivate" uuid="1bce2208-cf10-4646-abea-a0f0dee4ce0e" name="VPN Home" pid=2389 uid=1000 result="success"
Mar 23 13:00:10 ProBook dbus-daemon[528]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.0' (uid=0 pid=529 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Mar 23 13:00:10 ProBook systemd[1]: Starting Network Manager Script Dispatcher Service...
Mar 23 13:00:10 ProBook dbus-daemon[528]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 23 13:00:10 ProBook systemd[1]: Started Network Manager Script Dispatcher Service.
Mar 23 13:00:10 ProBook nm-openvpn[8268]: SIGTERM[hard,] received, process exiting
To compare with a successful connection from VM #2 which shows the following :

Code: Select all

Mar 23 11:24:43 DZ-32 NetworkManager[628]: <info>  [1679567083.9363] vpn[0x5652cd3d2750,bc1281d1-5763-4487-8a24-597bb8802aef,"VPN Home"]: starting openvpn
Mar 23 11:24:43 DZ-32 NetworkManager[628]: <info>  [1679567083.9367] audit: op="connection-activate" uuid="bc1281d1-5763-4487-8a24-597bb8802aef" name="VPN Home" pid=1519 uid=1000 result="success"
Mar 23 11:24:43 DZ-32 nm-openvpn[3361]: DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
Mar 23 11:24:43 DZ-32 nm-openvpn[3361]: OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
Mar 23 11:24:43 DZ-32 nm-openvpn[3361]: library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
Mar 23 11:24:44 DZ-32 nm-openvpn[3361]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: UDP link local: (not bound)
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: UDP link remote: [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: [OpenVPN Server] Peer Connection Initiated with [AF_INET]xx.xx.xx.xx:pp
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:4: dhcp-pre-release (2.5.5)
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:5: dhcp-renew (2.5.5)
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:6: dhcp-release (2.5.5)
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: WARNING: You have specified redirect-gateway and redirect-private at the same time (or the same option multiple times). This is not well supported and may lead to unexpected results
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: WARNING: You have specified redirect-gateway and redirect-private at the same time (or the same option multiple times). This is not well supported and may lead to unexpected results
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:16: register-dns (2.5.5)
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: TUN/TAP device tun0 opened
Mar 23 11:24:49 DZ-32 nm-openvpn[3361]: /usr/lib/NetworkManager/nm-openvpn-service-openvpn-helper --debug 0 3351 --bus-name org.freedesktop.NetworkManager.openvpn.Connection_6 --tun -- tun0 1500 1552 10.3.0.146 255.255.255.192 init
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4782] manager: (tun0): new Tun device (/org/freedesktop/NetworkManager/Devices/6)
Mar 23 11:24:49 DZ-32 systemd-udevd[3364]: Using default interface naming scheme 'v249'.
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4903] device (tun0): state change: unmanaged -> unavailable (reason 'connection-assumed', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 dbus-daemon[625]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.7' (uid=0 pid=628 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4911] device (tun0): state change: unavailable -> disconnected (reason 'connection-assumed', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4914] device (tun0): Activation: starting connection 'tun0' (fe255055-fd65-4857-9060-b43e82e8c3dc)
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4914] device (tun0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4915] device (tun0): state change: prepare -> config (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4916] device (tun0): state change: config -> ip-config (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.4916] device (tun0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 systemd[1]: Starting Network Manager Script Dispatcher Service...
Mar 23 11:24:49 DZ-32 dbus-daemon[625]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 23 11:24:49 DZ-32 systemd[1]: Started Network Manager Script Dispatcher Service.
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.5081] policy: set 'VPN Home' (tun0) as default for IPv4 routing and DNS
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.5092] device (tun0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.5093] device (tun0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'external')
Mar 23 11:24:49 DZ-32 NetworkManager[628]: <info>  [1679567089.5098] device (tun0): Activation: successful, device activated.
Mar 23 11:24:49 DZ-32 systemd-resolved[565]: wlx000fb5d8cc35: Bus client set default route setting: no
Mar 23 11:24:49 DZ-32 systemd-resolved[565]: wlx000fb5d8cc35: Bus client reset DNS server list.
Mar 23 11:24:49 DZ-32 systemd-resolved[565]: tun0: Bus client set default route setting: yes
Mar 23 11:24:49 DZ-32 systemd-resolved[565]: tun0: Bus client set DNS server list to: 192.168.1.249, 192.168.1.254
Mar 23 11:24:49 DZ-32 nm-dispatcher[3400]: /etc/network/if-up.d/resolved: 12: mystatedir: not found
Mar 23 11:24:49 DZ-32 nm-dispatcher[3441]: /etc/network/if-up.d/resolved: 12: mystatedir: not found
Mar 23 11:24:51 DZ-32 ntpd[767]: Listen normally on 13 tun0 10.3.0.146:123
Mar 23 11:24:51 DZ-32 ntpd[767]: Listen normally on 14 tun0 [fe80::a885:9aee:fc82:8dd1%6]:123
Mar 23 11:24:51 DZ-32 ntpd[767]: new interface(s) found: waking up resolver
Mar 23 11:24:54 DZ-32 nm-openvpn[3361]: chroot to '/var/lib/openvpn/chroot' and cd to '/' succeeded
Mar 23 11:24:54 DZ-32 nm-openvpn[3361]: GID set to nm-openvpn
Mar 23 11:24:54 DZ-32 nm-openvpn[3361]: UID set to nm-openvpn
Mar 23 11:24:54 DZ-32 nm-openvpn[3361]: Initialization Sequence Completed
Here is a syslog comparison between the failure and success of the two VMs, no much clue about what's happening :roll: :
VPN-compare.jpg
Network connection is the same in all cases : wifi using my smartphone's hotspot to access the internet.

Charly
Top
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

Re: [Mint 21.1] OpenVPN failure with strange behavior

Post by Charlymint »

t42 wrote: ⤴Wed Mar 22, 2023 12:53 pm In the first code snippet there is the current --script-security setting may allow this configuration to call user-defined scripts what points to script-security 2 which is potentially dangerous and subject to be blocked by NetworkManager (though it will not be blocked by OpenVPN per se.
Hello t42,

I've checked the ovpn file and the Network Manager options for the VPN settings. So far I can't see where this "script-security" option could be set, or whatever that looks like it. I don't see it anywhere !

Charly
Top
t42
Level 11
Level 11
Posts: 3747
Joined: Mon Jan 20, 2014 6:48 pm

Re: [Mint 21.1] OpenVPN failure with strange behaviorS

Post by t42 »

Charlymint wrote: ⤴Thu Mar 23, 2023 10:48 am I've checked the ovpn file
it's good if there is no script-security 2 or worse in your ovpn files. To be sure run something like grep -rnw ./ -e 'script-security' in the directory with ovpn files. As for the main issue I'm out with a hotspot in volatile environment connected to different servers or mobile networks.
-=t42=-
Top
Charlymint
Level 1
Level 1
Posts: 8
Joined: Thu Mar 10, 2022 1:38 pm
Location: Blue planet (so far)

Re: [Mint 21.1] OpenVPN failure with strange behaviorS

Post by Charlymint »

Thanks for your input t42.

No emergency, no worry 8) I'm not blocked here but wish to figure out what's happening...

So, even if there was no '--script-security' setting in the original ovpn settings, when I EXPORT the current settings from the network manager, I find it there !!! :?:

So I deleted all VPN configuration from the network manager, imported a new ovpn config file WITHOUT this setting, then export it again to a new file and ... voila ... here I find again 'script-security 2' in the file... :cry:

Anyway, I've checked the other machine with OpenVPN working fine, and this parameter is here as well. So even if this setting's behavior is weird, it's not the culprit.

Still digging...

Charly
Top
Locked

Return to “Networking”