Management auth + L2 bridge = data channel not established

V1pr

Hi,

I've a working client-server setup with PAM plugin auth (+OTP). All works ok, client gets IP from a separate DHCP server (tap is bridged). However, if I change the authentication (nothing else) from plugin to management-client-auth, the clients does not get IP addresses anymore. When checking with tcpdump I cannot see any DHCP REQ on server tap.

Client is on wifi, private IP + NAT.

dev-type tap

port 443
proto tcp-server
tls-server

# Certificates and ciphers
ca myserv-ca.crt
cert myserv-server.crt
key myserv-server.key # This file should be kept secret
# replaced by tls-crypt
#tls-auth ta.key 0 # This file is secret
tls-crypt tls-crypt.key

dh dh2048.pem
ecdh-curve ED25519

cipher AES-256-GCM
ncp-ciphers AES-256-GCM
# TLS 1.2
tls-cipher TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384
# TLS 1.3
tls-ciphersuites TLS-CHACHA20-POLY1305-SHA256:TLS-AES-256-GCM-SHA384:TLS-AES-128-GCM-SHA256
tls-version-min 1.2

auth-nocache
auth SHA512
# using token instead of MFA
auth-gen-token 14400

#keepalive 10 120
ping 60

persist-key
persist-tun

topology subnet
server-bridge

# Logging
status /var/log/openvpn/openvpn-status.log
status-version 1
log-append /var/log/openvpn/openvpn.log
verb 4
mute 20

verify-client-cert none
username-as-common-name

client-to-client

up "/etc/openvpn/server/bridge-addif.sh br0 ens33"

# to be able to call up/down script
script-security 2

management /etc/openvpn/server/.server-auth-socket unix
#management-client-auth

# if using managemet-client-auth, this is disabled
plugin /lib64/openvpn/plugins/openvpn-plugin-auth-pam-viper.so "openvpn login USERNAME password PASSWORD 'Enter PASSCODE' OTP"

mute-replay-warnings

#push "redirect-gateway def1"
push "route-gateway dhcp"

push "route-gateway 10.14.12.1"
#push "ip-win32 dynamic 0 3600"

client
dev tap

proto tcp

remote SERVER_PUBLIC_IP 443

connect-retry 3 600
resolv-retry infinite

verify-hash VRIFY_HASH

nobind
persist-key
persist-tun

# Use this cipher when negotiation is disabled
cipher AES-256-GCM

# Digest algorithm for HMAC authentication
auth SHA512

verify-x509-name "CN=myserver.server.com"

<ca>
-----BEGIN CERTIFICATE-----
MY-CA
-----END CERTIFICATE-----
</ca>

<tls-crypt>
-----BEGIN OpenVPN Static key V1-----
TLS-CRYPT
-----END OpenVPN Static key V1-----
</tls-crypt>

remote-cert-tls server

# Don't cache credentials in virtual memory
auth-nocache

auth-user-pass
auth-retry interact
static-challenge "RSA Token" 1

verb 4
float

pull

Server log (just the end, the first part is the same as the non working one):

TCP connection established with [AF_INET]CLIENT_PUBLIC_IP:62768
TCPv4_SERVER link local: (not bound)
TCPv4_SERVER link remote: [AF_INET]CLIENT_PUBLIC_IP:62768
CLIENT_PUBLIC_IP:62768 TLS: Initial packet from [AF_INET]CLIENT_PUBLIC_IP:62768, sid=8748730d f06f2521
CLIENT_PUBLIC_IP:62768 peer info: IV_VER=2.4.8
CLIENT_PUBLIC_IP:62768 peer info: IV_PLAT=win
CLIENT_PUBLIC_IP:62768 peer info: IV_PROTO=2
CLIENT_PUBLIC_IP:62768 peer info: IV_NCP=2
CLIENT_PUBLIC_IP:62768 peer info: IV_LZ4=1
CLIENT_PUBLIC_IP:62768 peer info: IV_LZ4v2=1
CLIENT_PUBLIC_IP:62768 peer info: IV_LZO=1
CLIENT_PUBLIC_IP:62768 peer info: IV_COMP_STUB=1
CLIENT_PUBLIC_IP:62768 peer info: IV_COMP_STUBv2=1
CLIENT_PUBLIC_IP:62768 peer info: IV_TCPNL=1
CLIENT_PUBLIC_IP:62768 peer info: IV_GUI_VER=OpenVPN_GUI_11
AUTH-PAM: BACKGROUND: received command code: 0
AUTH-PAM: BACKGROUND: USER: mysecretusername
AUTH-PAM: BACKGROUND: parsed static challenge password
AUTH-PAM: BACKGROUND: my_conv[0] query='login:' style=2
AUTH-PAM: BACKGROUND: name match found, query/match-string ['login:', 'login'] = 'USERNAME'
AUTH-PAM: BACKGROUND: my_conv[0] query='Password: ' style=1
AUTH-PAM: BACKGROUND: name match found, query/match-string ['Password: ', 'password'] = 'PASSWORD'
AUTH-PAM: BACKGROUND: my_conv[0] query='Enter PASSCODE:' style=1
AUTH-PAM: BACKGROUND: name match found, query/match-string ['Enter PASSCODE:', 'Enter PASSCODE'] = 'OTP'
CLIENT_PUBLIC_IP:62768 PLUGIN_CALL: POST /lib64/openvpn/plugins/openvpn-plugin-auth-pam-viper.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
CLIENT_PUBLIC_IP:62768 TLS: Username/Password authentication succeeded for username 'mysecretusername' [CN SET]
CLIENT_PUBLIC_IP:62768 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-ECDSA-AES256-GCM-SHA384
CLIENT_PUBLIC_IP:62768 [mysecretusername] Peer Connection Initiated with [AF_INET]CLIENT_PUBLIC_IP:62768
mysecretusername/CLIENT_PUBLIC_IP:62768 MULTI: no dynamic or static remote --ifconfig address is available for mysecretusername/CLIENT_PUBLIC_IP:62768
mysecretusername/CLIENT_PUBLIC_IP:62768 PUSH: Received control message: 'PUSH_REQUEST'
mysecretusername/CLIENT_PUBLIC_IP:62768 SENT CONTROL [mysecretusername]: 'PUSH_REPLY,route-gateway dhcp,route-gateway 10.14.12.1,route-gateway dhcp,peer-id 0,cipher AES-256-GCM,auth-token' (status=1)
mysecretusername/CLIENT_PUBLIC_IP:62768 Data Channel MTU parms [ L:1583 D:1450 EF:51 EB:411 ET:32 EL:3 ]
mysecretusername/CLIENT_PUBLIC_IP:62768 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
mysecretusername/CLIENT_PUBLIC_IP:62768 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
mysecretusername/CLIENT_PUBLIC_IP:62768 MULTI: Learn: 00:ff:18:74:57:ab -> mysecretusername/CLIENT_PUBLIC_IP:62768
mysecretusername/CLIENT_PUBLIC_IP:62768 Connection reset, restarting [-1]
mysecretusername/CLIENT_PUBLIC_IP:62768 SIGUSR1[soft,connection-reset] received, client-instance restarting
TCP/UDP: Closing socket

Server log with mgmt auth:

WARNING: POTENTIALLY DANGEROUS OPTION --verify-client-cert none|optional (or --client-cert-not-required) may accept clients which do not present a certificate
Current Parameter Settings:
  config = 'server.conf'
  mode = 1
  persist_config = DISABLED
  persist_mode = 1
  show_ciphers = DISABLED
  show_digests = DISABLED
  show_engines = DISABLED
  genkey = DISABLED
  key_pass_file = '[UNDEF]'
  show_tls_ciphers = DISABLED
  connect_retry_max = 0
Connection profiles [0]:
  proto = tcp-server
  local = '[UNDEF]'
  local_port = '443'
  remote = '[UNDEF]'
  remote_port = '443'
  remote_float = DISABLED
  bind_defined = DISABLED
NOTE: --mute triggered...
266 variation(s) on previous 20 message(s) suppressed by --mute
OpenVPN 2.4.8 x86_64-redhat-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Nov  1 2019
library versions: OpenSSL 1.1.1c FIPS  28 May 2019, LZO 2.08
MANAGEMENT: unix domain socket listening on /etc/openvpn/server/.server-auth-socket
WARNING: --ping should normally be used with --ping-restart or --ping-exit
NOTE: when bridging your LAN adapter with the TAP adapter, note that the new bridge adapter will often take on its own IP address that is different from what the LAN adapter was previously set to
WARNING: --keepalive option is missing from server config
NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Diffie-Hellman initialized with 2048 bit key
Failed to use supplied curve (ED25519), using secp384r1 instead.
ECDH curve secp384r1 added
Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
TLS-Auth MTU parms [ L:1655 D:1154 EF:96 EB:0 ET:0 EL:3 ]
TUN/TAP device tap0 opened
TUN/TAP TX queue length set to 100
/etc/openvpn/server/bridge-addif.sh br0 ens33 tap0 1500 1655   init
Data Channel MTU parms [ L:1655 D:1450 EF:123 EB:411 ET:32 EL:3 ]
Could not determine IPv4/IPv6 protocol. Using AF_INET
Socket Buffers: R=[87380->87380] S=[16384->16384]
Listening for incoming TCP connection on [AF_INET][undef]:443
TCPv4_SERVER link local (bound): [AF_INET][undef]:443
TCPv4_SERVER link remote: [AF_UNSPEC]
MULTI: multi_init called, r=256 v=256
MULTI: TCP INIT maxclients=1024 maxevents=1028
Initialization Sequence Completed
MANAGEMENT: Client connected from /etc/openvpn/server/.server-auth-socket
MULTI: multi_create_instance called
Re-using SSL/TLS context
Control Channel MTU parms [ L:1655 D:1154 EF:96 EB:0 ET:0 EL:3 ]
Data Channel MTU parms [ L:1655 D:1450 EF:123 EB:411 ET:32 EL:3 ]
Local Options String (VER=V4): 'V4,dev-type tap,link-mtu 1583,tun-mtu 1532,proto TCPv4_SERVER,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-server'
Expected Remote Options String (VER=V4): 'V4,dev-type tap,link-mtu 1583,tun-mtu 1532,proto TCPv4_CLIENT,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-client'
TCP connection established with [AF_INET]CLIENT_PUBLIC_IP:62822
TCPv4_SERVER link local: (not bound)
TCPv4_SERVER link remote: [AF_INET]CLIENT_PUBLIC_IP:62822
CLIENT_PUBLIC_IP:62822 TLS: Initial packet from [AF_INET]CLIENT_PUBLIC_IP:62822, sid=75d82fb4 3f8f3c9f
CLIENT_PUBLIC_IP:62822 peer info: IV_VER=2.4.8
CLIENT_PUBLIC_IP:62822 peer info: IV_PLAT=win
CLIENT_PUBLIC_IP:62822 peer info: IV_PROTO=2
CLIENT_PUBLIC_IP:62822 peer info: IV_NCP=2
CLIENT_PUBLIC_IP:62822 peer info: IV_LZ4=1
CLIENT_PUBLIC_IP:62822 peer info: IV_LZ4v2=1
CLIENT_PUBLIC_IP:62822 peer info: IV_LZO=1
CLIENT_PUBLIC_IP:62822 peer info: IV_COMP_STUB=1
CLIENT_PUBLIC_IP:62822 peer info: IV_COMP_STUBv2=1
CLIENT_PUBLIC_IP:62822 peer info: IV_TCPNL=1
CLIENT_PUBLIC_IP:62822 peer info: IV_GUI_VER=OpenVPN_GUI_11
CLIENT_PUBLIC_IP:62822 TLS: Username/Password authentication deferred for username 'mysecretusername' [CN SET]
CLIENT_PUBLIC_IP:62822 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-ECDSA-AES256-GCM-SHA384
CLIENT_PUBLIC_IP:62822 [mysecretusername] Peer Connection Initiated with [AF_INET]CLIENT_PUBLIC_IP:62822
CLIENT_PUBLIC_IP:62822 PUSH: Received control message: 'PUSH_REQUEST'
MANAGEMENT: CMD 'client-auth-nt 0 0'
mysecretusername/CLIENT_PUBLIC_IP:62822 MULTI: no dynamic or static remote --ifconfig address is available for mysecretusername/CLIENT_PUBLIC_IP:62822
mysecretusername/CLIENT_PUBLIC_IP:62822 SENT CONTROL [mysecretusername]: 'PUSH_REPLY,route-gateway dhcp,route-gateway 10.14.12.1,route-gateway dhcp,peer-id 0,cipher AES-256-GCM,auth-token' (status=1)
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 Key [AF_INET]CLIENT_PUBLIC_IP:62822 [0] not initialized (yet), dropping packet.
mysecretusername/CLIENT_PUBLIC_IP:62822 NOTE: --mute triggered...
mysecretusername/CLIENT_PUBLIC_IP:62822 517 variation(s) on previous 20 message(s) suppressed by --mute
mysecretusername/CLIENT_PUBLIC_IP:62822 Connection reset, restarting [-1]
mysecretusername/CLIENT_PUBLIC_IP:62822 SIGUSR1[soft,connection-reset] received, client-instance restarting
TCP/UDP: Closing socket

Client log, when mgmt auth used:

Tue Mar 31 16:07:52 2020 us=952559 Current Parameter Settings:
Tue Mar 31 16:07:52 2020 us=954554   config = 'myserver-client.ovpn'
Tue Mar 31 16:07:52 2020 us=954554   mode = 0
Tue Mar 31 16:07:52 2020 us=954554   show_ciphers = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   show_digests = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   show_engines = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   genkey = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   key_pass_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   show_tls_ciphers = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   connect_retry_max = 0
Tue Mar 31 16:07:52 2020 us=954554 Connection profiles [0]:
Tue Mar 31 16:07:52 2020 us=954554   proto = tcp-client
Tue Mar 31 16:07:52 2020 us=954554   local = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   local_port = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   remote = 'SERVER_PUB_IP'
Tue Mar 31 16:07:52 2020 us=954554   remote_port = '443'
Tue Mar 31 16:07:52 2020 us=954554   remote_float = ENABLED
Tue Mar 31 16:07:52 2020 us=954554   bind_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   bind_local = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   bind_ipv6_only = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   connect_retry_seconds = 3
Tue Mar 31 16:07:52 2020 us=954554   connect_timeout = 120
Tue Mar 31 16:07:52 2020 us=954554   socks_proxy_server = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   socks_proxy_port = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   tun_mtu = 1500
Tue Mar 31 16:07:52 2020 us=954554   tun_mtu_defined = ENABLED
Tue Mar 31 16:07:52 2020 us=954554   link_mtu = 1500
Tue Mar 31 16:07:52 2020 us=954554   link_mtu_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   tun_mtu_extra = 32
Tue Mar 31 16:07:52 2020 us=954554   tun_mtu_extra_defined = ENABLED
Tue Mar 31 16:07:52 2020 us=954554   mtu_discover_type = -1
Tue Mar 31 16:07:52 2020 us=954554   fragment = 0
Tue Mar 31 16:07:52 2020 us=954554   mssfix = 1450
Tue Mar 31 16:07:52 2020 us=954554   explicit_exit_notification = 0
Tue Mar 31 16:07:52 2020 us=954554 Connection profiles END
Tue Mar 31 16:07:52 2020 us=954554   remote_random = DISABLED
Tue Mar 31 16:07:52 2020 us=954554   ipchange = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=954554   dev = 'tap'
Tue Mar 31 16:07:52 2020 us=955551   dev_type = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   dev_node = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   lladdr = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   topology = 1
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_local = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_remote_netmask = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_noexec = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_nowarn = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_ipv6_local = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_ipv6_netbits = 0
Tue Mar 31 16:07:52 2020 us=955551   ifconfig_ipv6_remote = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   shaper = 0
Tue Mar 31 16:07:52 2020 us=955551   mtu_test = 0
Tue Mar 31 16:07:52 2020 us=955551   mlock = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   keepalive_ping = 0
Tue Mar 31 16:07:52 2020 us=955551   keepalive_timeout = 0
Tue Mar 31 16:07:52 2020 us=955551   inactivity_timeout = 0
Tue Mar 31 16:07:52 2020 us=955551   ping_send_timeout = 0
Tue Mar 31 16:07:52 2020 us=955551   ping_rec_timeout = 0
Tue Mar 31 16:07:52 2020 us=955551   ping_rec_timeout_action = 0
Tue Mar 31 16:07:52 2020 us=955551   ping_timer_remote = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   remap_sigusr1 = 0
Tue Mar 31 16:07:52 2020 us=955551   persist_tun = ENABLED
Tue Mar 31 16:07:52 2020 us=955551   persist_local_ip = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   persist_remote_ip = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   persist_key = ENABLED
Tue Mar 31 16:07:52 2020 us=955551   passtos = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   resolve_retry_seconds = 1000000000
Tue Mar 31 16:07:52 2020 us=955551   resolve_in_advance = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   username = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   groupname = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   chroot_dir = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   cd_dir = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   writepid = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   up_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   down_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   down_pre = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   up_restart = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   up_delay = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   daemon = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   inetd = 0
Tue Mar 31 16:07:52 2020 us=955551   log = ENABLED
Tue Mar 31 16:07:52 2020 us=955551   suppress_timestamps = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   machine_readable_output = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   nice = 0
Tue Mar 31 16:07:52 2020 us=955551   verbosity = 4
Tue Mar 31 16:07:52 2020 us=955551   mute = 0
Tue Mar 31 16:07:52 2020 us=955551   gremlin = 0
Tue Mar 31 16:07:52 2020 us=955551   status_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   status_file_version = 1
Tue Mar 31 16:07:52 2020 us=955551   status_file_update_freq = 60
Tue Mar 31 16:07:52 2020 us=955551   occ = ENABLED
Tue Mar 31 16:07:52 2020 us=955551   rcvbuf = 0
Tue Mar 31 16:07:52 2020 us=955551   sndbuf = 0
Tue Mar 31 16:07:52 2020 us=955551   sockflags = 0
Tue Mar 31 16:07:52 2020 us=955551   fast_io = DISABLED
Tue Mar 31 16:07:52 2020 us=955551   comp.alg = 0
Tue Mar 31 16:07:52 2020 us=955551   comp.flags = 0
Tue Mar 31 16:07:52 2020 us=955551   route_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=955551   route_default_gateway = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   route_default_metric = 0
Tue Mar 31 16:07:52 2020 us=956548   route_noexec = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   route_delay = 5
Tue Mar 31 16:07:52 2020 us=956548   route_delay_window = 30
Tue Mar 31 16:07:52 2020 us=956548   route_delay_defined = ENABLED
Tue Mar 31 16:07:52 2020 us=956548   route_nopull = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   route_gateway_via_dhcp = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   allow_pull_fqdn = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   Pull filters:
Tue Mar 31 16:07:52 2020 us=956548     ignore "route-method"
Tue Mar 31 16:07:52 2020 us=956548   management_addr = '127.0.0.1'
Tue Mar 31 16:07:52 2020 us=956548   management_port = '25350'
Tue Mar 31 16:07:52 2020 us=956548   management_user_pass = 'stdin'
Tue Mar 31 16:07:52 2020 us=956548   management_log_history_cache = 250
Tue Mar 31 16:07:52 2020 us=956548   management_echo_buffer_size = 100
Tue Mar 31 16:07:52 2020 us=956548   management_write_peer_info_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   management_client_user = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   management_client_group = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   management_flags = 6
Tue Mar 31 16:07:52 2020 us=956548   shared_secret_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   key_direction = not set
Tue Mar 31 16:07:52 2020 us=956548   ciphername = 'AES-256-GCM'
Tue Mar 31 16:07:52 2020 us=956548   ncp_enabled = ENABLED
Tue Mar 31 16:07:52 2020 us=956548   ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Tue Mar 31 16:07:52 2020 us=956548   authname = 'SHA512'
Tue Mar 31 16:07:52 2020 us=956548   prng_hash = 'SHA1'
Tue Mar 31 16:07:52 2020 us=956548   prng_nonce_secret_len = 16
Tue Mar 31 16:07:52 2020 us=956548   keysize = 0
Tue Mar 31 16:07:52 2020 us=956548   engine = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   replay = ENABLED
Tue Mar 31 16:07:52 2020 us=956548   mute_replay_warnings = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   replay_window = 64
Tue Mar 31 16:07:52 2020 us=956548   replay_time = 15
Tue Mar 31 16:07:52 2020 us=956548   packet_id_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   use_iv = ENABLED
Tue Mar 31 16:07:52 2020 us=956548   test_crypto = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   tls_server = DISABLED
Tue Mar 31 16:07:52 2020 us=956548   tls_client = ENABLED
Tue Mar 31 16:07:52 2020 us=956548   key_method = 2
Tue Mar 31 16:07:52 2020 us=956548   ca_file = '[[INLINE]]'
Tue Mar 31 16:07:52 2020 us=956548   ca_path = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   dh_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   cert_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   extra_certs_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   priv_key_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   pkcs12_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   cryptoapi_cert = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   cipher_list = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   cipher_list_tls13 = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=956548   tls_cert_profile = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=957548   tls_verify = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=957548   tls_export_cert = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=957548   verify_x509_type = 1
Tue Mar 31 16:07:52 2020 us=957548   verify_x509_name = 'CN=myserver.server.com'
Tue Mar 31 16:07:52 2020 us=957548   crl_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=957548   ns_cert_type = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 65535
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_ku[i] = 0
Tue Mar 31 16:07:52 2020 us=957548   remote_cert_eku = 'TLS Web Server Authentication'
Tue Mar 31 16:07:52 2020 us=957548   ssl_flags = 0
Tue Mar 31 16:07:52 2020 us=957548   tls_timeout = 2
Tue Mar 31 16:07:52 2020 us=957548   renegotiate_bytes = -1
Tue Mar 31 16:07:52 2020 us=957548   renegotiate_packets = 0
Tue Mar 31 16:07:52 2020 us=957548   renegotiate_seconds = 3600
Tue Mar 31 16:07:52 2020 us=957548   handshake_window = 60
Tue Mar 31 16:07:52 2020 us=957548   transition_window = 3600
Tue Mar 31 16:07:52 2020 us=957548   single_session = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   push_peer_info = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   tls_exit = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   tls_auth_file = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=957548   tls_crypt_file = '[[INLINE]]'
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_protected_authentication = DISABLED
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=957548   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_private_mode = 00000000
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_cert_private = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_pin_cache_period = -1
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_id = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   pkcs11_id_management = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   server_network = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   server_netmask = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   server_network_ipv6 = ::
Tue Mar 31 16:07:52 2020 us=958542   server_netbits_ipv6 = 0
Tue Mar 31 16:07:52 2020 us=958542   server_bridge_ip = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   server_bridge_netmask = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   server_bridge_pool_start = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   server_bridge_pool_end = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_start = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_end = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_netmask = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_pool_persist_refresh_freq = 600
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_ipv6_pool_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_ipv6_pool_base = ::
Tue Mar 31 16:07:52 2020 us=958542   ifconfig_ipv6_pool_netbits = 0
Tue Mar 31 16:07:52 2020 us=958542   n_bcast_buf = 256
Tue Mar 31 16:07:52 2020 us=958542   tcp_queue_limit = 64
Tue Mar 31 16:07:52 2020 us=958542   real_hash_size = 256
Tue Mar 31 16:07:52 2020 us=958542   virtual_hash_size = 256
Tue Mar 31 16:07:52 2020 us=958542   client_connect_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   learn_address_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   client_disconnect_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   client_config_dir = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   ccd_exclusive = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   tmp_dir = 'C:\Users\viper\AppData\Local\Temp\'
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_local = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_remote_netmask = 0.0.0.0
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_ipv6_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_ipv6_local = ::/0
Tue Mar 31 16:07:52 2020 us=958542   push_ifconfig_ipv6_remote = ::
Tue Mar 31 16:07:52 2020 us=958542   enable_c2c = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   duplicate_cn = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   cf_max = 0
Tue Mar 31 16:07:52 2020 us=958542   cf_per = 0
Tue Mar 31 16:07:52 2020 us=958542   max_clients = 1024
Tue Mar 31 16:07:52 2020 us=958542   max_routes_per_client = 256
Tue Mar 31 16:07:52 2020 us=958542   auth_user_pass_verify_script = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=958542   auth_user_pass_verify_script_via_file = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   auth_token_generate = DISABLED
Tue Mar 31 16:07:52 2020 us=958542   auth_token_lifetime = 0
Tue Mar 31 16:07:52 2020 us=958542   client = ENABLED
Tue Mar 31 16:07:52 2020 us=958542   pull = ENABLED
Tue Mar 31 16:07:52 2020 us=958542   auth_user_pass_file = 'stdin'
Tue Mar 31 16:07:52 2020 us=958542   show_net_up = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   route_method = 3
Tue Mar 31 16:07:52 2020 us=959540   block_outside_dns = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   ip_win32_defined = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   ip_win32_type = 3
Tue Mar 31 16:07:52 2020 us=959540   dhcp_masq_offset = 0
Tue Mar 31 16:07:52 2020 us=959540   dhcp_lease_time = 31536000
Tue Mar 31 16:07:52 2020 us=959540   tap_sleep = 0
Tue Mar 31 16:07:52 2020 us=959540   dhcp_options = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   dhcp_renew = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   dhcp_pre_release = DISABLED
Tue Mar 31 16:07:52 2020 us=959540   domain = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=959540   netbios_scope = '[UNDEF]'
Tue Mar 31 16:07:52 2020 us=959540   netbios_node_type = 0
Tue Mar 31 16:07:52 2020 us=959540   disable_nbt = DISABLED
Tue Mar 31 16:07:52 2020 us=959540 OpenVPN 2.4.8 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Oct 31 2019
Tue Mar 31 16:07:52 2020 us=959540 Windows version 6.2 (Windows 8 or greater) 64bit
Tue Mar 31 16:07:52 2020 us=959540 library versions: OpenSSL 1.1.0l  10 Sep 2019, LZO 2.10
Enter Management Password:
Tue Mar 31 16:07:52 2020 us=960538 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25350
Tue Mar 31 16:07:52 2020 us=960538 Need hold release from management interface, waiting...
Tue Mar 31 16:07:53 2020 us=428372 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25350
Tue Mar 31 16:07:53 2020 us=530120 MANAGEMENT: CMD 'state on'
Tue Mar 31 16:07:53 2020 us=530120 MANAGEMENT: CMD 'log all on'
Tue Mar 31 16:07:53 2020 us=838273 MANAGEMENT: CMD 'echo all on'
Tue Mar 31 16:07:53 2020 us=841265 MANAGEMENT: CMD 'bytecount 5'
Tue Mar 31 16:07:53 2020 us=843259 MANAGEMENT: CMD 'hold off'
Tue Mar 31 16:07:53 2020 us=846253 MANAGEMENT: CMD 'hold release'
Tue Mar 31 16:08:08 2020 us=355189 MANAGEMENT: CMD 'username "Auth" "mysecretuser"'
Tue Mar 31 16:08:08 2020 us=376098 MANAGEMENT: CMD 'password [...]'
Tue Mar 31 16:08:08 2020 us=383079 Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Tue Mar 31 16:08:08 2020 us=383079 Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
Tue Mar 31 16:08:08 2020 us=383079 Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Tue Mar 31 16:08:08 2020 us=383079 Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
Tue Mar 31 16:08:08 2020 us=384077 Control Channel MTU parms [ L:1655 D:1154 EF:96 EB:0 ET:0 EL:3 ]
Tue Mar 31 16:08:08 2020 us=385074 Data Channel MTU parms [ L:1655 D:1450 EF:123 EB:411 ET:32 EL:3 ]
Tue Mar 31 16:08:08 2020 us=385074 Local Options String (VER=V4): 'V4,dev-type tap,link-mtu 1583,tun-mtu 1532,proto TCPv4_CLIENT,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-client'
Tue Mar 31 16:08:08 2020 us=385074 Expected Remote Options String (VER=V4): 'V4,dev-type tap,link-mtu 1583,tun-mtu 1532,proto TCPv4_SERVER,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-server'
Tue Mar 31 16:08:08 2020 us=385074 TCP/UDP: Preserving recently used remote address: [AF_INET]SERVER_PUB_IP:443
Tue Mar 31 16:08:08 2020 us=385074 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Mar 31 16:08:08 2020 us=385074 Attempting to establish TCP connection with [AF_INET]SERVER_PUB_IP:443 [nonblock]
Tue Mar 31 16:08:08 2020 us=385074 MANAGEMENT: >STATE:1585663688,TCP_CONNECT,,,,,,
Tue Mar 31 16:08:09 2020 us=386565 TCP connection established with [AF_INET]SERVER_PUB_IP:443
Tue Mar 31 16:08:09 2020 us=386565 TCP_CLIENT link local: (not bound)
Tue Mar 31 16:08:09 2020 us=386565 TCP_CLIENT link remote: [AF_INET]SERVER_PUB_IP:443
Tue Mar 31 16:08:09 2020 us=386565 MANAGEMENT: >STATE:1585663689,WAIT,,,,,,
Tue Mar 31 16:08:09 2020 us=402530 MANAGEMENT: >STATE:1585663689,AUTH,,,,,,
Tue Mar 31 16:08:09 2020 us=402530 TLS: Initial packet from [AF_INET]SERVER_PUB_IP:443, sid=eb87ba0b 781ab707
Tue Mar 31 16:08:09 2020 us=483314 VERIFY OK: depth=1, CN=MyServer CA
Tue Mar 31 16:08:09 2020 us=493324 VERIFY KU OK
Tue Mar 31 16:08:09 2020 us=493324 Validating certificate extended key usage
Tue Mar 31 16:08:09 2020 us=493324 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Tue Mar 31 16:08:09 2020 us=493324 VERIFY EKU OK
Tue Mar 31 16:08:09 2020 us=493324 VERIFY X509NAME OK: CN=myserver.server.com
Tue Mar 31 16:08:09 2020 us=493324 VERIFY OK: depth=0, CN=myserver.server.com
Tue Mar 31 16:08:09 2020 us=537160 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-ECDSA-AES256-GCM-SHA384, 521 bit EC, curve: secp521r1
Tue Mar 31 16:08:09 2020 us=537160 [myserver.server.com] Peer Connection Initiated with [AF_INET]SERVER_PUB_IP:443
Tue Mar 31 16:08:10 2020 us=795305 MANAGEMENT: >STATE:1585663690,GET_CONFIG,,,,,,
Tue Mar 31 16:08:10 2020 us=795305 SENT CONTROL [myserver.server.com]: 'PUSH_REQUEST' (status=1)
Tue Mar 31 16:08:11 2020 us=978072 PUSH: Received control message: 'PUSH_REPLY,route-gateway dhcp,route-gateway 10.14.12.1,route-gateway dhcp,peer-id 0,cipher AES-256-GCM,auth-token'
Tue Mar 31 16:08:11 2020 us=978996 OPTIONS IMPORT: route-related options modified
Tue Mar 31 16:08:11 2020 us=978996 OPTIONS IMPORT: peer-id set
Tue Mar 31 16:08:11 2020 us=978996 OPTIONS IMPORT: adjusting link_mtu to 1658
Tue Mar 31 16:08:11 2020 us=978996 OPTIONS IMPORT: data channel crypto options modified
Tue Mar 31 16:08:11 2020 us=978996 Data Channel MTU parms [ L:1586 D:1450 EF:54 EB:411 ET:32 EL:3 ]
Tue Mar 31 16:08:11 2020 us=978996 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Mar 31 16:08:11 2020 us=978996 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Mar 31 16:08:11 2020 us=978996 interactive service msg_channel=872
Tue Mar 31 16:08:11 2020 us=978996 open_tun
Tue Mar 31 16:08:11 2020 us=984977 CreateFile failed on TAP device: \\.\Global\{70C228D6-4779-4756-8D43-AAD5DC57C27E}.tap
Tue Mar 31 16:08:11 2020 us=984977 TAP-WIN32 device [Helyi kapcsolat 2] opened: \\.\Global\{187457AB-0255-441E-91A1-A2AC7C682B2F}.tap
Tue Mar 31 16:08:11 2020 us=985972 TAP-Windows Driver Version 9.24 
Tue Mar 31 16:08:11 2020 us=985972 TAP-Windows MTU=1500
Tue Mar 31 16:08:11 2020 us=990958 Successful ARP Flush on interface [53] {187457AB-0255-441E-91A1-A2AC7C682B2F}
Tue Mar 31 16:08:16 2020 us=82308 TEST ROUTES: 0/0 succeeded len=0 ret=1 a=0 u/d=up
Tue Mar 31 16:08:16 2020 us=82308 Initialization Sequence Completed
Tue Mar 31 16:08:16 2020 us=82308 MANAGEMENT: >STATE:1585663696,CONNECTED,SUCCESS,,SERVER_PUB_IP,443,192.168.0.54,62822
Tue Mar 31 16:08:39 2020 us=938311 TCP/UDP: Closing socket
Tue Mar 31 16:08:39 2020 us=938311 Closing TUN/TAP interface
Tue Mar 31 16:08:39 2020 us=943264 NOTE: Release of DHCP-assigned IP address lease on TAP-Windows adapter failed: Address is not assigned to an interface   (code=1228)
Tue Mar 31 16:08:39 2020 us=972186 SIGTERM[hard,] received, process exiting
Tue Mar 31 16:08:39 2020 us=972186 MANAGEMENT: >STATE:1585663719,EXITING,SIGTERM,,,,,

If PAM plugin is used, I see two more lines in client ('Extracted DHCP router address'):

Tue Mar 31 20:48:05 2020 us=851059 CreateFile failed on TAP device: \\.\Global\{70C228D6-4779-4756-8D43-AAD5DC57C27E}.tap
Tue Mar 31 20:48:05 2020 us=851059 TAP-WIN32 device [Helyi kapcsolat 2] opened: \\.\Global\{187457AB-0255-441E-91A1-A2AC7C682B2F}.tap
Tue Mar 31 20:48:05 2020 us=854051 TAP-Windows Driver Version 9.24 
Tue Mar 31 20:48:05 2020 us=854051 TAP-Windows MTU=1500
Tue Mar 31 20:48:05 2020 us=861034 Successful ARP Flush on interface [53] {187457AB-0255-441E-91A1-A2AC7C682B2F}
Tue Mar 31 20:48:07 2020 us=1936 Extracted DHCP router address: 100.114.12.1
Tue Mar 31 20:48:07 2020 us=1936 Extracted DHCP router address: 100.114.12.1
Tue Mar 31 20:48:10 2020 us=17651 TEST ROUTES: 0/0 succeeded len=0 ret=1 a=0 u/d=up
Tue Mar 31 20:48:10 2020 us=17651 Initialization Sequence Completed

What can be wrong? Should I return something beside 'client-auth-nt' from the auth script?

TinCanTech

V1pr wroteserver-bridge

It must be your network not working.

V1pr

TinCanTech wrote
V1pr wroteserver-bridge
It must be your network not working.

Definetly not. If I change the authentication method in the config, everything works (uncomment line starting with 'plugin', comment out line starting with 'management-client-auth').

It seems to me, that data channel is not established properly with client-manamgement-auth, but that's only a guess so far. I'll check the logs soon in verb 6.

V1pr

With higher server verbose, the log is full with messages like this:

mysecretuser/CLIENT_PUBLIC_IP:63808 TCPv4_SERVER READ [172] from [AF_INET]CLIENT_PUBLIC_IP:63808: P_DATA_V2 kid=0 DATA len=171
mysecretuser/CLIENT_PUBLIC_IP:63808 Key [AF_INET]CLIENT_PUBLIC_IP:63808 [0] not initialized (yet), dropping packet.
mysecretuser/CLIENT_PUBLIC_IP:63808 TCPv4_SERVER READ [347] from [AF_INET]CLIENT_PUBLIC_IP:63808: P_DATA_V2 kid=0 DATA len=346
mysecretuser/CLIENT_PUBLIC_IP:63808 Key [AF_INET]CLIENT_PUBLIC_IP:63808 [0] not initialized (yet), dropping packet.
mysecretuser/CLIENT_PUBLIC_IP:63808 TCPv4_SERVER READ [108] from [AF_INET]CLIENT_PUBLIC_IP:63808: P_DATA_V2 kid=0 DATA len=107
mysecretuser/CLIENT_PUBLIC_IP:63808 Key [AF_INET]CLIENT_PUBLIC_IP:63808 [0] not initialized (yet), dropping packet.

However, it seems that the client gets the parameters:

Wed Apr 01 15:13:15 2020 us=17924 SENT CONTROL [myserver.server.com]: 'PUSH_REQUEST' (status=1)
Wed Apr 01 15:13:16 2020 us=224155 PUSH: Received control message: 'PUSH_REPLY,echo,route-gateway dhcp,route-gateway dhcp,peer-id 0,cipher AES-256-GCM,auth-token'
Wed Apr 01 15:13:16 2020 us=225028 OPTIONS IMPORT: route-related options modified
Wed Apr 01 15:13:16 2020 us=225028 OPTIONS IMPORT: peer-id set
Wed Apr 01 15:13:16 2020 us=225028 OPTIONS IMPORT: adjusting link_mtu to 1658
Wed Apr 01 15:13:16 2020 us=225028 OPTIONS IMPORT: data channel crypto options modified
Wed Apr 01 15:13:16 2020 us=226023 Data Channel MTU parms [ L:1586 D:1450 EF:54 EB:411 ET:32 EL:3 ]
Wed Apr 01 15:13:16 2020 us=226023 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Apr 01 15:13:16 2020 us=226023 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Apr 01 15:13:16 2020 us=227019 interactive service msg_channel=704
Wed Apr 01 15:13:16 2020 us=227019 open_tun

Edit: with higher verbosity I see TLS warning at server side:

mysecretuser/CLIENT_PUBLIC_IP:63979 TLS Warning: no data channel send key available:  [key#0 state=S_ACTIVE id=0 sid=f1576b13 7324afbe] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
mysecretuser/CLIENT_PUBLIC_IP:63979 MULTI: C2C/MCAST/BCAST