I posted the same into users mailing list, but looks like main life is here
I run openvpn --version
OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Mar 30 2012
( ubuntu 12.04) as server.
Client is
openvpn --version
OpenVPN 2.1.1 i386-redhat-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] built on Jan 26 2010 ( centos 5.5)
transport is udp.
link is over mobile phone provider, so it is quite unstable.
And I need to execute script on each client connect/disconnect to adjust routing.
And sometimes script is not executed, like it happend today
From client point of view connect time was at 09:22 ( server time is 5:22, we have UTC on this server)
Feb 28 05:21:13 polom-srv openvpn[2359]: read UDPv4 [ENETUNREACH]: Network is unreachable (code=101)
Feb 28 05:21:24 polom-srv openvpn[2359]: TLS: tls_process: killed expiring key
Feb 28 05:21:24 polom-srv openvpn[2359]: read UDPv4 [ENETUNREACH]: Network is unreachable (code=101)
Feb 28 05:21:25 polom-srv openvpn[2359]: TLS: soft reset sec=0 bytes=22525066/0 pkts=52415/0
Feb 28 05:21:25 polom-srv openvpn[2359]: read UDPv4 [ENETUNREACH]: Network is unreachable (code=101)
Feb 28 05:22:25 polom-srv openvpn[2359]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Feb 28 05:22:25 polom-srv openvpn[2359]: TLS Error: TLS handshake failed
Feb 28 05:22:25 polom-srv openvpn[2359]: TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Feb 28 05:22:25 polom-srv openvpn[2359]: TLS: Initial packet from OurServerIP:1194, sid=abbb9bcf a6b113b1
Feb 28 05:22:25 polom-srv openvpn[2359]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent t
his
Feb 28 05:22:26 polom-srv openvpn[2359]: VERIFY OK: depth=1, /C=RU/ST=Udm/L=Izhevsk/O=Belkam/CN=Belkam_CA/emailAddress=dm@belkam.com
Feb 28 05:22:26 polom-srv openvpn[2359]: VERIFY OK: depth=0, /C=RU/ST=Udm/L=Izhevsk/O=Belkam/CN=gopher/emailAddress=dm@belkam.com
Feb 28 05:22:27 polom-srv openvpn[2359]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 05:22:27 polom-srv openvpn[2359]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 05:22:27 polom-srv openvpn[2359]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 05:22:27 polom-srv openvpn[2359]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 05:22:27 polom-srv openvpn[2359]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
There was connectivity problem, but all OK- connection is restored, as I see client doesn't think there was session end
but from server point of view all is not that simple ( on server we have local time- UTC+4) :
Feb 28 09:21:24 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 TLS: tls_process: killed expiring key
Feb 28 09:21:25 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 TLS: soft reset sec=0 bytes=22503544/0 pkts=52352/0
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
Feb 28 09:21:27 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
then
Feb 28 09:22:26 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your n
etwork connectivity)
Feb 28 09:22:26 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 TLS Error: TLS handshake failed
Feb 28 09:22:26 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Feb 28 09:22:26 inetgw2 openvpn[2752]: read UDPv4 [CMSG=8|ECONNREFUSED]: Connection refused (code=111)
etc, etc,
then connection was restored, as new session ( without closing pervious one)
Feb 28 09:22:26 inetgw2 openvpn[2752]: 94.77.50.137:1024 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 09:22:26 inetgw2 openvpn[2752]: 94.77.50.137:1024 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 09:22:26 inetgw2 openvpn[2752]: 94.77.50.137:1024 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 09:22:26 inetgw2 openvpn[2752]: 94.77.50.137:1024 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 09:22:27 inetgw2 openvpn[2752]: 94.77.50.137:1024 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Feb 28 09:22:27 inetgw2 openvpn[2752]: 94.77.50.137:1024 [polom] Peer Connection Initiated with [AF_INET]94.77.50.137:1024 (via [AF_INET]192.1
68.42.3%vlan2)
Feb 28 09:22:27 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 OPTIONS IMPORT: reading client specific options from: ccd-udp/polom
Feb 28 09:22:27 inetgw2 openvpn: polom sudo route add -net 192.168.133.0 netmask 255.255.255.0 gw 192.168.206.1
Feb 28 09:22:27 inetgw2 openvpn: SIOCADDRT: File exists
then closed:
Feb 28 09:25:13 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 [UNDEF] Inactivity timeout (--ping-restart), restarting
Feb 28 09:25:13 inetgw2 openvpn[2752]: polom/94.77.50.137:57385 SIGUSR1[soft,ping-restart] received, client-instance restarting
Feb 28 09:25:13 inetgw2 openvpn: polom sudo route del -net 192.168.133.0 netmask 255.255.255.0 gw 192.168.206.1
then many messages like:
Feb 28 09:22:37 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 TLS Error: local/remote TLS keys are out of sync: [AF_INET]94.77.50.137:1024 (v
ia [AF_INET]192.168.42.3%vlan2) [5]
then
Feb 28 09:25:15 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 MULTI: Learn: 192.168.133.2 -> polom/94.77.50.137:1024
until:
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 CRL CHECK OK: /C=RU/ST=Udm/L=Izhevsk/O=Belkam/OU=Polom/CN=polom/emailAddress=dm
@belkam.com
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 VERIFY OK: depth=0, /C=RU/ST=Udm/L=Izhevsk/O=Belkam/OU=Polom/CN=polom/emailAddr
ess=dm@belkam.com
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 28 10:22:28 inetgw2 openvpn[2752]: polom/94.77.50.137:1024 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
and connection script was not executed
Could you tell me what can I do to force openvpn execute script?
Thank you!
