OpenVPN / openvpn

OpenVPN is an open source VPN daemon
http://openvpn.net
Other
10.94k stars 3.01k forks source link

OpenVPN 2.6.1 broken - Block_DNS Element not found #294

Closed chefino closed 1 year ago

chefino commented 1 year ago

Upgrading to OpenVPN-2.6.1-I001-amd64.msi on Windows 10 and 11 Pro is causing all our clients (connecting to latest pfSense+ OVPN server) to fail.

2023-03-20 09:26:45 OpenVPN 2.6.1 [git:v2.6.1/2c2a98a0e559928c] Windows-MSVC [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] [DCO] built on Mar 8 2023
2023-03-20 09:26:45 Windows version 10.0 (Windows 10 or greater), amd64 executable
2023-03-20 09:26:45 library versions: OpenSSL 3.0.8 7 Feb 2023, LZO 2.10
2023-03-20 09:26:47 TCP/UDP: Preserving recently used remote address: [AF_INET]****:1197
2023-03-20 09:26:47 UDPv4 link local (bound): [AF_INET][undef]:0
2023-03-20 09:26:47 UDPv4 link remote: [AF_INET]****:1197
2023-03-20 09:26:47 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2023-03-20 09:26:48 [**** VPN Server] Peer Connection Initiated with [AF_INET]****:1197
2023-03-20 09:27:20 Options error: --dhcp-option: unknown option type 'DOMAIN' or missing or unknown parameter
2023-03-20 09:27:20 open_tun
2023-03-20 09:27:20 tap-windows6 device [Local Area Connection] opened
2023-03-20 09:27:20 Set TAP-Windows TUN subnet mode network/local/netmask = 10.*/10.*/255.255.255.0 [SUCCEEDED]
2023-03-20 09:27:20 Notified TAP-Windows driver to set a DHCP IP/netmask of 10.*/255.255.255.0 on interface {*****} [DHCP-serv: 10.*, lease-time: 31536000]
2023-03-20 09:27:20 Successful ARP Flush on interface [16] {*****}
2023-03-20 09:27:20 IPv4 MTU set to 1500 on interface 16 using service
2023-03-20 09:27:20 Block_DNS: adding block dns filters using service failed: Element not found. [status=0x490 if_index=16]
2023-03-20 09:27:20 Blocking DNS failed!
2023-03-20 09:27:20 Exiting due to fatal error

Tried commenting out the two lines below did not help or change the error we are getting. Downgrading to 2.6.0, 2.5.9 or 2.5.8 fixes the issue.

This is our general config file (redacted parts - ****: commented out lines starting with #)

dev tun
# persist-tun
persist-key
data-ciphers ****
data-ciphers-fallback ****
auth SHA256
tls-client
client
resolv-retry infinite
remote **** 1197 udp4
# setenv opt block-outside-dns
lport 0
verify-x509-name "****" name
auth-user-pass
ca fw1-UDP4-1197-****-ca.crt
cryptoapicert "SUBJ:****"
tls-crypt fw1-UDP4-1197-****-tls.key
remote-cert-tls server
explicit-exit-notify
reneg-sec 0
lstipakov commented 1 year ago

Can you provide the client log with verb 4?

addy90 commented 1 year ago

I can confirm the issue. The server runs OpenVPN Community Server 2.6.1 from the official OpenVPN repository on Debian Bullseye. The client is OpenVPN Community Server 2.6.1 on Windows 10.

I have hidden all sensitive data from the following pastes (certificates also omitted):

The server config ``` dev tun port 1194 proto udp persist-tun persist-key user nobody group nogroup auth SHA1 cipher AES-256-GCM verify-client-cert none username-as-common-name duplicate-cn keepalive 10 60 key-direction 0 sndbuf 562144 rcvbuf 562144 push "sndbuf 562144" push "rcvbuf 562144" plugin /usr/lib/openvpn/openvpn-auth-ldap.so /etc/openvpn/server/ldap client-config-dir /etc/openvpn/server/client-config management localhost 7505 topology subnet server XXXXX XXXXX push "route XXXXX" push "dhcp-option DNS XXXXX" push "dhcp-option DOMAIN XXXXX" push "register-dns" push "block-outside-dns" ```
The client config (for example, we also have one with wintun device, same problem) ``` dev tun proto udp persist-tun persist-key client auth SHA1 cipher AES-256-GCM resolv-retry infinite remote XXXXX 1194 udp4 key-direction 1 lport 0 auth-user-pass remote-cert-tls server ```

When I connect with verb 4 setting enabled, the following log-file is shown:

The verb4 log file ``` 2023-03-22 10:33:49 us=500000 Current Parameter Settings: 2023-03-22 10:33:49 us=500000 config = 'XXXXX' 2023-03-22 10:33:49 us=500000 mode = 0 2023-03-22 10:33:49 us=500000 show_ciphers = DISABLED 2023-03-22 10:33:49 us=500000 show_digests = DISABLED 2023-03-22 10:33:49 us=500000 show_engines = DISABLED 2023-03-22 10:33:49 us=500000 genkey = DISABLED 2023-03-22 10:33:49 us=500000 genkey_filename = '[UNDEF]' 2023-03-22 10:33:49 us=500000 key_pass_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 show_tls_ciphers = DISABLED 2023-03-22 10:33:49 us=500000 connect_retry_max = 0 2023-03-22 10:33:49 us=500000 Connection profiles [0]: 2023-03-22 10:33:49 us=500000 proto = udp4 2023-03-22 10:33:49 us=500000 local = '[UNDEF]' 2023-03-22 10:33:49 us=500000 local_port = '0' 2023-03-22 10:33:49 us=500000 remote = 'XXXXX' 2023-03-22 10:33:49 us=500000 remote_port = '1194' 2023-03-22 10:33:49 us=500000 remote_float = DISABLED 2023-03-22 10:33:49 us=500000 bind_defined = DISABLED 2023-03-22 10:33:49 us=500000 bind_local = ENABLED 2023-03-22 10:33:49 us=500000 bind_ipv6_only = DISABLED 2023-03-22 10:33:49 us=500000 connect_retry_seconds = 1 2023-03-22 10:33:49 us=500000 connect_timeout = 120 2023-03-22 10:33:49 us=500000 socks_proxy_server = '[UNDEF]' 2023-03-22 10:33:49 us=500000 socks_proxy_port = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tun_mtu = 1500 2023-03-22 10:33:49 us=500000 tun_mtu_defined = ENABLED 2023-03-22 10:33:49 us=500000 link_mtu = 1500 2023-03-22 10:33:49 us=500000 link_mtu_defined = DISABLED 2023-03-22 10:33:49 us=500000 tun_mtu_extra = 0 2023-03-22 10:33:49 us=500000 tun_mtu_extra_defined = DISABLED 2023-03-22 10:33:49 us=500000 tls_mtu = 1250 2023-03-22 10:33:49 us=500000 mtu_discover_type = -1 2023-03-22 10:33:49 us=500000 fragment = 0 2023-03-22 10:33:49 us=500000 mssfix = 1492 2023-03-22 10:33:49 us=500000 mssfix_encap = ENABLED 2023-03-22 10:33:49 us=500000 mssfix_fixed = DISABLED 2023-03-22 10:33:49 us=500000 explicit_exit_notification = 0 2023-03-22 10:33:49 us=500000 tls_auth_file = '[INLINE]' 2023-03-22 10:33:49 us=500000 key_direction = 1 2023-03-22 10:33:49 us=500000 tls_crypt_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tls_crypt_v2_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 Connection profiles END 2023-03-22 10:33:49 us=500000 remote_random = DISABLED 2023-03-22 10:33:49 us=500000 ipchange = '[UNDEF]' 2023-03-22 10:33:49 us=500000 dev = 'tun' 2023-03-22 10:33:49 us=500000 dev_type = '[UNDEF]' 2023-03-22 10:33:49 us=500000 dev_node = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tuntap_options.disable_dco = DISABLED 2023-03-22 10:33:49 us=500000 lladdr = '[UNDEF]' 2023-03-22 10:33:49 us=500000 topology = 1 2023-03-22 10:33:49 us=500000 ifconfig_local = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ifconfig_remote_netmask = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ifconfig_noexec = DISABLED 2023-03-22 10:33:49 us=500000 ifconfig_nowarn = DISABLED 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_local = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_netbits = 0 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_remote = '[UNDEF]' 2023-03-22 10:33:49 us=500000 shaper = 0 2023-03-22 10:33:49 us=500000 mtu_test = 0 2023-03-22 10:33:49 us=500000 mlock = DISABLED 2023-03-22 10:33:49 us=500000 keepalive_ping = 0 2023-03-22 10:33:49 us=500000 keepalive_timeout = 0 2023-03-22 10:33:49 us=500000 inactivity_timeout = 0 2023-03-22 10:33:49 us=500000 session_timeout = 0 2023-03-22 10:33:49 us=500000 inactivity_minimum_bytes = 0 2023-03-22 10:33:49 us=500000 ping_send_timeout = 0 2023-03-22 10:33:49 us=500000 ping_rec_timeout = 0 2023-03-22 10:33:49 us=500000 ping_rec_timeout_action = 0 2023-03-22 10:33:49 us=500000 ping_timer_remote = DISABLED 2023-03-22 10:33:49 us=500000 remap_sigusr1 = 0 2023-03-22 10:33:49 us=500000 persist_tun = ENABLED 2023-03-22 10:33:49 us=500000 persist_local_ip = DISABLED 2023-03-22 10:33:49 us=500000 persist_remote_ip = DISABLED 2023-03-22 10:33:49 us=500000 persist_key = ENABLED 2023-03-22 10:33:49 us=500000 passtos = DISABLED 2023-03-22 10:33:49 us=500000 resolve_retry_seconds = 1000000000 2023-03-22 10:33:49 us=500000 resolve_in_advance = DISABLED 2023-03-22 10:33:49 us=500000 username = '[UNDEF]' 2023-03-22 10:33:49 us=500000 groupname = '[UNDEF]' 2023-03-22 10:33:49 us=500000 chroot_dir = '[UNDEF]' 2023-03-22 10:33:49 us=500000 cd_dir = '[UNDEF]' 2023-03-22 10:33:49 us=500000 writepid = '[UNDEF]' 2023-03-22 10:33:49 us=500000 up_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 down_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 down_pre = DISABLED 2023-03-22 10:33:49 us=500000 up_restart = DISABLED 2023-03-22 10:33:49 us=500000 up_delay = DISABLED 2023-03-22 10:33:49 us=500000 daemon = DISABLED 2023-03-22 10:33:49 us=500000 log = ENABLED 2023-03-22 10:33:49 us=500000 suppress_timestamps = DISABLED 2023-03-22 10:33:49 us=500000 machine_readable_output = DISABLED 2023-03-22 10:33:49 us=500000 nice = 0 2023-03-22 10:33:49 us=500000 verbosity = 4 2023-03-22 10:33:49 us=500000 mute = 0 2023-03-22 10:33:49 us=500000 status_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 status_file_version = 1 2023-03-22 10:33:49 us=500000 status_file_update_freq = 60 2023-03-22 10:33:49 us=500000 occ = ENABLED 2023-03-22 10:33:49 us=500000 rcvbuf = 0 2023-03-22 10:33:49 us=500000 sndbuf = 0 2023-03-22 10:33:49 us=500000 sockflags = 0 2023-03-22 10:33:49 us=500000 fast_io = DISABLED 2023-03-22 10:33:49 us=500000 comp.alg = 0 2023-03-22 10:33:49 us=500000 comp.flags = 24 2023-03-22 10:33:49 us=500000 route_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 route_default_gateway = '[UNDEF]' 2023-03-22 10:33:49 us=500000 route_default_metric = 0 2023-03-22 10:33:49 us=500000 route_noexec = DISABLED 2023-03-22 10:33:49 us=500000 route_delay = 0 2023-03-22 10:33:49 us=500000 route_delay_window = 30 2023-03-22 10:33:49 us=500000 route_delay_defined = DISABLED 2023-03-22 10:33:49 us=500000 route_nopull = DISABLED 2023-03-22 10:33:49 us=500000 route_gateway_via_dhcp = DISABLED 2023-03-22 10:33:49 us=500000 allow_pull_fqdn = DISABLED 2023-03-22 10:33:49 us=500000 Pull filters: 2023-03-22 10:33:49 us=500000 ignore "route-method" 2023-03-22 10:33:49 us=500000 management_addr = 'XXXXX' 2023-03-22 10:33:49 us=500000 management_port = '25342' 2023-03-22 10:33:49 us=500000 management_user_pass = 'stdin' 2023-03-22 10:33:49 us=500000 management_log_history_cache = 250 2023-03-22 10:33:49 us=500000 management_echo_buffer_size = 100 2023-03-22 10:33:49 us=500000 management_client_user = '[UNDEF]' 2023-03-22 10:33:49 us=500000 management_client_group = '[UNDEF]' 2023-03-22 10:33:49 us=500000 management_flags = 6 2023-03-22 10:33:49 us=500000 shared_secret_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 key_direction = 1 2023-03-22 10:33:49 us=500000 ciphername = 'AES-256-GCM' 2023-03-22 10:33:49 us=500000 ncp_ciphers = 'AES-256-GCM:AES-128-GCM' 2023-03-22 10:33:49 us=500000 authname = 'SHA1' 2023-03-22 10:33:49 us=500000 engine = DISABLED 2023-03-22 10:33:49 us=500000 replay = ENABLED 2023-03-22 10:33:49 us=500000 mute_replay_warnings = DISABLED 2023-03-22 10:33:49 us=500000 replay_window = 64 2023-03-22 10:33:49 us=500000 replay_time = 15 2023-03-22 10:33:49 us=500000 packet_id_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 test_crypto = DISABLED 2023-03-22 10:33:49 us=500000 tls_server = DISABLED 2023-03-22 10:33:49 us=500000 tls_client = ENABLED 2023-03-22 10:33:49 us=500000 ca_file = '[INLINE]' 2023-03-22 10:33:49 us=500000 ca_path = '[UNDEF]' 2023-03-22 10:33:49 us=500000 dh_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 cert_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 extra_certs_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 priv_key_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 pkcs12_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 cryptoapi_cert = '[UNDEF]' 2023-03-22 10:33:49 us=500000 cipher_list = '[UNDEF]' 2023-03-22 10:33:49 us=500000 cipher_list_tls13 = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tls_cert_profile = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tls_verify = '[UNDEF]' 2023-03-22 10:33:49 us=500000 tls_export_cert = '[UNDEF]' 2023-03-22 10:33:49 us=500000 verify_x509_type = 0 2023-03-22 10:33:49 us=500000 verify_x509_name = '[UNDEF]' 2023-03-22 10:33:49 us=500000 crl_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ns_cert_type = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 65535 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_ku[i] = 0 2023-03-22 10:33:49 us=500000 remote_cert_eku = 'TLS Web Server Authentication' 2023-03-22 10:33:49 us=500000 ssl_flags = 192 2023-03-22 10:33:49 us=500000 tls_timeout = 2 2023-03-22 10:33:49 us=500000 renegotiate_bytes = -1 2023-03-22 10:33:49 us=500000 renegotiate_packets = 0 2023-03-22 10:33:49 us=500000 renegotiate_seconds = 3600 2023-03-22 10:33:49 us=500000 handshake_window = 60 2023-03-22 10:33:49 us=500000 transition_window = 3600 2023-03-22 10:33:49 us=500000 single_session = DISABLED 2023-03-22 10:33:49 us=500000 push_peer_info = DISABLED 2023-03-22 10:33:49 us=500000 tls_exit = DISABLED 2023-03-22 10:33:49 us=500000 tls_crypt_v2_metadata = '[UNDEF]' 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_protected_authentication = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_private_mode = 00000000 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_cert_private = DISABLED 2023-03-22 10:33:49 us=500000 pkcs11_pin_cache_period = -1 2023-03-22 10:33:49 us=500000 pkcs11_id = '[UNDEF]' 2023-03-22 10:33:49 us=500000 pkcs11_id_management = DISABLED 2023-03-22 10:33:49 us=500000 server_network = 0.0.0.0 2023-03-22 10:33:49 us=500000 server_netmask = 0.0.0.0 2023-03-22 10:33:49 us=500000 server_network_ipv6 = :: 2023-03-22 10:33:49 us=500000 server_netbits_ipv6 = 0 2023-03-22 10:33:49 us=500000 server_bridge_ip = 0.0.0.0 2023-03-22 10:33:49 us=500000 server_bridge_netmask = 0.0.0.0 2023-03-22 10:33:49 us=500000 server_bridge_pool_start = 0.0.0.0 2023-03-22 10:33:49 us=500000 server_bridge_pool_end = 0.0.0.0 2023-03-22 10:33:49 us=500000 ifconfig_pool_defined = DISABLED 2023-03-22 10:33:49 us=500000 ifconfig_pool_start = 0.0.0.0 2023-03-22 10:33:49 us=500000 ifconfig_pool_end = 0.0.0.0 2023-03-22 10:33:49 us=500000 ifconfig_pool_netmask = 0.0.0.0 2023-03-22 10:33:49 us=500000 ifconfig_pool_persist_filename = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ifconfig_pool_persist_refresh_freq = 600 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_pool_defined = DISABLED 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_pool_base = :: 2023-03-22 10:33:49 us=500000 ifconfig_ipv6_pool_netbits = 0 2023-03-22 10:33:49 us=500000 n_bcast_buf = 256 2023-03-22 10:33:49 us=500000 tcp_queue_limit = 64 2023-03-22 10:33:49 us=500000 real_hash_size = 256 2023-03-22 10:33:49 us=500000 virtual_hash_size = 256 2023-03-22 10:33:49 us=500000 client_connect_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 learn_address_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 client_disconnect_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 client_crresponse_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 client_config_dir = '[UNDEF]' 2023-03-22 10:33:49 us=500000 ccd_exclusive = DISABLED 2023-03-22 10:33:49 us=500000 tmp_dir = 'C:\Users\XXXXX\AppData\Local\Temp\' 2023-03-22 10:33:49 us=500000 push_ifconfig_defined = DISABLED 2023-03-22 10:33:49 us=500000 push_ifconfig_local = 0.0.0.0 2023-03-22 10:33:49 us=500000 push_ifconfig_remote_netmask = 0.0.0.0 2023-03-22 10:33:49 us=500000 push_ifconfig_ipv6_defined = DISABLED 2023-03-22 10:33:49 us=500000 push_ifconfig_ipv6_local = ::/0 2023-03-22 10:33:49 us=500000 push_ifconfig_ipv6_remote = :: 2023-03-22 10:33:49 us=500000 enable_c2c = DISABLED 2023-03-22 10:33:49 us=500000 duplicate_cn = DISABLED 2023-03-22 10:33:49 us=500000 cf_max = 0 2023-03-22 10:33:49 us=500000 cf_per = 0 2023-03-22 10:33:49 us=500000 cf_initial_max = 100 2023-03-22 10:33:49 us=500000 cf_initial_per = 10 2023-03-22 10:33:49 us=500000 max_clients = 1024 2023-03-22 10:33:49 us=500000 max_routes_per_client = 256 2023-03-22 10:33:49 us=500000 auth_user_pass_verify_script = '[UNDEF]' 2023-03-22 10:33:49 us=500000 auth_user_pass_verify_script_via_file = DISABLED 2023-03-22 10:33:49 us=500000 auth_token_generate = DISABLED 2023-03-22 10:33:49 us=500000 auth_token_lifetime = 0 2023-03-22 10:33:49 us=500000 auth_token_secret_file = '[UNDEF]' 2023-03-22 10:33:49 us=500000 vlan_tagging = DISABLED 2023-03-22 10:33:49 us=500000 vlan_accept = all 2023-03-22 10:33:49 us=500000 vlan_pvid = 1 2023-03-22 10:33:49 us=500000 client = ENABLED 2023-03-22 10:33:49 us=500000 pull = ENABLED 2023-03-22 10:33:49 us=500000 auth_user_pass_file = 'stdin' 2023-03-22 10:33:49 us=500000 show_net_up = DISABLED 2023-03-22 10:33:49 us=500000 route_method = 3 2023-03-22 10:33:49 us=500000 block_outside_dns = DISABLED 2023-03-22 10:33:49 us=500000 ip_win32_defined = DISABLED 2023-03-22 10:33:49 us=500000 ip_win32_type = 1 2023-03-22 10:33:49 us=500000 dhcp_masq_offset = 0 2023-03-22 10:33:49 us=500000 dhcp_lease_time = 31536000 2023-03-22 10:33:49 us=500000 tap_sleep = 0 2023-03-22 10:33:49 us=500000 dhcp_options = 0x00000000 2023-03-22 10:33:49 us=500000 dhcp_renew = DISABLED 2023-03-22 10:33:49 us=500000 dhcp_pre_release = DISABLED 2023-03-22 10:33:49 us=500000 domain = '[UNDEF]' 2023-03-22 10:33:49 us=500000 netbios_scope = '[UNDEF]' 2023-03-22 10:33:49 us=500000 netbios_node_type = 0 2023-03-22 10:33:49 us=500000 disable_nbt = DISABLED 2023-03-22 10:33:49 us=500000 OpenVPN 2.6.1 [git:v2.6.1/2c2a98a0e559928c] Windows-MSVC [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] [DCO] built on Mar 8 2023 2023-03-22 10:33:49 us=500000 Windows version 10.0 (Windows 10 or greater), amd64 executable 2023-03-22 10:33:49 us=500000 library versions: OpenSSL 3.0.8 7 Feb 2023, LZO 2.10 2023-03-22 10:33:49 us=500000 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25342 2023-03-22 10:33:49 us=500000 Need hold release from management interface, waiting... 2023-03-22 10:33:50 us=15000 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:51847 2023-03-22 10:33:50 us=125000 MANAGEMENT: CMD 'state on' 2023-03-22 10:33:50 us=125000 MANAGEMENT: CMD 'log on all' 2023-03-22 10:33:50 us=265000 MANAGEMENT: CMD 'echo on all' 2023-03-22 10:33:50 us=265000 MANAGEMENT: CMD 'bytecount 5' 2023-03-22 10:33:50 us=265000 MANAGEMENT: CMD 'state' 2023-03-22 10:33:50 us=265000 MANAGEMENT: CMD 'hold off' 2023-03-22 10:33:50 us=265000 MANAGEMENT: CMD 'hold release' 2023-03-22 10:33:54 us=46000 MANAGEMENT: CMD 'username "Auth" "XXXXX"' 2023-03-22 10:33:54 us=78000 MANAGEMENT: CMD 'password [...]' 2023-03-22 10:33:54 us=78000 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2023-03-22 10:33:54 us=78000 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2023-03-22 10:33:54 us=78000 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-03-22 10:33:54 us=78000 MANAGEMENT: >STATE:1679477634,RESOLVE,,,,,, 2023-03-22 10:33:54 us=78000 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-03-22 10:33:54 us=78000 TCP/UDP: Preserving recently used remote address: [AF_INET]XXXXX:1194 2023-03-22 10:33:54 us=93000 ovpn-dco device [OpenVPN Data Channel Offload] opened 2023-03-22 10:33:54 us=93000 UDPv4 link local (bound): [AF_INET][undef]:0 2023-03-22 10:33:54 us=93000 UDPv4 link remote: [AF_INET]XXXXX:1194 2023-03-22 10:33:54 us=93000 MANAGEMENT: >STATE:1679477634,WAIT,,,,,, 2023-03-22 10:33:54 us=93000 MANAGEMENT: >STATE:1679477634,AUTH,,,,,, 2023-03-22 10:33:54 us=93000 TLS: Initial packet from [AF_INET]XXXXX:1194, sid=76cab27a 28252461 2023-03-22 10:33:54 us=93000 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this 2023-03-22 10:33:54 us=93000 VERIFY OK: depth=1, XXXXX 2023-03-22 10:33:54 us=93000 VERIFY KU OK 2023-03-22 10:33:54 us=93000 Validating certificate extended key usage 2023-03-22 10:33:54 us=93000 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication 2023-03-22 10:33:54 us=93000 VERIFY EKU OK 2023-03-22 10:33:54 us=93000 VERIFY OK: depth=0, XXXXX 2023-03-22 10:33:54 us=109000 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256 2023-03-22 10:33:54 us=109000 [OpenVPN Tunnel] Peer Connection Initiated with [AF_INET]XXXXX:1194 2023-03-22 10:33:54 us=109000 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1 2023-03-22 10:33:54 us=109000 TLS: tls_multi_process: initial untrusted session promoted to trusted 2023-03-22 10:33:54 us=125000 PUSH: Received control message: 'PUSH_REPLY,sndbuf 562144,rcvbuf 562144,route XXXXX,dhcp-option DNS XXXXX,dhcp-option DOMAIN XXXXX,register-dns,block-outside-dns,route-gateway XXXXX,topology subnet,ping 10,ping-restart 60,ifconfig XXXXX,peer-id 1,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500' 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: --sndbuf/--rcvbuf options modified 2023-03-22 10:33:54 us=125000 NOTE: setsockopt SO_SNDBUF=562144 failed 2023-03-22 10:33:54 us=125000 NOTE: setsockopt SO_RCVBUF=562144 failed 2023-03-22 10:33:54 us=125000 Socket Buffers: R=[0->0] S=[0->0] 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: --ifconfig/up options modified 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: route options modified 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: route-related options modified 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified 2023-03-22 10:33:54 us=125000 OPTIONS IMPORT: tun-mtu set to 1500 2023-03-22 10:33:54 us=125000 interactive service msg_channel=724 2023-03-22 10:33:54 us=125000 do_ifconfig, ipv4=1, ipv6=0 2023-03-22 10:33:54 us=125000 MANAGEMENT: >STATE:1679477634,ASSIGN_IP,,XXXXX,,,, 2023-03-22 10:33:54 us=125000 INET address service: add XXXXX/16 2023-03-22 10:33:54 us=125000 Setting IPv4 dns servers on 'OpenVPN Data Channel Offload' (if_index = 39) using service 2023-03-22 10:33:54 us=250000 IPv4 dns servers set using service 2023-03-22 10:33:54 us=250000 Setting dns domain on 'OpenVPN Data Channel Offload' (if_index = 39) using service 2023-03-22 10:33:54 us=406000 DNS domain set using service 2023-03-22 10:33:54 us=406000 IPv4 MTU set to 1500 on interface 39 using service 2023-03-22 10:33:54 us=406000 Block_DNS: adding block dns filters using service failed: Element nicht gefunden. [status=0x490 if_index=39] 2023-03-22 10:33:54 us=406000 MANAGEMENT: Client disconnected 2023-03-22 10:33:54 us=421000 Blocking DNS failed! 2023-03-22 10:33:54 us=421000 Exiting due to fatal error ```

(the setsockopt errors can be ignored, this setting works in combination with wintun device client setting, which we used prior to DCO)

After reverting back to OpenVPN Community Client 2.6.0 the same config without any change works, the Block_DNS error does not occur, so it only affects Windows Client 2.6.1 on my side.

When I remove the push "block-outside-dns" setting on the server side, the connection with 2.6.1 works, but the setting is not active, so this is no option. Only reverting back to 2.6.0 worked as expected.

By the way, the services were running:

PS C:\> Get-Service -Name *OpenVPN*

Status   Name               DisplayName
------   ----               -----------
Running  OpenVPNService     OpenVPNService
Running  OpenVPNServiceI... OpenVPN Interactive Service

Thank you for your assistance!

chefino commented 1 year ago

Can you provide the client log with verb 4?

I am sorry, tried to get it yesterday but was busy doing damage control. A testing PC with the bad version I grabbed didn't produce the same results, yet since weekend I had dozens of these issues on now downgraded client computers. Can't experiment with those at the moment. Glad @addy90 posted the logs, hopefully you guys can work off those?

EDIT: From first (lay) glance, it seems the DNS blocking component didn't get compiled properly or at all in the 2.6.1 build?

Me:

Block_DNS: adding block dns filters using service failed: Element not found. [status=0x490 if_index=16]

@addy90

Block_DNS: adding block dns filters using service failed: Element nicht gefunden.   [status=0x490 if_index=39]
lstipakov commented 1 year ago

Unfortunately I cannot reproduce this.

Can you check event log and see if there are relevant errors from OpenVPN Interactive Service? It should give a bit more error details.

lstipakov commented 1 year ago

@selvanair Do you have any ideas what in this patch might have caused it? This seems to be the only relevant change between 2.6.0 -> 2.6.1.

selvanair commented 1 year ago

I couldn't think of a way that patch could cause this error (hence my silence..). I too cannot reproduce this. Unfortunately our logging is not good enough to know where exactly its erroring. @addy90 could you run openvpn from command prompt using this config (run openvpn.exe --config <config-name> from an elevated command prompt) and see whether you get the same error? That will bypass the service and changes made by the patch in question.

addy90 commented 1 year ago

Thanks for investigating!

@selvanair I tried out as you proposed with command from elevated CMD. In this case, the error does not happen with 2.6.1! See attached log file. I tried to connect via GUI to see if it still is reproducible, and the error happens again.

See log (anonymized) ``` C:\Users\XXXXX\OpenVPN\config>"C:\Program Files\OpenVPN\bin\openvpn.exe" --config XXXXX.ovpn 2023-03-22 15:13:13 us=437000 Current Parameter Settings: 2023-03-22 15:13:13 us=437000 config = 'XXXXX' 2023-03-22 15:13:13 us=437000 mode = 0 2023-03-22 15:13:13 us=437000 show_ciphers = DISABLED 2023-03-22 15:13:13 us=437000 show_digests = DISABLED 2023-03-22 15:13:13 us=437000 show_engines = DISABLED 2023-03-22 15:13:13 us=437000 genkey = DISABLED 2023-03-22 15:13:13 us=437000 genkey_filename = '[UNDEF]' 2023-03-22 15:13:13 us=437000 key_pass_file = '[UNDEF]' 2023-03-22 15:13:13 us=437000 show_tls_ciphers = DISABLED 2023-03-22 15:13:13 us=437000 connect_retry_max = 0 2023-03-22 15:13:13 us=437000 Connection profiles [0]: 2023-03-22 15:13:13 us=437000 proto = udp4 2023-03-22 15:13:13 us=437000 local = '[UNDEF]' 2023-03-22 15:13:13 us=437000 local_port = '0' 2023-03-22 15:13:13 us=437000 remote = 'XXXXX' 2023-03-22 15:13:13 us=437000 remote_port = '1194' 2023-03-22 15:13:13 us=437000 remote_float = DISABLED 2023-03-22 15:13:13 us=437000 bind_defined = DISABLED 2023-03-22 15:13:13 us=437000 bind_local = ENABLED 2023-03-22 15:13:13 us=437000 bind_ipv6_only = DISABLED 2023-03-22 15:13:13 us=437000 connect_retry_seconds = 1 2023-03-22 15:13:13 us=437000 connect_timeout = 120 2023-03-22 15:13:13 us=437000 socks_proxy_server = '[UNDEF]' 2023-03-22 15:13:13 us=437000 socks_proxy_port = '[UNDEF]' 2023-03-22 15:13:13 us=437000 tun_mtu = 1500 2023-03-22 15:13:13 us=437000 tun_mtu_defined = ENABLED 2023-03-22 15:13:13 us=437000 link_mtu = 1500 2023-03-22 15:13:13 us=437000 link_mtu_defined = DISABLED 2023-03-22 15:13:13 us=437000 tun_mtu_extra = 0 2023-03-22 15:13:13 us=437000 tun_mtu_extra_defined = DISABLED 2023-03-22 15:13:13 us=437000 tls_mtu = 1250 2023-03-22 15:13:13 us=437000 mtu_discover_type = -1 2023-03-22 15:13:13 us=437000 fragment = 0 2023-03-22 15:13:13 us=437000 mssfix = 1492 2023-03-22 15:13:13 us=437000 mssfix_encap = ENABLED 2023-03-22 15:13:13 us=437000 mssfix_fixed = DISABLED 2023-03-22 15:13:13 us=437000 explicit_exit_notification = 0 2023-03-22 15:13:13 us=437000 tls_auth_file = '[INLINE]' 2023-03-22 15:13:13 us=437000 key_direction = 1 2023-03-22 15:13:13 us=437000 tls_crypt_file = '[UNDEF]' 2023-03-22 15:13:13 us=437000 tls_crypt_v2_file = '[UNDEF]' 2023-03-22 15:13:13 us=437000 Connection profiles END 2023-03-22 15:13:13 us=453000 remote_random = DISABLED 2023-03-22 15:13:13 us=453000 ipchange = '[UNDEF]' 2023-03-22 15:13:13 us=453000 dev = 'tun' 2023-03-22 15:13:13 us=453000 dev_type = '[UNDEF]' 2023-03-22 15:13:13 us=453000 dev_node = '[UNDEF]' 2023-03-22 15:13:13 us=453000 tuntap_options.disable_dco = DISABLED 2023-03-22 15:13:13 us=453000 lladdr = '[UNDEF]' 2023-03-22 15:13:13 us=453000 topology = 1 2023-03-22 15:13:13 us=453000 ifconfig_local = '[UNDEF]' 2023-03-22 15:13:13 us=453000 ifconfig_remote_netmask = '[UNDEF]' 2023-03-22 15:13:13 us=453000 ifconfig_noexec = DISABLED 2023-03-22 15:13:13 us=453000 ifconfig_nowarn = DISABLED 2023-03-22 15:13:13 us=453000 ifconfig_ipv6_local = '[UNDEF]' 2023-03-22 15:13:13 us=453000 ifconfig_ipv6_netbits = 0 2023-03-22 15:13:13 us=453000 ifconfig_ipv6_remote = '[UNDEF]' 2023-03-22 15:13:13 us=453000 shaper = 0 2023-03-22 15:13:13 us=453000 mtu_test = 0 2023-03-22 15:13:13 us=453000 mlock = DISABLED 2023-03-22 15:13:13 us=453000 keepalive_ping = 0 2023-03-22 15:13:13 us=453000 keepalive_timeout = 0 2023-03-22 15:13:13 us=453000 inactivity_timeout = 0 2023-03-22 15:13:13 us=453000 session_timeout = 0 2023-03-22 15:13:13 us=453000 inactivity_minimum_bytes = 0 2023-03-22 15:13:13 us=453000 ping_send_timeout = 0 2023-03-22 15:13:13 us=453000 ping_rec_timeout = 0 2023-03-22 15:13:13 us=453000 ping_rec_timeout_action = 0 2023-03-22 15:13:13 us=453000 ping_timer_remote = DISABLED 2023-03-22 15:13:13 us=453000 remap_sigusr1 = 0 2023-03-22 15:13:13 us=453000 persist_tun = ENABLED 2023-03-22 15:13:13 us=453000 persist_local_ip = DISABLED 2023-03-22 15:13:13 us=453000 persist_remote_ip = DISABLED 2023-03-22 15:13:13 us=453000 persist_key = ENABLED 2023-03-22 15:13:13 us=453000 passtos = DISABLED 2023-03-22 15:13:13 us=453000 resolve_retry_seconds = 1000000000 2023-03-22 15:13:13 us=453000 resolve_in_advance = DISABLED 2023-03-22 15:13:13 us=453000 username = '[UNDEF]' 2023-03-22 15:13:13 us=453000 groupname = '[UNDEF]' 2023-03-22 15:13:13 us=453000 chroot_dir = '[UNDEF]' 2023-03-22 15:13:13 us=453000 cd_dir = '[UNDEF]' 2023-03-22 15:13:13 us=453000 writepid = '[UNDEF]' 2023-03-22 15:13:13 us=453000 up_script = '[UNDEF]' 2023-03-22 15:13:13 us=453000 down_script = '[UNDEF]' 2023-03-22 15:13:13 us=453000 down_pre = DISABLED 2023-03-22 15:13:13 us=453000 up_restart = DISABLED 2023-03-22 15:13:13 us=453000 up_delay = DISABLED 2023-03-22 15:13:13 us=453000 daemon = DISABLED 2023-03-22 15:13:13 us=453000 log = DISABLED 2023-03-22 15:13:13 us=453000 suppress_timestamps = DISABLED 2023-03-22 15:13:13 us=453000 machine_readable_output = DISABLED 2023-03-22 15:13:13 us=453000 nice = 0 2023-03-22 15:13:13 us=453000 verbosity = 4 2023-03-22 15:13:13 us=453000 mute = 0 2023-03-22 15:13:13 us=453000 status_file = '[UNDEF]' 2023-03-22 15:13:13 us=453000 status_file_version = 1 2023-03-22 15:13:13 us=453000 status_file_update_freq = 60 2023-03-22 15:13:13 us=453000 occ = ENABLED 2023-03-22 15:13:13 us=453000 rcvbuf = 0 2023-03-22 15:13:13 us=453000 sndbuf = 0 2023-03-22 15:13:13 us=453000 sockflags = 0 2023-03-22 15:13:13 us=453000 fast_io = DISABLED 2023-03-22 15:13:13 us=453000 comp.alg = 0 2023-03-22 15:13:13 us=453000 comp.flags = 24 2023-03-22 15:13:13 us=453000 route_script = '[UNDEF]' 2023-03-22 15:13:13 us=453000 route_default_gateway = '[UNDEF]' 2023-03-22 15:13:13 us=453000 route_default_metric = 0 2023-03-22 15:13:13 us=453000 route_noexec = DISABLED 2023-03-22 15:13:13 us=453000 route_delay = 0 2023-03-22 15:13:13 us=453000 route_delay_window = 30 2023-03-22 15:13:13 us=453000 route_delay_defined = DISABLED 2023-03-22 15:13:13 us=453000 route_nopull = DISABLED 2023-03-22 15:13:13 us=453000 route_gateway_via_dhcp = DISABLED 2023-03-22 15:13:13 us=453000 allow_pull_fqdn = DISABLED 2023-03-22 15:13:13 us=453000 management_addr = '[UNDEF]' 2023-03-22 15:13:13 us=453000 management_port = '[UNDEF]' 2023-03-22 15:13:13 us=453000 management_user_pass = '[UNDEF]' 2023-03-22 15:13:13 us=453000 management_log_history_cache = 250 2023-03-22 15:13:13 us=453000 management_echo_buffer_size = 100 2023-03-22 15:13:13 us=453000 management_client_user = '[UNDEF]' 2023-03-22 15:13:13 us=453000 management_client_group = '[UNDEF]' 2023-03-22 15:13:13 us=453000 management_flags = 0 2023-03-22 15:13:13 us=453000 shared_secret_file = '[UNDEF]' 2023-03-22 15:13:13 us=453000 key_direction = 1 2023-03-22 15:13:13 us=453000 ciphername = 'AES-256-GCM' 2023-03-22 15:13:13 us=468000 ncp_ciphers = 'AES-256-GCM:AES-128-GCM' 2023-03-22 15:13:13 us=468000 authname = 'SHA1' 2023-03-22 15:13:13 us=468000 engine = DISABLED 2023-03-22 15:13:13 us=468000 replay = ENABLED 2023-03-22 15:13:13 us=468000 mute_replay_warnings = DISABLED 2023-03-22 15:13:13 us=468000 replay_window = 64 2023-03-22 15:13:13 us=468000 replay_time = 15 2023-03-22 15:13:13 us=468000 packet_id_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 test_crypto = DISABLED 2023-03-22 15:13:13 us=468000 tls_server = DISABLED 2023-03-22 15:13:13 us=468000 tls_client = ENABLED 2023-03-22 15:13:13 us=468000 ca_file = '[INLINE]' 2023-03-22 15:13:13 us=468000 ca_path = '[UNDEF]' 2023-03-22 15:13:13 us=468000 dh_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 cert_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 extra_certs_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 priv_key_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 pkcs12_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 cryptoapi_cert = '[UNDEF]' 2023-03-22 15:13:13 us=468000 cipher_list = '[UNDEF]' 2023-03-22 15:13:13 us=468000 cipher_list_tls13 = '[UNDEF]' 2023-03-22 15:13:13 us=468000 tls_cert_profile = '[UNDEF]' 2023-03-22 15:13:13 us=468000 tls_verify = '[UNDEF]' 2023-03-22 15:13:13 us=468000 tls_export_cert = '[UNDEF]' 2023-03-22 15:13:13 us=468000 verify_x509_type = 0 2023-03-22 15:13:13 us=468000 verify_x509_name = '[UNDEF]' 2023-03-22 15:13:13 us=468000 crl_file = '[UNDEF]' 2023-03-22 15:13:13 us=468000 ns_cert_type = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 65535 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_ku[i] = 0 2023-03-22 15:13:13 us=468000 remote_cert_eku = 'TLS Web Server Authentication' 2023-03-22 15:13:13 us=468000 ssl_flags = 192 2023-03-22 15:13:13 us=468000 tls_timeout = 2 2023-03-22 15:13:13 us=468000 renegotiate_bytes = -1 2023-03-22 15:13:13 us=468000 renegotiate_packets = 0 2023-03-22 15:13:13 us=468000 renegotiate_seconds = 3600 2023-03-22 15:13:13 us=468000 handshake_window = 60 2023-03-22 15:13:13 us=468000 transition_window = 3600 2023-03-22 15:13:13 us=468000 single_session = DISABLED 2023-03-22 15:13:13 us=468000 push_peer_info = DISABLED 2023-03-22 15:13:13 us=468000 tls_exit = DISABLED 2023-03-22 15:13:13 us=468000 tls_crypt_v2_metadata = '[UNDEF]' 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_protected_authentication = DISABLED 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=468000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_private_mode = 00000000 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_cert_private = DISABLED 2023-03-22 15:13:13 us=484000 pkcs11_pin_cache_period = -1 2023-03-22 15:13:13 us=484000 pkcs11_id = '[UNDEF]' 2023-03-22 15:13:13 us=484000 pkcs11_id_management = DISABLED 2023-03-22 15:13:13 us=484000 server_network = 0.0.0.0 2023-03-22 15:13:13 us=484000 server_netmask = 0.0.0.0 2023-03-22 15:13:13 us=484000 server_network_ipv6 = :: 2023-03-22 15:13:13 us=484000 server_netbits_ipv6 = 0 2023-03-22 15:13:13 us=484000 server_bridge_ip = 0.0.0.0 2023-03-22 15:13:13 us=484000 server_bridge_netmask = 0.0.0.0 2023-03-22 15:13:13 us=484000 server_bridge_pool_start = 0.0.0.0 2023-03-22 15:13:13 us=484000 server_bridge_pool_end = 0.0.0.0 2023-03-22 15:13:13 us=484000 ifconfig_pool_defined = DISABLED 2023-03-22 15:13:13 us=484000 ifconfig_pool_start = 0.0.0.0 2023-03-22 15:13:13 us=484000 ifconfig_pool_end = 0.0.0.0 2023-03-22 15:13:13 us=484000 ifconfig_pool_netmask = 0.0.0.0 2023-03-22 15:13:13 us=484000 ifconfig_pool_persist_filename = '[UNDEF]' 2023-03-22 15:13:13 us=484000 ifconfig_pool_persist_refresh_freq = 600 2023-03-22 15:13:13 us=484000 ifconfig_ipv6_pool_defined = DISABLED 2023-03-22 15:13:13 us=484000 ifconfig_ipv6_pool_base = :: 2023-03-22 15:13:13 us=484000 ifconfig_ipv6_pool_netbits = 0 2023-03-22 15:13:13 us=484000 n_bcast_buf = 256 2023-03-22 15:13:13 us=484000 tcp_queue_limit = 64 2023-03-22 15:13:13 us=484000 real_hash_size = 256 2023-03-22 15:13:13 us=484000 virtual_hash_size = 256 2023-03-22 15:13:13 us=484000 client_connect_script = '[UNDEF]' 2023-03-22 15:13:13 us=484000 learn_address_script = '[UNDEF]' 2023-03-22 15:13:13 us=484000 client_disconnect_script = '[UNDEF]' 2023-03-22 15:13:13 us=484000 client_crresponse_script = '[UNDEF]' 2023-03-22 15:13:13 us=484000 client_config_dir = '[UNDEF]' 2023-03-22 15:13:13 us=484000 ccd_exclusive = DISABLED 2023-03-22 15:13:13 us=484000 tmp_dir = 'C:\Users\XXXXX\AppData\Local\Temp\' 2023-03-22 15:13:13 us=484000 push_ifconfig_defined = DISABLED 2023-03-22 15:13:13 us=484000 push_ifconfig_local = 0.0.0.0 2023-03-22 15:13:13 us=484000 push_ifconfig_remote_netmask = 0.0.0.0 2023-03-22 15:13:13 us=484000 push_ifconfig_ipv6_defined = DISABLED 2023-03-22 15:13:13 us=484000 push_ifconfig_ipv6_local = ::/0 2023-03-22 15:13:13 us=484000 push_ifconfig_ipv6_remote = :: 2023-03-22 15:13:13 us=484000 enable_c2c = DISABLED 2023-03-22 15:13:13 us=484000 duplicate_cn = DISABLED 2023-03-22 15:13:13 us=484000 cf_max = 0 2023-03-22 15:13:13 us=484000 cf_per = 0 2023-03-22 15:13:13 us=484000 cf_initial_max = 100 2023-03-22 15:13:13 us=484000 cf_initial_per = 10 2023-03-22 15:13:13 us=484000 max_clients = 1024 2023-03-22 15:13:13 us=484000 max_routes_per_client = 256 2023-03-22 15:13:13 us=484000 auth_user_pass_verify_script = '[UNDEF]' 2023-03-22 15:13:13 us=484000 auth_user_pass_verify_script_via_file = DISABLED 2023-03-22 15:13:13 us=484000 auth_token_generate = DISABLED 2023-03-22 15:13:13 us=484000 auth_token_lifetime = 0 2023-03-22 15:13:13 us=484000 auth_token_secret_file = '[UNDEF]' 2023-03-22 15:13:13 us=484000 vlan_tagging = DISABLED 2023-03-22 15:13:13 us=484000 vlan_accept = all 2023-03-22 15:13:13 us=484000 vlan_pvid = 1 2023-03-22 15:13:13 us=484000 client = ENABLED 2023-03-22 15:13:13 us=484000 pull = ENABLED 2023-03-22 15:13:13 us=484000 auth_user_pass_file = 'stdin' 2023-03-22 15:13:13 us=484000 show_net_up = DISABLED 2023-03-22 15:13:13 us=484000 route_method = 0 2023-03-22 15:13:13 us=484000 block_outside_dns = DISABLED 2023-03-22 15:13:13 us=484000 ip_win32_defined = DISABLED 2023-03-22 15:13:13 us=484000 ip_win32_type = 1 2023-03-22 15:13:13 us=500000 dhcp_masq_offset = 0 2023-03-22 15:13:13 us=500000 dhcp_lease_time = 31536000 2023-03-22 15:13:13 us=500000 tap_sleep = 0 2023-03-22 15:13:13 us=500000 dhcp_options = 0x00000000 2023-03-22 15:13:13 us=500000 dhcp_renew = DISABLED 2023-03-22 15:13:13 us=500000 dhcp_pre_release = DISABLED 2023-03-22 15:13:13 us=500000 domain = '[UNDEF]' 2023-03-22 15:13:13 us=500000 netbios_scope = '[UNDEF]' 2023-03-22 15:13:13 us=500000 netbios_node_type = 0 2023-03-22 15:13:13 us=500000 disable_nbt = DISABLED 2023-03-22 15:13:13 us=500000 OpenVPN 2.6.1 [git:v2.6.1/2c2a98a0e559928c] Windows-MSVC [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] [DCO] built on Mar 8 2023 2023-03-22 15:13:13 us=500000 Windows version 10.0 (Windows 10 or greater), amd64 executable 2023-03-22 15:13:13 us=500000 library versions: OpenSSL 3.0.8 7 Feb 2023, LZO 2.10 Enter Auth Username:XXXXX Enter Auth Password: 2023-03-22 15:13:19 us=296000 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2023-03-22 15:13:19 us=296000 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2023-03-22 15:13:19 us=296000 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-03-22 15:13:19 us=296000 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-03-22 15:13:19 us=296000 TCP/UDP: Preserving recently used remote address: [AF_INET]XXXXX:1194 2023-03-22 15:13:19 us=312000 ovpn-dco device [OpenVPN Data Channel Offload] opened 2023-03-22 15:13:19 us=312000 UDPv4 link local (bound): [AF_INET][undef]:0 2023-03-22 15:13:19 us=312000 UDPv4 link remote: [AF_INET]XXXXX:1194 2023-03-22 15:13:19 us=312000 TLS: Initial packet from [AF_INET]XXXXX:1194, sid=7fb6f707 5084cf73 2023-03-22 15:13:19 us=312000 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this 2023-03-22 15:13:19 us=312000 VERIFY OK: depth=1, XXXXX 2023-03-22 15:13:19 us=312000 VERIFY KU OK 2023-03-22 15:13:19 us=312000 Validating certificate extended key usage 2023-03-22 15:13:19 us=328000 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication 2023-03-22 15:13:19 us=328000 VERIFY EKU OK 2023-03-22 15:13:19 us=328000 VERIFY OK: depth=0, XXXXX 2023-03-22 15:13:19 us=343000 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256 2023-03-22 15:13:19 us=343000 [OpenVPN Tunnel] Peer Connection Initiated with [AF_INET]XXXXX:1194 2023-03-22 15:13:19 us=343000 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1 2023-03-22 15:13:19 us=343000 TLS: tls_multi_process: initial untrusted session promoted to trusted 2023-03-22 15:13:19 us=343000 PUSH: Received control message: 'PUSH_REPLY,sndbuf 562144,rcvbuf 562144,route XXXXX,dhcp-option DNS XXXXX,dhcp-option DOMAIN XXXXX,register-dns,block-outside-dns,route-gateway XXXXX,topology subnet,ping 10,ping-restart 60,ifconfig XXXXX,peer-id 5,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500' 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: --sndbuf/--rcvbuf options modified 2023-03-22 15:13:19 us=343000 NOTE: setsockopt SO_SNDBUF=562144 failed 2023-03-22 15:13:19 us=343000 NOTE: setsockopt SO_RCVBUF=562144 failed 2023-03-22 15:13:19 us=343000 Socket Buffers: R=[0->0] S=[0->0] 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: --ifconfig/up options modified 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: route options modified 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: route-related options modified 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified 2023-03-22 15:13:19 us=343000 OPTIONS IMPORT: tun-mtu set to 1500 2023-03-22 15:13:19 us=343000 interactive service msg_channel=0 2023-03-22 15:13:19 us=359000 do_ifconfig, ipv4=1, ipv6=0 2023-03-22 15:13:19 us=359000 NETSH: C:\WINDOWS\system32\netsh.exe interface ip set address 39 static XXXXX 2023-03-22 15:13:19 us=421000 NETSH: C:\WINDOWS\system32\netsh.exe interface ip delete dns 39 all 2023-03-22 15:13:19 us=484000 NETSH: C:\WINDOWS\system32\netsh.exe interface ip set dns 39 static XXXXX validate=no 2023-03-22 15:13:19 us=546000 NETSH: C:\WINDOWS\system32\netsh.exe interface ip delete wins 39 all 2023-03-22 15:13:19 us=593000 IPv4 MTU set to 1500 on interface 39 using SetIpInterfaceEntry() 2023-03-22 15:13:19 us=593000 Block_DNS: WFP engine opened 2023-03-22 15:13:19 us=593000 Block_DNS: Using existing sublayer 2023-03-22 15:13:19 us=593000 Block_DNS: Added permit filters for exe_path 2023-03-22 15:13:19 us=593000 Block_DNS: Added block filters for all interfaces 2023-03-22 15:13:19 us=593000 Block_DNS: Added permit filters for TAP interface 2023-03-22 15:13:19 us=593000 C:\WINDOWS\system32\route.exe ADD XXXXX MASK XXXXX METRIC 200 2023-03-22 15:13:19 us=593000 Route addition via ipapi [adaptive] succeeded 2023-03-22 15:13:19 us=609000 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-03-22 15:13:19 us=609000 Outgoing dynamic tls-crypt: Cipher 'AES-256-CTR' initialized with 256 bit key 2023-03-22 15:13:19 us=609000 Outgoing dynamic tls-crypt: Using 256 bit message hash 'SHA256' for HMAC authentication 2023-03-22 15:13:19 us=609000 Incoming dynamic tls-crypt: Cipher 'AES-256-CTR' initialized with 256 bit key 2023-03-22 15:13:19 us=609000 Incoming dynamic tls-crypt: Using 256 bit message hash 'SHA256' for HMAC authentication 2023-03-22 15:13:19 us=609000 Initialization Sequence Completed 2023-03-22 15:13:19 us=625000 Data Channel: cipher 'AES-256-GCM', peer-id: 5 2023-03-22 15:13:19 us=625000 Timers: ping 10, ping-restart 60 2023-03-22 15:13:19 us=625000 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt 2023-03-22 15:13:19 Start ipconfig commands for register-dns... 2023-03-22 15:13:19 C:\WINDOWS\system32\ipconfig.exe /flushdns 2023-03-22 15:13:19 C:\WINDOWS\system32\ipconfig.exe /registerdns 2023-03-22 15:13:22 End ipconfig commands for register-dns... 2023-03-22 15:13:32 us=156000 C:\WINDOWS\system32\route.exe DELETE XXXXX MASK XXXXX 2023-03-22 15:13:32 us=171000 Route deletion via IPAPI succeeded [adaptive] 2023-03-22 15:13:32 us=187000 Closing DCO interface 2023-03-22 15:13:32 us=187000 NETSH: C:\WINDOWS\system32\netsh.exe interface ipv4 delete dns 39 all 2023-03-22 15:13:32 us=234000 NETSH: C:\WINDOWS\system32\netsh.exe interface ipv4 delete address 39 XXXXX store=active 2023-03-22 15:13:32 us=296000 SIGTERM[hard,] received, process exiting ```

I don't know where I find log files from the interactive service, there are none in the C:\Program Files\OpenVPN\log directory.

EDIT: Question: This line here sets the err variable again, might this change the return code and thus produce the error? Then the line that deletes the filters directly after might just revert the DNS change? I am not sure if my understanding is correct. https://github.com/OpenVPN/openvpn/blob/a85257e78f0d9f922941ad981bc4272d0aaf5594/src/openvpnserv/interactive.c#L850 In the previous commit, this was different: https://github.com/OpenVPN/openvpn/blob/f8b4a8e396f29ba52043379b04f17df5467c28d5/src/openvpnserv/interactive.c#L821

It looks like it has to do with IPv6 - in our environment, we have no IPv6 enabled. Maybe we receive an error here on the IPv6 interface and thus the DNS change is reverted by the DeleteBlockDNS directly following? Maybe this is why you cannot reproduce it since you have IPv6 enabled? Maybe @chefino also has no IPv6 in his environment?

I am just guessing...

selvanair commented 1 year ago

I don't know where I find log files from the interactive service, there are none in the C:\Program Files\OpenVPN\log directory.

The only log is from openvpn.exe and its what you posted earlier. The service may write errors to the event log, but I suspect anything useful will be written in this case.

Do you have ipv6 disabled on the DCO adapter (in the adapter properties in control panel)? If yes, please enable it and try again from the GUI. If that fixes it I know what is causing this -- we now trigger a fatal error if changing the metric for ipv6 interface fails.

selvanair commented 1 year ago

It looks like it has to do with IPv6 - in our environment, we have no IPv6 enabled. Maybe we receive an error here on the IPv6 interface and thus the DNS change is reverted by the DeleteBlockDNS directly following? Maybe this is why you cannot reproduce it since you have IPv6 enabled? Maybe @chefino also has no IPv6 in his environment?

Yes, we cross-posted. You do not have to be actively using ipv6 -- just do not manually disable ipv6 on the adapter unless you have a strong reason for that.

addy90 commented 1 year ago

I did not disable IPv6 for myself. In the adapter settings, the checkbox in front of IPv6 is enabled on all adapters. However, it seems that on the device that I am using (initially not configured by me), IPv6 was disabled system wide via registry, at least I have found this setting on 0xFF as described here: https://learn.microsoft.com/en-us/troubleshoot/windows-server/networking/configure-ipv6-in-windows

selvanair commented 1 year ago

Well, unfortunately ipv6 is still a pariah by some sys admins :) Will fix the service to not treat this as an error.

addy90 commented 1 year ago

I apologise for this, it was (and it is) not my decision to disable IPv6 system wide on this specific device here! It seems have found the issue! You should be able to reproduce it when you disable IPv6 on the adapter manually, correct? Thank you for fixing this!

selvanair commented 1 year ago

No problem -- it was not a deliberate intent to make this error FATAL. Will try to get the fix in to 2.6.2 which is expected to be out very very soon.

cron2 commented 1 year ago

Hi,

On Wed, Mar 22, 2023 at 08:31:22AM -0700, Selva Nair wrote:

No problem -- it was not a deliberate intent to make this error FATAL. Will try to get the fix in to 2.6.2 which is expected to be out very very soon.

I'm on standby :-) - thanks for diving into this, and congratulations on having the right idea. I always get surprised by "IPv6 might be disabled"...

gert -- "If was one thing all people took for granted, was conviction that if you feed honest figures into a computer, honest figures come out. Never doubted it myself till I met a computer with a sense of humor." Robert A. Heinlein, The Moon is a Harsh Mistress

Gert Doering - Munich, Germany @.***