Disconnect issue being analyzed

davidparks21

I'm connecting to 2 different openvpn servers (in separate regions) and getting disconnected a few minutes after connection (same problem on both servers). There are no known issues or changes since a day ago when everything was fine.

I am guessing this is a local client issue causing the disconnects, but I wonder if anyone has seen this before and has any comment/thoughts?

I can disconnect and get re-connected, but again only for a few minutes.

Fri Oct 28 09:51:03 2011 write TCPv4_CLIENT: Software caused connection abort (WSAECONNABORTED) (code=10053)
Fri Oct 28 09:51:03 2011 Connection reset, restarting [-1]
Fri Oct 28 09:51:03 2011 TCP/UDP: Closing socket
Fri Oct 28 09:51:03 2011 SIGUSR1[soft,connection-reset] received, process restarting
Fri Oct 28 09:51:03 2011 Restart pause, 5 second(s)

janjust

is there anything corresponding in the server logs?
this looks like a windows error, perhaps there are MTU issues? is the MTU of the adapter still set to the right value?
Set

verb 5

in the client config , reconnect and wait for the error: what shows up in the client log file?

terho

I have exactly the same issue. But unfortunately no idea about solution.

In log I have:

2011-12-09T07:30:13.040 OVPN:>LOG:1323408613,,463 variation(s) on previous 20 message(s) suppressed by --mute
2011-12-09T07:30:13.040 OVPN:>LOG:1323408613,N,write TCPv4_CLIENT: Software caused connection abort (WSAECONNABORTED) (code=10053)
2011-12-09T07:30:13.040 OVPN:>LOG:1323408613,N,Connection reset, restarting [-1]
2011-12-09T07:30:13.041 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.041 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.041 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.042 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.042 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.042 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.043 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.043 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.043 OVPN:>LOG:1323408613,,TCP/UDP: Closing socket
2011-12-09T07:30:13.043 OVPN:>LOG:1323408613,D,PID packet_id_free
2011-12-09T07:30:13.044 OVPN:>LOG:1323408613,I,SIGUSR1[soft,connection-reset] received, process restarting
2011-12-09T07:30:13.044 OVPN:>LOG:1323408613,,MANAGEMENT: >STATE:1323408613,RECONNECTING,connection-reset,,
2011-12-09T07:30:13.044 OVPN:>STATE:1323408613,RECONNECTING,connection-reset,,
2011-12-09T07:30:13.044 OVPN:>HOLD:Waiting for hold release
2011-12-09T07:30:13.105 OVPN:>LOG:1323408613,D,MANAGEMENT: CMD ''
2011-12-09T07:30:13.105 OVPN:>LOG:1323408613,D,MANAGEMENT: CMD 'hold release'
2011-12-09T07:30:13.106 OVPN:SUCCESS: hold release succeeded
2011-12-09T07:30:13.106 OVPN:>LOG:1323408613,W,WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
2011-12-09T07:30:13.106 OVPN:>LOG:1323408613,I,Re-using SSL/TLS context
2011-12-09T07:30:13.106 OVPN:>LOG:1323408613,D,MTU DYNAMIC mtu=0, flags=1, 0 -> 140
2011-12-09T07:30:13.107 OVPN:>LOG:1323408613,D,PID packet_id_init seq_backtrack=0 time_backtrack=0
2011-12-09T07:30:13.107 OVPN:>LOG:1323408613,D,PID packet_id_init seq_backtrack=0 time_backtrack=0
2011-12-09T07:30:13.107 OVPN:>LOG:1323408613,D,PID packet_id_init seq_backtrack=0 time_backtrack=0
2011-12-09T07:30:13.107 OVPN:>LOG:1323408613,D,PID packet_id_init seq_backtrack=0 time_backtrack=0
2011-12-09T07:30:13.108 OVPN:>LOG:1323408613,,Control Channel MTU parms [ L:1559 D:140 EF:40 EB:0 ET:0 EL:0 ]
2011-12-09T07:30:13.108 OVPN:>LOG:1323408613,D,MTU DYNAMIC mtu=1450, flags=2, 1559 -> 1450
2011-12-09T07:30:13.108 OVPN:>LOG:1323408613,D,RESOLVE_REMOTE flags=0x0101 phase=1 rrs=0 sig=-1 status=1
2011-12-09T07:30:13.109 OVPN:>LOG:1323408613,,Data Channel MTU parms [ L:1559 D:1450 EF:59 EB:4 ET:0 EL:0 ]
2011-12-09T07:30:13.109 OVPN:>LOG:1323408613,,Local Options String: 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-client'
2011-12-09T07:30:13.110 OVPN:>LOG:1323408613,,Expected Remote Options String: 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-server'
2011-12-09T07:30:13.110 OVPN:>LOG:1323408613,,Local Options hash (VER=V4): '5cb3f8dc'
2011-12-09T07:30:13.110 OVPN:>LOG:1323408613,,Expected Remote Options hash (VER=V4): '898ae6c6'
2011-12-09T07:30:13.110 OVPN:>LOG:1323408613,I,Attempting to establish TCP connection with 213.132.115.194:443
2011-12-09T07:30:13.111 OVPN:>LOG:1323408613,,MANAGEMENT: >STATE:1323408613,TCP_CONNECT,,,
2011-12-09T07:30:13.111 OVPN:>STATE:1323408613,TCP_CONNECT,,,
2011-12-09T07:30:13.111 OVPN:>LOG:1323408613,I,TCP connection established with 213.132.115.194:443
2011-12-09T07:30:13.112 OVPN:>LOG:1323408613,,Socket Buffers: R=[0->0] S=[0->0]
2011-12-09T07:30:13.112 OVPN:>LOG:1323408613,I,TCPv4_CLIENT link local: [undef]
2011-12-09T07:30:13.112 OVPN:>LOG:1323408613,I,TCPv4_CLIENT link remote: 213.132.115.194:443
2011-12-09T07:30:13.112 OVPN:>LOG:1323408613,D,SENT PING
2011-12-09T07:30:13.113 OVPN:>LOG:1323408613,,MANAGEMENT: >STATE:1323408613,WAIT,,,
2011-12-09T07:30:13.113 OVPN:>STATE:1323408613,WAIT,,,
2011-12-09T07:30:13.114 OVPN:>LOG:1323408613,D,TCPv4_CLIENT WRITE [14] to 213.132.115.194:443: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
2011-12-09T07:30:13.114 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.114 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.114 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.115 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.115 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.115 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.115 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.116 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.116 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.116 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.116 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.117 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.117 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.117 OVPN:>LOG:1323408613,D,TUN READ [60]
2011-12-09T07:30:13.118 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.118 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.118 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.118 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.119 OVPN:>LOG:1323408613,D,TUN READ [1391]
2011-12-09T07:30:13.119 OVPN:>LOG:1323408613,,NOTE: --mute triggered...
2011-12-09T07:30:13.659 OVPN:>LOG:1323408614,,47 variation(s) on previous 20 message(s) suppressed by --mute
2011-12-09T07:30:13.659 OVPN:>LOG:1323408614,D,MSS: 1460 -> 1351
2011-12-09T07:30:13.660 OVPN:>LOG:1323408614,D,TUN READ [52]
2011-12-09T07:30:13.660 OVPN:>LOG:1323408614,D,MSS: 1460 -> 1351
2011-12-09T07:30:13.780 OVPN:>LOG:1323408614,D,TUN READ [60]
2011-12-09T07:30:13.960 OVPN:>LOG:1323408614,D,TUN READ [52]
2011-12-09T07:30:13.960 OVPN:>LOG:1323408614,D,MSS: 1460 -> 1351
2011-12-09T07:30:13.960 OVPN:>LOG:1323408614,D,TUN READ [48]
2011-12-09T07:30:13.960 OVPN:>LOG:1323408614,D,MSS: 1460 -> 1351
2011-12-09T07:30:14.147 OVPN:>LOG:1323408614,D,TUN READ [1389]
2011-12-09T07:30:14.636 OVPN:>LOG:1323408615,D,TUN READ [64]
2011-12-09T07:30:14.636 OVPN:>LOG:1323408615,D,TCPv4_CLIENT WRITE [14] to 213.132.115.194:443: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
2011-12-09T07:30:14.636 OVPN:>LOG:1323408615,D,TUN READ [64]
2011-12-09T07:30:14.756 OVPN:>LOG:1323408615,D,TUN READ [67]
2011-12-09T07:30:14.819 OVPN:>LOG:1323408615,D,TUN READ [63]
2011-12-09T07:30:14.999 OVPN:>LOG:1323408615,D,TUN READ [1389]
2011-12-09T07:30:15.542 OVPN:>LOG:1323408616,D,TUN READ [67]
2011-12-09T07:30:15.662 OVPN:>LOG:1323408616,D,TUN READ [64]
2011-12-09T07:30:15.662 OVPN:>LOG:1323408616,D,TUN READ [64]
2011-12-09T07:30:15.782 OVPN:>LOG:1323408616,D,TUN READ [1389]
2011-12-09T07:30:15.842 OVPN:>LOG:1323408616,D,TUN READ [1389]
2011-12-09T07:30:16.863 OVPN:>LOG:1323408617,D,TUN READ [63]
2011-12-09T07:30:16.863 OVPN:>LOG:1323408617,D,TCPv4_CLIENT WRITE [14] to 213.132.115.194:443: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
2011-12-09T07:30:17.163 OVPN:>LOG:1323408617,D,TUN READ [847]
2011-12-09T07:30:17.463 OVPN:>LOG:1323408618,D,TUN READ [1389]
2011-12-09T07:30:18.063 OVPN:>LOG:1323408618,D,TCPv4_CLIENT READ [26] from 213.132.115.194:443: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
2011-12-09T07:30:18.063 OVPN:>LOG:1323408618,,MANAGEMENT: >STATE:1323408618,AUTH,,,
2011-12-09T07:30:18.063 OVPN:>STATE:1323408618,AUTH,,,
2011-12-09T07:30:18.064 OVPN:>LOG:1323408618,,TLS: Initial packet from 213.132.115.194:443, sid=d7efb3b8 a6a63889
2011-12-09T07:30:18.064 OVPN:>LOG:1323408618,D,TCPv4_CLIENT WRITE [22] to 213.132.115.194:443: P_ACK_V1 kid=0 [ 0 ]
2011-12-09T07:30:18.064 OVPN:>PASSWORD:Need 'Auth' username/password

davidparks21

Unfortunately I never tracked this down, it was pretty intermittent, some days it would be terrible, other days fine. And for me it seemed tied to a specific ISP I was accessing the VPN over. I still have it on my radar to troubleshoot if/when I see it again, but I haven't gotten further than this post yet myself. I'm still very interested though.