I made the adjustments to the config files as requested, but I still have a problem.
One other forum just talking strictly about the VPN (not involving phones) suggested that the dates and times being off might be the problem.
I noticed that the phone thinks the time is 15:13 whereas the server thinks the time is 10:13. I have tried setting the phone's time manually, but the same timestamp occurs.
server.conf
Code:
local xxx.xxx.xxx.xxx #(public IP of Elastix server)
port 1194
proto udp
dev tun
ca /etc/openvpn/easy-rsa/keys/ca.crt
cert /etc/openvpn/easy-rsa/keys/pbx102.crt
key /etc/openvpn/easy-rsa/keys/pbx102.key
dh /etc/openvpn/easy-rsa/keys/dh1024.pem
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "redirect-gateway def1"
push "dhcp-option DNS 8.8.8.8"
push "dhcp-option DNS 208.67.222.222"
client-to-client
keepalive 10 120
max-clients 10
persist-key
persist-tun
status /var/log/openvpn-status.log
log /var/log/openvpn.log
log-append /var/log/openvpn.log
verb 6
vpn.cnf
Code:
client
setenv SERVER_POLL_TIMEOUT 4
nobind
remote xxx.xxx.xxx.xxx 1194 udp
dev tun
dev-type tun
ns-cert-type server
reneg-sec 604800
sndbuf 100000
rcvbuf 100000
auth-retry nointeract
# NOTE: LZO commands are pushed by the Access Server at connect time.
# NOTE: The below line doesn't disable LZO.
# comp-lzo no
verb 9
ca /config/openvpn/keys/ca.crt
cert /config/openvpn/keys/ext101.crt
key /config/openvpn/keys/ext101.key
server log:
Code:
Thu Feb 27 10:13:12 2014 us=346045 xxx.xxx.xxx.xxx:1025 TLS: new session incoming connection from [AF_INET]xxx.xxx.xxx.xxx:1025
Thu Feb 27 10:13:12 2014 us=346124 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:12 2014 us=346216 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [22] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 27 10:13:12 2014 us=507456 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:12 2014 us=507622 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:13 2014 us=515303 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:13 2014 us=515436 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:13 2014 us=677283 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:14 2014 us=685082 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:14 2014 us=685238 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:14 2014 us=700063 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:14 2014 us=733688 xxx.xxx.xxx.xxx:1025 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 27 10:13:14 2014 us=733731 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [22] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 27 10:13:15 2014 us=740894 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=21 DATA len=100
Thu Feb 27 10:13:15 2014 us=741046 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:16 2014 us=762732 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:16 2014 us=762870 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=21 DATA len=100
Thu Feb 27 10:13:16 2014 us=830412 xxx.xxx.xxx.xxx:1025 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 27 10:13:16 2014 us=830434 xxx.xxx.xxx.xxx:1025 TLS: new session incoming connection from [AF_INET]xxx.xxx.xxx.xxx:1025
Thu Feb 27 10:13:16 2014 us=830481 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [22] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 27 10:13:17 2014 us=837528 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:17 2014 us=837678 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:18 2014 us=858359 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:18 2014 us=858554 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:18 2014 us=873329 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=21 DATA len=100
Thu Feb 27 10:13:18 2014 us=873458 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=21 DATA len=100
Thu Feb 27 10:13:18 2014 us=906118 xxx.xxx.xxx.xxx:1025 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 27 10:13:18 2014 us=906168 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [22] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 27 10:13:19 2014 us=913171 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=24 DATA len=100
Thu Feb 27 10:13:19 2014 us=928116 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:19 2014 us=928230 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=22 DATA len=100
Thu Feb 27 10:13:20 2014 us=939983 xxx.xxx.xxx.xxx:1025 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_V1 kid=0 [ ] pid=21 DATA len=100
Thu Feb 27 10:13:20 2014 us=954953 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:20 2014 us=955091 xxx.xxx.xxx.xxx:1024 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1024: P_CONTROL_V1 kid=0 [ ] pid=23 DATA len=100
Thu Feb 27 10:13:21 2014 us=14110 xxx.xxx.xxx.xxx:1025 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.xxx:1025: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
phone log:
Code:
Feb 27 15:13:11 openvpn[289]: event_wait returned 1
Feb 27 15:13:11 openvpn[289]: UDPv4 read returned 114
Feb 27 15:13:11 openvpn[289]: UDPv4 READ [114] from xxx.xxx.xxx.xxx:1194: P_CONTROL_V1 kid=0 sid=efd774cb d67255ae [ ] pid=21 DATA c6c2f540 1970f640 9d201c15 0f140d05 5902acb3 de50d039 cdfa3f47 ae7827a[more...]
Feb 27 15:13:11 openvpn[289]: VERIFY ERROR: depth=1, error=certificate signature failure: /C=US/ST=FL/L=PSL/O=L4/OU=VoIP/CN=CA/name=EasyRSA/emailAddress=email@domain.com
Feb 27 15:13:11 openvpn[289]: TLS_ERROR: BIO read tls_read_plaintext error: error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
Feb 27 15:13:11 openvpn[289]: TLS Error: TLS object -> incoming plaintext read error
Feb 27 15:13:11 openvpn[289]: TLS Error: TLS handshake failed
Feb 27 15:13:11 openvpn[289]: TCP/UDP: Closing socket
Feb 27 15:13:11 openvpn[289]: SIGUSR1[soft,tls-error] received, process restarting
Feb 27 15:13:11 openvpn[289]: Restart pause, 1 second(s)
Feb 27 15:13:12 openvpn[289]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Feb 27 15:13:12 openvpn[289]: Control Channel MTU parms [ L:1541 D:138 EF:38 EB:0 ET:0 EL:0 ]
Feb 27 15:13:12 openvpn[289]: Socket Buffers: R=[112640->200000] S=[112640->200000]
Feb 27 15:13:12 openvpn[289]: Data Channel MTU parms [ L:1541 D:1450 EF:41 EB:4 ET:0 EL:0 ]
Feb 27 15:13:12 openvpn[289]: Local Options String: 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Feb 27 15:13:12 openvpn[289]: Expected Remote Options String: 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Feb 27 15:13:12 openvpn[289]: Local Options hash (VER=V4): '3514370b'
Feb 27 15:13:12 openvpn[289]: Expected Remote Options hash (VER=V4): '239669a8'
Feb 27 15:13:12 openvpn[289]: UDPv4 link local: [undef]
Feb 27 15:13:12 openvpn[289]: UDPv4 link remote: xxx.xxx.xxx.xxx:1194
Feb 27 15:13:12 openvpn[289]: event_wait returned 1
Feb 27 15:13:12 openvpn[289]: UDPv4 WRITE [14] to xxx.xxx.xxx.xxx:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=9556f882 e5b163bb [ ] pid=0 DATA
Feb 27 15:13:12 openvpn[289]: UDPv4 write returned 14
Feb 27 15:13:12 openvpn[289]: event_wait returned 1
Feb 27 15:13:12 openvpn[289]: UDPv4 read returned 114
Feb 27 15:13:12 openvpn[289]: UDPv4 READ [114] from xxx.xxx.xxx.xxx:1194: P_CONTROL_V1 kid=0 sid=1e9fbd62 67d1be10 [ ] pid=22 DATA 59b3efd8 f23841af 5c1e51ec 1b36994c ed207f7a ea1f4c89 a041f56f f4417bd[more...]
Feb 27 15:13:12 openvpn[289]: TLS Error: Unroutable control packet received from xxx.xxx.xxx.xxx:1194 (si=3 op=P_CONTROL_V1)
Feb 27 15:13:12 openvpn[289]: event_wait returned 1
Feb 27 15:13:12 openvpn[289]: UDPv4 read returned 22
Feb 27 15:13:12 openvpn[289]: UDPv4 READ [22] from xxx.xxx.xxx.xxx:1194: P_ACK_V1 kid=0 sid=efd774cb d67255ae [ 0 sid=9556f882 e5b163bb ]
Feb 27 15:13:12 openvpn[289]: TLS Error: Unroutable control packet received from xxx.xxx.xxx.xxx:1194 (si=3 op=P_ACK_V1)
I also now noticed this in the phone log:
Code:
Feb 27 15:13:11 openvpn[289]: VERIFY ERROR: depth=1, error=certificate signature failure: /C=US/ST=FL/L=PSL/O=L4/OU=VoIP/CN=CA/name=EasyRSA/emailAddress=email@domain.com
Feb 27 15:13:11 openvpn[289]: TLS_ERROR: BIO read tls_read_plaintext error: error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
Feb 27 15:13:11 openvpn[289]: TLS Error: TLS object -> incoming plaintext read error
Feb 27 15:13:11 openvpn[289]: TLS Error: TLS handshake failed
Although, I'm not really sure what to make of it...
I found a user with a similar problem in
http://forum.yealink.com/forum/showthread.php?tid=1007 but I am unsure of how to verify that I am using sha1 (which is supposedly the default for openvpn). I did verify that the pbx102.crt and ext101.crt certificates verify ok against ca.crt using 'openssl verify -CAfile ca.crt ext101.crt' and 'openssl verify -CAfile ca.crt pbx102.crt'
