Opened 10 years ago
Closed 10 years ago
#349 closed Bug / Defect (fixed)
push-continuation not working correctly
Reported by: | fpeter | Owned by: | Gert Döring |
---|---|---|---|
Priority: | major | Milestone: | release 2.3.3 |
Component: | Generic / unclassified | Version: | OpenVPN 2.3.2 (Community Ed) |
Severity: | Not set (select this one, unless your'e a OpenVPN developer) | Keywords: | |
Cc: | David Sommerseth, Gert Döring |
Description
Server - debian 7.1
OpenVPN 2.2.1 i486-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Jun 19 2013 Originally developed by James Yonan Copyright (C) 2002-2010 OpenVPN Technologies, Inc. <sales@openvpn.net> $ ./configure --build=i486-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --libexecdir=${prefix}/lib/openvpn --disable-maintainer-mode --disable-dependency-tracking CFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security CPPFLAGS=-D_FORTIFY_SOURCE=2 CXXFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security FFLAGS=-g -O2 LDFLAGS=-fPIE -pie -Wl,-z,relro -Wl,-z,now --enable-password-save --host=i486-linux-gnu --build=i486-linux-gnu --prefix=/usr --mandir=${prefix}/share/man --with-ifconfig-path=/sbin/ifconfig --with-route-path=/sbin/route Compile time defines: ENABLE_CLIENT_SERVER ENABLE_DEBUG ENABLE_EUREPHIA ENABLE_FRAGMENT ENABLE_HTTP_PROXY ENABLE_MANAGEMENT ENABLE_MULTIHOME ENABLE_PASSWORD_SAVE ENABLE_PORT_SHARE ENABLE_SOCKS USE_CRYPTO USE_LIBDL USE_LZO USE_PF_INET6 USE_PKCS11 USE_SSL
Client - Ubuntu 12.04 + 13.04
OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Feb 27 2013 Originally developed by James Yonan Copyright (C) 2002-2010 OpenVPN Technologies, Inc. <sales@openvpn.net> $ ./configure --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --libexecdir=${prefix}/lib/openvpn --disable-maintainer-mode --disable-dependency-tracking CFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security CPPFLAGS=-D_FORTIFY_SOURCE=2 CXXFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security FFLAGS=-g -O2 LDFLAGS=-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now --enable-password-save --host=x86_64-linux-gnu --build=x86_64-linux-gnu --prefix=/usr --mandir=${prefix}/share/man --with-ifconfig-path=/sbin/ifconfig --with-route-path=/sbin/route Compile time defines: ENABLE_CLIENT_SERVER ENABLE_DEBUG ENABLE_EUREPHIA ENABLE_FRAGMENT ENABLE_HTTP_PROXY ENABLE_MANAGEMENT ENABLE_MULTIHOME ENABLE_PASSWORD_SAVE ENABLE_PORT_SHARE ENABLE_SOCKS USE_CRYPTO USE_LIBDL USE_LZO USE_PF_INET6 USE_PKCS11 USE_SSL
Problem
Depending on the user that is connected, we're pushing between 5 and 40+ routes. Some user's had problem with the stability of the VPN connection, according to the VPN server log the server received SIGUSR1 signals after a soft restart due to inactivity. Other users did not have this problem.
We looked into this and found out with tcpdump, that openVPN clients of users with 40+ routes are not sending the pushed "ping" every 10 seconds according to the config while the other users' openVPN clients are sending the pings.
In the corresponding client log you can see that the PUSH command coming from the server has been splitted in 2 parts (push-continuation). At this point, the routes are set, but some directives - like "ping" and "ping-restart" - are omitted, which results in clients with more routes having more timeouts due to inactivity.
Client-Log with push-continuation
/usr/sbin/openvpn --remote 77.244.108.138 --comp-lzo --nobind --dev tun --proto udp --port 443 --auth-nocache --up-restart --persist-key --persist-tun --client --ca /home/hexonet/Dokumente/VPN/meeting-office/hexonet-ca.crt --cert /home/hexonet/Dokumente/VPN/meeting-office/meeting-office-cert.pem --key /home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem --verb 5 Tue Nov 26 10:50:58 2013 us=569611 Current Parameter Settings: Tue Nov 26 10:50:58 2013 us=569852 config = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=569937 mode = 0 Tue Nov 26 10:50:58 2013 us=569996 persist_config = DISABLED Tue Nov 26 10:50:58 2013 us=570034 persist_mode = 1 Tue Nov 26 10:50:58 2013 us=570083 show_ciphers = DISABLED Tue Nov 26 10:50:58 2013 us=570118 show_digests = DISABLED Tue Nov 26 10:50:58 2013 us=570171 show_engines = DISABLED Tue Nov 26 10:50:58 2013 us=570206 genkey = DISABLED Tue Nov 26 10:50:58 2013 us=570259 key_pass_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=570312 show_tls_ciphers = DISABLED Tue Nov 26 10:50:58 2013 us=570358 Connection profiles [default]: Tue Nov 26 10:50:58 2013 us=570402 proto = udp Tue Nov 26 10:50:58 2013 us=570444 local = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=570486 local_port = 0 Tue Nov 26 10:50:58 2013 us=570721 remote = '77.244.108.138' Tue Nov 26 10:50:58 2013 us=570767 remote_port = 443 Tue Nov 26 10:50:58 2013 us=570840 remote_float = DISABLED Tue Nov 26 10:50:58 2013 us=570877 bind_defined = DISABLED Tue Nov 26 10:50:58 2013 us=570915 bind_local = DISABLED Tue Nov 26 10:50:58 2013 us=570925 connect_retry_seconds = 5 Tue Nov 26 10:50:58 2013 us=570934 connect_timeout = 10 Tue Nov 26 10:50:58 2013 us=570951 connect_retry_max = 0 Tue Nov 26 10:50:58 2013 us=570965 socks_proxy_server = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=570976 socks_proxy_port = 0 Tue Nov 26 10:50:58 2013 us=570985 socks_proxy_retry = DISABLED Tue Nov 26 10:50:58 2013 us=570995 Connection profiles END Tue Nov 26 10:50:58 2013 us=571005 remote_random = DISABLED Tue Nov 26 10:50:58 2013 us=571016 ipchange = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571026 dev = 'tun' Tue Nov 26 10:50:58 2013 us=571035 dev_type = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571045 dev_node = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571059 lladdr = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571071 topology = 1 Tue Nov 26 10:50:58 2013 us=571081 tun_ipv6 = DISABLED Tue Nov 26 10:50:58 2013 us=571104 ifconfig_local = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571117 ifconfig_remote_netmask = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571127 ifconfig_noexec = DISABLED Tue Nov 26 10:50:58 2013 us=571136 ifconfig_nowarn = DISABLED Tue Nov 26 10:50:58 2013 us=571151 ifconfig_ipv6_local = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571165 ifconfig_ipv6_netbits = 0 Tue Nov 26 10:50:58 2013 us=571175 ifconfig_ipv6_remote = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571185 shaper = 0 Tue Nov 26 10:50:58 2013 us=571195 tun_mtu = 1500 Tue Nov 26 10:50:58 2013 us=571204 tun_mtu_defined = ENABLED Tue Nov 26 10:50:58 2013 us=571217 link_mtu = 1500 Tue Nov 26 10:50:58 2013 us=571227 link_mtu_defined = DISABLED Tue Nov 26 10:50:58 2013 us=571237 tun_mtu_extra = 0 Tue Nov 26 10:50:58 2013 us=571273 tun_mtu_extra_defined = DISABLED Tue Nov 26 10:50:58 2013 us=571284 fragment = 0 Tue Nov 26 10:50:58 2013 us=571294 mtu_discover_type = -1 Tue Nov 26 10:50:58 2013 us=571304 mtu_test = 0 Tue Nov 26 10:50:58 2013 us=571320 mlock = DISABLED Tue Nov 26 10:50:58 2013 us=571332 keepalive_ping = 0 Tue Nov 26 10:50:58 2013 us=571341 keepalive_timeout = 0 Tue Nov 26 10:50:58 2013 us=571351 inactivity_timeout = 0 Tue Nov 26 10:50:58 2013 us=571360 ping_send_timeout = 0 Tue Nov 26 10:50:58 2013 us=571387 ping_rec_timeout = 0 Tue Nov 26 10:50:58 2013 us=571397 ping_rec_timeout_action = 0 Tue Nov 26 10:50:58 2013 us=571406 ping_timer_remote = DISABLED Tue Nov 26 10:50:58 2013 us=571416 remap_sigusr1 = 0 Tue Nov 26 10:50:58 2013 us=571431 explicit_exit_notification = 0 Tue Nov 26 10:50:58 2013 us=571446 persist_tun = ENABLED Tue Nov 26 10:50:58 2013 us=571456 persist_local_ip = DISABLED Tue Nov 26 10:50:58 2013 us=571466 persist_remote_ip = DISABLED Tue Nov 26 10:50:58 2013 us=571484 persist_key = ENABLED Tue Nov 26 10:50:58 2013 us=571496 mssfix = 1450 Tue Nov 26 10:50:58 2013 us=571506 passtos = DISABLED Tue Nov 26 10:50:58 2013 us=571515 resolve_retry_seconds = 1000000000 Tue Nov 26 10:50:58 2013 us=571531 username = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571545 groupname = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571556 chroot_dir = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571566 cd_dir = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571575 writepid = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571598 up_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571608 down_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571617 down_pre = DISABLED Tue Nov 26 10:50:58 2013 us=571633 up_restart = ENABLED Tue Nov 26 10:50:58 2013 us=571643 up_delay = DISABLED Tue Nov 26 10:50:58 2013 us=571653 daemon = DISABLED Tue Nov 26 10:50:58 2013 us=571662 inetd = 0 Tue Nov 26 10:50:58 2013 us=571672 log = DISABLED Tue Nov 26 10:50:58 2013 us=571690 suppress_timestamps = DISABLED Tue Nov 26 10:50:58 2013 us=571700 nice = 0 Tue Nov 26 10:50:58 2013 us=571710 verbosity = 5 Tue Nov 26 10:50:58 2013 us=571720 mute = 0 Tue Nov 26 10:50:58 2013 us=571731 gremlin = 0 Tue Nov 26 10:50:58 2013 us=571740 status_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571749 status_file_version = 1 Tue Nov 26 10:50:58 2013 us=571765 status_file_update_freq = 60 Tue Nov 26 10:50:58 2013 us=571775 occ = ENABLED Tue Nov 26 10:50:58 2013 us=571785 rcvbuf = 65536 Tue Nov 26 10:50:58 2013 us=571810 sndbuf = 65536 Tue Nov 26 10:50:58 2013 us=571823 sockflags = 0 Tue Nov 26 10:50:58 2013 us=571834 fast_io = DISABLED Tue Nov 26 10:50:58 2013 us=571843 lzo = 7 Tue Nov 26 10:50:58 2013 us=571853 route_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571868 route_default_gateway = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=571882 route_default_metric = 0 Tue Nov 26 10:50:58 2013 us=571892 route_noexec = DISABLED Tue Nov 26 10:50:58 2013 us=571912 route_delay = 0 Tue Nov 26 10:50:58 2013 us=571922 route_delay_window = 30 Tue Nov 26 10:50:58 2013 us=571934 route_delay_defined = DISABLED Tue Nov 26 10:50:58 2013 us=571944 route_nopull = DISABLED Tue Nov 26 10:50:58 2013 us=571954 route_gateway_via_dhcp = DISABLED Tue Nov 26 10:50:58 2013 us=571967 max_routes = 100 Tue Nov 26 10:50:58 2013 us=571978 allow_pull_fqdn = DISABLED Tue Nov 26 10:50:58 2013 us=571997 management_addr = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572009 management_port = 0 Tue Nov 26 10:50:58 2013 us=572019 management_user_pass = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572029 management_log_history_cache = 250 Tue Nov 26 10:50:58 2013 us=572038 management_echo_buffer_size = 100 Tue Nov 26 10:50:58 2013 us=572050 management_write_peer_info_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572068 management_client_user = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572085 management_client_group = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572098 management_flags = 0 Tue Nov 26 10:50:58 2013 us=572109 shared_secret_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572119 key_direction = 0 Tue Nov 26 10:50:58 2013 us=572129 ciphername_defined = ENABLED Tue Nov 26 10:50:58 2013 us=572138 ciphername = 'BF-CBC' Tue Nov 26 10:50:58 2013 us=572149 authname_defined = ENABLED Tue Nov 26 10:50:58 2013 us=572159 authname = 'SHA1' Tue Nov 26 10:50:58 2013 us=572168 prng_hash = 'SHA1' Tue Nov 26 10:50:58 2013 us=572190 prng_nonce_secret_len = 16 Tue Nov 26 10:50:58 2013 us=572202 keysize = 0 Tue Nov 26 10:50:58 2013 us=572212 engine = DISABLED Tue Nov 26 10:50:58 2013 us=572221 replay = ENABLED Tue Nov 26 10:50:58 2013 us=572231 mute_replay_warnings = DISABLED Tue Nov 26 10:50:58 2013 us=572243 replay_window = 64 Tue Nov 26 10:50:58 2013 us=572252 replay_time = 15 Tue Nov 26 10:50:58 2013 us=572262 packet_id_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572272 use_iv = ENABLED Tue Nov 26 10:50:58 2013 us=572283 test_crypto = DISABLED Tue Nov 26 10:50:58 2013 us=572303 tls_server = DISABLED Tue Nov 26 10:50:58 2013 us=572319 tls_client = ENABLED Tue Nov 26 10:50:58 2013 us=572329 key_method = 2 Tue Nov 26 10:50:58 2013 us=572339 ca_file = '/home/hexonet/Dokumente/VPN/meeting-office/hexonet-ca.crt' Tue Nov 26 10:50:58 2013 us=572349 ca_path = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572374 dh_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572386 cert_file = '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-cert.pem' Tue Nov 26 10:50:58 2013 us=572397 priv_key_file = '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem' Tue Nov 26 10:50:58 2013 us=572407 pkcs12_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572419 cipher_list = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572429 tls_verify = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572439 tls_export_cert = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572448 tls_remote = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572467 crl_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572477 ns_cert_type = 0 Tue Nov 26 10:50:58 2013 us=572487 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572502 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572516 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572526 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572536 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572545 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572575 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572585 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572594 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572609 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572622 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572633 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572642 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572652 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572661 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572672 remote_cert_ku[i] = 0 Tue Nov 26 10:50:58 2013 us=572691 remote_cert_eku = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572701 tls_timeout = 2 Tue Nov 26 10:50:58 2013 us=572713 renegotiate_bytes = 0 Tue Nov 26 10:50:58 2013 us=572723 renegotiate_packets = 0 Tue Nov 26 10:50:58 2013 us=572733 renegotiate_seconds = 3600 Tue Nov 26 10:50:58 2013 us=572745 handshake_window = 60 Tue Nov 26 10:50:58 2013 us=572755 transition_window = 3600 Tue Nov 26 10:50:58 2013 us=572774 single_session = DISABLED Tue Nov 26 10:50:58 2013 us=572786 push_peer_info = DISABLED Tue Nov 26 10:50:58 2013 us=572796 tls_exit = DISABLED Tue Nov 26 10:50:58 2013 us=572806 tls_auth_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=572818 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572828 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572838 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572853 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572864 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572883 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572893 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572906 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572916 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572926 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572941 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572955 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572966 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572984 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=572995 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=573010 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:50:58 2013 us=573024 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573036 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573045 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573055 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573065 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573088 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573098 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573108 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573124 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573134 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573153 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573164 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573176 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573186 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573195 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573210 pkcs11_private_mode = 00000000 Tue Nov 26 10:50:58 2013 us=573224 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573235 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573245 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573264 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573279 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573290 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573299 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573309 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573319 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573330 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573340 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573349 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573367 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573380 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573389 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573399 pkcs11_cert_private = DISABLED Tue Nov 26 10:50:58 2013 us=573416 pkcs11_pin_cache_period = -1 Tue Nov 26 10:50:58 2013 us=573428 pkcs11_id = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573438 pkcs11_id_management = DISABLED Tue Nov 26 10:50:58 2013 us=573457 server_network = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573475 server_netmask = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573497 server_network_ipv6 = :: Tue Nov 26 10:50:58 2013 us=573508 server_netbits_ipv6 = 0 Tue Nov 26 10:50:58 2013 us=573518 server_bridge_ip = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573532 server_bridge_netmask = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573543 server_bridge_pool_start = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573553 server_bridge_pool_end = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573566 ifconfig_pool_defined = DISABLED Tue Nov 26 10:50:58 2013 us=573577 ifconfig_pool_start = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573605 ifconfig_pool_end = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573616 ifconfig_pool_netmask = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573626 ifconfig_pool_persist_filename = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573636 ifconfig_pool_persist_refresh_freq = 600 Tue Nov 26 10:50:58 2013 us=573649 ifconfig_ipv6_pool_defined = DISABLED Tue Nov 26 10:50:58 2013 us=573659 ifconfig_ipv6_pool_base = :: Tue Nov 26 10:50:58 2013 us=573669 ifconfig_ipv6_pool_netbits = 0 Tue Nov 26 10:50:58 2013 us=573688 n_bcast_buf = 256 Tue Nov 26 10:50:58 2013 us=573700 tcp_queue_limit = 64 Tue Nov 26 10:50:58 2013 us=573709 real_hash_size = 256 Tue Nov 26 10:50:58 2013 us=573724 virtual_hash_size = 256 Tue Nov 26 10:50:58 2013 us=573738 client_connect_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573749 learn_address_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573759 client_disconnect_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573781 client_config_dir = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573792 ccd_exclusive = DISABLED Tue Nov 26 10:50:58 2013 us=573802 tmp_dir = '/tmp' Tue Nov 26 10:50:58 2013 us=573812 push_ifconfig_defined = DISABLED Tue Nov 26 10:50:58 2013 us=573825 push_ifconfig_local = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573835 push_ifconfig_remote_netmask = 0.0.0.0 Tue Nov 26 10:50:58 2013 us=573845 push_ifconfig_ipv6_defined = DISABLED Tue Nov 26 10:50:58 2013 us=573859 push_ifconfig_ipv6_local = ::/0 Tue Nov 26 10:50:58 2013 us=573879 push_ifconfig_ipv6_remote = :: Tue Nov 26 10:50:58 2013 us=573895 enable_c2c = DISABLED Tue Nov 26 10:50:58 2013 us=573908 duplicate_cn = DISABLED Tue Nov 26 10:50:58 2013 us=573918 cf_max = 0 Tue Nov 26 10:50:58 2013 us=573927 cf_per = 0 Tue Nov 26 10:50:58 2013 us=573942 max_clients = 1024 Tue Nov 26 10:50:58 2013 us=573967 max_routes_per_client = 256 Tue Nov 26 10:50:58 2013 us=573979 auth_user_pass_verify_script = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=573989 auth_user_pass_verify_script_via_file = DISABLED Tue Nov 26 10:50:58 2013 us=573999 ssl_flags = 0 Tue Nov 26 10:50:58 2013 us=574014 port_share_host = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=574028 port_share_port = 0 Tue Nov 26 10:50:58 2013 us=574038 client = ENABLED Tue Nov 26 10:50:58 2013 us=574058 pull = ENABLED Tue Nov 26 10:50:58 2013 us=574069 auth_user_pass_file = '[UNDEF]' Tue Nov 26 10:50:58 2013 us=574080 OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Feb 27 2013 Tue Nov 26 10:50:58 2013 us=574194 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info. Tue Nov 26 10:50:58 2013 us=574211 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables Tue Nov 26 10:50:58 2013 us=574733 WARNING: file '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem' is group or others accessible Tue Nov 26 10:50:58 2013 us=575124 LZO compression initialized Tue Nov 26 10:50:58 2013 us=575202 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ] Tue Nov 26 10:50:58 2013 us=575243 Socket Buffers: R=[229376->131072] S=[229376->131072] Tue Nov 26 10:50:58 2013 us=575285 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ] Tue Nov 26 10:50:58 2013 us=575305 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' Tue Nov 26 10:50:58 2013 us=575328 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server' Tue Nov 26 10:50:58 2013 us=575349 Local Options hash (VER=V4): '41690919' Tue Nov 26 10:50:58 2013 us=575368 Expected Remote Options hash (VER=V4): '530fdded' Tue Nov 26 10:50:58 2013 us=575385 UDPv4 link local: [undef] Tue Nov 26 10:50:58 2013 us=575398 UDPv4 link remote: [AF_INET]77.244.108.138:443 WRTue Nov 26 10:50:58 2013 us=589244 TLS: Initial packet from [AF_INET]77.244.108.138:443, sid=549c093b 7027bd0d WWWWRRRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRTue Nov 26 10:50:58 2013 us=732946 VERIFY OK: depth=1, /C=DE/ST=Saarland/L=Homburg/O=HEXONET_GmbH/OU=NOC/CN=HEXONET_Certificate_Authority/emailAddress=noc@hexonet.net Tue Nov 26 10:50:58 2013 us=733580 VERIFY OK: depth=0, /C=DE/ST=Saarland/L=Homburg/O=HEXONET_GmbH/O=f92229a9c920b8edda0c4ec880d8e83b/OU=NOC/CN=vpn1/emailAddress=noc@hexonet.net WRWRWRWRWRWRWRWRWRWRWWWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRRRRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWWWWRRRRWRWRTue Nov 26 10:50:58 2013 us=984155 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Tue Nov 26 10:50:58 2013 us=984237 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Tue Nov 26 10:50:58 2013 us=984407 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Tue Nov 26 10:50:58 2013 us=984456 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication WTue Nov 26 10:50:58 2013 us=984681 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA Tue Nov 26 10:50:58 2013 us=984766 [vpn1] Peer Connection Initiated with [AF_INET]77.244.108.138:443 Tue Nov 26 10:51:01 2013 us=127155 SENT CONTROL [vpn1]: 'PUSH_REQUEST' (status=1) WRRWRWRWRWRWRWRWRWRWRWRTue Nov 26 10:51:01 2013 us=170502 PUSH: Received control message: 'PUSH_REPLY,ping 10,ping-restart 45,explicit-exit-notify 2,route-gateway 10.100.100.1,topology subnet,route 10.10.10.10 255.255.255.255,route 10.11.10.10 255.255.255.255,route 10.12.10.10 255.255.255.255,route 10.13.10.10 255.255.255.255,route 10.14.10.10 255.255.255.255,route 10.15.10.10 255.255.255.255,route 10.16.10.10 255.255.255.255,route 10.17.10.10 255.255.255.255,route 10.18.10.10 255.255.255.255,route 10.19.10.10 255.255.255.255,route 10.20.10.10 255.255.255.255,route 10.21.10.10 255.255.255.255,route 10.22.10.10 255.255.255.255,route 10.23.10.10 255.255.255.255,route 10.24.10.10 255.255.255.255,route 10.25.10.10 255.255.255.255,route 10.26.10.10 255.255.255.255,route 10.27.10.10 255.255.255.255,route 10.28.10.10 255.255.255.255,route 10.29.10.10 255.255.255.255,route 10.30.10.10 255.255.255.255,route 10.31.10.10 255.255.255.255,route 10.32.10.10 255.255.255.255,route 10.33.10.10 255.255.255.255,route 10.34.10.10 255.255.255.255,push-continuation 2' WRWRTue Nov 26 10:51:01 2013 us=180596 PUSH: Received control message: 'PUSH_REPLY,route 10.35.10.10 255.255.255.255,ifconfig 10.100.100.27 255.255.255.0,push-continuation 1' Tue Nov 26 10:51:01 2013 us=180752 OPTIONS IMPORT: --ifconfig/up options modified Tue Nov 26 10:51:01 2013 us=180798 OPTIONS IMPORT: route options modified Tue Nov 26 10:51:01 2013 us=181193 ROUTE default_gateway=192.168.52.1 Tue Nov 26 10:51:01 2013 us=184305 TUN/TAP device tun0 opened Tue Nov 26 10:51:01 2013 us=184576 TUN/TAP TX queue length set to 100 Tue Nov 26 10:51:01 2013 us=184736 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0 Tue Nov 26 10:51:01 2013 us=184929 /sbin/ifconfig tun0 10.100.100.27 netmask 255.255.255.0 mtu 1500 broadcast 10.100.100.255 Tue Nov 26 10:51:01 2013 us=197183 /sbin/route add -net 10.10.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=199214 /sbin/route add -net 10.11.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=200859 /sbin/route add -net 10.12.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=202391 /sbin/route add -net 10.13.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=203828 /sbin/route add -net 10.14.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=205191 /sbin/route add -net 10.15.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=206473 /sbin/route add -net 10.16.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=207764 /sbin/route add -net 10.17.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=209023 /sbin/route add -net 10.18.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=210303 /sbin/route add -net 10.19.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=211633 /sbin/route add -net 10.20.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=213371 /sbin/route add -net 10.21.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=215189 /sbin/route add -net 10.22.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=216880 /sbin/route add -net 10.23.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=218628 /sbin/route add -net 10.24.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=220190 /sbin/route add -net 10.25.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=221767 /sbin/route add -net 10.26.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=223506 /sbin/route add -net 10.27.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=225256 /sbin/route add -net 10.28.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=227033 /sbin/route add -net 10.29.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=228800 /sbin/route add -net 10.30.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=230601 /sbin/route add -net 10.31.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=232369 /sbin/route add -net 10.32.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=234134 /sbin/route add -net 10.33.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=236008 /sbin/route add -net 10.34.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=237807 /sbin/route add -net 10.35.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:01 2013 us=239477 Initialization Sequence Completed
When tracing packets with tcpdump on port 443 (which we use for openVPN), in this case we only see ping packets from the server to the client every 10 seconds:
10:51:11.039625 IP tvpn1.x.hexonet.net.https > hexonet-meetingraum.hom.de.hexonet.net.53835: UDP, length 53 10:51:21.347139 IP tvpn1.x.hexonet.net.https > hexonet-meetingraum.hom.de.hexonet.net.53835: UDP, length 53
Client-Log without push-continuation (lees routes are pushed)
/usr/sbin/openvpn --remote 77.244.108.138 --comp-lzo --nobind --dev tun --proto udp --port 443 --auth-nocache --up-restart --persist-key --persist-tun --client --ca /home/hexonet/Dokumente/VPN/meeting-office/hexonet-ca.crt --cert /home/hexonet/Dokumente/VPN/meeting-office/meeting-office-cert.pem --key /home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem --verb 5 Tue Nov 26 10:51:53 2013 us=193445 Current Parameter Settings: Tue Nov 26 10:51:53 2013 us=193679 config = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=193725 mode = 0 Tue Nov 26 10:51:53 2013 us=193810 persist_config = DISABLED Tue Nov 26 10:51:53 2013 us=193850 persist_mode = 1 Tue Nov 26 10:51:53 2013 us=193886 show_ciphers = DISABLED Tue Nov 26 10:51:53 2013 us=193940 show_digests = DISABLED Tue Nov 26 10:51:53 2013 us=193998 show_engines = DISABLED Tue Nov 26 10:51:53 2013 us=194034 genkey = DISABLED Tue Nov 26 10:51:53 2013 us=194088 key_pass_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194143 show_tls_ciphers = DISABLED Tue Nov 26 10:51:53 2013 us=194204 Connection profiles [default]: Tue Nov 26 10:51:53 2013 us=194245 proto = udp Tue Nov 26 10:51:53 2013 us=194287 local = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194329 local_port = 0 Tue Nov 26 10:51:53 2013 us=194369 remote = '77.244.108.138' Tue Nov 26 10:51:53 2013 us=194609 remote_port = 443 Tue Nov 26 10:51:53 2013 us=194672 remote_float = DISABLED Tue Nov 26 10:51:53 2013 us=194711 bind_defined = DISABLED Tue Nov 26 10:51:53 2013 us=194753 bind_local = DISABLED Tue Nov 26 10:51:53 2013 us=194795 connect_retry_seconds = 5 Tue Nov 26 10:51:53 2013 us=194814 connect_timeout = 10 Tue Nov 26 10:51:53 2013 us=194824 connect_retry_max = 0 Tue Nov 26 10:51:53 2013 us=194850 socks_proxy_server = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194862 socks_proxy_port = 0 Tue Nov 26 10:51:53 2013 us=194871 socks_proxy_retry = DISABLED Tue Nov 26 10:51:53 2013 us=194881 Connection profiles END Tue Nov 26 10:51:53 2013 us=194895 remote_random = DISABLED Tue Nov 26 10:51:53 2013 us=194905 ipchange = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194915 dev = 'tun' Tue Nov 26 10:51:53 2013 us=194927 dev_type = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194937 dev_node = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194947 lladdr = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194959 topology = 1 Tue Nov 26 10:51:53 2013 us=194970 tun_ipv6 = DISABLED Tue Nov 26 10:51:53 2013 us=194980 ifconfig_local = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=194991 ifconfig_remote_netmask = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195003 ifconfig_noexec = DISABLED Tue Nov 26 10:51:53 2013 us=195012 ifconfig_nowarn = DISABLED Tue Nov 26 10:51:53 2013 us=195022 ifconfig_ipv6_local = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195034 ifconfig_ipv6_netbits = 0 Tue Nov 26 10:51:53 2013 us=195044 ifconfig_ipv6_remote = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195066 shaper = 0 Tue Nov 26 10:51:53 2013 us=195078 tun_mtu = 1500 Tue Nov 26 10:51:53 2013 us=195088 tun_mtu_defined = ENABLED Tue Nov 26 10:51:53 2013 us=195099 link_mtu = 1500 Tue Nov 26 10:51:53 2013 us=195110 link_mtu_defined = DISABLED Tue Nov 26 10:51:53 2013 us=195119 tun_mtu_extra = 0 Tue Nov 26 10:51:53 2013 us=195136 tun_mtu_extra_defined = DISABLED Tue Nov 26 10:51:53 2013 us=195146 fragment = 0 Tue Nov 26 10:51:53 2013 us=195165 mtu_discover_type = -1 Tue Nov 26 10:51:53 2013 us=195175 mtu_test = 0 Tue Nov 26 10:51:53 2013 us=195185 mlock = DISABLED Tue Nov 26 10:51:53 2013 us=195195 keepalive_ping = 0 Tue Nov 26 10:51:53 2013 us=195211 keepalive_timeout = 0 Tue Nov 26 10:51:53 2013 us=195222 inactivity_timeout = 0 Tue Nov 26 10:51:53 2013 us=195232 ping_send_timeout = 0 Tue Nov 26 10:51:53 2013 us=195253 ping_rec_timeout = 0 Tue Nov 26 10:51:53 2013 us=195269 ping_rec_timeout_action = 0 Tue Nov 26 10:51:53 2013 us=195282 ping_timer_remote = DISABLED Tue Nov 26 10:51:53 2013 us=195291 remap_sigusr1 = 0 Tue Nov 26 10:51:53 2013 us=195301 explicit_exit_notification = 0 Tue Nov 26 10:51:53 2013 us=195313 persist_tun = ENABLED Tue Nov 26 10:51:53 2013 us=195328 persist_local_ip = DISABLED Tue Nov 26 10:51:53 2013 us=195340 persist_remote_ip = DISABLED Tue Nov 26 10:51:53 2013 us=195359 persist_key = ENABLED Tue Nov 26 10:51:53 2013 us=195370 mssfix = 1450 Tue Nov 26 10:51:53 2013 us=195379 passtos = DISABLED Tue Nov 26 10:51:53 2013 us=195389 resolve_retry_seconds = 1000000000 Tue Nov 26 10:51:53 2013 us=195405 username = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195417 groupname = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195427 chroot_dir = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195446 cd_dir = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195461 writepid = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195475 up_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195486 down_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195496 down_pre = DISABLED Tue Nov 26 10:51:53 2013 us=195506 up_restart = ENABLED Tue Nov 26 10:51:53 2013 us=195515 up_delay = DISABLED Tue Nov 26 10:51:53 2013 us=195531 daemon = DISABLED Tue Nov 26 10:51:53 2013 us=195543 inetd = 0 Tue Nov 26 10:51:53 2013 us=195560 log = DISABLED Tue Nov 26 10:51:53 2013 us=195570 suppress_timestamps = DISABLED Tue Nov 26 10:51:53 2013 us=195580 nice = 0 Tue Nov 26 10:51:53 2013 us=195595 verbosity = 5 Tue Nov 26 10:51:53 2013 us=195609 mute = 0 Tue Nov 26 10:51:53 2013 us=195620 gremlin = 0 Tue Nov 26 10:51:53 2013 us=195630 status_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195647 status_file_version = 1 Tue Nov 26 10:51:53 2013 us=195663 status_file_update_freq = 60 Tue Nov 26 10:51:53 2013 us=195673 occ = ENABLED Tue Nov 26 10:51:53 2013 us=195684 rcvbuf = 65536 Tue Nov 26 10:51:53 2013 us=195694 sndbuf = 65536 Tue Nov 26 10:51:53 2013 us=195704 sockflags = 0 Tue Nov 26 10:51:53 2013 us=195719 fast_io = DISABLED Tue Nov 26 10:51:53 2013 us=195729 lzo = 7 Tue Nov 26 10:51:53 2013 us=195740 route_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195750 route_default_gateway = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195776 route_default_metric = 0 Tue Nov 26 10:51:53 2013 us=195790 route_noexec = DISABLED Tue Nov 26 10:51:53 2013 us=195803 route_delay = 0 Tue Nov 26 10:51:53 2013 us=195813 route_delay_window = 30 Tue Nov 26 10:51:53 2013 us=195823 route_delay_defined = DISABLED Tue Nov 26 10:51:53 2013 us=195839 route_nopull = DISABLED Tue Nov 26 10:51:53 2013 us=195849 route_gateway_via_dhcp = DISABLED Tue Nov 26 10:51:53 2013 us=195860 max_routes = 100 Tue Nov 26 10:51:53 2013 us=195879 allow_pull_fqdn = DISABLED Tue Nov 26 10:51:53 2013 us=195889 management_addr = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195901 management_port = 0 Tue Nov 26 10:51:53 2013 us=195910 management_user_pass = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195920 management_log_history_cache = 250 Tue Nov 26 10:51:53 2013 us=195934 management_echo_buffer_size = 100 Tue Nov 26 10:51:53 2013 us=195945 management_write_peer_info_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195955 management_client_user = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195965 management_client_group = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=195982 management_flags = 0 Tue Nov 26 10:51:53 2013 us=195993 shared_secret_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196003 key_direction = 0 Tue Nov 26 10:51:53 2013 us=196013 ciphername_defined = ENABLED Tue Nov 26 10:51:53 2013 us=196023 ciphername = 'BF-CBC' Tue Nov 26 10:51:53 2013 us=196046 authname_defined = ENABLED Tue Nov 26 10:51:53 2013 us=196060 authname = 'SHA1' Tue Nov 26 10:51:53 2013 us=196071 prng_hash = 'SHA1' Tue Nov 26 10:51:53 2013 us=196080 prng_nonce_secret_len = 16 Tue Nov 26 10:51:53 2013 us=196090 keysize = 0 Tue Nov 26 10:51:53 2013 us=196100 engine = DISABLED Tue Nov 26 10:51:53 2013 us=196115 replay = ENABLED Tue Nov 26 10:51:53 2013 us=196129 mute_replay_warnings = DISABLED Tue Nov 26 10:51:53 2013 us=196148 replay_window = 64 Tue Nov 26 10:51:53 2013 us=196158 replay_time = 15 Tue Nov 26 10:51:53 2013 us=196167 packet_id_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196177 use_iv = ENABLED Tue Nov 26 10:51:53 2013 us=196192 test_crypto = DISABLED Tue Nov 26 10:51:53 2013 us=196207 tls_server = DISABLED Tue Nov 26 10:51:53 2013 us=196219 tls_client = ENABLED Tue Nov 26 10:51:53 2013 us=196238 key_method = 2 Tue Nov 26 10:51:53 2013 us=196249 ca_file = '/home/hexonet/Dokumente/VPN/meeting-office/hexonet-ca.crt' Tue Nov 26 10:51:53 2013 us=196264 ca_path = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196279 dh_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196290 cert_file = '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-cert.pem' Tue Nov 26 10:51:53 2013 us=196301 priv_key_file = '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem' Tue Nov 26 10:51:53 2013 us=196314 pkcs12_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196324 cipher_list = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196339 tls_verify = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196358 tls_export_cert = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196369 tls_remote = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196379 crl_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196388 ns_cert_type = 0 Tue Nov 26 10:51:53 2013 us=196399 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196410 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196420 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196429 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196440 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196451 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196460 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196470 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196482 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196501 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196511 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196524 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196534 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196543 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196555 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196575 remote_cert_ku[i] = 0 Tue Nov 26 10:51:53 2013 us=196592 remote_cert_eku = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196604 tls_timeout = 2 Tue Nov 26 10:51:53 2013 us=196614 renegotiate_bytes = 0 Tue Nov 26 10:51:53 2013 us=196624 renegotiate_packets = 0 Tue Nov 26 10:51:53 2013 us=196635 renegotiate_seconds = 3600 Tue Nov 26 10:51:53 2013 us=196646 handshake_window = 60 Tue Nov 26 10:51:53 2013 us=196656 transition_window = 3600 Tue Nov 26 10:51:53 2013 us=196666 single_session = DISABLED Tue Nov 26 10:51:53 2013 us=196689 push_peer_info = DISABLED Tue Nov 26 10:51:53 2013 us=196701 tls_exit = DISABLED Tue Nov 26 10:51:53 2013 us=196710 tls_auth_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=196721 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196731 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196743 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196753 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196763 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196778 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196800 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196810 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196820 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196836 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196851 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196864 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196874 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196892 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196908 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196919 pkcs11_protected_authentication = DISABLED Tue Nov 26 10:51:53 2013 us=196931 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=196942 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=196952 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=196962 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=196977 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=196995 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197006 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197016 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197026 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197041 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197056 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197068 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197088 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197098 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197113 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197124 pkcs11_private_mode = 00000000 Tue Nov 26 10:51:53 2013 us=197135 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197145 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197155 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197165 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197176 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197186 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197211 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197225 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197238 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197248 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197258 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197268 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197281 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197291 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197301 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197316 pkcs11_cert_private = DISABLED Tue Nov 26 10:51:53 2013 us=197327 pkcs11_pin_cache_period = -1 Tue Nov 26 10:51:53 2013 us=197344 pkcs11_id = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197354 pkcs11_id_management = DISABLED Tue Nov 26 10:51:53 2013 us=197372 server_network = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197388 server_netmask = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197402 server_network_ipv6 = :: Tue Nov 26 10:51:53 2013 us=197417 server_netbits_ipv6 = 0 Tue Nov 26 10:51:53 2013 us=197440 server_bridge_ip = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197451 server_bridge_netmask = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197462 server_bridge_pool_start = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197478 server_bridge_pool_end = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197489 ifconfig_pool_defined = DISABLED Tue Nov 26 10:51:53 2013 us=197501 ifconfig_pool_start = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197512 ifconfig_pool_end = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197537 ifconfig_pool_netmask = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197547 ifconfig_pool_persist_filename = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197558 ifconfig_pool_persist_refresh_freq = 600 Tue Nov 26 10:51:53 2013 us=197574 ifconfig_ipv6_pool_defined = DISABLED Tue Nov 26 10:51:53 2013 us=197586 ifconfig_ipv6_pool_base = :: Tue Nov 26 10:51:53 2013 us=197597 ifconfig_ipv6_pool_netbits = 0 Tue Nov 26 10:51:53 2013 us=197607 n_bcast_buf = 256 Tue Nov 26 10:51:53 2013 us=197617 tcp_queue_limit = 64 Tue Nov 26 10:51:53 2013 us=197637 real_hash_size = 256 Tue Nov 26 10:51:53 2013 us=197648 virtual_hash_size = 256 Tue Nov 26 10:51:53 2013 us=197663 client_connect_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197675 learn_address_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197686 client_disconnect_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197696 client_config_dir = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197706 ccd_exclusive = DISABLED Tue Nov 26 10:51:53 2013 us=197722 tmp_dir = '/tmp' Tue Nov 26 10:51:53 2013 us=197741 push_ifconfig_defined = DISABLED Tue Nov 26 10:51:53 2013 us=197752 push_ifconfig_local = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197763 push_ifconfig_remote_netmask = 0.0.0.0 Tue Nov 26 10:51:53 2013 us=197774 push_ifconfig_ipv6_defined = DISABLED Tue Nov 26 10:51:53 2013 us=197786 push_ifconfig_ipv6_local = ::/0 Tue Nov 26 10:51:53 2013 us=197796 push_ifconfig_ipv6_remote = :: Tue Nov 26 10:51:53 2013 us=197806 enable_c2c = DISABLED Tue Nov 26 10:51:53 2013 us=197822 duplicate_cn = DISABLED Tue Nov 26 10:51:53 2013 us=197841 cf_max = 0 Tue Nov 26 10:51:53 2013 us=197852 cf_per = 0 Tue Nov 26 10:51:53 2013 us=197862 max_clients = 1024 Tue Nov 26 10:51:53 2013 us=197872 max_routes_per_client = 256 Tue Nov 26 10:51:53 2013 us=197888 auth_user_pass_verify_script = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197902 auth_user_pass_verify_script_via_file = DISABLED Tue Nov 26 10:51:53 2013 us=197914 ssl_flags = 0 Tue Nov 26 10:51:53 2013 us=197933 port_share_host = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197944 port_share_port = 0 Tue Nov 26 10:51:53 2013 us=197960 client = ENABLED Tue Nov 26 10:51:53 2013 us=197973 pull = ENABLED Tue Nov 26 10:51:53 2013 us=197983 auth_user_pass_file = '[UNDEF]' Tue Nov 26 10:51:53 2013 us=197994 OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Feb 27 2013 Tue Nov 26 10:51:53 2013 us=198099 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info. Tue Nov 26 10:51:53 2013 us=198115 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables Tue Nov 26 10:51:53 2013 us=198627 WARNING: file '/home/hexonet/Dokumente/VPN/meeting-office/meeting-office-key.pem' is group or others accessible Tue Nov 26 10:51:53 2013 us=199021 LZO compression initialized Tue Nov 26 10:51:53 2013 us=199095 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ] Tue Nov 26 10:51:53 2013 us=199148 Socket Buffers: R=[229376->131072] S=[229376->131072] Tue Nov 26 10:51:53 2013 us=199178 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ] Tue Nov 26 10:51:53 2013 us=199198 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' Tue Nov 26 10:51:53 2013 us=199211 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server' Tue Nov 26 10:51:53 2013 us=199232 Local Options hash (VER=V4): '41690919' Tue Nov 26 10:51:53 2013 us=199248 Expected Remote Options hash (VER=V4): '530fdded' Tue Nov 26 10:51:53 2013 us=199265 UDPv4 link local: [undef] Tue Nov 26 10:51:53 2013 us=199289 UDPv4 link remote: [AF_INET]77.244.108.138:443 WRTue Nov 26 10:51:53 2013 us=211802 TLS: Initial packet from [AF_INET]77.244.108.138:443, sid=e16a46ad 2f94e1be WWWWRRRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRTue Nov 26 10:51:53 2013 us=356998 VERIFY OK: depth=1, /C=DE/ST=Saarland/L=Homburg/O=HEXONET_GmbH/OU=NOC/CN=HEXONET_Certificate_Authority/emailAddress=noc@hexonet.net Tue Nov 26 10:51:53 2013 us=357634 VERIFY OK: depth=0, /C=DE/ST=Saarland/L=Homburg/O=HEXONET_GmbH/O=f92229a9c920b8edda0c4ec880d8e83b/OU=NOC/CN=vpn1/emailAddress=noc@hexonet.net WRWRWRWRWRWRWRWRWRWRWWWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRRRRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWWWWRRRRWRWRTue Nov 26 10:51:53 2013 us=605147 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Tue Nov 26 10:51:53 2013 us=605228 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Tue Nov 26 10:51:53 2013 us=605387 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Tue Nov 26 10:51:53 2013 us=605436 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication WTue Nov 26 10:51:53 2013 us=605633 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA Tue Nov 26 10:51:53 2013 us=605717 [vpn1] Peer Connection Initiated with [AF_INET]77.244.108.138:443 Tue Nov 26 10:51:55 2013 us=632018 SENT CONTROL [vpn1]: 'PUSH_REQUEST' (status=1) WRRWRWRWRWRWRWRWRWRWRWRTue Nov 26 10:51:55 2013 us=671220 PUSH: Received control message: 'PUSH_REPLY,ping 10,ping-restart 45,explicit-exit-notify 2,route-gateway 10.100.100.1,topology subnet,route 10.10.10.10 255.255.255.255,route 10.11.10.10 255.255.255.255,route 10.12.10.10 255.255.255.255,route 10.13.10.10 255.255.255.255,route 10.14.10.10 255.255.255.255,route 10.15.10.10 255.255.255.255,route 10.16.10.10 255.255.255.255,route 10.17.10.10 255.255.255.255,route 10.18.10.10 255.255.255.255,route 10.19.10.10 255.255.255.255,route 10.20.10.10 255.255.255.255,route 10.21.10.10 255.255.255.255,route 10.22.10.10 255.255.255.255,route 10.23.10.10 255.255.255.255,route 10.24.10.10 255.255.255.255,route 10.25.10.10 255.255.255.255,route 10.26.10.10 255.255.255.255,route 10.27.10.10 255.255.255.255,route 10.28.10.10 255.255.255.255,route 10.29.10.10 255.255.255.255,route 10.30.10.10 255.255.255.255,route 10.31.10.10 255.255.255.255,route 10.32.10.10 255.255.255.255,route 10.33.10.10 255.255.255.255,ifconfig 10.100.100.27 255.255.255.0' Tue Nov 26 10:51:55 2013 us=671701 OPTIONS IMPORT: timers and/or timeouts modified Tue Nov 26 10:51:55 2013 us=671751 OPTIONS IMPORT: explicit notify parm(s) modified Tue Nov 26 10:51:55 2013 us=671832 OPTIONS IMPORT: --ifconfig/up options modified Tue Nov 26 10:51:55 2013 us=671869 OPTIONS IMPORT: route options modified Tue Nov 26 10:51:55 2013 us=671920 OPTIONS IMPORT: route-related options modified Tue Nov 26 10:51:55 2013 us=672310 ROUTE default_gateway=192.168.52.1 Tue Nov 26 10:51:55 2013 us=677637 TUN/TAP device tun0 opened Tue Nov 26 10:51:55 2013 us=677749 TUN/TAP TX queue length set to 100 Tue Nov 26 10:51:55 2013 us=677809 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0 Tue Nov 26 10:51:55 2013 us=677897 /sbin/ifconfig tun0 10.100.100.27 netmask 255.255.255.0 mtu 1500 broadcast 10.100.100.255 Tue Nov 26 10:51:55 2013 us=683603 /sbin/route add -net 10.10.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=687539 /sbin/route add -net 10.11.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=690641 /sbin/route add -net 10.12.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=693626 /sbin/route add -net 10.13.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=696615 /sbin/route add -net 10.14.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=700040 /sbin/route add -net 10.15.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=702986 /sbin/route add -net 10.16.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=705275 /sbin/route add -net 10.17.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=707554 /sbin/route add -net 10.18.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=709843 /sbin/route add -net 10.19.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=712968 /sbin/route add -net 10.20.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=715534 /sbin/route add -net 10.21.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=718751 /sbin/route add -net 10.22.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=721871 /sbin/route add -net 10.23.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=724969 /sbin/route add -net 10.24.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=728345 /sbin/route add -net 10.25.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=731590 /sbin/route add -net 10.26.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=735044 /sbin/route add -net 10.27.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=738437 /sbin/route add -net 10.28.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=742406 /sbin/route add -net 10.29.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=745640 /sbin/route add -net 10.30.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=748860 /sbin/route add -net 10.31.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=751472 /sbin/route add -net 10.32.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=754431 /sbin/route add -net 10.33.10.10 netmask 255.255.255.255 gw 10.100.100.1 Tue Nov 26 10:51:55 2013 us=757213 Initialization Sequence Completed
Packet-Trace - with ping from client to server and vice-versa:
10:55:05.544372 IP 192.168.52.156.50214 > 77.244.108.138.443: UDP, length 53 10:55:05.556408 IP 77.244.108.138.443 > 192.168.52.156.50214: UDP, length 53 10:55:15.038549 IP 77.244.108.138.443 > 192.168.52.156.50214: UDP, length 53 10:55:15.038772 IP 192.168.52.156.50214 > 77.244.108.138.443: UDP, length 53
We've been fixing this temporarily by omitting the subnet mask in the "push" directives, which works well for single hosts but will result in a problem as soon as we're pushing more routes or routes to networks - which will definitely happen.
It seems that the openVPN client on Ubuntu (and possibly on other distributions, too) just omits the ping-directives in this case when the push packets exceed the 1024 bytes (or whatever the limit currently is) and the packet is splitted in several parts.
Attachments (2)
Change History (15)
comment:1 Changed 10 years ago by
Cc: | David Sommerseth Gert Döring added |
---|
comment:2 Changed 10 years ago by
Also please attach a config for both server and client which we can use to reproduce this issue with. That'll save us a bunch of time trying to reproduce this issue.
comment:3 Changed 10 years ago by
We investigated to code regarding this issue. Attached, you'll find a patch fixing this issue (tested with the latest stable release, client-side) and a comment from the patching developer:
---
There is a bug in all current openvpn versions, when servers pushes configs that exceed one push message, e.g. large route configs (push-continuation).
This causes keepalive push options (ping) to get ignored, despite being sent by the server, and makes connections look instable.
Without the patch, a client ignores part of the push options, like ping send intervals, if not included in the last push message received.
Questions to Jens Wagner (jwagner[at]hexonet.net)
---
The patch is based on the latest 2.3 stable code, although named to fit the version dealt with in this report.
Additionally, here are our configs:
Server
log-append /var/log/openvpn/openvpn.log verb 3 status /var/log/openvpn/status 10 status-version 2 dev tun ### IP data - pool the openVPN server takes the client addresses from server x.x.x.x 255.255.255.0 port 443 comp-lzo mssfix 1450 reneg-sec 3600 ### Only 1 IP per client instead of a /30 subnet topology subnet ping 10 ping-restart 120 ping-timer-rem persist-tun persist-key push "ping 10" push "ping-restart 45" ### CERTS & KEYS ### dh keys.USER/dh1024.pem dh keys/dh2048.pem ### CA Cert ca certs/HEXONET-CA.crt ### Server Cert & Key cert certs/vpn1.pem key keys/vpn1.pem ### Certificate Reovkation List crl-verify crl/HEXONET-CRL.pem script-security 2 # Scripts which are loading the "push" directives and firewall rules based on the user's common-name client-connect scripts/client-connect.sh client-disconnect scripts/client-disconnect.sh learn-address scripts/learn-address.sh max-clients 100 push "explicit-exit-notify 3" push "route 10.10.10.10 255.255.255.255" push "route 10.11.10.10 255.255.255.255" push "route 10.12.10.10 255.255.255.255" push "route 10.13.10.10 255.255.255.255" push "route 10.14.10.10 255.255.255.255" push "route 10.15.10.10 255.255.255.255" push "route 10.16.10.10 255.255.255.255" push "route 10.17.10.10 255.255.255.255" push "route 10.18.10.10 255.255.255.255" push "route 10.19.10.10 255.255.255.255" push "route 10.20.10.10 255.255.255.255" push "route 10.21.10.10 255.255.255.255" push "route 10.22.10.10 255.255.255.255" push "route 10.23.10.10 255.255.255.255" push "route 10.24.10.10 255.255.255.255" push "route 10.25.10.10 255.255.255.255" push "route 10.26.10.10 255.255.255.255" push "route 10.27.10.10 255.255.255.255" push "route 10.28.10.10 255.255.255.255" push "route 10.29.10.10 255.255.255.255" push "route 10.30.10.10 255.255.255.255" push "route 10.31.10.10 255.255.255.255" push "route 10.32.10.10 255.255.255.255" push "route 10.33.10.10 255.255.255.255" push "route 10.34.10.10 255.255.255.255" push "route 10.35.10.10 255.255.255.255"
Client
client dev tun proto udp remote x.x.x.x xxx resolv-retry infinite nobind ca hexonet-ca.crt cert meeting-office-cert.pem key meeting-office-key.pem comp-lzo verb 4 # Silence repeating messages ;mute 20
Changed 10 years ago by
Attachment: | openvpn-2.3.2.patch added |
---|
push-continuation openvpn 2.3.2 patch
comment:4 Changed 10 years ago by
Hi dazo,
the function incoming_push_message(...) in push.c uses a local variable option_types_found, that gets passed to do_up(...).
If the server push got split into several parts, only the last part (PUSH_MSG_REPLY) option_types_found is used for do_up (initilized as 0 locally), the previous ones (PUSH_MSG_CONTINUATION) are ignored.
So e.g. a ping config, pushed by the server in the first push, followed by a lot of "push route" configs, causing a second push message, will have the do_up() called, but without e.g. the OPT_P_TIMER flag.
The patch resolves that, by storing the push option_types_found in the context.
Best,
jens
comment:5 Changed 10 years ago by
Btw, the results of this bug are not obvious, as there's nothing visible in the log files. The PING option pushed by the server shows up correctly (the timer just doesn't get started).
But when using e.g. tcpdump, you can see that the client does not send keepalive messages, and this causes a lot of reconnects (when running as a daemon), or connection breaks (when used by network manager).
This affects all connections, where the server push exceeds ((PUSH_BUNDLE_SIZE = 1024) - 84) bytes.
comment:6 Changed 10 years ago by
Owner: | set to Gert Döring |
---|---|
Status: | new → assigned |
thanks for the detailed explanation and the patch. I'll take care of it.
It will take a few days, as I'm busy with the dual-stack revolution in master right now :-)
comment:7 Changed 10 years ago by
Maybe you want to update the version number in the bug report, as the bug affects the latest one, too.
http://sourceforge.net/p/openvpn/openvpn-testing/ci/master/tree/src/openvpn/push.c
Thank you, and keep up the great work :-)
comment:8 Changed 10 years ago by
Please let me know if we can help somehow. The patch we created works flawlessly for the latest versions, maybe you might want to change the declaration a bit (to match the declaration of the stack variable option_types_found
):
int push_option_types_found;
to
unsigned int push_option_types_found;
Would be great if you could apply the patch!
comment:9 Changed 10 years ago by
Well, right now it's a matter of available time to review, understand, and merge - which should not actually be that much given that you've done most of the work already (thanks).
I hope I an get to it in the next days (depends a bit on plaisthos' work on the dual-stack changes, where I'd like to have the patches "close together" with few unrelated fixes committed in between).
comment:10 Changed 10 years ago by
Version: | 2.2.1 → git master branch |
---|
comment:11 Changed 10 years ago by
Milestone: | → release 2.3.3 |
---|
comment:12 Changed 10 years ago by
sometimes this code is too brilliant for mere mortals to understand... and sometimes it's too brilliant for the original author, it seems :-)
After some scratching of my head, I now fully understand what the code tries to do and why it fails - a nice and subtle bug you've found here. A huge thanks for reporting it, tracking it down and providing a patch :-)
Patch applied (using "unsigned int") to master and release/2.3
commit 1aac9a0b7a4046822a0134cd8693a828f2e16576 (master)
commit e93fb8ceebe9ca7748d8874893221a40330564e4 (release/2.3)
we'll release 2.3.3 with this patch "soon".
I'm not sure whether we'll do another 2.2.x release - if we do, the patch will go in.
comment:13 Changed 10 years ago by
Resolution: | → fixed |
---|---|
Status: | assigned → closed |
Version: | git master branch → 2.3.2 |
Could you try with something a bit less venerable on the server side? 2.2.1 is really old, and there have been bugfixes in the 2.3 series related to push requests.
If this happens with 2.3.2 as well on both ends, this is much more likely to receive due attention than if it only happens in 2.2.1 - which is end of maintenance, except for catastrophic security issues.
(CC'ing dazo, you've done a lot of investigation on push, push-restart, no soup for you...)