p2p tunnel crashing

Need help configuring your VPN? Just post here and you'll get that help.
Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
Post Reply
copn37
OpenVpn Newbie
Posts: 1
Joined: Wed Jun 23, 2021 1:35 am

p2p tunnel crashing

Post by copn37 » Wed Jun 23, 2021 2:15 am

Network looks like this:

VPS (OVPN-Server) <-p2p-> Cloud -Local(OVPN-Client with Nextcloud on a Proxmox VM)
Image
https://www.udrop.com/5GyF/Untitled_Diagram.png

This works, but only for ~24h. After trying to ssh into my VPS -> no route to host. After reboot i can ssh into it again. SSH into local Cloud, local access to webserver etc no problem. Cant find anything special in the logs which could help me. This is very strange for me. I understand that i cant reach my webserver from inet when tun down. But why ssh'ing into not working, only after reboot. (no special fw, fail2ban etc)

local firewall im using is pfsense, but nothing in logs -by the way-

config server:

Code: Select all

local XXX.XXX.XXX.XXX
port 1163
mode server
dev tun
proto udp4
user nobody
group nogroup
persist-key
persist-tun
keepalive 10 120
topology p2p
push "topology p2p"
ifconfig 10.8.0.0 0.0.0.0
push "route-gateway 10.8.0.0"
client-config-dir ccd
tls-crypt tls-crypt.key 0
crl-verify crl.pem
ca ca.crt
cert ovpn.myvps.com.crt
key ovpn.myvps.com.key
dh none
auth SHA256
cipher AES-128-GCM
ncp-ciphers AES-128-GCM
tls-server
tls-version-min 1.2
tls-cipher TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256
log-append /var/log/openvpn/openvpn.log
status /etc/openvpn/openvpn-status.log
verb 4

config client:

Code: Select all

client
proto udp
remote ovpn.myvps.com 1163
dev tun
resolv-retry infinite
nobind
persist-key
persist-tun
remote-cert-tls server
verify-x509-name ovpn.myvps.com name
auth SHA256
auth-nocache
cipher AES-128-GCM
tls-client
tls-version-min 1.2
tls-cipher TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256
log-append /var/log/openvpn/openvpn.log
verb 3
<ca>
iptables vps:

Code: Select all

#Nextcloud Port 80
iptables -t nat -A PREROUTING -p tcp -d XXX.XXX.XXX.XXX --dport 80 -j DNAT --to-destination 10.8.0.2:80
iptables -t nat -A POSTROUTING -d 10.8.0.2/32 -p tcp -m tcp --dport 80 -j SNAT --to-source 10.8.0.0

#nextcloud Port 443
iptables -t nat -A PREROUTING -p tcp -d XXX.XXX.XXX.XXX --dport 443 -j DNAT --to-destination 10.8.0.2:443
iptables -t nat -A POSTROUTING -d 10.8.0.2/32 -p tcp -m tcp --dport 443 -j SNAT --to-source 10.8.0.0

ip route add 10.8.0.0/24 dev tun0

ccd on server: (nc.mync.com):

Code: Select all

ifconfig-push 10.8.0.2 10.8.0.0
log vps:

Code: Select all

Tue Jun 22 18:59:59 2021 us=89434 nc.mync.com/XX.XX.XX.XX:24901 Incoming Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
Tue Jun 22 18:59:59 2021 us=104448 nc.mync.com/XX.XX.XX.XX:24901 Control Channel: TLSv1.2, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 256 bit EC, curve: prime256v1
Tue Jun 22 19:50:35 2021 us=755655 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:50:45 2021 us=880786 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:50:56 2021 us=45708 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:06 2021 us=440565 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:16 2021 us=609984 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:26 2021 us=744556 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:36 2021 us=799241 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:46 2021 us=997977 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:51:57 2021 us=8275 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:07 2021 us=353063 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:17 2021 us=684992 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:27 2021 us=847558 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:38 2021 us=18490 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:48 2021 us=326641 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:52:58 2021 us=377434 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:08 2021 us=402032 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:18 2021 us=454582 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:28 2021 us=664301 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:38 2021 us=716987 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:49 2021 us=29965 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:53:59 2021 us=210736 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:54:09 2021 us=617790 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:54:19 2021 us=668416 nc.mync.com/XX.XX.XX.XX:24901 write UDPv4: Network is unreachable (code=101)
Tue Jun 22 19:54:25 2021 us=707617 nc.mync.com/XX.XX.XX.XX:24901 [nc.mync.com] Inactivity timeout (--ping-restart), restarting
Tue Jun 22 19:54:25 2021 us=707773 nc.mync.com/XX.XX.XX.XX:24901 SIGUSR1[soft,ping-restart] received, client-instance restarting
client log:

Code: Select all

Tue Jun 22 19:50:01 2021 us=818772 TUN WRITE [84]
Tue Jun 22 19:50:01 2021 us=818799 TUN READ [84]
Tue Jun 22 19:50:01 2021 us=818803 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:01 2021 us=818813 UDP WRITE [108] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:02 2021 us=819869 UDP READ [108] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:02 2021 us=819908 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:02 2021 us=819931 PID_TEST [0] [SSL-2] [16>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:377 0:378 t=1624384202[0] r=[-1,64,15,0,1] sl=[7,64,64,528]
Tue Jun 22 19:50:02 2021 us=819940 TUN WRITE [84]
Tue Jun 22 19:50:02 2021 us=819965 TUN READ [84]
Tue Jun 22 19:50:02 2021 us=819970 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:02 2021 us=819979 UDP WRITE [108] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:03 2021 us=821602 UDP READ [108] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:03 2021 us=821639 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:03 2021 us=821660 PID_TEST [0] [SSL-2] [127>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:378 0:379 t=1624384203[0] r=[-2,64,15,0,1] sl=[6,64,64,528]
Tue Jun 22 19:50:03 2021 us=821668 TUN WRITE [84]
Tue Jun 22 19:50:03 2021 us=821692 TUN READ [84]
Tue Jun 22 19:50:03 2021 us=821696 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:03 2021 us=821705 UDP WRITE [108] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:04 2021 us=822907 UDP READ [108] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:04 2021 us=822951 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:04 2021 us=822990 PID_TEST [0] [SSL-2] [1238>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:379 0:380 t=1624384204[0] r=[-3,64,15,0,1] sl=[5,64,64,528]
Tue Jun 22 19:50:04 2021 us=822998 TUN WRITE [84]
Tue Jun 22 19:50:04 2021 us=823020 TUN READ [84]
Tue Jun 22 19:50:04 2021 us=823024 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:04 2021 us=823033 UDP WRITE [108] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:05 2021 us=824285 UDP READ [108] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:05 2021 us=824298 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:05 2021 us=824310 PID_TEST [0] [SSL-2] [12349>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:380 0:381 t=1624384205[0] r=[-4,64,15,0,1] sl=[4,64,64,528]
Tue Jun 22 19:50:05 2021 us=824316 TUN WRITE [84]
Tue Jun 22 19:50:05 2021 us=824326 TUN READ [84]
Tue Jun 22 19:50:05 2021 us=824329 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:05 2021 us=824336 UDP WRITE [108] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=107
Tue Jun 22 19:50:15 2021 us=181392 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:15 2021 us=181450 SENT PING
Tue Jun 22 19:50:15 2021 us=181462 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:15 2021 us=196568 UDP READ [40] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:15 2021 us=196582 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:15 2021 us=196598 PID_TEST [0] [SSL-2] [>>>>>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:381 0:382 t=1624384215[0] r=[0,64,15,0,1] sl=[3,64,64,528]
Tue Jun 22 19:50:15 2021 us=196601 RECEIVED PING PACKET
Tue Jun 22 19:50:25 2021 us=519980 UDP READ [40] from [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:25 2021 us=520028 TLS: tls_pre_decrypt, key_id=2, IP=[AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:50:25 2021 us=520056 PID_TEST [0] [SSL-2] [>EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE] 0:382 0:383 t=1624384225[0] r=[0,64,15,0,1] sl=[2,64,64,528]
Tue Jun 22 19:50:25 2021 us=520060 RECEIVED PING PACKET
Tue Jun 22 19:50:25 2021 us=520064 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:25 2021 us=520071 SENT PING
Tue Jun 22 19:50:25 2021 us=520077 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:35 2021 us=867547 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:35 2021 us=867609 SENT PING
Tue Jun 22 19:50:35 2021 us=867622 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:45 2021 us=233296 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:45 2021 us=233354 SENT PING
Tue Jun 22 19:50:45 2021 us=233367 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:50:55 2021 us=425828 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:50:55 2021 us=425889 SENT PING
Tue Jun 22 19:50:55 2021 us=425899 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:05 2021 us=701310 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:05 2021 us=701372 SENT PING
Tue Jun 22 19:51:05 2021 us=701384 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:15 2021 us=158041 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:15 2021 us=158104 SENT PING
Tue Jun 22 19:51:15 2021 us=158117 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:25 2021 us=315420 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:25 2021 us=315482 SENT PING
Tue Jun 22 19:51:25 2021 us=315512 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:35 2021 us=501951 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:35 2021 us=502012 SENT PING
Tue Jun 22 19:51:35 2021 us=502026 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:45 2021 us=879794 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:45 2021 us=879862 SENT PING
Tue Jun 22 19:51:45 2021 us=879874 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:51:56 2021 us=85319 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:51:56 2021 us=85382 SENT PING
Tue Jun 22 19:51:56 2021 us=85411 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:52:06 2021 us=378964 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:52:06 2021 us=379025 SENT PING
Tue Jun 22 19:52:06 2021 us=379039 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:52:16 2021 us=893836 TLS: tls_pre_encrypt: key_id=2
Tue Jun 22 19:52:16 2021 us=893904 SENT PING
Tue Jun 22 19:52:16 2021 us=893919 UDP WRITE [40] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_DATA_V2 kid=2 DATA len=39
Tue Jun 22 19:52:25 2021 us=156445 [ovpn.myvps.com] Inactivity timeout (--ping-restart), restarting
Tue Jun 22 19:52:25 2021 us=156501 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156587 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156609 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156613 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156631 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156634 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156636 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156639 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156643 TCP/UDP: Closing socket
Tue Jun 22 19:52:25 2021 us=156658 PID packet_id_free
Tue Jun 22 19:52:25 2021 us=156665 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jun 22 19:52:25 2021 us=156675 Restart pause, 5 second(s)
Tue Jun 22 19:52:30 2021 us=156757 Re-using SSL/TLS context
Tue Jun 22 19:52:30 2021 us=156785 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:52:30 2021 us=156799 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:52:30 2021 us=157048 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:52:30 2021 us=157076 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:52:30 2021 us=157090 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:52:30 2021 us=157095 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:52:30 2021 us=157103 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:52:30 2021 us=157108 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:52:30 2021 us=157120 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:52:30 2021 us=157123 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:52:30 2021 us=157129 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:52:30 2021 us=157132 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:52:30 2021 us=157136 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:52:30 2021 us=157139 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:52:30 2021 us=157145 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:52:30 2021 us=157162 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:52:30 2021 us=157165 UDP link local: (not bound)
Tue Jun 22 19:52:30 2021 us=157168 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:52:30 2021 us=157204 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:52:30 2021 us=157208 SENT PING
Tue Jun 22 19:52:30 2021 us=157231 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:52:32 2021 us=195528 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:52:36 2021 us=271941 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:52:44 2021 us=725323 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:52:54 2021 us=849082 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:52:54 2021 us=849130 SENT PING
Tue Jun 22 19:53:00 2021 us=665254 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:53:10 2021 us=516270 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:53:10 2021 us=516295 SENT PING
Tue Jun 22 19:53:20 2021 us=363890 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:53:20 2021 us=363916 SENT PING
Tue Jun 22 19:53:30 2021 us=526850 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:53:30 2021 us=526874 SENT PING
Tue Jun 22 19:53:30 2021 us=526882 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:53:30 2021 us=526886 TLS Error: TLS handshake failed
Tue Jun 22 19:53:30 2021 us=526890 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526928 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526932 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526944 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:30 2021 us=526964 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:30 2021 us=526970 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526977 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526980 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526983 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526993 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=526996 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=527000 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=527003 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=527007 TCP/UDP: Closing socket
Tue Jun 22 19:53:30 2021 us=527021 PID packet_id_free
Tue Jun 22 19:53:30 2021 us=527026 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:53:30 2021 us=527036 Restart pause, 5 second(s)
Tue Jun 22 19:53:35 2021 us=527248 Re-using SSL/TLS context
Tue Jun 22 19:53:35 2021 us=527307 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:53:35 2021 us=527327 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:35 2021 us=527363 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:35 2021 us=527368 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:35 2021 us=527382 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:53:35 2021 us=527387 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:53:35 2021 us=527394 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:53:35 2021 us=527438 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:53:35 2021 us=574092 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:53:35 2021 us=574130 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:53:35 2021 us=574148 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:53:35 2021 us=574152 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:53:35 2021 us=574159 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:53:35 2021 us=574178 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:53:35 2021 us=574184 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:53:35 2021 us=574187 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:53:35 2021 us=574194 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:53:35 2021 us=574207 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:53:35 2021 us=574211 UDP link local: (not bound)
Tue Jun 22 19:53:35 2021 us=574215 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:53:35 2021 us=574228 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:53:35 2021 us=574232 SENT PING
Tue Jun 22 19:53:35 2021 us=574266 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:53:37 2021 us=931072 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:53:41 2021 us=465250 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:53:49 2021 us=704012 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:53:59 2021 us=926604 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:53:59 2021 us=926639 SENT PING
Tue Jun 22 19:54:05 2021 us=212203 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:54:16 2021 us=30689 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:54:16 2021 us=30731 SENT PING
Tue Jun 22 19:54:27 2021 us=30951 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:54:27 2021 us=30990 SENT PING
Tue Jun 22 19:54:35 2021 us=40241 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:54:35 2021 us=40273 TLS Error: TLS handshake failed
Tue Jun 22 19:54:35 2021 us=40278 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40316 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40320 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40333 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:35 2021 us=40352 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:35 2021 us=40359 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40365 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40369 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40372 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40382 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40386 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40389 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40392 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40396 TCP/UDP: Closing socket
Tue Jun 22 19:54:35 2021 us=40409 PID packet_id_free
Tue Jun 22 19:54:35 2021 us=40415 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:54:35 2021 us=40425 Restart pause, 5 second(s)
Tue Jun 22 19:54:40 2021 us=40515 Re-using SSL/TLS context
Tue Jun 22 19:54:40 2021 us=40553 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:54:40 2021 us=40587 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:40 2021 us=40828 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:40 2021 us=40841 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:40 2021 us=40854 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:54:40 2021 us=40859 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:54:40 2021 us=40866 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:54:40 2021 us=40877 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:54:40 2021 us=85788 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:54:40 2021 us=85801 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:54:40 2021 us=85815 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:54:40 2021 us=85818 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:54:40 2021 us=85825 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:54:40 2021 us=85828 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:54:40 2021 us=85833 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:54:40 2021 us=85836 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:54:40 2021 us=85842 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:54:40 2021 us=85851 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:54:40 2021 us=85855 UDP link local: (not bound)
Tue Jun 22 19:54:40 2021 us=85858 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:54:40 2021 us=85870 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:54:40 2021 us=85873 SENT PING
Tue Jun 22 19:54:40 2021 us=85896 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:54:42 2021 us=455537 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:54:46 2021 us=11615 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:54:54 2021 us=272719 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:55:04 2021 us=886588 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:55:04 2021 us=886623 SENT PING
Tue Jun 22 19:55:10 2021 us=822655 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:55:20 2021 us=84157 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:55:20 2021 us=84187 SENT PING
Tue Jun 22 19:55:30 2021 us=575059 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:55:30 2021 us=575090 SENT PING
Tue Jun 22 19:55:40 2021 us=314134 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:55:40 2021 us=314168 SENT PING
Tue Jun 22 19:55:40 2021 us=314188 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:55:40 2021 us=314191 TLS Error: TLS handshake failed
Tue Jun 22 19:55:40 2021 us=314195 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314232 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314236 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314248 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:40 2021 us=314267 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:40 2021 us=314273 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314279 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314282 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314285 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314293 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314297 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314300 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314302 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314306 TCP/UDP: Closing socket
Tue Jun 22 19:55:40 2021 us=314316 PID packet_id_free
Tue Jun 22 19:55:40 2021 us=314322 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:55:40 2021 us=314331 Restart pause, 5 second(s)
Tue Jun 22 19:55:45 2021 us=314426 Re-using SSL/TLS context
Tue Jun 22 19:55:45 2021 us=314474 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:55:45 2021 us=314493 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:45 2021 us=314527 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:45 2021 us=314532 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:45 2021 us=314545 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:55:45 2021 us=314549 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:55:45 2021 us=314556 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:55:45 2021 us=314568 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:55:45 2021 us=534743 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:55:45 2021 us=534758 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:55:45 2021 us=534772 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:55:45 2021 us=534775 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:55:45 2021 us=534781 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:55:45 2021 us=534784 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:55:45 2021 us=534789 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:55:45 2021 us=534792 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:55:45 2021 us=534798 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:55:45 2021 us=534807 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:55:45 2021 us=534811 UDP link local: (not bound)
Tue Jun 22 19:55:45 2021 us=534814 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:55:45 2021 us=534838 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:55:45 2021 us=534842 SENT PING
Tue Jun 22 19:55:45 2021 us=534866 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:55:47 2021 us=607144 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:55:51 2021 us=751492 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:55:59 2021 us=923310 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:56:09 2021 us=76822 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:56:09 2021 us=76843 SENT PING
Tue Jun 22 19:56:15 2021 us=299357 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:56:25 2021 us=118574 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:56:25 2021 us=118597 SENT PING
Tue Jun 22 19:56:35 2021 us=31911 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:56:35 2021 us=31934 SENT PING
Tue Jun 22 19:56:46 2021 us=175244 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:56:46 2021 us=175268 SENT PING
Tue Jun 22 19:56:46 2021 us=175277 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:56:46 2021 us=175281 TLS Error: TLS handshake failed
Tue Jun 22 19:56:46 2021 us=175285 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175325 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175329 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175341 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:46 2021 us=175361 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:46 2021 us=175367 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175374 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175377 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175380 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175390 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175394 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175397 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175400 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175404 TCP/UDP: Closing socket
Tue Jun 22 19:56:46 2021 us=175417 PID packet_id_free
Tue Jun 22 19:56:46 2021 us=175423 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:56:46 2021 us=175432 Restart pause, 5 second(s)
Tue Jun 22 19:56:51 2021 us=175631 Re-using SSL/TLS context
Tue Jun 22 19:56:51 2021 us=175657 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:56:51 2021 us=175670 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:51 2021 us=175696 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:51 2021 us=175700 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:51 2021 us=175713 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:56:51 2021 us=175718 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:56:51 2021 us=175725 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:56:51 2021 us=175736 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:56:51 2021 us=238207 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:56:51 2021 us=238221 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:56:51 2021 us=238234 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:56:51 2021 us=238238 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:56:51 2021 us=238245 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:56:51 2021 us=238248 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:56:51 2021 us=238254 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:56:51 2021 us=238266 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:56:51 2021 us=238272 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:56:51 2021 us=238281 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:56:51 2021 us=238285 UDP link local: (not bound)
Tue Jun 22 19:56:51 2021 us=238288 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:56:51 2021 us=238299 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:56:51 2021 us=238302 SENT PING
Tue Jun 22 19:56:51 2021 us=238325 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:56:53 2021 us=452844 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:56:57 2021 us=880416 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:57:05 2021 us=801973 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:57:16 2021 us=133225 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:57:16 2021 us=133248 SENT PING
Tue Jun 22 19:57:21 2021 us=858754 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:57:31 2021 us=904031 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:57:31 2021 us=904058 SENT PING
Tue Jun 22 19:57:41 2021 us=787447 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:57:41 2021 us=787469 SENT PING
Tue Jun 22 19:57:51 2021 us=927784 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:57:51 2021 us=927814 SENT PING
Tue Jun 22 19:57:51 2021 us=927823 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:57:51 2021 us=927827 TLS Error: TLS handshake failed
Tue Jun 22 19:57:51 2021 us=927830 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927867 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927871 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927883 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:51 2021 us=927903 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:51 2021 us=927910 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927916 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927919 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927923 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927933 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927936 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927940 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927943 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927947 TCP/UDP: Closing socket
Tue Jun 22 19:57:51 2021 us=927957 PID packet_id_free
Tue Jun 22 19:57:51 2021 us=927963 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:57:51 2021 us=927972 Restart pause, 5 second(s)
Tue Jun 22 19:57:56 2021 us=928069 Re-using SSL/TLS context
Tue Jun 22 19:57:56 2021 us=928127 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:57:56 2021 us=928147 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:56 2021 us=928183 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:56 2021 us=928187 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:56 2021 us=928201 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:57:56 2021 us=928205 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:57:56 2021 us=928212 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:57:56 2021 us=928224 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:57:56 2021 us=943119 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:57:56 2021 us=943133 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:57:56 2021 us=943148 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:57:56 2021 us=943152 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:57:56 2021 us=943158 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:57:56 2021 us=943161 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:57:56 2021 us=943166 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:57:56 2021 us=943170 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:57:56 2021 us=943175 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:57:56 2021 us=943185 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:57:56 2021 us=943189 UDP link local: (not bound)
Tue Jun 22 19:57:56 2021 us=943192 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:57:56 2021 us=943217 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:57:56 2021 us=943221 SENT PING
Tue Jun 22 19:57:56 2021 us=943245 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:57:58 2021 us=200669 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:58:03 2021 us=229908 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:58:11 2021 us=938849 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:58:21 2021 us=472990 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:58:21 2021 us=473029 SENT PING
Tue Jun 22 19:58:27 2021 us=113843 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:58:37 2021 us=731697 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:58:37 2021 us=731727 SENT PING
Tue Jun 22 19:58:47 2021 us=495456 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:58:47 2021 us=495479 SENT PING
Tue Jun 22 19:58:57 2021 us=153920 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:58:57 2021 us=153953 SENT PING
Tue Jun 22 19:58:57 2021 us=153961 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 22 19:58:57 2021 us=153965 TLS Error: TLS handshake failed
Tue Jun 22 19:58:57 2021 us=153968 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154006 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154010 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154021 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:58:57 2021 us=154041 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:58:57 2021 us=154047 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154053 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154056 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154059 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154068 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154071 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154074 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154077 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154081 TCP/UDP: Closing socket
Tue Jun 22 19:58:57 2021 us=154095 PID packet_id_free
Tue Jun 22 19:58:57 2021 us=154100 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 22 19:58:57 2021 us=154109 Restart pause, 10 second(s)
Tue Jun 22 19:59:07 2021 us=154202 Re-using SSL/TLS context
Tue Jun 22 19:59:07 2021 us=154248 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Tue Jun 22 19:59:07 2021 us=154267 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:59:07 2021 us=154301 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:59:07 2021 us=154306 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:59:07 2021 us=154319 PID packet_id_init seq_backtrack=64 time_backtrack=15
Tue Jun 22 19:59:07 2021 us=154323 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Jun 22 19:59:07 2021 us=154330 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Tue Jun 22 19:59:07 2021 us=154342 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
Tue Jun 22 19:59:07 2021 us=193508 RESOLVE_REMOTE flags=0x0901 phase=1 rrs=0 sig=-1 status=0
Tue Jun 22 19:59:07 2021 us=193522 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Jun 22 19:59:07 2021 us=193536 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:59:07 2021 us=193540 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:59:07 2021 us=193546 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 48 bytes
Tue Jun 22 19:59:07 2021 us=193550 calc_options_string_link_mtu: link-mtu 1621 -> 1549
Tue Jun 22 19:59:07 2021 us=193554 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-client'
Tue Jun 22 19:59:07 2021 us=193558 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto UDPv4,cipher AES-128-GCM,auth [null-digest],keysize 128,key-method 2,tls-server'
Tue Jun 22 19:59:07 2021 us=193564 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:59:07 2021 us=193573 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Jun 22 19:59:07 2021 us=193577 UDP link local: (not bound)
Tue Jun 22 19:59:07 2021 us=193581 UDP link remote: [AF_INET]XXX.XXX.XXX.XXX:1163
Tue Jun 22 19:59:07 2021 us=193606 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:59:07 2021 us=193610 SENT PING
Tue Jun 22 19:59:07 2021 us=193634 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=352 DATA len=40
Tue Jun 22 19:59:09 2021 us=420046 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=608 DATA len=40
Tue Jun 22 19:59:13 2021 us=872741 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=864 DATA len=40
Tue Jun 22 19:59:21 2021 us=673645 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1120 DATA len=40
Tue Jun 22 19:59:31 2021 us=962352 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:59:31 2021 us=962392 SENT PING
Tue Jun 22 19:59:37 2021 us=853516 UDP WRITE [54] to [AF_INET]XXX.XXX.XXX.XXX:1163: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=1376 DATA len=40
Tue Jun 22 19:59:47 2021 us=367627 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:59:47 2021 us=367647 SENT PING
Tue Jun 22 19:59:58 2021 us=17074 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Tue Jun 22 19:59:58 2021 us=17104 SENT PING

User avatar
TinCanTech
Forum Team
Posts: 9767
Joined: Fri Jun 03, 2016 1:17 pm

Re: p2p tunnel crashing

Post by TinCanTech » Wed Jun 23, 2021 1:33 pm

Your configs are all wrong and your logs don't match your configs.

I recommend you start with a standard server/client setup first.
https://github.com/OpenVPN/openvpn/tree ... nfig-files

Post Reply