I've had a working openvpn client on my NV+ for quite some time, then the readynas updated itself to 4.1.7 since I had the box update auto ticked and the device shuts down every night. I only use the openvpn connection for diff backups, so it's not used that often.
openvpn starts fine without any error message, but the process dies after a few seconds. I've traced this on client (NV+) and server (linux).
The server says established TCP connection and a while later receives SIGUSR1[soft,connection-reset] received, client-instance restarting
On the client side it says it established TCP connection then prints a bunch of TCP READ/WRITE and eventually stops printing/crashes. I've tried logging on verbosity 9, but can't find an error message that points to a problem.
I have done apt-get upgrade openvpn openssl liblzo1 just to have the latest. Server openvpn version is 2.0.7 and client is 2.0. Any ideas?
Thanks.
Server side log: Sun Feb 6 17:42:22 2011 us=761325 MULTI: multi_create_instance called Sun Feb 6 17:42:22 2011 us=761436 Re-using SSL/TLS context Sun Feb 6 17:42:22 2011 us=761460 LZO compression initialized Sun Feb 6 17:42:22 2011 us=761585 Control Channel MTU parms [ L:1544 D:140 EF:40 EB:0 ET:0 EL:0 ] Sun Feb 6 17:42:22 2011 us=761610 Data Channel MTU parms [ L:1544 D:1450 EF:44 EB:135 ET:0 EL:0 AF:3/1 ] Sun Feb 6 17:42:22 2011 us=761669 Local Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server' Sun Feb 6 17:42:22 2011 us=761682 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' Sun Feb 6 17:42:22 2011 us=761710 Local Options hash (VER=V4): 'c0103fa8' Sun Feb 6 17:42:22 2011 us=761732 Expected Remote Options hash (VER=V4): '69109d17' Sun Feb 6 17:42:22 2011 us=761773 TCP connection established with "client ip":55809 Sun Feb 6 17:42:22 2011 us=761795 Socket Buffers: R=[131072->131072] S=[131072->131072] Sun Feb 6 17:42:22 2011 us=761814 TCPv4_SERVER link local: [undef] Sun Feb 6 17:42:22 2011 us=761828 TCPv4_SERVER link remote: "client ip":55809 Sun Feb 6 17:42:22 2011 us=762156 "client ip":55809 TLS: Initial packet from "client ip":55809, sid=8ccc7a49 c38f6139 Sun Feb 6 17:42:26 2011 us=985294 "client ip":55809 VERIFY OK: depth=1, … Sun Feb 6 17:42:26 2011 us=985611 "client ip":55809 VERIFY OK: depth=0, … Sun Feb 6 17:42:27 2011 us=676269 "client ip":55809 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Sun Feb 6 17:42:27 2011 us=676336 "client ip":55809 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Sun Feb 6 17:42:27 2011 us=676403 "client ip":55809 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Sun Feb 6 17:42:27 2011 us=676421 "client ip":55809 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Sun Feb 6 17:42:27 2011 us=821788 "client ip":55809 Connection reset, restarting [0] Sun Feb 6 17:42:27 2011 us=821854 "client ip":55809 SIGUSR1[soft,connection-reset] received, client-instance restarting Sun Feb 6 17:42:27 2011 us=822075 TCP/UDP: Closing socket
Client side log: Sun Feb 6 17:42:20 2011 us=161163 Current Parameter Settings: Sun Feb 6 17:42:20 2011 us=162986 config = '/etc/openvpn/1.conf' Sun Feb 6 17:42:20 2011 us=163307 mode = 0 Sun Feb 6 17:42:20 2011 us=163608 persist_config = DISABLED Sun Feb 6 17:42:20 2011 us=163888 persist_mode = 1 Sun Feb 6 17:42:20 2011 us=164169 show_ciphers = DISABLED Sun Feb 6 17:42:20 2011 us=164449 show_digests = DISABLED Sun Feb 6 17:42:20 2011 us=164750 show_engines = DISABLED Sun Feb 6 17:42:20 2011 us=165030 genkey = DISABLED Sun Feb 6 17:42:20 2011 us=165311 key_pass_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=165612 show_tls_ciphers = DISABLED Sun Feb 6 17:42:20 2011 us=165892 proto = 2 Sun Feb 6 17:42:20 2011 us=166173 local = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=166473 remote_list[0] = {'server ip', 443} Sun Feb 6 17:42:20 2011 us=166754 remote_random = DISABLED Sun Feb 6 17:42:20 2011 us=167054 local_port = 1194 Sun Feb 6 17:42:20 2011 us=167335 remote_port = 1194 Sun Feb 6 17:42:20 2011 us=167616 remote_float = DISABLED Sun Feb 6 17:42:20 2011 us=167916 ipchange = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=168197 bind_local = DISABLED Sun Feb 6 17:42:20 2011 us=168477 dev = 'tun' Sun Feb 6 17:42:20 2011 us=168758 dev_type = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=169058 dev_node = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=169399 tun_ipv6 = DISABLED Sun Feb 6 17:42:20 2011 us=169680 ifconfig_local = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=169960 ifconfig_remote_netmask = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=170261 ifconfig_noexec = DISABLED Sun Feb 6 17:42:20 2011 us=170541 ifconfig_nowarn = DISABLED Sun Feb 6 17:42:20 2011 us=170842 shaper = 0 Sun Feb 6 17:42:20 2011 us=171123 tun_mtu = 1500 Sun Feb 6 17:42:20 2011 us=171403 tun_mtu_defined = ENABLED Sun Feb 6 17:42:20 2011 us=171684 link_mtu = 1500 Sun Feb 6 17:42:20 2011 us=171984 link_mtu_defined = DISABLED Sun Feb 6 17:42:20 2011 us=172265 tun_mtu_extra = 0 Sun Feb 6 17:42:20 2011 us=172545 tun_mtu_extra_defined = DISABLED Sun Feb 6 17:42:20 2011 us=172846 fragment = 0 Sun Feb 6 17:42:20 2011 us=173127 mtu_discover_type = -1 Sun Feb 6 17:42:20 2011 us=173407 mtu_test = 0 Sun Feb 6 17:42:20 2011 us=173688 mlock = DISABLED Sun Feb 6 17:42:20 2011 us=173968 keepalive_ping = 0 Sun Feb 6 17:42:20 2011 us=174269 keepalive_timeout = 0 Sun Feb 6 17:42:20 2011 us=174549 inactivity_timeout = 0 Sun Feb 6 17:42:20 2011 us=174850 ping_send_timeout = 0 Sun Feb 6 17:42:20 2011 us=175131 ping_rec_timeout = 0 Sun Feb 6 17:42:20 2011 us=175431 ping_rec_timeout_action = 0 Sun Feb 6 17:42:20 2011 us=175712 ping_timer_remote = DISABLED Sun Feb 6 17:42:20 2011 us=176012 remap_sigusr1 = 0 Sun Feb 6 17:42:20 2011 us=176293 explicit_exit_notification = 0 Sun Feb 6 17:42:20 2011 us=176594 persist_tun = ENABLED Sun Feb 6 17:42:20 2011 us=176874 persist_local_ip = DISABLED Sun Feb 6 17:42:20 2011 us=177175 persist_remote_ip = DISABLED Sun Feb 6 17:42:20 2011 us=177455 persist_key = ENABLED Sun Feb 6 17:42:20 2011 us=177736 mssfix = 1450 Sun Feb 6 17:42:20 2011 us=178016 passtos = DISABLED Sun Feb 6 17:42:20 2011 us=178317 resolve_retry_seconds = 1000000000 Sun Feb 6 17:42:20 2011 us=178618 connect_retry_seconds = 5 Sun Feb 6 17:42:20 2011 us=178898 username = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=179219 groupname = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=179519 chroot_dir = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=179800 cd_dir = '/etc/openvpn' Sun Feb 6 17:42:20 2011 us=180101 writepid = '/var/run/server ip.pid' Sun Feb 6 17:42:20 2011 us=180381 up_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=180662 down_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=180962 down_pre = DISABLED Sun Feb 6 17:42:20 2011 us=181243 up_restart = DISABLED Sun Feb 6 17:42:20 2011 us=181523 up_delay = DISABLED Sun Feb 6 17:42:20 2011 us=181804 daemon = ENABLED Sun Feb 6 17:42:20 2011 us=182105 inetd = 0 Sun Feb 6 17:42:20 2011 us=182385 log = ENABLED Sun Feb 6 17:42:20 2011 us=182666 suppress_timestamps = DISABLED Sun Feb 6 17:42:20 2011 us=182946 nice = 0 Sun Feb 6 17:42:20 2011 us=183227 verbosity = 5 Sun Feb 6 17:42:20 2011 us=183507 mute = 0 Sun Feb 6 17:42:20 2011 us=183788 gremlin = 0 Sun Feb 6 17:42:20 2011 us=184089 status_file = 'openvpn-status.log' Sun Feb 6 17:42:20 2011 us=184369 status_file_version = 1 Sun Feb 6 17:42:20 2011 us=184670 status_file_update_freq = 60 Sun Feb 6 17:42:20 2011 us=184950 occ = ENABLED Sun Feb 6 17:42:20 2011 us=185231 rcvbuf = 65536 Sun Feb 6 17:42:20 2011 us=185511 sndbuf = 65536 Sun Feb 6 17:42:20 2011 us=185812 socks_proxy_server = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=186093 socks_proxy_port = 0 Sun Feb 6 17:42:20 2011 us=186393 socks_proxy_retry = DISABLED Sun Feb 6 17:42:20 2011 us=186674 fast_io = DISABLED Sun Feb 6 17:42:20 2011 us=186954 comp_lzo = ENABLED Sun Feb 6 17:42:20 2011 us=187235 comp_lzo_adaptive = ENABLED Sun Feb 6 17:42:20 2011 us=187535 route_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=187816 route_default_gateway = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=188097 route_noexec = DISABLED Sun Feb 6 17:42:20 2011 us=188397 route_delay = 0 Sun Feb 6 17:42:20 2011 us=188678 route_delay_window = 30 Sun Feb 6 17:42:20 2011 us=188978 route_delay_defined = DISABLED Sun Feb 6 17:42:20 2011 us=189399 management_addr = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=189700 management_port = 0 Sun Feb 6 17:42:20 2011 us=189980 management_user_pass = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=190281 management_log_history_cache = 250 Sun Feb 6 17:42:20 2011 us=190561 management_echo_buffer_size = 100 Sun Feb 6 17:42:20 2011 us=190862 management_query_passwords = DISABLED Sun Feb 6 17:42:20 2011 us=191143 management_hold = DISABLED Sun Feb 6 17:42:20 2011 us=191443 shared_secret_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=191724 key_direction = 0 Sun Feb 6 17:42:20 2011 us=192024 ciphername_defined = ENABLED Sun Feb 6 17:42:20 2011 us=192305 ciphername = 'BF-CBC' Sun Feb 6 17:42:20 2011 us=192606 authname_defined = ENABLED Sun Feb 6 17:42:20 2011 us=192906 authname = 'SHA1' Sun Feb 6 17:42:20 2011 us=193187 keysize = 0 Sun Feb 6 17:42:20 2011 us=193467 engine = DISABLED Sun Feb 6 17:42:20 2011 us=193768 replay = ENABLED Sun Feb 6 17:42:20 2011 us=194048 mute_replay_warnings = DISABLED Sun Feb 6 17:42:20 2011 us=194349 replay_window = 0 Sun Feb 6 17:42:20 2011 us=194630 replay_time = 0 Sun Feb 6 17:42:20 2011 us=194930 packet_id_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=195211 use_iv = ENABLED Sun Feb 6 17:42:20 2011 us=195491 test_crypto = DISABLED Sun Feb 6 17:42:20 2011 us=195792 tls_server = DISABLED Sun Feb 6 17:42:20 2011 us=196072 tls_client = ENABLED Sun Feb 6 17:42:20 2011 us=196373 key_method = 2 Sun Feb 6 17:42:20 2011 us=196654 ca_file = 'ca.crt' Sun Feb 6 17:42:20 2011 us=196934 dh_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=197235 cert_file = 'storage2.crt' Sun Feb 6 17:42:20 2011 us=197535 priv_key_file = 'storage2.key' Sun Feb 6 17:42:20 2011 us=197816 pkcs12_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=198117 cipher_list = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=198397 tls_verify = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=198678 tls_remote = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=198978 crl_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=199299 ns_cert_type = 0 Sun Feb 6 17:42:20 2011 us=199600 tls_timeout = 2 Sun Feb 6 17:42:20 2011 us=199880 renegotiate_bytes = 0 Sun Feb 6 17:42:20 2011 us=200181 renegotiate_packets = 0 Sun Feb 6 17:42:20 2011 us=200481 renegotiate_seconds = 3600 Sun Feb 6 17:42:20 2011 us=200782 handshake_window = 60 Sun Feb 6 17:42:20 2011 us=201062 transition_window = 3600 Sun Feb 6 17:42:20 2011 us=201363 single_session = DISABLED Sun Feb 6 17:42:20 2011 us=201664 tls_exit = DISABLED Sun Feb 6 17:42:20 2011 us=201944 tls_auth_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=202565 server_network = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=202926 server_netmask = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=203267 server_bridge_ip = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=203588 server_bridge_netmask = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=203928 server_bridge_pool_start = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=204249 server_bridge_pool_end = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=204549 ifconfig_pool_defined = DISABLED Sun Feb 6 17:42:20 2011 us=204870 ifconfig_pool_start = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=205211 ifconfig_pool_end = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=205531 ifconfig_pool_netmask = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=205832 ifconfig_pool_persist_filename = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=206133 ifconfig_pool_persist_refresh_freq = 600 Sun Feb 6 17:42:20 2011 us=206413 ifconfig_pool_linear = DISABLED Sun Feb 6 17:42:20 2011 us=206714 n_bcast_buf = 256 Sun Feb 6 17:42:20 2011 us=207014 tcp_queue_limit = 64 Sun Feb 6 17:42:20 2011 us=207295 real_hash_size = 256 Sun Feb 6 17:42:20 2011 us=207596 virtual_hash_size = 256 Sun Feb 6 17:42:20 2011 us=207896 client_connect_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=208177 learn_address_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=208477 client_disconnect_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=208778 client_config_dir = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=209058 ccd_exclusive = DISABLED Sun Feb 6 17:42:20 2011 us=209379 tmp_dir = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=209660 push_ifconfig_defined = DISABLED Sun Feb 6 17:42:20 2011 us=210000 push_ifconfig_local = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=210321 push_ifconfig_remote_netmask = 0.0.0.0 Sun Feb 6 17:42:20 2011 us=210602 enable_c2c = DISABLED Sun Feb 6 17:42:20 2011 us=210902 duplicate_cn = DISABLED Sun Feb 6 17:42:20 2011 us=211183 cf_max = 0 Sun Feb 6 17:42:20 2011 us=211463 cf_per = 0 Sun Feb 6 17:42:20 2011 us=211744 max_clients = 1024 Sun Feb 6 17:42:20 2011 us=212044 max_routes_per_client = 256 Sun Feb 6 17:42:20 2011 us=212325 client_cert_not_required = DISABLED Sun Feb 6 17:42:20 2011 us=212626 username_as_common_name = DISABLED Sun Feb 6 17:42:20 2011 us=212926 auth_user_pass_verify_script = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=213207 auth_user_pass_verify_script_via_file = DISABLED Sun Feb 6 17:42:20 2011 us=213507 client = ENABLED Sun Feb 6 17:42:20 2011 us=213788 pull = ENABLED Sun Feb 6 17:42:20 2011 us=214068 auth_user_pass_file = '[UNDEF]' Sun Feb 6 17:42:20 2011 us=214389 OpenVPN 2.0 sparc-unknown-linux [SSL] [LZO] [EPOLL] built on Jan 17 2007 Sun Feb 6 17:42:20 2011 us=215531 IMPORTANT: OpenVPN's default port number is now 1194, based on an official port number assignment by IANA. OpenVPN 2.0-beta16 and earlier used 5000 as the default port. Sun Feb 6 17:42:20 2011 us=215852 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info. Sun Feb 6 17:42:20 2011 us=241203 LZO compression initialized Sun Feb 6 17:42:20 2011 us=243588 Control Channel MTU parms [ L:1544 D:140 EF:40 EB:0 ET:0 EL:0 ] Sun Feb 6 17:42:20 2011 us=392746 Data Channel MTU parms [ L:1544 D:1450 EF:44 EB:23 ET:0 EL:0 AF:3/1 ] Sun Feb 6 17:42:20 2011 us=393387 Local Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' Sun Feb 6 17:42:20 2011 us=393648 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server' Sun Feb 6 17:42:20 2011 us=394409 Local Options hash (VER=V4): '69109d17' Sun Feb 6 17:42:20 2011 us=394910 Expected Remote Options hash (VER=V4): 'c0103fa8' Sun Feb 6 17:42:20 2011 us=410341 Attempting to establish TCP connection with "server ip":443 Sun Feb 6 17:42:20 2011 us=529840 TCP connection established with "server ip":443 Sun Feb 6 17:42:20 2011 us=530321 Socket Buffers: R=[262144->131072] S=[16384->131072] Sun Feb 6 17:42:20 2011 us=530702 TCPv4_CLIENT link local: [undef] Sun Feb 6 17:42:20 2011 us=531042 TCPv4_CLIENT link remote: "server ip":443 WRSun Feb 6 17:42:20 2011 us=629640 TLS: Initial packet from "server ip":443, sid=f59165c8 148c5610 WWRWRRRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRWRSun Feb 6 17:42:22 2011 us=528016 VERIFY OK: depth=1, ... Sun Feb 6 17:42:22 2011 us=540962 VERIFY OK: depth=0, ... RWWRWRWRRWWRWWWWRWRWRRRWWWRWRWRRWWRWRRRRWWWWRRRRRR
Re: OpenVPN broken after upgrading to RAIDiator 4.1.7
I updated my Duo also to 4.1.7 and do have since then the same behavior. Any news on this topic ? Otherwise I have to downgrade to 4.1.6 if possible, because I am in urgent need of the openvpn connection.
Forgot to mention I had a openvpn server running on the duo.
Re: OpenVPN broken after upgrading to RAIDiator 4.1.7
Thanks a lot for that hint, I allready downgraded and it did not help. Now I did a factory reset and it works again, cheer ! Still makes me unhappy I did not find out where the problem is, shuffling 2TB Data and reset the device is no fun I like to do every firmware update 🙂
