openvpn supposedly dropped privs so that is cannot re-read "auth-user-pass auth.txt" file

[mmokrejs]

Hi,

I use "auth-user-pass auth.txt" in configfile to pass username/pass pair for authentication. That works but after one hour, the connection is dropped because oepnvpn failed to re-negotiate (supposedly connection keys?). Not sure why it needed to have access to username/passphrase again but it clearly dropped the connection because of lack of privs. I assume openvpn was started under root privs and then dropped them.

It was started as follows:

/usr/sbin/openvpn --config /etc/openvpn/foo.conf --writepid /var/run/openvpn.foo.pid --daemon --setenv SVCNAME openvpn.foo --user openvpn --group openvpn --setenv PEER_DNS yes

Sep 21 20:14:22 vostro openvpn [12594] : Current Parameter Settings:
Sep 21 20:14:22 vostro openvpn [12594] : config = '/etc/openvpn/foo.conf'
Sep 21 20:14:22 vostro openvpn [12594] : mode = 0
Sep 21 20:14:22 vostro openvpn [12594] : persist_config = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : persist_mode = 1
Sep 21 20:14:22 vostro openvpn [12594] : show_ciphers = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : show_digests = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : show_engines = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : genkey = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : key_pass_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : show_tls_ciphers = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : connect_retry_max = 0
Sep 21 20:14:22 vostro openvpn [12594] : Connection profiles [0] :
Sep 21 20:14:22 vostro openvpn [12594] : proto = udp
Sep 21 20:14:22 vostro openvpn [12594] : local = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : local_port = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : remote = 'vpn.foo.bar'
Sep 21 20:14:22 vostro openvpn [12594] : remote_port = '1194'
Sep 21 20:14:22 vostro openvpn [12594] : remote_float = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : bind_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : bind_local = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : bind_ipv6_only = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : connect_retry_seconds = 5
Sep 21 20:14:22 vostro openvpn [12594] : connect_timeout = 120
Sep 21 20:14:22 vostro openvpn [12594] : socks_proxy_server = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : socks_proxy_port = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : tun_mtu = 9000
Sep 21 20:14:22 vostro openvpn [12594] : tun_mtu_defined = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : link_mtu = 1500
Sep 21 20:14:22 vostro openvpn [12594] : link_mtu_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tun_mtu_extra = 0
Sep 21 20:14:22 vostro openvpn [12594] : tun_mtu_extra_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : mtu_discover_type = -1
Sep 21 20:14:22 vostro openvpn [12594] : fragment = 0
Sep 21 20:14:22 vostro openvpn [12594] : mssfix = 0
Sep 21 20:14:22 vostro openvpn [12594] : explicit_exit_notification = 0
Sep 21 20:14:22 vostro openvpn [12594] : Connection profiles END
Sep 21 20:14:22 vostro openvpn [12594] : remote_random = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : ipchange = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : dev = 'tun'
Sep 21 20:14:22 vostro openvpn [12594] : dev_type = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : dev_node = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : lladdr = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : topology = 1
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_local = '192.168.253.6'
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_remote_netmask = '192.168.253.5'
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_noexec = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_nowarn = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_local = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_netbits = 0
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_remote = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : shaper = 0
Sep 21 20:14:22 vostro openvpn [12594] : mtu_test = 0
Sep 21 20:14:22 vostro openvpn [12594] : mlock = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : keepalive_ping = 10
Sep 21 20:14:22 vostro openvpn [12594] : keepalive_timeout = 120
Sep 21 20:14:22 vostro openvpn [12594] : inactivity_timeout = 0
Sep 21 20:14:22 vostro openvpn [12594] : ping_send_timeout = 10
Sep 21 20:14:22 vostro openvpn [12594] : ping_rec_timeout = 120
Sep 21 20:14:22 vostro openvpn [12594] : ping_rec_timeout_action = 2
Sep 21 20:14:22 vostro openvpn [12594] : ping_timer_remote = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : remap_sigusr1 = 0
Sep 21 20:14:22 vostro openvpn [12594] : persist_tun = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : persist_local_ip = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : persist_remote_ip = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : persist_key = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : passtos = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : resolve_retry_seconds = 1000000000
Sep 21 20:14:22 vostro openvpn [12594] : resolve_in_advance = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : username = 'openvpn'
Sep 21 20:14:22 vostro openvpn [12594] : groupname = 'openvpn'
Sep 21 20:14:22 vostro openvpn [12594] : chroot_dir = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : cd_dir = '/etc/openvpn/foo'
Sep 21 20:14:22 vostro openvpn [12594] : writepid = '/var/run/openvpn.foo.pid'
Sep 21 20:14:22 vostro openvpn [12594] : up_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : down_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : down_pre = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : up_restart = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : up_delay = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : daemon = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : inetd = 0
Sep 21 20:14:22 vostro openvpn [12594] : log = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : suppress_timestamps = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : machine_readable_output = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : nice = 0
Sep 21 20:14:22 vostro openvpn [12594] : verbosity = 99
Sep 21 20:14:22 vostro openvpn [12594] : mute = 0
Sep 21 20:14:22 vostro openvpn [12594] : gremlin = 0
Sep 21 20:14:22 vostro openvpn [12594] : status_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : status_file_version = 1
Sep 21 20:14:22 vostro openvpn [12594] : status_file_update_freq = 60
Sep 21 20:14:22 vostro openvpn [12594] : occ = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : rcvbuf = 0
Sep 21 20:14:22 vostro openvpn [12594] : sndbuf = 0
Sep 21 20:14:22 vostro openvpn [12594] : mark = 0
Sep 21 20:14:22 vostro openvpn [12594] : sockflags = 0
Sep 21 20:14:22 vostro openvpn [12594] : fast_io = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : comp.alg = 2
Sep 21 20:14:22 vostro openvpn [12594] : comp.flags = 1
Sep 21 20:14:22 vostro openvpn [12594] : route_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : route_default_gateway = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : route_default_metric = 0
Sep 21 20:14:22 vostro openvpn [12594] : route_noexec = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : route_delay = 0
Sep 21 20:14:22 vostro openvpn [12594] : route_delay_window = 30
Sep 21 20:14:22 vostro openvpn [12594] : route_delay_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : route_nopull = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : route_gateway_via_dhcp = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : allow_pull_fqdn = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : management_addr = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_port = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_user_pass = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_log_history_cache = 250
Sep 21 20:14:22 vostro openvpn [12594] : management_echo_buffer_size = 100
Sep 21 20:14:22 vostro openvpn [12594] : management_write_peer_info_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_client_user = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_client_group = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : management_flags = 0
Sep 21 20:14:22 vostro openvpn [12594] : shared_secret_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : key_direction = 0
Sep 21 20:14:22 vostro openvpn [12594] : ciphername = 'BF-CBC'
Sep 21 20:14:22 vostro openvpn [12594] : ncp_enabled = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Sep 21 20:14:22 vostro openvpn [12594] : authname = 'SHA1'
Sep 21 20:14:22 vostro openvpn [12594] : prng_hash = 'SHA1'
Sep 21 20:14:22 vostro openvpn [12594] : prng_nonce_secret_len = 16
Sep 21 20:14:22 vostro openvpn [12594] : keysize = 0
Sep 21 20:14:22 vostro openvpn [12594] : engine = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : replay = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : mute_replay_warnings = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : replay_window = 64
Sep 21 20:14:22 vostro openvpn [12594] : replay_time = 15
Sep 21 20:14:22 vostro openvpn [12594] : packet_id_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : use_iv = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : test_crypto = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tls_server = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tls_client = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : key_method = 2
Sep 21 20:14:22 vostro openvpn [12594] : ca_file = ' INLINE? '
Sep 21 20:14:22 vostro openvpn [12594] : ca_path = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : dh_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : cert_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : extra_certs_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : priv_key_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : pkcs12_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : cipher_list = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : tls_verify = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : tls_export_cert = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : verify_x509_type = 0
Sep 21 20:14:22 vostro openvpn [12594] : verify_x509_name = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : crl_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : ns_cert_type = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_ku[i] = 0
Sep 21 20:14:22 vostro openvpn [12594] : remote_cert_eku = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : ssl_flags = 0
Sep 21 20:14:22 vostro openvpn [12594] : tls_timeout = 2
Sep 21 20:14:22 vostro openvpn [12594] : renegotiate_bytes = -1
Sep 21 20:14:22 vostro openvpn [12594] : renegotiate_packets = 0
Sep 21 20:14:22 vostro openvpn [12594] : renegotiate_seconds = 3600
Sep 21 20:14:22 vostro openvpn [12594] : handshake_window = 60
Sep 21 20:14:22 vostro openvpn [12594] : transition_window = 3600
Sep 21 20:14:22 vostro openvpn [12594] : single_session = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : push_peer_info = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tls_exit = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tls_auth_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : tls_crypt_file = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_protected_authentication = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_private_mode = 00000000
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_cert_private = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_pin_cache_period = -1
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_id = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : pkcs11_id_management = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : server_network = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : server_netmask = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : server_network_ipv6 = ::
Sep 21 20:14:22 vostro openvpn [12594] : server_netbits_ipv6 = 0
Sep 21 20:14:22 vostro openvpn [12594] : server_bridge_ip = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : server_bridge_netmask = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : server_bridge_pool_start = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : server_bridge_pool_end = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_start = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_end = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_netmask = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_persist_filename = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_pool_persist_refresh_freq = 600
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_pool_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_pool_base = ::
Sep 21 20:14:22 vostro openvpn [12594] : ifconfig_ipv6_pool_netbits = 0
Sep 21 20:14:22 vostro openvpn [12594] : n_bcast_buf = 256
Sep 21 20:14:22 vostro openvpn [12594] : tcp_queue_limit = 64
Sep 21 20:14:22 vostro openvpn [12594] : real_hash_size = 256
Sep 21 20:14:22 vostro openvpn [12594] : virtual_hash_size = 256
Sep 21 20:14:22 vostro openvpn [12594] : client_connect_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : learn_address_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : client_disconnect_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : client_config_dir = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : ccd_exclusive = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : tmp_dir = '/tmp'
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_local = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_remote_netmask = 0.0.0.0
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_ipv6_defined = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_ipv6_local = ::/0
Sep 21 20:14:22 vostro openvpn [12594] : push_ifconfig_ipv6_remote = ::
Sep 21 20:14:22 vostro openvpn [12594] : enable_c2c = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : duplicate_cn = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : cf_max = 0
Sep 21 20:14:22 vostro openvpn [12594] : cf_per = 0
Sep 21 20:14:22 vostro openvpn [12594] : max_clients = 1024
Sep 21 20:14:22 vostro openvpn [12594] : max_routes_per_client = 256
Sep 21 20:14:22 vostro openvpn [12594] : auth_user_pass_verify_script = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : auth_user_pass_verify_script_via_file = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : auth_token_generate = DISABLED
Sep 21 20:14:22 vostro openvpn [12594] : auth_token_lifetime = 0
Sep 21 20:14:22 vostro openvpn [12594] : port_share_host = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : port_share_port = '[UNDEF]'
Sep 21 20:14:22 vostro openvpn [12594] : client = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : pull = ENABLED
Sep 21 20:14:22 vostro openvpn [12594] : auth_user_pass_file = 'auth.txt'
Sep 21 20:14:22 vostro openvpn [12594] : OpenVPN 2.4.3 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep 14 2017
Sep 21 20:14:22 vostro openvpn [12594] : library versions: OpenSSL 1.0.2l 25 May 2017, LZO 2.10
Sep 21 20:14:22 vostro openvpn [12596] : PKCS #11 : pkcs11_initialize - entered
Sep 21 20:14:22 vostro openvpn [12596] : PKCS #11 : pkcs11_initialize - return 0-'CKR_OK'
Sep 21 20:14:22 vostro openvpn [12596] : WARNING: using --pull/--client and --ifconfig together is probably not what you want
Sep 21 20:14:22 vostro openvpn [12596] : WARNING: No server certificate verification method has been enabled. See ​ http://openvpn.net/howto.html#mitm for more info.
Sep 21 20:14:22 vostro openvpn [12596] : PO_INIT maxevents=4 flags=0x00000002
Sep 21 20:14:22 vostro openvpn [12596] : PRNG init md=SHA1 size=36
Sep 21 20:14:22 vostro openvpn [12596] : LZO compression initializing
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_session_init: entry
Sep 21 20:14:22 vostro openvpn [12596] : PID packet_id_init seq_backtrack=64 time_backtrack=15
Sep 21 20:14:22 vostro openvpn [12596] : PID packet_id_init seq_backtrack=64 time_backtrack=15
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_session_init: new session object, sid=1dd6ecbc 176d82db
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_session_init: entry
Sep 21 20:14:22 vostro openvpn [12596] : PID packet_id_init seq_backtrack=64 time_backtrack=15
Sep 21 20:14:22 vostro openvpn [12596] : PID packet_id_init seq_backtrack=64 time_backtrack=15
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_session_init: new session object, sid=a7a3521e 4821d36d
Sep 21 20:14:22 vostro openvpn [12596] : Control Channel MTU parms [ L:9122 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Sep 21 20:14:22 vostro openvpn [12596] : GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Sep 21 20:14:22 vostro openvpn [12596] : RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Sep 21 20:14:22 vostro openvpn [12596] : Data Channel MTU parms [ L:9122 D:9122 EF:122 EB:1656 ET:0 EL:3 AF:3/1 ]
Sep 21 20:14:22 vostro openvpn [12596] : crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 40 bytes
Sep 21 20:14:22 vostro openvpn [12596] : calc_options_string_link_mtu: link-mtu 9122 -> 9042
Sep 21 20:14:22 vostro openvpn [12596] : crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 40 bytes
Sep 21 20:14:22 vostro openvpn [12596] : calc_options_string_link_mtu: link-mtu 9122 -> 9042
Sep 21 20:14:22 vostro openvpn [12596] : Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 9042,tun-mtu 9000,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Sep 21 20:14:22 vostro openvpn [12596] : Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 9042,tun-mtu 9000,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Sep 21 20:14:22 vostro openvpn [12596] : TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:1194
Sep 21 20:14:22 vostro openvpn [12596] : Socket Buffers: R=[212992->212992] S=[212992->212992]
Sep 21 20:14:22 vostro openvpn [12596] : UDP link local: (not bound)
Sep 21 20:14:22 vostro openvpn [12596] : UDP link remote: [AF_INET]xx.xx.xx.xx:1194
Sep 21 20:14:22 vostro openvpn [12596] : NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Sep 21 20:14:22 vostro openvpn [12596] : TLS Warning: no data channel send key available: [key #0 state=S_INITIAL id=0 sid=00000000 00000000] [key #1 state=S_UNDEF id=0 sid=00000000 00000000] [key #2 state=S_UNDEF id=0 sid=00000000 00000000]
Sep 21 20:14:22 vostro openvpn [12596] : SENT PING
Sep 21 20:14:22 vostro openvpn [12596] : TIMER: coarse timer wakeup 1 seconds
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=1dd6ecbc 176d82db, stored-sid=00000000 00000000, stored-ip=[AF_INET]xx.xx.xx.xx:1194
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_process: chg=0 ks=S_INITIAL lame=S_UNDEF to_link->len=0 wakeup=604800
Sep 21 20:14:22 vostro openvpn [12596] : ACK mark active outgoing ID 0
Sep 21 20:14:22 vostro openvpn [12596] : TLS: Initial Handshake, sid=1dd6ecbc 176d82db
Sep 21 20:14:22 vostro openvpn [12596] : ACK reliable_can_send active=1 current=1 : [1] 0
Sep 21 20:14:22 vostro openvpn [12596] : ACK reliable_send ID 0 (size=4 to=2)
Sep 21 20:14:22 vostro openvpn [12596] : Reliable -> TCP/UDP
Sep 21 20:14:22 vostro openvpn [12596] : ACK reliable_send_timeout 2 [1] 0
Sep 21 20:14:22 vostro openvpn [12596] : TLS: tls_process: timeout set to 2

...

Sep 21 21:14:24 vostro openvpn [12596] : Error opening 'Auth' auth file: auth.txt: Permission denied (errno=13)
Sep 21 21:14:24 vostro openvpn [12596] : Exiting due to fatal error

ls -latr /etc/openvpn/foo/auth.txt
-rw------- 1 root root xx Sep 21 20:07 auth.txt

I run openvpn 2.4.3- r1 from/on Gentoo Linux, actually.

[David Sommerseth]

This is not unexpected at all, and even more so if you also uss --auth-nocache in your configuration. The auth.txt file is read before it drops privileges ( --user and --group ) and --auth-nocache tells OpenVPN to not save passwords in memory, so it needs to re-read the auth.txt file. But now it reads it as the openvpn user, not root. And since the file is owned by root:root with mode 0600, you get the permission denied.

If --auth-nocache is crucial for you, I would rather recommend to add --auth-gen-token on the server side. This replaces the password with a temporary session password valid for only a single session. That session password is a 32 bytes long random string, so it should be fairly safe - also for long running instances. --auth-gen-token might have some side-effects which might be important though; it will no longer call --auth-user-pass-verify scripts or user/password authentication plug-ins after the first initial and successful authentication (with the proper user password).

Otherwise, the quick-fix on the client side ... chown openvpn:openvpn auth.txt or remove auth-nocache from the config.