Opened 5 years ago

Last modified 5 years ago

#1252 new Bug / Defect

Unable to reconnect after Windows standby / hibernation

Reported by: blaupause Owned by:
Priority: major Milestone:
Component: Generic / unclassified Version: OpenVPN 2.4.8 (Community Ed)
Severity: Not set (select this one, unless your'e a OpenVPN developer) Keywords:
Cc:

Description

Upgraded from 2.4.6 to 2.4.8 (Windows 10).
2.4.6 was very stable - no configs have been changed etc.
After the upgrade to 2.4.8 I notice that when I put by computer with an active connection to standby / hibernation and wake it up later it will not reconnect.

When I double click on the icon it says something like: "The connection to the management interface failed" (message translated as English is not my native language).

Restarting the service sometimes worked but sometimes the service was completly stuck and wouldn't end.

I thought this might be an issue with my computer so I installed it on colleges computer with the same behavior. We discussed it and he said that he has the feeling that is only happens when he uses the secure connection (2 profiles - 1. split DNS; 2. full VPN tunneling). I couldn't verify this as i already rolled back for now.

Configs:
#SPLIT DNS TUN
dev tun
persist-key
cipher AES-256-CBC
ncp-ciphers AES-128-GCM:AES-192-GCM:AES-256-GCM
auth SHA256
tls-client
client
resolv-retry infinite
remote vpn.company.com 1196 udp
verify-x509-name "vpn.company.com" name
auth-user-pass
pkcs12 a-b-p1-UDP4-1196-vpn.company.com.p12
remote-cert-tls server
register-dns
verb 3
fragment 1400
mssfix 1400

# FULL TUN
dev tun
persist-tun
persist-key
cipher AES-256-CBC
ncp-ciphers AES-128-GCM:AES-192-GCM:AES-256-GCM
auth SHA256
tls-client
client
resolv-retry infinite
remote vpn.company.com 1197 udp
verify-x509-name "vpn.company.com" name
auth-user-pass
pkcs12 a-b-p1-UDP4-1196-vpn.company.com.p12
remote-cert-tls server
register-dns
verb 3
fragment 1400
mssfix 1400

Logfile mentioned in the error mesage:
...
12:19:18 2020 C:\windows\system32\route.exe DELETE XXX.XXX.XXX.XXX MASK 255.255.255.255 192.168.2.1
12:19:18 2020 Warning: route gateway is not reachable on any active network adapters: 192.168.2.1
12:19:18 2020 Route deletion via service failed
12:19:18 2020 C:\windows\system32\route.exe DELETE 0.0.0.0 MASK 128.0.0.0 XX.XX.XX.XX
12:19:18 2020 Route deletion via service succeeded
12:19:18 2020 C:\windows\system32\route.exe DELETE 128.0.0.0 MASK 128.0.0.0 XX.XX.XX.XX
12:19:18 2020 Route deletion via service succeeded
12:19:18 2020 Closing TUN/TAP interface
12:19:31 2020 TAP: DHCP address released
12:19:31 2020 SIGTERM[hard,] received, process exiting
12:19:31 2020 MANAGEMENT: >STATE:1581506371,EXITING,SIGTERM,

Change History (4)

comment:1 Changed 5 years ago by Selva Nair

I cannot reproduce this. Your log shows termination of OpenVPN (SIGTERM received) -- are you pushing ping-exit from server? What is the value of keep-alive on the server? Use a sensible keep-alive so that OpenVPN will automatically reconnect after wakeup if required.

Also the connection to management interface failed message in the GUI seems to indicate somehow GUI has exited leaving OpenVPN running. But that is not consistent with the log snippet posted.

When woken up from hibernation this is what is expected in 2.4.8: if the time lapsed is shorter than ping restart (say 120 seconds), on wake up the client may print a few UDP write error messages at worst and heal automatically. After a longer hibernation, the client will notice ping timeout and reconnect after a 5 second delay. In either case, the service should not lock-up.

If still not working, please post the complete client log at verb=4 starting from before hibernation to after the wakeup. If multiple connections are involved, post logs of both.

comment:2 Changed 5 years ago by blaupause

I cannot reproduce this. Your log shows termination of OpenVPN (SIGTERM received) -- are you pushing ping-exit from server? What is the value of keep-alive on the server? Use a sensible keep-alive so that OpenVPN will automatically reconnect after wakeup if required.

So In the morning i closed the VPN connection. Was working all day and left the office (put computer into hibernation). Woke it up right now and wanted to connect to VPN (trayicon next to the clock is still there).

The window is empty and it shows a popup "Connecting to management interface failed ... view log..."

Log shows:

Wed Feb 19 21:33:34 2020 us=944762 Current Parameter Settings:

Wed Feb 19 21:33:34 2020 us=944762 config = 'office.ovpn'
Wed Feb 19 21:33:34 2020 us=944762 mode = 0
Wed Feb 19 21:33:34 2020 us=944762 show_ciphers = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 show_digests = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 show_engines = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 genkey = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 key_pass_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=944762 show_tls_ciphers = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 connect_retry_max = 0
Wed Feb 19 21:33:34 2020 us=944762 Connection profiles [0]:
Wed Feb 19 21:33:34 2020 us=944762 proto = udp
Wed Feb 19 21:33:34 2020 us=944762 local = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=944762 local_port = '1194'
Wed Feb 19 21:33:34 2020 us=944762 remote = 'vpn.company.com'
Wed Feb 19 21:33:34 2020 us=944762 remote_port = '1196'
Wed Feb 19 21:33:34 2020 us=944762 remote_float = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 bind_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 bind_local = ENABLED
Wed Feb 19 21:33:34 2020 us=944762 bind_ipv6_only = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 connect_retry_seconds = 5
Wed Feb 19 21:33:34 2020 us=944762 connect_timeout = 120
Wed Feb 19 21:33:34 2020 us=944762 socks_proxy_server = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=944762 socks_proxy_port = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=944762 tun_mtu = 1500
Wed Feb 19 21:33:34 2020 us=944762 tun_mtu_defined = ENABLED
Wed Feb 19 21:33:34 2020 us=944762 link_mtu = 1500
Wed Feb 19 21:33:34 2020 us=944762 link_mtu_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 tun_mtu_extra = 0
Wed Feb 19 21:33:34 2020 us=944762 tun_mtu_extra_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=944762 mtu_discover_type = -1
Wed Feb 19 21:33:34 2020 us=944762 fragment = 1400
Wed Feb 19 21:33:34 2020 us=944762 mssfix = 1400
Wed Feb 19 21:33:34 2020 us=944762 explicit_exit_notification = 0
Wed Feb 19 21:33:34 2020 us=945717 Connection profiles END
Wed Feb 19 21:33:34 2020 us=945717 remote_random = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 ipchange = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 dev = 'tun'
Wed Feb 19 21:33:34 2020 us=945717 dev_type = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 dev_node = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 lladdr = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 topology = 1
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_local = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_remote_netmask = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_noexec = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_nowarn = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_local = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_netbits = 0
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_remote = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 shaper = 0
Wed Feb 19 21:33:34 2020 us=945717 mtu_test = 0
Wed Feb 19 21:33:34 2020 us=945717 mlock = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 keepalive_ping = 0
Wed Feb 19 21:33:34 2020 us=945717 keepalive_timeout = 0
Wed Feb 19 21:33:34 2020 us=945717 inactivity_timeout = 0
Wed Feb 19 21:33:34 2020 us=945717 ping_send_timeout = 0
Wed Feb 19 21:33:34 2020 us=945717 ping_rec_timeout = 0
Wed Feb 19 21:33:34 2020 us=945717 ping_rec_timeout_action = 0
Wed Feb 19 21:33:34 2020 us=945717 ping_timer_remote = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 remap_sigusr1 = 0
Wed Feb 19 21:33:34 2020 us=945717 persist_tun = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 persist_local_ip = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 persist_remote_ip = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 persist_key = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 passtos = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 resolve_retry_seconds = 1000000000
Wed Feb 19 21:33:34 2020 us=945717 resolve_in_advance = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 username = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 groupname = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 chroot_dir = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 cd_dir = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 writepid = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 up_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 down_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 down_pre = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 up_restart = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 up_delay = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 daemon = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 inetd = 0
Wed Feb 19 21:33:34 2020 us=945717 log = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 suppress_timestamps = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 machine_readable_output = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 nice = 0
Wed Feb 19 21:33:34 2020 us=945717 verbosity = 4
Wed Feb 19 21:33:34 2020 us=945717 mute = 0
Wed Feb 19 21:33:34 2020 us=945717 gremlin = 0
Wed Feb 19 21:33:34 2020 us=945717 status_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 status_file_version = 1
Wed Feb 19 21:33:34 2020 us=945717 status_file_update_freq = 60
Wed Feb 19 21:33:34 2020 us=945717 occ = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 rcvbuf = 0
Wed Feb 19 21:33:34 2020 us=945717 sndbuf = 0
Wed Feb 19 21:33:34 2020 us=945717 sockflags = 0
Wed Feb 19 21:33:34 2020 us=945717 fast_io = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 comp.alg = 0
Wed Feb 19 21:33:34 2020 us=945717 comp.flags = 0
Wed Feb 19 21:33:34 2020 us=945717 route_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 route_default_gateway = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 route_default_metric = 0
Wed Feb 19 21:33:34 2020 us=945717 route_noexec = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 route_delay = 5
Wed Feb 19 21:33:34 2020 us=945717 route_delay_window = 30
Wed Feb 19 21:33:34 2020 us=945717 route_delay_defined = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 route_nopull = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 route_gateway_via_dhcp = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 allow_pull_fqdn = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 Pull filters:
Wed Feb 19 21:33:34 2020 us=945717 ignore "route-method"
Wed Feb 19 21:33:34 2020 us=945717 management_addr = '127.0.0.1'
Wed Feb 19 21:33:34 2020 us=945717 management_port = '25340'
Wed Feb 19 21:33:34 2020 us=945717 management_user_pass = 'stdin'
Wed Feb 19 21:33:34 2020 us=945717 management_log_history_cache = 250
Wed Feb 19 21:33:34 2020 us=945717 management_echo_buffer_size = 100
Wed Feb 19 21:33:34 2020 us=945717 management_write_peer_info_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 management_client_user = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 management_client_group = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 management_flags = 6
Wed Feb 19 21:33:34 2020 us=945717 shared_secret_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 key_direction = not set
Wed Feb 19 21:33:34 2020 us=945717 ciphername = 'AES-256-CBC'
Wed Feb 19 21:33:34 2020 us=945717 ncp_enabled = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 ncp_ciphers = 'AES-128-GCM:AES-192-GCM:AES-256-GCM'
Wed Feb 19 21:33:34 2020 us=945717 authname = 'SHA256'
Wed Feb 19 21:33:34 2020 us=945717 prng_hash = 'SHA1'
Wed Feb 19 21:33:34 2020 us=945717 prng_nonce_secret_len = 16
Wed Feb 19 21:33:34 2020 us=945717 keysize = 0
Wed Feb 19 21:33:34 2020 us=945717 engine = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 replay = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 mute_replay_warnings = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 replay_window = 64
Wed Feb 19 21:33:34 2020 us=945717 replay_time = 15
Wed Feb 19 21:33:34 2020 us=945717 packet_id_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 use_iv = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 test_crypto = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 tls_server = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 tls_client = ENABLED
Wed Feb 19 21:33:34 2020 us=945717 key_method = 2
Wed Feb 19 21:33:34 2020 us=945717 ca_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ca_path = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 dh_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 cert_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 extra_certs_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 priv_key_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 pkcs12_file = 'pfsense-am-p1-UDP4-1196-vpn.company.com.p12'
Wed Feb 19 21:33:34 2020 us=945717 cryptoapi_cert = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 cipher_list = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 cipher_list_tls13 = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 tls_cert_profile = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 tls_verify = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 tls_export_cert = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 verify_x509_type = 2
Wed Feb 19 21:33:34 2020 us=945717 verify_x509_name = 'vpn.company.com'
Wed Feb 19 21:33:34 2020 us=945717 crl_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ns_cert_type = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 65535
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_ku[i] = 0
Wed Feb 19 21:33:34 2020 us=945717 remote_cert_eku = 'TLS Web Server Authentication'
Wed Feb 19 21:33:34 2020 us=945717 ssl_flags = 0
Wed Feb 19 21:33:34 2020 us=945717 tls_timeout = 2
Wed Feb 19 21:33:34 2020 us=945717 renegotiate_bytes = -1
Wed Feb 19 21:33:34 2020 us=945717 renegotiate_packets = 0
Wed Feb 19 21:33:34 2020 us=945717 renegotiate_seconds = 3600
Wed Feb 19 21:33:34 2020 us=945717 handshake_window = 60
Wed Feb 19 21:33:34 2020 us=945717 transition_window = 3600
Wed Feb 19 21:33:34 2020 us=945717 single_session = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 push_peer_info = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 tls_exit = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 tls_auth_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 tls_crypt_file = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_protected_authentication = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_private_mode = 00000000
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_cert_private = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_pin_cache_period = -1
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_id = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 pkcs11_id_management = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 server_network = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 server_netmask = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 server_network_ipv6 = ::
Wed Feb 19 21:33:34 2020 us=945717 server_netbits_ipv6 = 0
Wed Feb 19 21:33:34 2020 us=945717 server_bridge_ip = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 server_bridge_netmask = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 server_bridge_pool_start = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 server_bridge_pool_end = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_start = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_end = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_netmask = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_persist_filename = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_pool_persist_refresh_freq = 600
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_pool_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_pool_base = ::
Wed Feb 19 21:33:34 2020 us=945717 ifconfig_ipv6_pool_netbits = 0
Wed Feb 19 21:33:34 2020 us=945717 n_bcast_buf = 256
Wed Feb 19 21:33:34 2020 us=946756 tcp_queue_limit = 64
Wed Feb 19 21:33:34 2020 us=946756 real_hash_size = 256
Wed Feb 19 21:33:34 2020 us=946756 virtual_hash_size = 256
Wed Feb 19 21:33:34 2020 us=946756 client_connect_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 learn_address_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 client_disconnect_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 client_config_dir = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 ccd_exclusive = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 tmp_dir = 'C:\Users\redacted\AppData?\Local\Temp\'
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_local = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_remote_netmask = 0.0.0.0
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_ipv6_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_ipv6_local = ::/0
Wed Feb 19 21:33:34 2020 us=946756 push_ifconfig_ipv6_remote = ::
Wed Feb 19 21:33:34 2020 us=946756 enable_c2c = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 duplicate_cn = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 cf_max = 0
Wed Feb 19 21:33:34 2020 us=946756 cf_per = 0
Wed Feb 19 21:33:34 2020 us=946756 max_clients = 1024
Wed Feb 19 21:33:34 2020 us=946756 max_routes_per_client = 256
Wed Feb 19 21:33:34 2020 us=946756 auth_user_pass_verify_script = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 auth_user_pass_verify_script_via_file = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 auth_token_generate = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 auth_token_lifetime = 0
Wed Feb 19 21:33:34 2020 us=946756 client = ENABLED
Wed Feb 19 21:33:34 2020 us=946756 pull = ENABLED
Wed Feb 19 21:33:34 2020 us=946756 auth_user_pass_file = 'stdin'
Wed Feb 19 21:33:34 2020 us=946756 show_net_up = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 route_method = 3
Wed Feb 19 21:33:34 2020 us=946756 block_outside_dns = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 ip_win32_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 ip_win32_type = 3
Wed Feb 19 21:33:34 2020 us=946756 dhcp_masq_offset = 0
Wed Feb 19 21:33:34 2020 us=946756 dhcp_lease_time = 31536000
Wed Feb 19 21:33:34 2020 us=946756 tap_sleep = 0
Wed Feb 19 21:33:34 2020 us=946756 dhcp_options = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 dhcp_renew = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 dhcp_pre_release = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 domain = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 netbios_scope = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 netbios_node_type = 0
Wed Feb 19 21:33:34 2020 us=946756 disable_nbt = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 OpenVPN 2.4.8 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Oct 31 2019
Wed Feb 19 21:33:34 2020 us=946756 Windows version 6.2 (Windows 8 or greater) 64bit
Wed Feb 19 21:33:34 2020 us=947712 library versions: OpenSSL 1.1.0l 10 Sep 2019, LZO 2.10
Enter Management Password:
Wed Feb 19 21:33:34 2020 us=950743 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Wed Feb 19 21:33:34 2020 us=950743 Need hold release from management interface, waiting...

I am not able to ping anything within the network and the tray icon shows no connection.

Also the connection to management interface failed message in the GUI seems to indicate somehow GUI has exited leaving OpenVPN running. But that is not consistent with the log snippet posted.

If the GUI is just the trayicon - its still there and responsive.

When woken up from hibernation this is what is expected in 2.4.8: if the time lapsed is shorter than ping restart (say 120 seconds), on wake up the client may print a few UDP write error messages at worst and heal automatically. After a longer hibernation, the client will notice ping timeout and reconnect after a 5 second delay. In either case, the service should not lock-up.

That would be my expected behavior and totally fine but that doesn't seem to be working form me.

If still not working, please post the complete client log at verb=4 starting from before hibernation to after the wakeup. If multiple connections are involved, post logs of both.

After your post I immediately upgraded to 2.4.8 again and set the config (see updated below).
Multiple connections are not used simultaneously.
The problem is that the log I posted a couple lines above is the full log (it seems be be cleared on every connection attempt).

dev tun
persist-tun
persist-key
cipher AES-256-CBC
ncp-ciphers AES-128-GCM:AES-192-GCM:AES-256-GCM
auth SHA256
tls-client
client
resolv-retry infinite
remote vpn.company.com 1196 udp
verify-x509-name "vpn.company.com" name
auth-user-pass
pkcs12 Redacted-p1-UDP4-1196-vpn.company.com.p12
remote-cert-tls server
register-dns
verb 4
fragment 1400
mssfix 1400

comment:3 Changed 5 years ago by blaupause

So the last post took a bit time. After the post I retried the connection without changing anything.

I get the same error popup but now in the backgroud there is this text:
"OpenVPN exited with error: exit code = 1
Check the log for details"

Log:
...(log above)
Wed Feb 19 21:33:34 2020 us=946756 block_outside_dns = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 ip_win32_defined = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 ip_win32_type = 3
Wed Feb 19 21:33:34 2020 us=946756 dhcp_masq_offset = 0
Wed Feb 19 21:33:34 2020 us=946756 dhcp_lease_time = 31536000
Wed Feb 19 21:33:34 2020 us=946756 tap_sleep = 0
Wed Feb 19 21:33:34 2020 us=946756 dhcp_options = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 dhcp_renew = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 dhcp_pre_release = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 domain = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 netbios_scope = '[UNDEF]'
Wed Feb 19 21:33:34 2020 us=946756 netbios_node_type = 0
Wed Feb 19 21:33:34 2020 us=946756 disable_nbt = DISABLED
Wed Feb 19 21:33:34 2020 us=946756 OpenVPN 2.4.8 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Oct 31 2019
Wed Feb 19 21:33:34 2020 us=946756 Windows version 6.2 (Windows 8 or greater) 64bit
Wed Feb 19 21:33:34 2020 us=947712 library versions: OpenSSL 1.1.0l 10 Sep 2019, LZO 2.10
Enter Management Password:
Wed Feb 19 21:33:34 2020 us=950743 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Wed Feb 19 21:33:34 2020 us=950743 Need hold release from management interface, waiting...
Wed Feb 19 21:51:07 2020 us=829795 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Wed Feb 19 21:51:28 2020 us=928189 MANAGEMENT: Client disconnected
Wed Feb 19 21:51:42 2020 us=968234 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Wed Feb 19 21:51:44 2020 us=765651 MANAGEMENT: Client disconnected

Windows event log:
The description for Event ID 0 from source openvpnserv cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

If the event originated on another computer, the display information had to be saved with the event.

The following information was included with the event:

openvpnserv error:
0x20000000
OpenVPN exited with error: exit code = 1

After I restart the service (OpenVPNServiceInteractive) it works.

Is there any other log from the service?

Thank you for your help!

comment:4 Changed 5 years ago by Selva Nair

You say the connection was stopped before hibernating but the error you see (failed to connect to the management but the log shows its waiting for management client) seems to indicate that openvpn got started by something else before the GUI tried to start it.

Hard to guess, but check whether openvpnservice or openvpnservicelegacy are running. If so, stop them. Leave only openvpnserviceinteractive running. The former will start the connection automatically if the config is in C:\Program Files\OpenVPN\config (not otherwise) and mess up with interactive use through the GUI.

If openvpn exits with error (as in the service event log), it will write some error to the log file. But multiple processes may be competing for the same log if you have competing services running or a stale process is left behind. One way to check is to open the task manager and look for openvpn.exe processes. Do this before attempting to start any connection through the GUI and/or when it gives startup errors.

Note: See TracTickets for help on using tickets.