UDP TAP works, TCP TAP Causes Connection Reset Loop

ryanspletzer

Greetings,

If this isn't the right place to post this let me know and I'll put it in another area.

I've been struggling for a while with this one, not my first go-around with OpenVPN, but first time with the Buffalo 1750DHPD router. (DD-WRT Build 23709c firmware that came on the router.) OpenVPN server version is 2.3.2 and clients are 2.3.6 (tested on official clients and Tunnelblick on OS X, as well as older 2.3.2 client), same results for all clients.

With the following client and server configs and firewall rules (note I may have more FW rules than probably necessary atm, throwing things at the wall trying to get things to work), UDP will work TOTALLY fine (even without changing anything firewall-wise), but using TCP fails with looping connection resets. (What's even more infuriating was TCP *was* working at one point, but then one day I tried to connect an it suddenly wasn't anymore -- something caught in memory that was flushed out after a router restart maybe? Who knows...)

I know UDP is more performant and all-around works better, but sadly the corporate network I'm on at work is restrictive with UDP traffic... so would really like to get TCP working again.

I'll post the logs from server and client after this. Here are the configs and added firewall rules first:

Server (most of these set through the DD-WRT GUI except for push lines):

dh /tmp/openvpn/dh.pem
ca /tmp/openvpn/ca.crt
cert /tmp/openvpn/cert.pem
key /tmp/openvpn/key.pem
keepalive 10 120
verb 3
mute 3
syslog
writepid /var/run/openvpnd.pid
management 127.0.0.1 14
management-log-cache 100
topology subnet
script-security 2
port 443
proto tcp-server
cipher bf-cbc
auth sha1
client-config-dir /tmp/openvpn/ccd
comp-lzo adaptive
tls-server
ifconfig-pool-persist /tmp/openvpn/ip-pool 86400
client-to-client
tcp-nodelay
tun-mtu 1400
mtu-disc yes
server-bridge 192.168.2.1 255.255.255.0 192.168.2.101 192.168.2.200
dev tap2
push "dhcp-option DNS 8.8.8.8"
push "dhcp-option DNS 8.8.4.4"

Client:

client
dev tap
proto tcp-client
remote xxxxxxxxxxxx.no-ip.org 443
nobind
resolv-retry infinite
persist-key
persist-tun
tun-mtu 1400
auth sha1
float
comp-lzo
cipher BF-CBC
up-delay
pull

ca ca.crt
cert surfacepro2.crt
key surfacepro2.key

ns-cert-type server
verb 5

Firewall:

iptables -A INPUT -i tap2 -j ACCEPT
iptables -A INPUT -i br0 -j ACCEPT
iptables -A FORWARD -i br0 -j ACCEPT
iptables -I FORWARD -i br0 -o tap2 -j ACCEPT
iptables -I FORWARD -i tap2 -o br0 -j ACCEPT
iptables -I FORWARD 1 --source 192.168.2.0/24 -j ACCEPT
iptables -I INPUT -p tcp --dport 443 -j ACCEPT

Any help and pointers are greatly appreciated!!!

maikcat

please post logs from both sides...

Michael.

ryanspletzer

Here are the verb 5 Client and Server logs:

Client Log:

Tue Apr 07 13:46:31 2015 us=255464 Current Parameter Settings:
Tue Apr 07 13:46:31 2015 us=257447   config = 'surfacepro2.ovpn'
Tue Apr 07 13:46:31 2015 us=257447   mode = 0
Tue Apr 07 13:46:31 2015 us=257447   show_ciphers = DISABLED
Tue Apr 07 13:46:31 2015 us=257447   show_digests = DISABLED
Tue Apr 07 13:46:31 2015 us=257447   show_engines = DISABLED
Tue Apr 07 13:46:31 2015 us=257447   genkey = DISABLED
Tue Apr 07 13:46:31 2015 us=257447   key_pass_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=257447   show_tls_ciphers = DISABLED
Tue Apr 07 13:46:31 2015 us=257447 Connection profiles [default]:
Tue Apr 07 13:46:31 2015 us=257447   proto = tcp-client
Tue Apr 07 13:46:31 2015 us=257447   local = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=257447   local_port = 0
Tue Apr 07 13:46:31 2015 us=257447   remote = '68.188.249.156'
Tue Apr 07 13:46:31 2015 us=257447   remote_port = 443
Tue Apr 07 13:46:31 2015 us=258464   remote_float = ENABLED
Tue Apr 07 13:46:31 2015 us=258464   bind_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   bind_local = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   connect_retry_seconds = 5
Tue Apr 07 13:46:31 2015 us=258464   connect_timeout = 10
Tue Apr 07 13:46:31 2015 us=258464   connect_retry_max = 0
Tue Apr 07 13:46:31 2015 us=258464   socks_proxy_server = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   socks_proxy_port = 0
Tue Apr 07 13:46:31 2015 us=258464   socks_proxy_retry = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   tun_mtu = 1400
Tue Apr 07 13:46:31 2015 us=258464   tun_mtu_defined = ENABLED
Tue Apr 07 13:46:31 2015 us=258464   link_mtu = 1500
Tue Apr 07 13:46:31 2015 us=258464   link_mtu_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   tun_mtu_extra = 32
Tue Apr 07 13:46:31 2015 us=258464   tun_mtu_extra_defined = ENABLED
Tue Apr 07 13:46:31 2015 us=258464   mtu_discover_type = -1
Tue Apr 07 13:46:31 2015 us=258464   fragment = 0
Tue Apr 07 13:46:31 2015 us=258464   mssfix = 1450
Tue Apr 07 13:46:31 2015 us=258464   explicit_exit_notification = 0
Tue Apr 07 13:46:31 2015 us=258464 Connection profiles END
Tue Apr 07 13:46:31 2015 us=258464   remote_random = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   ipchange = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   dev = 'tap'
Tue Apr 07 13:46:31 2015 us=258464   dev_type = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   dev_node = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   lladdr = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   topology = 1
Tue Apr 07 13:46:31 2015 us=258464   tun_ipv6 = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_local = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_remote_netmask = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_noexec = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_nowarn = DISABLED
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_ipv6_local = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=258464   ifconfig_ipv6_netbits = 0
Tue Apr 07 13:46:31 2015 us=259444   ifconfig_ipv6_remote = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   shaper = 0
Tue Apr 07 13:46:31 2015 us=259444   mtu_test = 0
Tue Apr 07 13:46:31 2015 us=259444   mlock = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   keepalive_ping = 0
Tue Apr 07 13:46:31 2015 us=259444   keepalive_timeout = 0
Tue Apr 07 13:46:31 2015 us=259444   inactivity_timeout = 0
Tue Apr 07 13:46:31 2015 us=259444   ping_send_timeout = 0
Tue Apr 07 13:46:31 2015 us=259444   ping_rec_timeout = 0
Tue Apr 07 13:46:31 2015 us=259444   ping_rec_timeout_action = 0
Tue Apr 07 13:46:31 2015 us=259444   ping_timer_remote = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   remap_sigusr1 = 0
Tue Apr 07 13:46:31 2015 us=259444   persist_tun = ENABLED
Tue Apr 07 13:46:31 2015 us=259444   persist_local_ip = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   persist_remote_ip = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   persist_key = ENABLED
Tue Apr 07 13:46:31 2015 us=259444   passtos = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   resolve_retry_seconds = 1000000000
Tue Apr 07 13:46:31 2015 us=259444   username = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   groupname = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   chroot_dir = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   cd_dir = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   writepid = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   up_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   down_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=259444   down_pre = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   up_restart = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   up_delay = ENABLED
Tue Apr 07 13:46:31 2015 us=259444   daemon = DISABLED
Tue Apr 07 13:46:31 2015 us=259444   inetd = 0
Tue Apr 07 13:46:31 2015 us=259444   log = ENABLED
Tue Apr 07 13:46:31 2015 us=259444   suppress_timestamps = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   nice = 0
Tue Apr 07 13:46:31 2015 us=260466   verbosity = 5
Tue Apr 07 13:46:31 2015 us=260466   mute = 0
Tue Apr 07 13:46:31 2015 us=260466   status_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=260466   status_file_version = 1
Tue Apr 07 13:46:31 2015 us=260466   status_file_update_freq = 60
Tue Apr 07 13:46:31 2015 us=260466   occ = ENABLED
Tue Apr 07 13:46:31 2015 us=260466   rcvbuf = 0
Tue Apr 07 13:46:31 2015 us=260466   sndbuf = 0
Tue Apr 07 13:46:31 2015 us=260466   sockflags = 0
Tue Apr 07 13:46:31 2015 us=260466   fast_io = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   lzo = 7
Tue Apr 07 13:46:31 2015 us=260466   route_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=260466   route_default_gateway = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=260466   route_default_metric = 0
Tue Apr 07 13:46:31 2015 us=260466   route_noexec = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   route_delay = 5
Tue Apr 07 13:46:31 2015 us=260466   route_delay_window = 30
Tue Apr 07 13:46:31 2015 us=260466   route_delay_defined = ENABLED
Tue Apr 07 13:46:31 2015 us=260466   route_nopull = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   route_gateway_via_dhcp = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   max_routes = 100
Tue Apr 07 13:46:31 2015 us=260466   allow_pull_fqdn = DISABLED
Tue Apr 07 13:46:31 2015 us=260466   management_addr = '127.0.0.1'
Tue Apr 07 13:46:31 2015 us=260466   management_port = 25340
Tue Apr 07 13:46:31 2015 us=260466   management_user_pass = 'stdin'
Tue Apr 07 13:46:31 2015 us=260466   management_log_history_cache = 250
Tue Apr 07 13:46:31 2015 us=260466   management_echo_buffer_size = 100
Tue Apr 07 13:46:31 2015 us=260466   management_write_peer_info_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=260466   management_client_user = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=260466   management_client_group = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=261445   management_flags = 6
Tue Apr 07 13:46:31 2015 us=261445   shared_secret_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=261445   key_direction = 0
Tue Apr 07 13:46:31 2015 us=261445   ciphername_defined = ENABLED
Tue Apr 07 13:46:31 2015 us=261445   ciphername = 'BF-CBC'
Tue Apr 07 13:46:31 2015 us=261445   authname_defined = ENABLED
Tue Apr 07 13:46:31 2015 us=261445   authname = 'sha1'
Tue Apr 07 13:46:31 2015 us=261445   prng_hash = 'SHA1'
Tue Apr 07 13:46:31 2015 us=261445   prng_nonce_secret_len = 16
Tue Apr 07 13:46:31 2015 us=261445   keysize = 0
Tue Apr 07 13:46:31 2015 us=261445   engine = DISABLED
Tue Apr 07 13:46:31 2015 us=261445   replay = ENABLED
Tue Apr 07 13:46:31 2015 us=261445   mute_replay_warnings = DISABLED
Tue Apr 07 13:46:31 2015 us=261445   replay_window = 64
Tue Apr 07 13:46:31 2015 us=261445   replay_time = 15
Tue Apr 07 13:46:31 2015 us=261445   packet_id_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=261445   use_iv = ENABLED
Tue Apr 07 13:46:31 2015 us=261445   test_crypto = DISABLED
Tue Apr 07 13:46:31 2015 us=261445   tls_server = DISABLED
Tue Apr 07 13:46:31 2015 us=261445   tls_client = ENABLED
Tue Apr 07 13:46:31 2015 us=261445   key_method = 2
Tue Apr 07 13:46:31 2015 us=261445   ca_file = 'ca.crt'
Tue Apr 07 13:46:31 2015 us=262470   ca_path = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   dh_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   cert_file = 'surfacepro2.crt'
Tue Apr 07 13:46:31 2015 us=262470   priv_key_file = 'surfacepro2.key'
Tue Apr 07 13:46:31 2015 us=262470   pkcs12_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   cryptoapi_cert = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   cipher_list = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   tls_verify = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   tls_export_cert = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   verify_x509_type = 0
Tue Apr 07 13:46:31 2015 us=262470   verify_x509_name = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   crl_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   ns_cert_type = 1
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_ku[i] = 0
Tue Apr 07 13:46:31 2015 us=262470   remote_cert_eku = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=262470   ssl_flags = 0
Tue Apr 07 13:46:31 2015 us=262470   tls_timeout = 2
Tue Apr 07 13:46:31 2015 us=262470   renegotiate_bytes = 0
Tue Apr 07 13:46:31 2015 us=262470   renegotiate_packets = 0
Tue Apr 07 13:46:31 2015 us=263465   renegotiate_seconds = 3600
Tue Apr 07 13:46:31 2015 us=263465   handshake_window = 60
Tue Apr 07 13:46:31 2015 us=263465   transition_window = 3600
Tue Apr 07 13:46:31 2015 us=263465   single_session = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   push_peer_info = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   tls_exit = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   tls_auth_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_protected_authentication = DISABLED
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=263465   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_private_mode = 00000000
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_cert_private = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_pin_cache_period = -1
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_id = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=264464   pkcs11_id_management = DISABLED
Tue Apr 07 13:46:31 2015 us=264464   server_network = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=264464   server_netmask = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   server_network_ipv6 = ::
Tue Apr 07 13:46:31 2015 us=268465   server_netbits_ipv6 = 0
Tue Apr 07 13:46:31 2015 us=268465   server_bridge_ip = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   server_bridge_netmask = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   server_bridge_pool_start = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   server_bridge_pool_end = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_start = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_end = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_netmask = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_pool_persist_refresh_freq = 600
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_ipv6_pool_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_ipv6_pool_base = ::
Tue Apr 07 13:46:31 2015 us=268465   ifconfig_ipv6_pool_netbits = 0
Tue Apr 07 13:46:31 2015 us=268465   n_bcast_buf = 256
Tue Apr 07 13:46:31 2015 us=268465   tcp_queue_limit = 64
Tue Apr 07 13:46:31 2015 us=268465   real_hash_size = 256
Tue Apr 07 13:46:31 2015 us=268465   virtual_hash_size = 256
Tue Apr 07 13:46:31 2015 us=268465   client_connect_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=268465   learn_address_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=268465   client_disconnect_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=268465   client_config_dir = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=268465   ccd_exclusive = DISABLED
Tue Apr 07 13:46:31 2015 us=268465   tmp_dir = 'C:\Users\u582290\AppData\Local\Temp\'
Tue Apr 07 13:46:31 2015 us=268465   push_ifconfig_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   push_ifconfig_local = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=269465   push_ifconfig_remote_netmask = 0.0.0.0
Tue Apr 07 13:46:31 2015 us=269465   push_ifconfig_ipv6_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   push_ifconfig_ipv6_local = ::/0
Tue Apr 07 13:46:31 2015 us=269465   push_ifconfig_ipv6_remote = ::
Tue Apr 07 13:46:31 2015 us=269465   enable_c2c = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   duplicate_cn = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   cf_max = 0
Tue Apr 07 13:46:31 2015 us=269465   cf_per = 0
Tue Apr 07 13:46:31 2015 us=269465   max_clients = 1024
Tue Apr 07 13:46:31 2015 us=269465   max_routes_per_client = 256
Tue Apr 07 13:46:31 2015 us=269465   auth_user_pass_verify_script = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=269465   auth_user_pass_verify_script_via_file = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   client = ENABLED
Tue Apr 07 13:46:31 2015 us=269465   pull = ENABLED
Tue Apr 07 13:46:31 2015 us=269465   auth_user_pass_file = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=269465   show_net_up = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   route_method = 0
Tue Apr 07 13:46:31 2015 us=269465   ip_win32_defined = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   ip_win32_type = 3
Tue Apr 07 13:46:31 2015 us=269465   dhcp_masq_offset = 0
Tue Apr 07 13:46:31 2015 us=269465   dhcp_lease_time = 31536000
Tue Apr 07 13:46:31 2015 us=269465   tap_sleep = 0
Tue Apr 07 13:46:31 2015 us=269465   dhcp_options = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   dhcp_renew = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   dhcp_pre_release = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   dhcp_release = DISABLED
Tue Apr 07 13:46:31 2015 us=269465   domain = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=269465   netbios_scope = '[UNDEF]'
Tue Apr 07 13:46:31 2015 us=269465   netbios_node_type = 0
Tue Apr 07 13:46:31 2015 us=269465   disable_nbt = DISABLED
Tue Apr 07 13:46:31 2015 us=269465 OpenVPN 2.3.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [IPv6] built on Mar 19 2015
Tue Apr 07 13:46:31 2015 us=270465 library versions: OpenSSL 1.0.1m 19 Mar 2015, LZO 2.08
Enter Management Password:
Tue Apr 07 13:46:31 2015 us=270465 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Tue Apr 07 13:46:31 2015 us=270465 Need hold release from management interface, waiting...
Tue Apr 07 13:46:31 2015 us=684630 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Tue Apr 07 13:46:31 2015 us=798396 MANAGEMENT: CMD 'state on'
Tue Apr 07 13:46:31 2015 us=798396 MANAGEMENT: CMD 'log all on'
Tue Apr 07 13:46:32 2015 us=173403 MANAGEMENT: CMD 'hold off'
Tue Apr 07 13:46:32 2015 us=176385 MANAGEMENT: CMD 'hold release'
Tue Apr 07 13:46:32 2015 us=324393 LZO compression initialized
Tue Apr 07 13:46:32 2015 us=324393 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Tue Apr 07 13:46:32 2015 us=324393 Control Channel MTU parms [ L:1476 D:140 EF:40 EB:0 ET:0 EL:0 ]
Tue Apr 07 13:46:32 2015 us=324393 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Apr 07 13:46:32 2015 us=324393 Data Channel MTU parms [ L:1476 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Apr 07 13:46:32 2015 us=324393 Local Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Apr 07 13:46:32 2015 us=324393 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Apr 07 13:46:32 2015 us=324393 Local Options hash (VER=V4): 'ef060fcc'
Tue Apr 07 13:46:32 2015 us=324393 Expected Remote Options hash (VER=V4): '249a8e18'
Tue Apr 07 13:46:32 2015 us=325393 Attempting to establish TCP connection with [AF_INET]68.188.249.156:443 [nonblock]
Tue Apr 07 13:46:32 2015 us=325393 MANAGEMENT: >STATE:1428428792,TCP_CONNECT,,,
Tue Apr 07 13:46:33 2015 us=326004 TCP connection established with [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:33 2015 us=326004 TCPv4_CLIENT link local: [undef]
Tue Apr 07 13:46:33 2015 us=326004 TCPv4_CLIENT link remote: [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:33 2015 us=326004 MANAGEMENT: >STATE:1428428793,WAIT,,,
Tue Apr 07 13:46:33 2015 us=485157 Connection reset, restarting [0]
Tue Apr 07 13:46:33 2015 us=486129 TCP/UDP: Closing socket
Tue Apr 07 13:46:33 2015 us=486129 SIGUSR1[soft,connection-reset] received, process restarting
Tue Apr 07 13:46:33 2015 us=486129 MANAGEMENT: >STATE:1428428793,RECONNECTING,connection-reset,,
Tue Apr 07 13:46:33 2015 us=486129 Restart pause, 5 second(s)
Tue Apr 07 13:46:38 2015 us=488827 Re-using SSL/TLS context
Tue Apr 07 13:46:38 2015 us=488827 LZO compression initialized
Tue Apr 07 13:46:38 2015 us=488827 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Tue Apr 07 13:46:38 2015 us=488827 Control Channel MTU parms [ L:1476 D:140 EF:40 EB:0 ET:0 EL:0 ]
Tue Apr 07 13:46:38 2015 us=489806 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Apr 07 13:46:38 2015 us=489806 Data Channel MTU parms [ L:1476 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Apr 07 13:46:38 2015 us=489806 Local Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Apr 07 13:46:38 2015 us=489806 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Apr 07 13:46:38 2015 us=489806 Local Options hash (VER=V4): 'ef060fcc'
Tue Apr 07 13:46:38 2015 us=489806 Expected Remote Options hash (VER=V4): '249a8e18'
Tue Apr 07 13:46:38 2015 us=489806 Attempting to establish TCP connection with [AF_INET]68.188.249.156:443 [nonblock]
Tue Apr 07 13:46:38 2015 us=489806 MANAGEMENT: >STATE:1428428798,TCP_CONNECT,,,
Tue Apr 07 13:46:39 2015 us=491341 TCP connection established with [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:39 2015 us=491341 TCPv4_CLIENT link local: [undef]
Tue Apr 07 13:46:39 2015 us=492278 TCPv4_CLIENT link remote: [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:39 2015 us=492278 MANAGEMENT: >STATE:1428428799,WAIT,,,
Tue Apr 07 13:46:39 2015 us=628740 Connection reset, restarting [0]
Tue Apr 07 13:46:39 2015 us=629710 TCP/UDP: Closing socket
Tue Apr 07 13:46:39 2015 us=630710 SIGUSR1[soft,connection-reset] received, process restarting
Tue Apr 07 13:46:39 2015 us=630710 MANAGEMENT: >STATE:1428428799,RECONNECTING,connection-reset,,
Tue Apr 07 13:46:39 2015 us=630710 Restart pause, 5 second(s)
Tue Apr 07 13:46:44 2015 us=632951 Re-using SSL/TLS context
Tue Apr 07 13:46:44 2015 us=632951 LZO compression initialized
Tue Apr 07 13:46:44 2015 us=633892 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Tue Apr 07 13:46:44 2015 us=633892 Control Channel MTU parms [ L:1476 D:140 EF:40 EB:0 ET:0 EL:0 ]
Tue Apr 07 13:46:44 2015 us=634883 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Apr 07 13:46:44 2015 us=634883 Data Channel MTU parms [ L:1476 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Apr 07 13:46:44 2015 us=634883 Local Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Apr 07 13:46:44 2015 us=635894 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1476,tun-mtu 1432,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Apr 07 13:46:44 2015 us=635894 Local Options hash (VER=V4): 'ef060fcc'
Tue Apr 07 13:46:44 2015 us=635894 Expected Remote Options hash (VER=V4): '249a8e18'
Tue Apr 07 13:46:44 2015 us=635894 Attempting to establish TCP connection with [AF_INET]68.188.249.156:443 [nonblock]
Tue Apr 07 13:46:44 2015 us=635894 MANAGEMENT: >STATE:1428428804,TCP_CONNECT,,,
Tue Apr 07 13:46:45 2015 us=637529 TCP connection established with [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:45 2015 us=638512 TCPv4_CLIENT link local: [undef]
Tue Apr 07 13:46:45 2015 us=638512 TCPv4_CLIENT link remote: [AF_INET]68.188.249.156:443
Tue Apr 07 13:46:45 2015 us=638512 MANAGEMENT: >STATE:1428428805,WAIT,,,
Tue Apr 07 13:46:45 2015 us=768801 Connection reset, restarting [0]
Tue Apr 07 13:46:45 2015 us=769798 TCP/UDP: Closing socket
Tue Apr 07 13:46:45 2015 us=769798 SIGUSR1[soft,connection-reset] received, process restarting
Tue Apr 07 13:46:45 2015 us=770799 MANAGEMENT: >STATE:1428428805,RECONNECTING,connection-reset,,
Tue Apr 07 13:46:45 2015 us=770799 Restart pause, 5 second(s)
Tue Apr 07 13:46:48 2015 us=772464 SIGTERM[hard,init_instance] received, process exiting
Tue Apr 07 13:46:48 2015 us=772464 MANAGEMENT: >STATE:1428428808,EXITING,init_instance,,
WWW

Server Log (I did set it to verb 5 with vi in an ssh section, but this was all DD-WRT gave me, both through the GUI and in ssh...) :

407 13:25:25 I OpenVPN 2.3.2 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH] [IPv6] built on Jun 12 2014
407 13:25:25  MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:14
407 13:25:25 W 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 previousl  to
407 13:25:25 W NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
407 13:25:25  Diffie-Hellman initialized with 1024 bit key
407 13:25:25 W WARNING: normally if you use --mssfix and/or --fragment  you should also set --tun-mtu 1500 (currently it is 1400)
407 13:25:25  Socket Buffers: R=[87380->131072] S=[16384->131072]
407 13:25:25 I TUN/TAP device tap2 opened
407 13:25:25  TUN/TAP TX queue length set to 100
407 13:25:28 I Listening for incoming TCP connection on [undef]
407 13:25:28  Socket flags: TCP_NODELAY=1 succeeded
407 13:25:28 I TCPv4_SERVER link local (bound): [undef]
407 13:25:28 I TCPv4_SERVER link remote: [undef]
407 13:25:28  MULTI: multi_init called  r=256 v=256
407 13:25:28  IFCONFIG POOL: base=192.168.2.101 size=100  ipv6=0
407 13:25:28  IFCONFIG POOL LIST
407 13:25:28  MULTI: TCP INIT maxclients=1024 maxevents=1028
407 13:25:28 I Initialization Sequence Completed
407 13:42:54  MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14
407 13:42:54 D MANAGEMENT: CMD 'log 500'
407 13:42:54  MANAGEMENT: Client disconnected
407 13:44:13  MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14
407 13:44:13 D MANAGEMENT: CMD 'log 500'
407 13:44:13  MANAGEMENT: Client disconnected
407 13:47:39  MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14
407 13:47:39 D MANAGEMENT: CMD 'log 500'
19700101 00:00:00

maikcat

if you use the log directive in your server config to direct logging output file, does it still
produce the same output?

Michael.

ryanspletzer

I tried adding both log and log-append (with verb 5 back in) based on reading the man page, but for some reason both methods only produced the log of initialization sequence of OpenVPN, they did not log when I tried having client connect. This was all the log file had from that directive:

Wed Apr  8 08:59:37 2015 OpenVPN 2.3.2 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH] [IPv6] built on Jun 12 2014
Wed Apr  8 08:59:37 2015 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:14
Wed Apr  8 08:59:37 2015 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 adapte
Wed Apr  8 08:59:37 2015 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Apr  8 08:59:37 2015 Diffie-Hellman initialized with 1024 bit key
Wed Apr  8 08:59:37 2015 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Wed Apr  8 08:59:37 2015 Socket Buffers: R=[87380->131072] S=[16384->131072]
Wed Apr  8 08:59:37 2015 TUN/TAP device tap2 opened
Wed Apr  8 08:59:37 2015 TUN/TAP TX queue length set to 100
Wed Apr  8 08:59:39 2015 Listening for incoming TCP connection on [undef]
Wed Apr  8 08:59:39 2015 Socket flags: TCP_NODELAY=1 succeeded
Wed Apr  8 08:59:39 2015 TCPv4_SERVER link local (bound): [undef]
Wed Apr  8 08:59:39 2015 TCPv4_SERVER link remote: [undef]
Wed Apr  8 08:59:39 2015 MULTI: multi_init called, r=256 v=256
Wed Apr  8 08:59:39 2015 IFCONFIG POOL: base=192.168.2.101 size=100, ipv6=0
Wed Apr  8 08:59:39 2015 IFCONFIG POOL LIST
Wed Apr  8 08:59:39 2015 MULTI: TCP INIT maxclients=1024 maxevents=1028
Wed Apr  8 08:59:39 2015 Initialization Sequence Completed
Wed Apr  8 09:03:49 2015 Closing TUN/TAP interface
Wed Apr  8 09:03:49 2015 SIGTERM[hard,] received, process exiting
Wed Apr  8 09:03:53 2015 OpenVPN 2.3.2 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH] [IPv6] built on Jun 12 2014
Wed Apr  8 09:03:53 2015 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:14
Wed Apr  8 09:03:53 2015 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 adapte
Wed Apr  8 09:03:53 2015 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Apr  8 09:03:53 2015 Diffie-Hellman initialized with 1024 bit key
Wed Apr  8 09:03:53 2015 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Wed Apr  8 09:03:53 2015 Socket Buffers: R=[87380->131072] S=[16384->131072]
Wed Apr  8 09:03:53 2015 TUN/TAP device tap2 opened
Wed Apr  8 09:03:53 2015 TUN/TAP TX queue length set to 100
Wed Apr  8 09:03:56 2015 Listening for incoming TCP connection on [undef]
Wed Apr  8 09:03:56 2015 Socket flags: TCP_NODELAY=1 succeeded
Wed Apr  8 09:03:56 2015 TCPv4_SERVER link local (bound): [undef]
Wed Apr  8 09:03:56 2015 TCPv4_SERVER link remote: [undef]
Wed Apr  8 09:03:56 2015 MULTI: multi_init called, r=256 v=256
Wed Apr  8 09:03:56 2015 IFCONFIG POOL: base=192.168.2.101 size=100, ipv6=0
Wed Apr  8 09:03:56 2015 IFCONFIG POOL LIST
Wed Apr  8 09:03:56 2015 MULTI: TCP INIT maxclients=1024 maxevents=1028
Wed Apr  8 09:03:56 2015 Initialization Sequence Completed

And with verb 5 the regular log in the DD-WRT GUI and from looking over SSH terminal remained the same as before, no more verbosity...

AH, ok, dug some more. Though you can set verb 5 in the openvpn.conf file, OpenVPN doesn't care, it ignores it. In this particular router / DD-WRT model at least, you have to set the verbosity via the management interface, which is done with the following in an SSH session:

/usr/bin/nc 127.0.0.1 14

That drops you into the OpenVPN management interface, then you enter:

verb 5

And that actually sets it.

After doing that, here's the real verb 5 log from the server, but sadly there's no more actual verbosity, I even asked for the log directly from the OpenVPN management interface command itself to ensure I was getting a non-filtered view (it wasn't as nicely formatted as this, but same stuff):

20150408 09:46:19 MANAGEMENT: Client disconnected 
20150408 09:46:53 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14 
20150408 09:46:53 D MANAGEMENT: CMD 'state' 
20150408 09:46:53 MANAGEMENT: Client disconnected 
20150408 09:46:53 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14 
20150408 09:46:53 D MANAGEMENT: CMD 'state' 
20150408 09:46:53 MANAGEMENT: Client disconnected 
20150408 09:46:53 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14 
20150408 09:46:53 D MANAGEMENT: CMD 'state' 
20150408 09:46:53 MANAGEMENT: Client disconnected 
20150408 09:46:53 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14 
20150408 09:46:53 D MANAGEMENT: CMD 'status 2' 
20150408 09:46:53 MANAGEMENT: Client disconnected 
20150408 09:46:53 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:14 
20150408 09:46:53 D MANAGEMENT: CMD 'log 500'

maikcat

they did not log when I tried having client connect

maybe because firewall rules block traffic...?
if you telnet from outside to openvpn tcp port, do you recieve anything back?

Michael.

ryanspletzer

If I don't have telnet service on, I get a blinking cursor when telnet-ing to 443 from outside.

If I do have telnet service on, I still get a blinking cursor when telnet-ing to 443 from outside.

(I'm guessing that means I'm connected, because I can also telnet to 80 and get the same. Trying on another random port like 1995 does not open connection.)

If I do have telnet service on and turn on telnet remote management over 443 I get the DD-WRT management response:

DD-WRT v24-sp2 std (c) 2014 NewMedia-NET GmbH
Release: 06/12/14 (SVN revision: 23709c)

WZR1750DHPD login: root
Password:
==========================================================

 ____  ___    __        ______ _____         ____  _  _
 | _ \| _ \   \ \      / /  _ \_   _| __   _|___ \| || |
 || | || ||____\ \ /\ / /| |_) || |   \ \ / / __) | || |_
 ||_| ||_||_____\ V  V / |  _ < | |    \ V / / __/|__   _|
 |___/|___/      \_/\_/  |_| \_\|_|     \_/ |_____|  |_|

                       DD-WRT v24-sp2
                   http://www.dd-wrt.com

==========================================================


BusyBox v1.22.1 (2014-06-12 06:51:23 CEST) built-in shell (ash)
Enter 'help' for a list of built-in commands.

root@WZR1750DHPD:~# exit

I would guess that means my firewall is open for TCP 443. (Unless turning on telnet remote management on a specified port automatically adds a firewall rule to allow it...)

(Note: I turned remote management off after trying that, I know not to leave telnet management open to the outside...)

I would think this iptables line takes care of 443, unless there's another firewall rule I noted in the original post that would interfere with this.

iptables -I INPUT -p tcp --dport 443 -j ACCEPT