Openvpn3 - session-start: Backend VPN process is not ready

[pratham-sharma-uplight]

on Ubuntu 22.04

Openvpn details:

$ openvpn3 version
OpenVPN3/Linux v20 (openvpn3)
OpenVPN core v3.7.2 linux x86_64 64-bit
Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.

Getting error when trying to connect to VPN

$ sudo openvpn3 session-start --config config_file.ovpn
Using pre-loaded configuration profile config_file.ovpn
Session path: /net/openvpn/v3/sessions/46198bf0s15fbs4d9dsb6dds98041020920e
session-start: ** ERROR ** Failed to start new session: Failed calling D-Bus method Ready: GDBus.Error:net.openvpn.v3.sessions.error: Backend VPN process is not ready

[dsommers]

Please provide more logs.

 $ sudo openvpn3-admin log-service --log-level 6
 $ openvpn3 config-manage --show --config config_file.ovpn --log-level 6

Then run this command to get all the needed log details:

 $ sudo openvpn3-admin journal --since $(date +%F)

[pratham-sharma-uplight]

Hello @dsommers

$ sudo openvpn3-admin log-service --log-level 6

Log method: journald
Attached log subscriptions: 1
Log timestamps: enabled
Log tag prefix enabled: enabled
Log D-Bus details: disabled
Current log level: 6

$ openvpn3 config-manage --show --config config_file.ovpn --log-level 6

Set override 'log-level' to '6'

------------------------------------------------------------

                          Name: vpn_device_1.ovpn
                     Read only: No
             Persistent config: No
          Data Channel Offload: No

  Overrides: 
                  persist-tun: true
                  log-level: 6

$ sudo openvpn3-admin journal --since $(date +%F)

Thu Jan  4 15:30:09 2024  Logger INFO: OpenVPN3/Linux v20 (openvpn3-service-logger)
               OpenVPN core v3.7.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v20 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.7.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Thu Jan  4 15:30:09 2024  Logger INFO: Log method: journald
Thu Jan  4 15:30:09 2024  Logger INFO: Idle exit set to 10 minutes
Thu Jan  4 15:30:09 2024  Logger VERB2: Attached: {tag:16006046960397757405}  [:1.70/net.openvpn.v3.sessions]
Thu Jan  4 15:30:09 2024  Logger VERB2: Attached: {tag:6666382611828467354}  [:1.72/net.openvpn.v3.configuration]
Thu Jan  4 15:33:09 2024  Logger VERB2: Detached: {tag:16006046960397757405}  [:1.70/net.openvpn.v3.sessions]
Thu Jan  4 15:36:09 2024  Logger VERB2: Detached: {tag:6666382611828467354}  [:1.72/net.openvpn.v3.configuration]
Wed Jan 19 13:31:49 586524  openvpn3-service-logger starting idle shutdown (pid: 6361)
Thu Jan  4 19:58:37 2024  Logger INFO: OpenVPN3/Linux v20 (openvpn3-service-logger)
               OpenVPN core v3.7.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Thu Jan  4 19:58:37 2024  Logger INFO: Log method: journald
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v20 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.7.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Thu Jan  4 19:58:37 2024  Logger INFO: Idle exit set to 10 minutes
Thu Jan  4 19:58:46 2024  Logger VERB2: Attached: {tag:3977047199776577422}  [:1.185/net.openvpn.v3.configuration]
Thu Jan  4 20:00:41 2024  Logger VERB2: Attached: {tag:528159723475589405}  [:1.214/net.openvpn.v3.sessions]
Thu Jan  4 20:00:41 2024  {tag:3977047199776577422} Config Manager INFO: {tag:3977047199776577422} Parsed single-use configuration 'config_file.ovpn', owner: root
Thu Jan  4 20:00:41 2024  {tag:3977047199776577422} Config Manager INFO: {tag:3977047199776577422} Setting configuration override 'persist-tun' to 'true' by UID 0
Thu Jan  4 20:00:41 2024  Logger VERB2: Attached: {tag:11680149820217006088}  [:1.215/net.openvpn.v3.backends]
Thu Jan  4 20:00:47 2024  Logger VERB2: Detached: {tag:11680149820217006088}  [:1.215/net.openvpn.v3.backends]
Thu Jan  4 20:01:06 2024  {tag:3977047199776577422} Config Manager INFO: {tag:3977047199776577422} Setting configuration override 'log-level' to '6' by UID 0

[dsommers]

Okay, looks reasonable. But you need to also start a VPN session (I forgot that in the instructions above). What I see here is just the changes you did to the configuration profile.

 $ openvpn3 session-start --config vpn_device_1.ovpn

And then do the same sudo openvpn3-admin journal command to retrieve all the log entries once again.

I also see that you still run the v20 release. I would also recommend you to upgrade to v21. Please note that the apt repository has moved to a new location, so you need to tweak your setup slightly. Most likely you just need to update the URL to the repo; details here: https://community.openvpn.net/openvpn/wiki/OpenVPN3Linux#Stablerepository-DebianUbuntu

[pratham-sharma-uplight]

Hey @dsommers

After installing the latest version of Openvpn3(v21) I restarted my system and follows are the out for you:

$ sudo openvpn3 sessions-list
No sessions available

$ sudo openvpn3 configs-list

Configuration Name                                        Last used
------------------------------------------------------------------------------
------------------------------------------------------------------------------

$ sudo openvpn3-admin journal --since $(date +%F)

Fri Jan  5 12:15:52 2024  {tag:528159723475589405} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Fri Jan  5 12:16:02 2024  {tag:528159723475589405} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Fri Jan  5 12:16:30 2024  Logger VERB2: Attached: {tag:6616519286352099422}  [:1.274/net.openvpn.v3.backends]
Fri Jan  5 12:16:36 2024  Logger VERB2: Detached: {tag:6616519286352099422}  [:1.274/net.openvpn.v3.backends]
Fri Jan  5 12:19:01 2024  Logger INFO: OpenVPN3/Linux v21 (openvpn3-service-logger)
               OpenVPN core v3.8.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v21 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.8.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Fri Jan  5 12:19:01 2024  Logger INFO: Log method: journald
Fri Jan  5 12:19:01 2024  Logger INFO: Idle exit set to 10 minutes
Fri Jan  5 12:19:01 2024  Logger VERB2: Attached: {tag:3785525035484998611}  [:1.69/net.openvpn.v3.sessions], pid 6255
Fri Jan  5 12:19:01 2024  Logger VERB2: Attached: {tag:8660400497094378258}  [:1.71/net.openvpn.v3.configuration], pid 6291

$ sudo openvpn3 session-start --config vpn_device_1.ovpn

Using configuration profile from file: vpn_device_1.ovpn
Session path: /net/openvpn/v3/sessions/f04a7143sbb43s489ds9538sfd45a63937be
session-start: ** ERROR ** Failed to start new session: Failed calling D-Bus method [net.openvpn.v3.sessions] net.openvpn.v3.sessions.Ready: GDBus.Error:net.openvpn.v3.sessions.error: Backend VPN process is not ready

$ sudo openvpn3 sessions-list

-----------------------------------------------------------------------------
        Path: /net/openvpn/v3/sessions/f04a7143sbb43s489ds9538sfd45a63937be
     Created: (Not available)                           PID: -
       Owner: (not available)                        Device: (None)
      Status: (No status)
-----------------------------------------------------------------------------

$ sudo openvpn3 configs-list

Configuration Name                                        Last used
------------------------------------------------------------------------------
vpn_device_1.ovpn                                         -
------------------------------------------------------------------------------

$ sudo openvpn3-admin journal --since $(date +%F)

Fri Jan  5 12:15:52 2024  {tag:528159723475589405} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Fri Jan  5 12:16:02 2024  {tag:528159723475589405} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Fri Jan  5 12:16:30 2024  Logger VERB2: Attached: {tag:6616519286352099422}  [:1.274/net.openvpn.v3.backends]
Fri Jan  5 12:16:36 2024  Logger VERB2: Detached: {tag:6616519286352099422}  [:1.274/net.openvpn.v3.backends]
Fri Jan  5 12:19:01 2024  Logger INFO: OpenVPN3/Linux v21 (openvpn3-service-logger)
               OpenVPN core v3.8.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v21 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.8.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Fri Jan  5 12:19:01 2024  Logger INFO: Log method: journald
Fri Jan  5 12:19:01 2024  Logger INFO: Idle exit set to 10 minutes
Fri Jan  5 12:19:01 2024  Logger VERB2: Attached: {tag:3785525035484998611}  [:1.69/net.openvpn.v3.sessions], pid 6255
Fri Jan  5 12:19:01 2024  Logger VERB2: Attached: {tag:8660400497094378258}  [:1.71/net.openvpn.v3.configuration], pid 6291
Fri Jan  5 12:25:02 2024  Logger VERB2: Detached: {tag:3785525035484998611}  [:1.69/net.openvpn.v3.sessions], pid 6255
Fri Jan  5 12:25:02 2024  Logger VERB2: Detached: {tag:8660400497094378258}  [:1.71/net.openvpn.v3.configuration], pid 6291
Fri Jan  5 12:29:59 2024  Logger VERB2: Attached: {tag:7919269897507281558}  [:1.149/net.openvpn.v3.configuration], pid 22813
Fri Jan  5 12:30:13 2024  Logger VERB2: Attached: {tag:16248270841017367073}  [:1.158/net.openvpn.v3.sessions], pid 23533
Fri Jan  5 12:30:14 2024  {tag:7919269897507281558} Config Manager INFO: Parsed single-use configuration 'vpn_device_1.ovpn', owner: root
Fri Jan  5 12:30:14 2024  {tag:7919269897507281558} Config Manager INFO: Setting configuration override 'persist-tun' to 'true' by UID 0
Fri Jan  5 12:30:14 2024  Logger VERB2: Attached: {tag:12638940724868537016}  [:1.159/net.openvpn.v3.backends], pid 23568
Fri Jan  5 12:30:20 2024  Logger VERB2: Detached: {tag:12638940724868537016}  [:1.159/net.openvpn.v3.backends], pid 23568
Fri Jan  5 12:32:05 2024  {tag:7919269897507281558} Config Manager INFO: Setting configuration override 'log-level' to '6' by UID 0
Fri Jan  5 12:32:27 2024  Logger VERB2: Attached: {tag:15084667738735099305}  [:1.167/net.openvpn.v3.backends], pid 27043
Fri Jan  5 12:32:33 2024  Logger VERB2: Detached: {tag:15084667738735099305}  [:1.167/net.openvpn.v3.backends], pid 27043

$ sudo openvpn3-admin version --services

OpenVPN 3 D-Bus services:

  - Client backend starter service
     openvpn3-service-backendstart: v21

  - Configuration Service
     openvpn3-service-configmgr:    v21

  - Log Service
     openvpn3-service-logger:       v21

  - Network Configuration Service
     openvpn3-service-netcfg:       v21

  - Session Manager Service
     openvpn3-service-sessionmgr:   v21

[leocao91]

Fix it with the following steps:

• Ubuntu 22.04 with OpenVPN3/Linux v20 (openvpn3)

1. Update file: /usr/share/dbus-1/system-services/net.openvpn.v3.netcfg.service
2. Replace line to: Exec=/usr/lib/x86_64-linux-gnu/openvpn3-linux/openvpn3-service-netcfg --resolv-conf /etc/resolv.conf --state-dir "/var/lib/openvpn3"
3. Run command:
   openvpn3-admin netcfg-service --config-set resolve-conf /etc/resolv.conf
   openvpn3-admin netcfg-service --config-set systemd-resolved false
   ======
   *Ubuntu 22.04 with OpenVPN3/Linux v21 + (openvpn3)
4. Update file: /usr/share/dbus-1/system-services/net.openvpn.v3.netcfg.service
5. Replace line to: Exec=/usr/libexec/openvpn3-linux/openvpn3-service-netcfg --resolv-conf /etc/resolv.conf --state-dir "/var/lib/openvpn3"
6. Run command:
   openvpn3-admin netcfg-service --config-set resolve-conf /etc/resolv.conf
   openvpn3-admin netcfg-service --config-set systemd-resolved false

[pratham-sharma-uplight]

Hi @leocao91

Here are the following outputs for you, but no success.

$ cat /usr/share/dbus-1/system-services/net.openvpn.v3.netcfg.service

#  This file is part of the OpenVPN 3 Linux client
#
#  SPDX-License-Identifier: AGPL-3.0-only
#
#  Copyright (C) 2018 - 2023  OpenVPN Inc <sales@openvpn.net>
#  Copyright (C) 2018 - 2023  David Sommerseth <davids@openvpn.net>
#

[D-BUS Service]
Name=net.openvpn.v3.netcfg
User=root
#Exec=/usr/libexec/openvpn3-linux/openvpn3-service-netcfg --systemd-resolved --state-dir "/var/lib/openvpn3"
Exec=/usr/libexec/openvpn3-linux/openvpn3-service-netcfg --resolv-conf /etc/resolv.conf --state-dir "/var/lib/openvpn3"

$ sudo openvpn3-admin netcfg-service --config-set resolve-conf /etc/resolv.conf
Loading configuration file: /var/lib/openvpn3/netcfg.json

$ sudo openvpn3-admin netcfg-service --config-set systemd-resolved false

Loading configuration file: /var/lib/openvpn3/netcfg.json
Configuration file updated.  Changes will be activated next time openvpn3-service-netcfg restarts

$ sudo cat /var/lib/openvpn3/netcfg.json

{
	//  Option --systemd-resolved :: Systemd-resolved in use
	"systemd_resolved" : false
}

$ sudo openvpn3 session-start --config vpn_device_1.ovpn

Using pre-loaded configuration profile 'vpn_device_1.ovpn'
Session path: /net/openvpn/v3/sessions/12c8cc12s4276s4734s8aa2s069566cadb77
session-start: ** ERROR ** Failed to start new session: Failed calling D-Bus method [net.openvpn.v3.sessions] net.openvpn.v3.sessions.Ready: GDBus.Error:net.openvpn.v3.sessions.error: Backend VPN process is not ready

[dsommers]

@leocao91 Your step which modifies the auto-start service file may actually make things worse. That is not even needed when you do the openvpn3-admin netcfg-service steps. Those settings overrides the command line.

@pratham-sharma-uplight Your log output still does not provide any log output from the session manager nor the VPN client process. So lets try a different approach. First, revert the change you did in /usr/share/dbus-1/system-services/net.openvpn.v3.netcfg.service. That is just plain wrong at this point.

Then try starting the configuration using a configuration file:

 $ openvpn2 --config vpn_device_1.ovpn --verb 6

If it fails, then run this command and provide the output (without key/certificate data):

 $ OPENVPN3_DEBUG=DUMP_PARSE openvpn2 --config vpn_device_1.ovpn --verb 6

[pratham-sharma-uplight]

Hey @dsommers

$ openvpn2 --config vpn_device_1.ovpn --verb 6

** ERROR ** org.freedesktop.DBus.Error.AccessDenied: Rejected send message, 1 matched rules; type="method_call", sender=":1.190" (uid=0 pid=262724 comm="/usr/bin/python3 /usr/bin/openvpn2 --config vpn_de" label="unconfined") interface="net.openvpn.v3.sessions" member="Ready" error name="(unset)" requested_reply="0" destination=":1.188" (uid=129 pid=261024 comm="/usr/libexec/openvpn3-linux/openvpn3-service-sessi" label="unconfined")

$ OPENVPN3_DEBUG=DUMP_PARSE openvpn2 --config vpn_device_1.ovpn --verb 6

auth SHA256
<ca>
-----BEGIN CERTIFICATE-----
// some key here
-----END CERTIFICATE-----
</ca>
<cert>
-----BEGIN CERTIFICATE-----
// some key here
-----END CERTIFICATE-----
</cert>
cipher AES-256-CBC
client
dev tun
<key>
-----BEGIN RSA PRIVATE KEY-----
// some key here
-----END RSA PRIVATE KEY-----
</key>
key-direction 1
persist-tun
push-peer-info
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 443 tcp
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 1194 udp
remote in-bom.gw.openvpn.com 1194 udp
remote-cert-tls server
setenv USERNAME "uplight/pratham.sharma%40uplight.com_3453/XXXXXXXXXXXXXXXXXXXXXX"
verb 6
<tls-auth>
-----BEGIN OpenVPN Static key V1-----
// some key here
-----END OpenVPN Static key V1-----
</tls-auth>

[dsommers]

Okay, this gives some more informative clues ... can you try to reload the D-Bus daemon? (not restart) ...

  $ sudo systemctl reload dbus.service

Also ensure you have some D-Bus policy files installed here:

$ ls -l /usr/share/dbus-1/system.d/net.openvpn.v3.*.conf
-rw-r--r-- 1 root root 5982 Dec 16 18:09 /usr/share/dbus-1/system.d/net.openvpn.v3.client.conf
-rw-r--r-- 1 root root 5126 Mar 20  2023 /usr/share/dbus-1/system.d/net.openvpn.v3.configuration.conf
-rw-r--r-- 1 root root 4509 Mar 20  2023 /usr/share/dbus-1/system.d/net.openvpn.v3.log.conf
-rw-r--r-- 1 root root 8026 Mar 20  2023 /usr/share/dbus-1/system.d/net.openvpn.v3.netcfg.conf
-rw-r--r-- 1 root root 5904 Mar 20  2023 /usr/share/dbus-1/system.d/net.openvpn.v3.sessions.conf
$

[pratham-sharma-uplight]

yes I have all the D-Bus policy files installed here:

$ ls -l /usr/share/dbus-1/system.d/net.openvpn.v3.*.conf
-rw-r--r-- 1 root root 5982 Oct  6 15:57 /usr/share/dbus-1/system.d/net.openvpn.v3.client.conf
-rw-r--r-- 1 root root 5881 Oct  6 15:57 /usr/share/dbus-1/system.d/net.openvpn.v3.configuration.conf
-rw-r--r-- 1 root root 4509 Oct  6 15:57 /usr/share/dbus-1/system.d/net.openvpn.v3.log.conf
-rw-r--r-- 1 root root 8026 Oct  6 15:57 /usr/share/dbus-1/system.d/net.openvpn.v3.netcfg.conf
-rw-r--r-- 1 root root 5904 Oct  6 15:57 /usr/share/dbus-1/system.d/net.openvpn.v3.sessions.conf

I tried this too
$ sudo systemctl reload dbus.service

and in following journal output:
$ sudo openvpn3-admin journal --since $(date +%F)

Mon Jan  8 10:54:18 2024  Logger INFO: OpenVPN3/Linux v21 (openvpn3-service-logger)
               OpenVPN core v3.8.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v21 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.8.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Mon Jan  8 10:54:18 2024  Logger INFO: Log method: journald
Mon Jan  8 10:54:18 2024  Logger INFO: Idle exit set to 10 minutes
Mon Jan  8 10:54:18 2024  Logger VERB2: Attached: {tag:16006046960397757405}  [:1.70/net.openvpn.v3.sessions], pid 6406
Mon Jan  8 10:54:18 2024  Logger VERB2: Attached: {tag:6666382611828467354}  [:1.72/net.openvpn.v3.configuration], pid 6444
Mon Jan  8 10:57:23 2024  Logger VERB2: Detached: {tag:16006046960397757405}  [:1.70/net.openvpn.v3.sessions], pid 6406
Mon Jan  8 11:00:23 2024  Logger VERB2: Detached: {tag:6666382611828467354}  [:1.72/net.openvpn.v3.configuration], pid 6444
Wed Jan 19 13:31:49 586524  openvpn3-service-logger starting idle shutdown (pid: 6425)
Mon Jan  8 15:22:58 2024  Logger INFO: OpenVPN3/Linux v21 (openvpn3-service-logger)
               OpenVPN core v3.8.2 linux x86_64 64-bit
               Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Mon Jan  8 15:22:58 2024  Logger INFO: Log method: journald
Wed Jan 19 13:31:49 586524  OpenVPN3/Linux v21 (openvpn3-service-logger)
Wed Jan 19 13:31:49 586524  OpenVPN core v3.8.2 linux x86_64 64-bit
Wed Jan 19 13:31:49 586524  Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
Wed Jan 19 13:31:49 586524  Log method: journald
Mon Jan  8 15:22:58 2024  Logger INFO: Idle exit set to 10 minutes
Mon Jan  8 15:22:58 2024  Logger VERB2: Attached: {tag:659435728684274318}  [:1.184/net.openvpn.v3.netcfg], pid 259489
Mon Jan  8 15:22:58 2024  Logger VERB2: Attached: {tag:8377701857831903868}  [:1.184/net.openvpn.v3.netcfg.core], pid 259489
Mon Jan  8 15:22:58 2024  {tag:8377701857831903868} Network Configuration DEBUG: OpenVPN 3 Core library logging initialized
Mon Jan  8 15:22:58 2024  {tag:659435728684274318} Network Configuration VERB1: Redirect method: host-route
Mon Jan  8 15:23:51 2024  Logger VERB2: Attached: {tag:14493396140449146603}  [:1.187/net.openvpn.v3.configuration], pid 261006
Mon Jan  8 15:23:51 2024  {tag:14493396140449146603} Config Manager INFO: Parsed single-use configuration 'vpn_device_1.ovpn', owner: prathamsharma
Mon Jan  8 15:23:51 2024  {tag:14493396140449146603} Config Manager INFO: Setting configuration override 'persist-tun' to 'true' by UID 1003
Mon Jan  8 15:23:51 2024  Logger VERB2: Attached: {tag:12220714250632486670}  [:1.188/net.openvpn.v3.sessions], pid 261024
Mon Jan  8 15:23:51 2024  Logger VERB2: Attached: {tag:11212960311964532105}  [:1.189/net.openvpn.v3.backends], pid 261042
Mon Jan  8 15:23:57 2024  Logger VERB2: Detached: {tag:11212960311964532105}  [:1.189/net.openvpn.v3.backends], pid 261042
Mon Jan  8 15:24:27 2024  {tag:14493396140449146603} Config Manager INFO: Parsed single-use configuration 'vpn_device_1.ovpn', owner: root
Mon Jan  8 15:24:27 2024  {tag:14493396140449146603} Config Manager INFO: Setting configuration override 'persist-tun' to 'true' by UID 0
Mon Jan  8 15:24:27 2024  Logger VERB2: Attached: {tag:13050616340229785464}  [:1.191/net.openvpn.v3.backends], pid 262743
Mon Jan  8 15:24:33 2024  Logger VERB2: Detached: {tag:13050616340229785464}  [:1.191/net.openvpn.v3.backends], pid 262743
Mon Jan  8 15:27:54 2024  Logger VERB2: Attached: {tag:14155269390281304573}  [:1.195/net.openvpn.v3.backends], pid 266399
Mon Jan  8 15:28:00 2024  Logger VERB2: Detached: {tag:14155269390281304573}  [:1.195/net.openvpn.v3.backends], pid 266399
Mon Jan  8 15:32:58 2024  Logger VERB2: Detached: {tag:659435728684274318}  [:1.184/net.openvpn.v3.netcfg], pid 259489
Mon Jan  8 15:32:58 2024  Logger WARNING: Unexpected Detach call from :1.184, pid not found for this sender
Mon Jan  8 15:32:58 2024  Logger VERB2: Detached: {tag:8377701857831903868}  [:1.184/net.openvpn.v3.netcfg.core]
Mon Jan  8 15:34:05 2024  {tag:12220714250632486670} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Mon Jan  8 15:34:12 2024  {tag:12220714250632486670} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Mon Jan  8 15:35:57 2024  {tag:14493396140449146603} Config Manager INFO: Parsed single-use configuration 'vpn_device_1.ovpn', owner: prathamsharma
Mon Jan  8 15:35:57 2024  {tag:14493396140449146603} Config Manager INFO: Setting configuration override 'persist-tun' to 'true' by UID 1003
Mon Jan  8 15:35:57 2024  Logger VERB2: Attached: {tag:8869862730241784378}  [:1.218/net.openvpn.v3.backends], pid 277212
Mon Jan  8 15:36:03 2024  Logger VERB2: Detached: {tag:8869862730241784378}  [:1.218/net.openvpn.v3.backends], pid 277212
Mon Jan  8 15:36:24 2024  Logger VERB2: Attached: {tag:3555200485608283618}  [:1.221/net.openvpn.v3.backends], pid 277763
Mon Jan  8 15:36:30 2024  Logger VERB2: Detached: {tag:3555200485608283618}  [:1.221/net.openvpn.v3.backends], pid 277763
Mon Jan  8 16:03:39 2024  {tag:12220714250632486670} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration
Mon Jan  8 16:03:47 2024  Logger VERB2: Attached: {tag:16936617597321978154}  [:1.227/net.openvpn.v3.backends], pid 303048
Mon Jan  8 16:03:53 2024  Logger VERB2: Detached: {tag:16936617597321978154}  [:1.227/net.openvpn.v3.backends], pid 303048
Mon Jan  8 16:10:03 2024  {tag:12220714250632486670} Session Manager !! CRITICAL !!: Forced session shutdown before backend registration

[dsommers]

Hmmm .... for some reason, the client process seems to abruptly stop before it can do everything it need to do.

Can you open another terminal to this host, enable the /bin/bash shell for the openvpn user (sudo chsh openvpn). Then run sudo su - openvpn. As this openvpn user, you need to start a process manually with some extra arguments. I would like to see the console output of this command as you start the openvpn2 command line you did. I need to see the full output from the command starts and until the openvpn2 command fails.

[openvpn@host: ~] $ /usr/libexec/openvpn3-linux/openvpn3-service-backendstart --log-level 6 --idle-exit 0 --client-log-level 6 --client-log-file stdout:

[pratham-sharma-uplight]

Hey @dsommers

I think system does not have openvpn user.

Can you check If I am doing it right?

[dsommers]

@pratham-sharma-uplight When you run the sudo chsh openvpn command, you are expected to type /bin/bash. The warning with /nonexistent can be ignored (the openvpn user does not need to have a real home directory).

The reason it says This account is currently not available. is because the login shell is still set to /usr/sbin/nologin.

[pratham-sharma-uplight]

Hey @dsommers
I tried to run the commands as follows:

Terminal 1:
$ sudo chsh openvpn

Changing the login shell for openvpn
Enter the new value, or press ENTER for the default
	Login Shell [/bin/bash]: /bin/bash

 $ sudo systemctl reload dbus.service
 $ openvpn2 --config device_1_ubuntu22_pratham_sharma@uplight.openvpn.com_[Mumbai].ovpn --verb 6

(This is not failing now)

Terminal 2:

 $ /usr/libexec/openvpn3-linux/openvpn3-service-backendstart --log-level 6 --idle-exit 0 --client-log-level 6 --client-log-file stdout:

OpenVPN3/Linux v21 (openvpn3-service-backendstart)
OpenVPN core v3.8.2 linux x86_64 64-bit
Copyright (C) 2012-2022 OpenVPN Inc. All rights reserved.
terminate called after throwing an instance of 'DBusProxyAccessDeniedException'
  what():  Access denied to Attach
Aborted (core dumped)

[dsommers]

Okay, now this is getting interesting. Finally a real failure we can debug more into. This looks like an issue which only some installs experience, and sometimes seems to resolve itself after a reboot. I would like to understand this issue better, so we can get a proper fix in place.

Can you please provide the output if this command?

 $ sudo journalctl --since -4weeks -u dbus | grep -E 'Rejected .*="net.openvpn.v3'