Page 1 of 1

How can Incorrect Name/Pass/TOTP fail immediately?

Posted: Sun Jul 30, 2023 8:01 pm
by Snuffy2
In general, the OpenVPN server is working well and using auth-user-pass-verify with TOTP for 2FA. However, if the TOTP code isn't accepted (ex. the code changed), the client doesn't prompt for credentials again for a minute (until TLS handshake errors). Is there anyway to have the client receive a signal that the Username/Password/TOTP failed immediately and re-prompt the user again?

Server ovpn

mode server
server xx.yy.aa.0 255.255.255.0
port 1234
proto udp4
dev tun0
topology subnet
verb 3
mute 10
log-append '/var/log/openvpn.log'
status '/var/log/openvpn-status.log'
status-version 2
persist-key
persist-tun
user openvpn
group openvpn
ca '/etc/easy-rsa/pki/ca.crt'
cert '/etc/easy-rsa/pki/issued/server.crt'
dh '/etc/easy-rsa/pki/dh.pem'
key '/etc/easy-rsa/pki/private/server.key'
script-security 2
tmp-dir /dev/shm
auth-user-pass-verify /etc/config/ovpnauth/openvpn_otp_auth.py via-file
auth-gen-token 0 external-auth
reneg-sec 3600
keepalive 10 60
explicit-exit-notify
client-to-client
username-as-common-name
push "persist-key"
push "persist-tun"
push "topology subnet"
push "route xx.yy.bb.0 255.255.255.0"
push "dhcp-option DNS xx.yy.bb.1"
push "dhcp-option DOMAIN-SEARCH vpn"


Client ovpn

client
remote vpn.server.address 1234
proto udp4
dev tun
verb 3
nobind
persist-key
persist-tun
remote-cert-tls server
resolv-retry 5
connect-retry-max 5
explicit-exit-notify
auth-user-pass
auth-nocache
auth-retry interact
static-challenge "Enter Authentication Code (TOTP)" 1
<key>
-----BEGIN PRIVATE KEY-----
-----END PRIVATE KEY-----
</key>
<cert>
-----BEGIN CERTIFICATE-----
-----END CERTIFICATE-----
</cert>
<ca>
-----BEGIN CERTIFICATE-----
-----END CERTIFICATE-----
</ca>


Tunnelblick Client log

2023-07-30 15:25:21.599968 *Tunnelblick: macOS 13.4.1 (22F770820d); Tunnelblick 4.0.0beta06 (build 5860); prior version 3.8.8a (build 5776)
2023-07-30 15:25:22.208028 *Tunnelblick: Cannot recognize the vpnserver-loadTap preference value of '(null)', so Tunnelblick will not load the tap kext
2023-07-30 15:25:22.226361 *Tunnelblick: Attempting connection with vpnserver using shadow copy; Set nameserver = 0x00000401; monitoring connection
2023-07-30 15:25:22.228001 *Tunnelblick: openvpnstart start vpnserver.tblk 64575 0x00000401 0 1 0 0x0210c1b0 -ptADGNWradsgnw 2.6.4-openssl-3.0.9 <password>
2023-07-30 15:25:22.260733 *Tunnelblick: openvpnstart starting OpenVPN
2023-07-30 15:25:23.025934 Note: --cipher is not set. OpenVPN versions before 2.5 defaulted to BF-CBC as fallback when cipher negotiation failed in this case. If you need this fallback please add '--data-ciphers-fallback BF-CBC' to your configuration and/or add BF-CBC to --data-ciphers.
2023-07-30 15:25:23.026481 Current Parameter Settings:
2023-07-30 15:25:23.026512 config = '/Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources/config.ovpn'
2023-07-30 15:25:23.026528 mode = 0
2023-07-30 15:25:23.026542 show_ciphers = DISABLED
2023-07-30 15:25:23.026555 show_digests = DISABLED
2023-07-30 15:25:23.026568 show_engines = DISABLED
2023-07-30 15:25:23.026582 genkey = DISABLED
2023-07-30 15:25:23.026595 genkey_filename = '[UNDEF]'
2023-07-30 15:25:23.026607 key_pass_file = '[UNDEF]'
2023-07-30 15:25:23.026620 show_tls_ciphers = DISABLED
2023-07-30 15:25:23.026633 connect_retry_max = 5
2023-07-30 15:25:23.026646 Connection profiles [0]:
2023-07-30 15:25:23.026660 proto = udp4
2023-07-30 15:25:23.026674 local = '[UNDEF]'
2023-07-30 15:25:23.026686 local_port = '[UNDEF]'
2023-07-30 15:25:23.026699 remote = 'vpn.server.address'
2023-07-30 15:25:23.026713 remote_port = '1234'
2023-07-30 15:25:23.026726 remote_float = DISABLED
2023-07-30 15:25:23.026739 bind_defined = DISABLED
2023-07-30 15:25:23.026752 bind_local = DISABLED
2023-07-30 15:25:23.026765 bind_ipv6_only = DISABLED
2023-07-30 15:25:23.026778 connect_retry_seconds = 1
2023-07-30 15:25:23.026791 connect_timeout = 120
2023-07-30 15:25:23.026811 xormethod = 0
2023-07-30 15:25:23.026825 xormask = ''
2023-07-30 15:25:23.026837 xormasklen = 0
2023-07-30 15:25:23.026850 socks_proxy_server = '[UNDEF]'
2023-07-30 15:25:23.026864 socks_proxy_port = '[UNDEF]'
2023-07-30 15:25:23.026877 tun_mtu = 1500
2023-07-30 15:25:23.026895 tun_mtu_defined = ENABLED
2023-07-30 15:25:23.026909 link_mtu = 1500
2023-07-30 15:25:23.026922 link_mtu_defined = DISABLED
2023-07-30 15:25:23.026935 tun_mtu_extra = 0
2023-07-30 15:25:23.026948 tun_mtu_extra_defined = DISABLED
2023-07-30 15:25:23.026961 tls_mtu = 1250
2023-07-30 15:25:23.026974 mtu_discover_type = -1
2023-07-30 15:25:23.026987 fragment = 0
2023-07-30 15:25:23.027000 mssfix = 1492
2023-07-30 15:25:23.027013 mssfix_encap = ENABLED
2023-07-30 15:25:23.027026 mssfix_fixed = DISABLED
2023-07-30 15:25:23.027039 explicit_exit_notification = 1
2023-07-30 15:25:23.027051 tls_auth_file = '[UNDEF]'
2023-07-30 15:25:23.027106 key_direction = not set
2023-07-30 15:25:23.027119 tls_crypt_file = '[UNDEF]'
2023-07-30 15:25:23.027133 tls_crypt_v2_file = '[UNDEF]'
2023-07-30 15:25:23.027145 Connection profiles END
2023-07-30 15:25:23.027158 remote_random = DISABLED
2023-07-30 15:25:23.027171 ipchange = '[UNDEF]'
2023-07-30 15:25:23.027184 dev = 'tun'
2023-07-30 15:25:23.027197 dev_type = '[UNDEF]'
2023-07-30 15:25:23.027210 dev_node = '[UNDEF]'
2023-07-30 15:25:23.027223 lladdr = '[UNDEF]'
2023-07-30 15:25:23.027236 topology = 1
2023-07-30 15:25:23.027249 ifconfig_local = '[UNDEF]'
2023-07-30 15:25:23.027262 ifconfig_remote_netmask = '[UNDEF]'
2023-07-30 15:25:23.027274 ifconfig_noexec = DISABLED
2023-07-30 15:25:23.027287 ifconfig_nowarn = DISABLED
2023-07-30 15:25:23.027300 ifconfig_ipv6_local = '[UNDEF]'
2023-07-30 15:25:23.027313 ifconfig_ipv6_netbits = 0
2023-07-30 15:25:23.027326 ifconfig_ipv6_remote = '[UNDEF]'
2023-07-30 15:25:23.027339 shaper = 0
2023-07-30 15:25:23.027351 mtu_test = 0
2023-07-30 15:25:23.027364 mlock = DISABLED
2023-07-30 15:25:23.027418 keepalive_ping = 0
2023-07-30 15:25:23.027431 keepalive_timeout = 0
2023-07-30 15:25:23.027444 inactivity_timeout = 0
2023-07-30 15:25:23.027457 session_timeout = 0
2023-07-30 15:25:23.027470 inactivity_minimum_bytes = 0
2023-07-30 15:25:23.027483 ping_send_timeout = 0
2023-07-30 15:25:23.027495 ping_rec_timeout = 0
2023-07-30 15:25:23.027508 ping_rec_timeout_action = 0
2023-07-30 15:25:23.027521 ping_timer_remote = DISABLED
2023-07-30 15:25:23.027534 remap_sigusr1 = 0
2023-07-30 15:25:23.027568 persist_tun = ENABLED
2023-07-30 15:25:23.027578 persist_local_ip = DISABLED
2023-07-30 15:25:23.027588 persist_remote_ip = DISABLED
2023-07-30 15:25:23.027597 persist_key = ENABLED
2023-07-30 15:25:23.027606 passtos = DISABLED
2023-07-30 15:25:23.027616 resolve_retry_seconds = 5
2023-07-30 15:25:23.027625 resolve_in_advance = DISABLED
2023-07-30 15:25:23.027634 username = '[UNDEF]'
2023-07-30 15:25:23.027643 groupname = '[UNDEF]'
2023-07-30 15:25:23.027653 chroot_dir = '[UNDEF]'
2023-07-30 15:25:23.027663 cd_dir = '/Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources'
2023-07-30 15:25:23.027672 writepid = '[UNDEF]'
2023-07-30 15:25:23.027681 up_script = '[UNDEF]'
2023-07-30 15:25:23.027691 down_script = '/Applications/Tunnelblick.app/Contents/Resources/client.down.tunnelblick.sh -9 -d -f -m -p -w -ptADGNWradsgnw'
2023-07-30 15:25:23.027700 down_pre = DISABLED
2023-07-30 15:25:23.027710 up_restart = DISABLED
2023-07-30 15:25:23.027719 up_delay = DISABLED
2023-07-30 15:25:23.027728 daemon = ENABLED
2023-07-30 15:25:23.027737 log = ENABLED
2023-07-30 15:25:23.027747 suppress_timestamps = DISABLED
2023-07-30 15:25:23.027756 machine_readable_output = ENABLED
2023-07-30 15:25:23.027766 nice = 0
2023-07-30 15:25:23.027775 verbosity = 4
2023-07-30 15:25:23.027784 mute = 0
2023-07-30 15:25:23.027794 status_file = '[UNDEF]'
2023-07-30 15:25:23.027803 status_file_version = 1
2023-07-30 15:25:23.027814 status_file_update_freq = 60
2023-07-30 15:25:23.027824 occ = ENABLED
2023-07-30 15:25:23.027833 rcvbuf = 0
2023-07-30 15:25:23.027842 sndbuf = 0
2023-07-30 15:25:23.027852 sockflags = 0
2023-07-30 15:25:23.027861 fast_io = DISABLED
2023-07-30 15:25:23.027871 comp.alg = 0
2023-07-30 15:25:23.027880 comp.flags = 24
2023-07-30 15:25:23.027890 route_script = '/Applications/Tunnelblick.app/Contents/Resources/client.up.tunnelblick.sh -9 -d -f -m -p -w -ptADGNWradsgnw'
2023-07-30 15:25:23.027899 route_default_gateway = '[UNDEF]'
2023-07-30 15:25:23.027909 route_default_metric = 0
2023-07-30 15:25:23.027918 route_noexec = DISABLED
2023-07-30 15:25:23.027928 route_delay = 0
2023-07-30 15:25:23.027937 route_delay_window = 30
2023-07-30 15:25:23.027947 route_delay_defined = DISABLED
2023-07-30 15:25:23.027956 route_nopull = DISABLED
2023-07-30 15:25:23.027966 route_gateway_via_dhcp = DISABLED
2023-07-30 15:25:23.027975 allow_pull_fqdn = DISABLED
2023-07-30 15:25:23.027985 management_addr = '127.0.0.1'
2023-07-30 15:25:23.027994 management_port = '64575'
2023-07-30 15:25:23.028004 management_user_pass = '/Library/Application Support/Tunnelblick/Mips/vpnserver.tblk.mip'
2023-07-30 15:25:23.028055 management_log_history_cache = 250
2023-07-30 15:25:23.028065 management_echo_buffer_size = 100
2023-07-30 15:25:23.028074 management_client_user = '[UNDEF]'
2023-07-30 15:25:23.028084 management_client_group = '[UNDEF]'
2023-07-30 15:25:23.028093 management_flags = 6
2023-07-30 15:25:23.028103 shared_secret_file = '[UNDEF]'
2023-07-30 15:25:23.028117 key_direction = not set
2023-07-30 15:25:23.028127 ciphername = 'BF-CBC'
2023-07-30 15:25:23.028137 ncp_ciphers = 'AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305'
2023-07-30 15:25:23.028203 authname = 'SHA1'
2023-07-30 15:25:23.028325 engine = DISABLED
2023-07-30 15:25:23.028341 replay = ENABLED
2023-07-30 15:25:23.028351 mute_replay_warnings = DISABLED
2023-07-30 15:25:23.028360 replay_window = 64
2023-07-30 15:25:23.028370 replay_time = 15
2023-07-30 15:25:23.028379 packet_id_file = '[UNDEF]'
2023-07-30 15:25:23.028389 test_crypto = DISABLED
2023-07-30 15:25:23.028398 tls_server = DISABLED
2023-07-30 15:25:23.028408 tls_client = ENABLED
2023-07-30 15:25:23.028417 ca_file = '[INLINE]'
2023-07-30 15:25:23.028427 ca_path = '[UNDEF]'
2023-07-30 15:25:23.028436 dh_file = '[UNDEF]'
2023-07-30 15:25:23.028446 cert_file = '[INLINE]'
2023-07-30 15:25:23.028455 extra_certs_file = '[UNDEF]'
2023-07-30 15:25:23.028483 priv_key_file = '[INLINE]'
2023-07-30 15:25:23.028493 pkcs12_file = '[UNDEF]'
2023-07-30 15:25:23.028503 cipher_list = '[UNDEF]'
2023-07-30 15:25:23.028512 cipher_list_tls13 = '[UNDEF]'
2023-07-30 15:25:23.028522 tls_cert_profile = '[UNDEF]'
2023-07-30 15:25:23.028531 tls_verify = '[UNDEF]'
2023-07-30 15:25:23.028541 tls_export_cert = '[UNDEF]'
2023-07-30 15:25:23.028550 verify_x509_type = 0
2023-07-30 15:25:23.028560 verify_x509_name = '[UNDEF]'
2023-07-30 15:25:23.028569 crl_file = '[UNDEF]'
2023-07-30 15:25:23.028579 ns_cert_type = 0
2023-07-30 15:25:23.028588 remote_cert_ku = 65535
2023-07-30 15:25:23.028598 remote_cert_ku = 0
2023-07-30 15:25:23.028607 remote_cert_ku = 0
2023-07-30 15:25:23.028616 remote_cert_ku = 0
2023-07-30 15:25:23.028625 remote_cert_ku = 0
2023-07-30 15:25:23.028635 remote_cert_ku = 0
2023-07-30 15:25:23.028644 remote_cert_ku = 0
2023-07-30 15:25:23.028653 remote_cert_ku = 0
2023-07-30 15:25:23.028663 remote_cert_ku = 0
2023-07-30 15:25:23.028672 remote_cert_ku = 0
2023-07-30 15:25:23.028682 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028691 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028700 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028709 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028719 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028728 remote_cert_ku[i] = 0
2023-07-30 15:25:23.028738 remote_cert_eku = 'TLS Web Server Authentication'
2023-07-30 15:25:23.028748 ssl_flags = 192
2023-07-30 15:25:23.028757 tls_timeout = 2
2023-07-30 15:25:23.028767 renegotiate_bytes = -1
2023-07-30 15:25:23.028776 renegotiate_packets = 0
2023-07-30 15:25:23.028786 renegotiate_seconds = 3600
2023-07-30 15:25:23.028796 handshake_window = 60
2023-07-30 15:25:23.028812 transition_window = 3600
2023-07-30 15:25:23.028821 single_session = DISABLED
2023-07-30 15:25:23.028831 push_peer_info = DISABLED
2023-07-30 15:25:23.028840 tls_exit = DISABLED
2023-07-30 15:25:23.028850 tls_crypt_v2_metadata = '[UNDEF]'
2023-07-30 15:25:23.028906 server_network = 0.0.0.0
2023-07-30 15:25:23.028917 server_netmask = 0.0.0.0
2023-07-30 15:25:23.028928 server_network_ipv6 = ::
2023-07-30 15:25:23.028937 server_netbits_ipv6 = 0
2023-07-30 15:25:23.028948 server_bridge_ip = 0.0.0.0
2023-07-30 15:25:23.028959 server_bridge_netmask = 0.0.0.0
2023-07-30 15:25:23.028970 server_bridge_pool_start = 0.0.0.0
2023-07-30 15:25:23.028980 server_bridge_pool_end = 0.0.0.0
2023-07-30 15:25:23.028990 ifconfig_pool_defined = DISABLED
2023-07-30 15:25:23.029000 ifconfig_pool_start = 0.0.0.0
2023-07-30 15:25:23.029011 ifconfig_pool_end = 0.0.0.0
2023-07-30 15:25:23.029021 ifconfig_pool_netmask = 0.0.0.0
2023-07-30 15:25:23.029031 ifconfig_pool_persist_filename = '[UNDEF]'
2023-07-30 15:25:23.029041 ifconfig_pool_persist_refresh_freq = 600
2023-07-30 15:25:23.029050 ifconfig_ipv6_pool_defined = DISABLED
2023-07-30 15:25:23.029060 ifconfig_ipv6_pool_base = ::
2023-07-30 15:25:23.029070 ifconfig_ipv6_pool_netbits = 0
2023-07-30 15:25:23.029079 n_bcast_buf = 256
2023-07-30 15:25:23.029089 tcp_queue_limit = 64
2023-07-30 15:25:23.029099 real_hash_size = 256
2023-07-30 15:25:23.029108 virtual_hash_size = 256
2023-07-30 15:25:23.029118 client_connect_script = '[UNDEF]'
2023-07-30 15:25:23.029127 learn_address_script = '[UNDEF]'
2023-07-30 15:25:23.029137 client_disconnect_script = '[UNDEF]'
2023-07-30 15:25:23.029146 client_crresponse_script = '[UNDEF]'
2023-07-30 15:25:23.029155 client_config_dir = '[UNDEF]'
2023-07-30 15:25:23.029165 ccd_exclusive = DISABLED
2023-07-30 15:25:23.029175 tmp_dir = '/var/folders/23/9pdnvfm91v1_g6092xvkpd8m0000gn/T/'
2023-07-30 15:25:23.029184 push_ifconfig_defined = DISABLED
2023-07-30 15:25:23.029195 push_ifconfig_local = 0.0.0.0
2023-07-30 15:25:23.029205 push_ifconfig_remote_netmask = 0.0.0.0
2023-07-30 15:25:23.029215 push_ifconfig_ipv6_defined = DISABLED
2023-07-30 15:25:23.029225 push_ifconfig_ipv6_local = ::/0
2023-07-30 15:25:23.029252 push_ifconfig_ipv6_remote = ::
2023-07-30 15:25:23.029261 enable_c2c = DISABLED
2023-07-30 15:25:23.029271 duplicate_cn = DISABLED
2023-07-30 15:25:23.029281 cf_max = 0
2023-07-30 15:25:23.029291 cf_per = 0
2023-07-30 15:25:23.029300 cf_initial_max = 100
2023-07-30 15:25:23.029310 cf_initial_per = 10
2023-07-30 15:25:23.029320 max_clients = 1024
2023-07-30 15:25:23.029329 max_routes_per_client = 256
2023-07-30 15:25:23.029339 auth_user_pass_verify_script = '[UNDEF]'
2023-07-30 15:25:23.029348 auth_user_pass_verify_script_via_file = DISABLED
2023-07-30 15:25:23.029358 auth_token_generate = DISABLED
2023-07-30 15:25:23.029367 auth_token_lifetime = 0
2023-07-30 15:25:23.029377 auth_token_secret_file = '[UNDEF]'
2023-07-30 15:25:23.029387 port_share_host = '[UNDEF]'
2023-07-30 15:25:23.029396 port_share_port = '[UNDEF]'
2023-07-30 15:25:23.029406 vlan_tagging = DISABLED
2023-07-30 15:25:23.029416 vlan_accept = all
2023-07-30 15:25:23.029425 vlan_pvid = 1
2023-07-30 15:25:23.029435 client = ENABLED
2023-07-30 15:25:23.029444 pull = ENABLED
2023-07-30 15:25:23.029454 auth_user_pass_file = 'stdin'
2023-07-30 15:25:23.029465 OpenVPN 2.6.4 x86_64-apple-darwin [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD]
2023-07-30 15:25:23.029601 library versions: OpenSSL 3.0.9 30 May 2023, LZO 2.10
2023-07-30 15:25:23.032442 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:64575
2023-07-30 15:25:23.032493 Need hold release from management interface, waiting...
2023-07-30 15:25:23.492666 *Tunnelblick: openvpnstart log:
OpenVPN started successfully.
Command used to start OpenVPN (one argument per displayed line):
/Applications/Tunnelblick.app/Contents/Resources/openvpn/openvpn-2.6.4-openssl-3.0.9/openvpn
--daemon
--log-append /Library/Application Support/Tunnelblick/Logs/-SUsers-Ssnuffy2-SLibrary-SApplication Support-STunnelblick-SConfigurations-Svpnserver.tblk-SContents-SResources-Sconfig.ovpn.1025_0_1_0_34652592.64575.openvpn.log
--cd /Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources
--machine-readable-output
--setenv IV_GUI_VER "net.tunnelblick.tunnelblick 5860 4.0.0beta06 (build 5860)"
--verb 4
--config /Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources/config.ovpn
--setenv TUNNELBLICK_CONFIG_FOLDER /Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources
--verb 4
--cd /Library/Application Support/Tunnelblick/Users/snuffy2/vpnserver.tblk/Contents/Resources
--management 127.0.0.1 64575 /Library/Application Support/Tunnelblick/Mips/vpnserver.tblk.mip
--management-query-passwords
--management-hold
--script-security 2
--route-up /Applications/Tunnelblick.app/Contents/Resources/client.up.tunnelblick.sh -9 -d -f -m -p -w -ptADGNWradsgnw
--down /Applications/Tunnelblick.app/Contents/Resources/client.down.tunnelblick.sh -9 -d -f -m -p -w -ptADGNWradsgnw
2023-07-30 15:25:23.509495 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:57004
2023-07-30 15:25:23.571469 *Tunnelblick: Established communication with OpenVPN
2023-07-30 15:25:23.572489 MANAGEMENT: CMD 'pid'
2023-07-30 15:25:23.572669 MANAGEMENT: CMD 'state on'
2023-07-30 15:25:23.572808 MANAGEMENT: CMD 'state'
2023-07-30 15:25:23.572900 MANAGEMENT: CMD 'bytecount 1'
2023-07-30 15:25:23.600097 *Tunnelblick: >INFO:OpenVPN Management Interface Version 5 -- type 'help' for more info
2023-07-30 15:25:23.602567 MANAGEMENT: CMD 'hold release'
2023-07-30 15:25:23.609449 *Tunnelblick: Obtained VPN username and password from the Keychain
2023-07-30 15:25:29.136570 *Tunnelblick: User responded to static challenge: 'Enter Authentication Code (TOTP)'
2023-07-30 15:25:29.138638 MANAGEMENT: CMD 'username "Auth" "snuffy2"'
2023-07-30 15:25:29.140402 MANAGEMENT: CMD 'password [...]'
2023-07-30 15:25:29.140736 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2023-07-30 15:25:29.165280 Control Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1250 tun_max_mtu:0 headroom:126 payload:1600 tailroom:126 ET:0 ]
2023-07-30 15:25:29.165439 MANAGEMENT: >STATE:1690745129,RESOLVE,,,,,,
2023-07-30 15:25:29.278076 Data Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1500 tun_max_mtu:1600 headroom:136 payload:1768 tailroom:562 ET:0 ]
2023-07-30 15:25:29.278404 TCP/UDP: Preserving recently used remote address: [AF_INET]ss.dd.ff.gg:1234
2023-07-30 15:25:29.278476 Socket Buffers: R=[786896->786896] S=[9216->9216]
2023-07-30 15:25:29.278492 UDPv4 link local: (not bound)
2023-07-30 15:25:29.278505 UDPv4 link remote: [AF_INET]ss.dd.ff.gg:1234
2023-07-30 15:25:29.278773 MANAGEMENT: >STATE:1690745129,WAIT,,,,,,
2023-07-30 15:25:29.302547 MANAGEMENT: >STATE:1690745129,AUTH,,,,,,
2023-07-30 15:25:29.302668 TLS: Initial packet from [AF_INET]ss.dd.ff.gg:1234, sid=bcf83b42 7e64dfc9
2023-07-30 15:25:29.348769 VERIFY OK: depth=1, CN=ovpnca
2023-07-30 15:25:29.349324 VERIFY KU OK
2023-07-30 15:25:29.349339 Validating certificate extended key usage
2023-07-30 15:25:29.349346 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2023-07-30 15:25:29.349352 VERIFY EKU OK
2023-07-30 15:25:29.349357 VERIFY OK: depth=0, CN=server
2023-07-30 15:26:30.145894 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
2023-07-30 15:26:30.146068 TLS Error: TLS handshake failed
2023-07-30 15:26:30.148772 TCP/UDP: Closing socket
2023-07-30 15:26:30.149799 SIGUSR1[soft,tls-error] received, process restarting
2023-07-30 15:26:30.149903 MANAGEMENT: >STATE:1690745190,RECONNECTING,tls-error,,,,,
2023-07-30 15:26:30.455505 MANAGEMENT: CMD 'hold release'
2023-07-30 15:26:30.459917 MANAGEMENT: CMD 'hold release'
2023-07-30 15:26:30.471502 *Tunnelblick: Obtained VPN username and password from the Keychain
2023-07-30 15:26:40.446136 *Tunnelblick: User responded to static challenge: 'Enter Authentication Code (TOTP)'
2023-07-30 15:26:40.447868 MANAGEMENT: CMD 'username "Auth" "snuffy2"'
2023-07-30 15:26:40.449279 MANAGEMENT: CMD 'password [...]'
2023-07-30 15:26:40.449419 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2023-07-30 15:26:40.449468 Re-using SSL/TLS context
2023-07-30 15:26:40.449697 Control Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1250 tun_max_mtu:0 headroom:126 payload:1600 tailroom:126 ET:0 ]
2023-07-30 15:26:40.449740 MANAGEMENT: >STATE:1690745200,RESOLVE,,,,,,
2023-07-30 15:26:40.451363 Data Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1500 tun_max_mtu:1600 headroom:136 payload:1768 tailroom:562 ET:0 ]
2023-07-30 15:26:40.451534 TCP/UDP: Preserving recently used remote address: [AF_INET]ss.dd.ff.gg:1234
2023-07-30 15:26:40.451634 Socket Buffers: R=[786896->786896] S=[9216->9216]
2023-07-30 15:26:40.451663 UDPv4 link local: (not bound)
2023-07-30 15:26:40.451689 UDPv4 link remote: [AF_INET]ss.dd.ff.gg:1234
2023-07-30 15:26:40.451839 MANAGEMENT: >STATE:1690745200,WAIT,,,,,,
2023-07-30 15:26:40.473190 MANAGEMENT: >STATE:1690745200,AUTH,,,,,,
2023-07-30 15:26:40.473309 TLS: Initial packet from [AF_INET]ss.dd.ff.gg:1234, sid=503b6e72 4ab45626
2023-07-30 15:26:40.511947 VERIFY OK: depth=1, CN=ovpnca
2023-07-30 15:26:40.512180 VERIFY KU OK
2023-07-30 15:26:40.512193 Validating certificate extended key usage
2023-07-30 15:26:40.512201 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2023-07-30 15:26:40.512207 VERIFY EKU OK
2023-07-30 15:26:40.512213 VERIFY OK: depth=0, CN=server
2023-07-30 15:26:41.079986 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256
2023-07-30 15:26:41.080113 [server] Peer Connection Initiated with [AF_INET]ss.dd.ff.gg:1234
2023-07-30 15:26:41.080176 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
2023-07-30 15:26:41.080397 TLS: tls_multi_process: initial untrusted session promoted to trusted
2023-07-30 15:26:41.097241 PUSH: Received control message: 'PUSH_REPLY,persist-key,persist-tun,topology subnet,route xx.yy.bb.0 255.255.255.0,dhcp-option DNS xx.yy.bb.1,dhcp-option DOMAIN-SEARCH vpn,route-gateway xx.yy.aa.1,topology subnet,ping 10,ping-restart 60,ifconfig xx.yy.aa.2 255.255.255.0,peer-id 0,auth-tokenSESS_ID,cipher AES-256-GCM'
2023-07-30 15:26:41.097630 OPTIONS IMPORT: --persist options modified
2023-07-30 15:26:41.097697 OPTIONS IMPORT: --ifconfig/up options modified
2023-07-30 15:26:41.097717 OPTIONS IMPORT: route options modified
2023-07-30 15:26:41.097733 OPTIONS IMPORT: route-related options modified
2023-07-30 15:26:41.097749 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
2023-07-30 15:26:41.100928 Opened utun device utun7
2023-07-30 15:26:41.100981 do_ifconfig, ipv4=1, ipv6=0
2023-07-30 15:26:41.101043 MANAGEMENT: >STATE:1690745201,ASSIGN_IP,,xx.yy.aa.2,,,,
2023-07-30 15:26:41.101084 /sbin/ifconfig utun7 delete
ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address
2023-07-30 15:26:41.118004 NOTE: Tried to delete pre-existing tun/tap instance -- No Problem if failure
2023-07-30 15:26:41.118074 /sbin/ifconfig utun7 xx.yy.aa.2 xx.yy.aa.2 netmask 255.255.255.0 mtu 1500 up
2023-07-30 15:26:41.124813 /sbin/route add -net xx.yy.aa.0 xx.yy.aa.2 255.255.255.0
add net xx.yy.aa.0: gateway xx.yy.aa.2
2023-07-30 15:26:41.136037 MANAGEMENT: >STATE:1690745201,ADD_ROUTES,,,,,,
2023-07-30 15:26:41.136104 /sbin/route add -net xx.yy.bb.0 xx.yy.aa.1 255.255.255.0
add net xx.yy.bb.0: gateway xx.yy.aa.1
15:26:41 *Tunnelblick: **********************************************
15:26:41 *Tunnelblick: Start of output from client.up.tunnelblick.sh
15:26:44 *Tunnelblick: Disabled IPv6 for 'USB 10/100/1000 LAN 2'
15:26:44 *Tunnelblick: Disabled IPv6 for 'Wi-Fi'
15:26:44 *Tunnelblick: Disabled IPv6 for 'Thunderbolt Bridge'
15:26:44 *Tunnelblick: Retrieved from OpenVPN: name server(s) [ xx.yy.bb.1 ], search domain(s) [ vpn ] and SMB server(s) [ ] and using default domain name [ openvpn ]
15:26:44 *Tunnelblick: Not aggregating ServerAddresses because running on macOS 10.6 or higher
15:26:44 *Tunnelblick: Prepending 'vpn' to search domains 'home' because the search domains were not set manually (or are allowed to be changed) and 'Prepend domain name to search domains' was selected
15:26:44 *Tunnelblick: Prepending 'openvpn' to search domains 'vpn home' because the search domains were not set manually (or are allowed to be changed) and 'Prepend domain name to search domains' was selected
15:26:46 *Tunnelblick: Saved the DNS and SMB configurations so they can be restored
15:26:46 *Tunnelblick: Changed DNS ServerAddresses setting from 'jj.kk.ll.1' to 'xx.yy.bb.1'
15:26:46 *Tunnelblick: Changed DNS SearchDomains setting from 'home' to 'openvpn vpn home'
15:26:46 *Tunnelblick: Changed DNS DomainName setting from '' to 'openvpn'
15:26:46 *Tunnelblick: Did not change SMB NetBIOSName setting of ''
15:26:46 *Tunnelblick: Did not change SMB Workgroup setting of ''
15:26:46 *Tunnelblick: Did not change SMB WINSAddresses setting of ''
15:26:46 *Tunnelblick: DNS servers 'xx.yy.bb.1' will be used for DNS queries when the VPN is active
15:26:46 *Tunnelblick: NOTE: The DNS servers do not include any free public DNS servers known to Tunnelblick. This may cause DNS queries to fail or be intercepted or falsified even if they are directed through the VPN. Specify only known public DNS servers or DNS servers located on the VPN network to avoid such problems.
15:26:46 *Tunnelblick: Flushed the DNS cache via dscacheutil
15:26:46 *Tunnelblick: /usr/sbin/discoveryutil not present. Not flushing the DNS cache via discoveryutil
15:26:46 *Tunnelblick: Notified mDNSResponder that the DNS cache was flushed
15:26:46 *Tunnelblick: Not notifying mDNSResponderHelper that the DNS cache was flushed because it is not running
15:26:46 *Tunnelblick: Setting up to monitor system configuration with process-network-changes
15:26:46 *Tunnelblick: End of output from client.up.tunnelblick.sh
15:26:46 *Tunnelblick: **********************************************
2023-07-30 15:26:46.924175 Data Channel MTU parms [ mss_fix:1400 max_frag:0 tun_mtu:1500 tun_max_mtu:1600 headroom:136 payload:1768 tailroom:562 ET:0 ]
2023-07-30 15:26:46.927877 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-07-30 15:26:46.927942 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-07-30 15:26:46.927979 Initialization Sequence Completed
2023-07-30 15:26:46.928028 MANAGEMENT: >STATE:1690745206,CONNECTED,SUCCESS,xx.yy.aa.2,ss.dd.ff.gg,1234,,
2023-07-30 15:26:46.928061 Data Channel: cipher 'AES-256-GCM', peer-id: 0
2023-07-30 15:26:46.928085 Timers: ping 10, ping-restart 60
2023-07-30 15:26:46.928097 Protocol options: explicit-exit-notify 1
2023-07-30 15:26:48.153801 *Tunnelblick: DNS address xx.yy.bb.1 is being routed through the VPN
2023-07-30 15:26:53.211587 *Tunnelblick: This computer's apparent public IP address (qq.ww.ee.rr) was unchanged after the connection was made


Server log

2023-07-30 15:17:13 us=273671 --cipher is not set. Previous OpenVPN version defaulted to BF-CBC as fallback when cipher negotiation failed in this case. If you need this fallback please add '--data-ciphers-fallback BF-CBC' to your configuration and/or add BF-CBC to --data-ciphers.
2023-07-30 15:17:13 us=274249 OpenVPN 2.5.7 aarch64-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD]
2023-07-30 15:17:13 us=274363 library versions: OpenSSL 1.1.1u 30 May 2023, LZO 2.10
2023-07-30 15:17:13 us=274541 net_route_v4_best_gw query: dst 0.0.0.0
2023-07-30 15:17:13 us=274799 net_route_v4_best_gw result: via 0.0.0.0 dev
2023-07-30 15:17:13 us=274945 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2023-07-30 15:17:13 us=278428 Diffie-Hellman initialized with 2048 bit key
2023-07-30 15:17:13 us=282605 Using random OpenVPN auth-token server key.
2023-07-30 15:17:13 us=282797 auth-token secret: Using 256 bit message hash 'SHA256' for HMAC authentication
2023-07-30 15:17:13 us=282902 TLS-Auth MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
2023-07-30 15:17:13 us=284167 TUN/TAP device tun0 opened
2023-07-30 15:17:13 us=284305 do_ifconfig, ipv4=1, ipv6=0
2023-07-30 15:17:13 us=284435 net_iface_mtu_set: mtu 1500 for tun0
2023-07-30 15:17:13 us=284652 net_iface_up: set tun0 up
2023-07-30 15:17:13 us=285108 net_addr_v4_add: xx.yy.aa.1/24 dev tun0
2023-07-30 15:17:13 us=285980 /usr/libexec/openvpn-hotplug up VPNServer tun0 1500 1621 xx.yy.aa.1 255.255.255.0 init
2023-07-30 15:17:13 us=304432 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
2023-07-30 15:17:13 us=304782 Socket Buffers: R=[212992->212992] S=[212992->212992]
2023-07-30 15:17:13 us=304981 UDPv4 link local (bound): [AF_INET][undef]:7314
2023-07-30 15:17:13 us=305081 UDPv4 link remote: [AF_UNSPEC]
2023-07-30 15:17:13 us=305171 GID set to openvpn
2023-07-30 15:17:13 us=305241 UID set to openvpn
2023-07-30 15:17:13 us=305307 MULTI: multi_init called, r=256 v=256
2023-07-30 15:17:13 us=305432 IFCONFIG POOL IPv4: base=xx.yy.aa.2 size=253
2023-07-30 15:17:13 us=305607 Initialization Sequence Completed
2023-07-30 15:25:29 us=374719 MULTI: multi_create_instance called
2023-07-30 15:25:29 us=375134 qq.ww.ee.rr:10024 Re-using SSL/TLS context
2023-07-30 15:25:29 us=376329 qq.ww.ee.rr:10024 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
2023-07-30 15:25:29 us=376766 qq.ww.ee.rr:10024 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
2023-07-30 15:25:29 us=377308 qq.ww.ee.rr:10024 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,auth SHA1,keysize 128,key-method 2,tls-server'
2023-07-30 15:25:29 us=377682 qq.ww.ee.rr:10024 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,auth SHA1,keysize 128,key-method 2,tls-client'
2023-07-30 15:25:29 us=378140 qq.ww.ee.rr:10024 TLS: Initial packet from [AF_INET]qq.ww.ee.rr:10024, sid=6e6c8a72 40a58233
2023-07-30 15:25:29 us=448565 qq.ww.ee.rr:10024 VERIFY OK: depth=1, CN=ovpnca
2023-07-30 15:25:29 us=450357 qq.ww.ee.rr:10024 VERIFY OK: depth=0, CN=client
2023-07-30 15:25:29 us=454403 qq.ww.ee.rr:10024 peer info: IV_VER=2.6.4
2023-07-30 15:25:29 us=454836 qq.ww.ee.rr:10024 peer info: IV_PLAT=mac
2023-07-30 15:25:29 us=455137 qq.ww.ee.rr:10024 peer info: IV_TCPNL=1
2023-07-30 15:25:29 us=455423 qq.ww.ee.rr:10024 peer info: IV_MTU=1600
2023-07-30 15:25:29 us=455708 qq.ww.ee.rr:10024 peer info: IV_NCP=2
2023-07-30 15:25:29 us=456005 qq.ww.ee.rr:10024 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
2023-07-30 15:25:29 us=456355 qq.ww.ee.rr:10024 peer info: IV_PROTO=990
2023-07-30 15:25:29 us=456658 qq.ww.ee.rr:10024 peer info: IV_LZO_STUB=1
2023-07-30 15:25:29 us=456947 qq.ww.ee.rr:10024 peer info: IV_COMP_STUB=1
2023-07-30 15:25:29 us=457285 qq.ww.ee.rr:10024 peer info: IV_COMP_STUBv2=1
2023-07-30 15:25:29 us=457588 qq.ww.ee.rr:10024 peer info: IV_GUI_VER="net.tunnelblick.tunnelblick_5860_4.0.0beta06__build_5860)"
>> Username: snuffy2
>> Wrong TOTP for user: snuffy2
2023-07-30 15:25:29 us=991974 qq.ww.ee.rr:10024 WARNING: Failed running command (--auth-user-pass-verify): external program exited with error status: 1
2023-07-30 15:25:29 us=992279 qq.ww.ee.rr:10024 TLS Auth Error: Auth Username/Password verification failed for peer
2023-07-30 15:25:29 us=992612 qq.ww.ee.rr:10024 SIGTERM[soft,auth-control-exit] received, client-instance exiting
2023-07-30 15:26:40 us=556635 MULTI: multi_create_instance called
2023-07-30 15:26:40 us=557077 qq.ww.ee.rr:53083 Re-using SSL/TLS context
2023-07-30 15:26:40 us=558184 qq.ww.ee.rr:53083 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
2023-07-30 15:26:40 us=558589 qq.ww.ee.rr:53083 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
2023-07-30 15:26:40 us=559012 qq.ww.ee.rr:53083 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,auth SHA1,keysize 128,key-method 2,tls-server'
2023-07-30 15:26:40 us=559226 qq.ww.ee.rr:53083 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,auth SHA1,keysize 128,key-method 2,tls-client'
2023-07-30 15:26:40 us=559570 qq.ww.ee.rr:53083 TLS: Initial packet from [AF_INET]qq.ww.ee.rr:53083, sid=2f90252a 7f36e3f6
2023-07-30 15:26:40 us=622162 qq.ww.ee.rr:53083 VERIFY OK: depth=1, CN=ovpnca
2023-07-30 15:26:40 us=623967 qq.ww.ee.rr:53083 VERIFY OK: depth=0, CN=client
2023-07-30 15:26:40 us=627340 qq.ww.ee.rr:53083 peer info: IV_VER=2.6.4
2023-07-30 15:26:40 us=627685 qq.ww.ee.rr:53083 peer info: IV_PLAT=mac
2023-07-30 15:26:40 us=627875 qq.ww.ee.rr:53083 peer info: IV_TCPNL=1
2023-07-30 15:26:40 us=628075 qq.ww.ee.rr:53083 peer info: IV_MTU=1600
2023-07-30 15:26:40 us=628260 qq.ww.ee.rr:53083 peer info: IV_NCP=2
2023-07-30 15:26:40 us=628465 qq.ww.ee.rr:53083 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
2023-07-30 15:26:40 us=628657 qq.ww.ee.rr:53083 peer info: IV_PROTO=990
2023-07-30 15:26:40 us=628857 qq.ww.ee.rr:53083 peer info: IV_LZO_STUB=1
2023-07-30 15:26:40 us=629101 qq.ww.ee.rr:53083 peer info: IV_COMP_STUB=1
2023-07-30 15:26:40 us=629303 qq.ww.ee.rr:53083 peer info: IV_COMP_STUBv2=1
2023-07-30 15:26:40 us=629511 qq.ww.ee.rr:53083 peer info: IV_GUI_VER="net.tunnelblick.tunnelblick_5860_4.0.0beta06__build_5860)"
>> Username: snuffy2
>> Login valid for user: snuffy2
>> New OTP session for user snuffy2 from qq.ww.ee.rr using "net.tunnelblick.tunnelblick_5860_4.0.0beta06__build_5860)".
2023-07-30 15:26:41 us=166555 qq.ww.ee.rr:53083 TLS: Username/Password authentication succeeded for username 'snuffy2' [CN SET]
2023-07-30 15:26:41 us=179659 qq.ww.ee.rr:53083 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256
2023-07-30 15:26:41 us=179886 qq.ww.ee.rr:53083 [snuffy2] Peer Connection Initiated with [AF_INET]qq.ww.ee.rr:53083
2023-07-30 15:26:41 us=180099 snuffy2/qq.ww.ee.rr:53083 MULTI_sva: pool returned IPv4=xx.yy.aa.2, IPv6=(Not enabled)
2023-07-30 15:26:41 us=180294 snuffy2/qq.ww.ee.rr:53083 MULTI: Learn: xx.yy.aa.2 -> snuffy2/qq.ww.ee.rr:53083
2023-07-30 15:26:41 us=180363 snuffy2/qq.ww.ee.rr:53083 MULTI: primary virtual IP for snuffy2/qq.ww.ee.rr:53083: xx.yy.aa.2
2023-07-30 15:26:41 us=180473 snuffy2/qq.ww.ee.rr:53083 Data Channel: using negotiated cipher 'AES-256-GCM'
2023-07-30 15:26:41 us=180593 snuffy2/qq.ww.ee.rr:53083 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
2023-07-30 15:26:41 us=180843 snuffy2/qq.ww.ee.rr:53083 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-07-30 15:26:41 us=180937 snuffy2/qq.ww.ee.rr:53083 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-07-30 15:26:41 us=181147 snuffy2/qq.ww.ee.rr:53083 SENT CONTROL [snuffy2]: 'PUSH_REPLY,persist-key,persist-tun,topology subnet,route xx.yy.bb.0 255.255.255.0,dhcp-option DNS xx.yy.bb.1,dhcp-option DOMAIN-SEARCH vpn,route-gateway xx.yy.aa.1,topology subnet,ping 10,ping-restart 60,ifconfig xx.yy.aa.2 255.255.255.0,peer-id 0,auth-tokenSESS_ID,cipher AES-256-GCM' (status=1)