OpenVPN server - TLS key failed to occur within 60 secs

remenakb1 · February 12, 2018, 11:04am

I followed that guide (comprehensive) and used the commands that were listed in it, so I thought I did since I see a -nodes in the csr/key creation command for the server. Maybe I didn't copy and paste correctly. Is there an easy way to redo or remove this or do I need to redo creating all keys and certs?

JW0914 · February 12, 2018, 12:26pm

Open the server key in a text editor, and if the header begins with the following, it's encrypted:

-----BEGIN ENCRYPTED PRIVATE KEY-----
- If you're utilizing a PKCS12 for the VPN Server, did you export it with a password?
  - i.e. When prompted for an export password when creating a PKCS12 for a server, don't enter a password when prompted and press [ENTER] key twice

You deviated from the wiki at some point, so please perform the steps in Troubleshooting for your next post.

Skip all client steps (i.e. #2, client related info in #3)
Please post logs and configs within code boxes (three backticks on new line, code/log output on new line, followed by three backticks on new line)

tmomas · February 12, 2018, 1:49pm

Simply use the "Preformatted text </>" button in the editor for any configs, logs and general console output.

remenakb1 · February 12, 2018, 1:59pm

I did create the PKCS12 file and create an export password. You might be onto something, that might be it! I will try it later today when I get a chance to work on it again. If I am still having issues I will post back after following the steps in "Troubleshooting".

Also just so you know I found a typo in the guide (at least I think it is one):
Under the Server Cert Commands -> Export to PKCS12 the command is

openssl pkcs12 -export -out openvpn/vpn-server.p12 -inkey openvpn/vpn-server.key.pem
-in certs/vpn-server.crt.pem -certfile ca/OpenWrt-OpenVPN_CA-Chain.crt.pem

I believe is should be (added an I in the last filename)

openssl pkcs12 -export -out openvpn/vpn-server.p12 -inkey openvpn/vpn-server.key.pem
-in certs/vpn-server.crt.pem -certfile ca/OpenWrt-OpenVPN_ICA-Chain.crt.pem

Also some more deviations I needed to do, which may be just my system, but in all the commands I needed to add "/etc/ssl/" to filenames so it could properly find the files.

I also needed to change the openssl.cnf file to have anywhere the $dir was to be /etc/ssl/

Maybe that is something that is wrong with my setup, but everything seemed to create and find files once I specifically called out the full path and didn't use the variable in the openssl.cnf file. I was issuing the commands from /etc/ssl/

remenakb1 · February 13, 2018, 1:29am

My Server Log:

Mon Feb 12 19:14:26 2018 us=930313 OpenVPN 2.4.4 mips-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD]
Mon Feb 12 19:14:26 2018 us=930530 library versions: OpenSSL 1.0.2n  7 Dec 2017, LZO 2.10
Mon Feb 12 19:14:26 2018 us=933091 Diffie-Hellman initialized with 2048 bit key
Mon Feb 12 19:14:26 2018 us=933599 No valid translation found for TLS cipher '!aNULL'
Mon Feb 12 19:14:26 2018 us=934087 No valid translation found for TLS cipher '!eNULL'
Mon Feb 12 19:14:26 2018 us=934482 No valid translation found for TLS cipher '!3DES'
Mon Feb 12 19:14:26 2018 us=934790 No valid translation found for TLS cipher '!MD5'
Mon Feb 12 19:14:26 2018 us=935189 No valid translation found for TLS cipher '!SHA'
Mon Feb 12 19:14:26 2018 us=935560 No valid translation found for TLS cipher '!PSK'
Mon Feb 12 19:14:26 2018 us=945994 No valid translation found for TLS cipher '!DSS'
Mon Feb 12 19:14:26 2018 us=946365 No valid translation found for TLS cipher '!RC4'
Mon Feb 12 19:14:27 2018 us=13552 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:14:27 2018 us=13872 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:14:27 2018 us=14134 TLS-Auth MTU parms [ L:48122 D:1140 EF:110 EB:0 ET:0 EL:3 ]
Mon Feb 12 19:14:27 2018 us=25174 TUN/TAP device tun0 opened
Mon Feb 12 19:14:27 2018 us=25464 TUN/TAP TX queue length set to 100
Mon Feb 12 19:14:27 2018 us=25717 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Mon Feb 12 19:14:27 2018 us=26087 /sbin/ifconfig tun0 10.1.0.1 netmask 255.255.255.240 mtu 48000 broadcast 10.1.0.15
Mon Feb 12 19:14:27 2018 us=52424 Data Channel MTU parms [ L:48122 D:48122 EF:122 EB:8156 ET:0 EL:3 ]
Mon Feb 12 19:14:27 2018 us=52842 Could not determine IPv4/IPv6 protocol. Using AF_INET
Mon Feb 12 19:14:27 2018 us=53101 Socket Buffers: R=[163840->327680] S=[163840->327680]
Mon Feb 12 19:14:27 2018 us=53366 UDPv4 link local (bound): [AF_INET][undef]:MYPORT
Mon Feb 12 19:14:27 2018 us=53585 UDPv4 link remote: [AF_UNSPEC]
Mon Feb 12 19:14:27 2018 us=53813 GID set to nogroup
Mon Feb 12 19:14:27 2018 us=54050 UID set to nobody
Mon Feb 12 19:14:27 2018 us=54283 MULTI: multi_init called, r=256 v=256
Mon Feb 12 19:14:27 2018 us=54609 IFCONFIG POOL: base=10.1.0.2 size=12, ipv6=0
Mon Feb 12 19:14:27 2018 us=60664 Initialization Sequence Completed
Mon Feb 12 19:34:07 2018 us=19825 event_wait : Interrupted system call (code=4)
Mon Feb 12 19:34:07 2018 us=20351 TCP/UDP: Closing socket
Mon Feb 12 19:34:07 2018 us=20760 Closing TUN/TAP interface
Mon Feb 12 19:34:07 2018 us=21007 /sbin/ifconfig tun0 0.0.0.0
ifconfig: SIOCSIFADDR: Operation not permitted
Mon Feb 12 19:34:07 2018 us=26455 Linux ip addr del failed: external program exited with error status: 1
Mon Feb 12 19:34:07 2018 us=34188 SIGTERM[hard,] received, process exiting
Mon Feb 12 19:34:07 2018 us=507413 OpenVPN 2.4.4 mips-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD]
Mon Feb 12 19:34:07 2018 us=507609 library versions: OpenSSL 1.0.2n  7 Dec 2017, LZO 2.10
Mon Feb 12 19:34:07 2018 us=517909 Diffie-Hellman initialized with 2048 bit key
Mon Feb 12 19:34:07 2018 us=518433 No valid translation found for TLS cipher '!aNULL'
Mon Feb 12 19:34:07 2018 us=518753 No valid translation found for TLS cipher '!eNULL'
Mon Feb 12 19:34:07 2018 us=519119 No valid translation found for TLS cipher '!3DES'
Mon Feb 12 19:34:07 2018 us=519429 No valid translation found for TLS cipher '!MD5'
Mon Feb 12 19:34:07 2018 us=519738 No valid translation found for TLS cipher '!SHA'
Mon Feb 12 19:34:07 2018 us=520116 No valid translation found for TLS cipher '!PSK'
Mon Feb 12 19:34:07 2018 us=520490 No valid translation found for TLS cipher '!DSS'
Mon Feb 12 19:34:07 2018 us=520801 No valid translation found for TLS cipher '!RC4'
Mon Feb 12 19:34:07 2018 us=655060 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:34:07 2018 us=655380 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:34:07 2018 us=655665 TLS-Auth MTU parms [ L:48124 D:1138 EF:112 EB:0 ET:0 EL:3 ]
Mon Feb 12 19:34:07 2018 us=676423 TUN/TAP device tun0 opened
Mon Feb 12 19:34:07 2018 us=676711 TUN/TAP TX queue length set to 100
Mon Feb 12 19:34:07 2018 us=676966 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Mon Feb 12 19:34:07 2018 us=677295 /sbin/ifconfig tun0 10.1.0.1 netmask 255.255.255.240 mtu 48000 broadcast 10.1.0.15
Mon Feb 12 19:34:07 2018 us=692752 Data Channel MTU parms [ L:48124 D:48124 EF:124 EB:8156 ET:0 EL:3 ]
Mon Feb 12 19:34:07 2018 us=694489 Could not determine IPv4/IPv6 protocol. Using AF_INET
Mon Feb 12 19:34:07 2018 us=694772 Socket Buffers: R=[87380->327680] S=[16384->327680]
Mon Feb 12 19:34:07 2018 us=695037 Listening for incoming TCP connection on [AF_INET][undef]:MYPORT
Mon Feb 12 19:34:07 2018 us=695303 TCPv4_SERVER link local (bound): [AF_INET][undef]:MYPORT
Mon Feb 12 19:34:07 2018 us=695533 TCPv4_SERVER link remote: [AF_UNSPEC]
Mon Feb 12 19:34:07 2018 us=695774 GID set to nogroup
Mon Feb 12 19:34:07 2018 us=696112 UID set to nobody
Mon Feb 12 19:34:07 2018 us=696371 MULTI: multi_init called, r=256 v=256
Mon Feb 12 19:34:07 2018 us=696671 IFCONFIG POOL: base=10.1.0.2 size=12, ipv6=0
Mon Feb 12 19:34:07 2018 us=697065 MULTI: TCP INIT maxclients=1024 maxevents=1028
Mon Feb 12 19:34:07 2018 us=702781 Initialization Sequence Completed
Mon Feb 12 19:35:07 2018 us=626887 TCP/UDP: Closing socket
Mon Feb 12 19:35:07 2018 us=627364 Closing TUN/TAP interface
Mon Feb 12 19:35:07 2018 us=627629 /sbin/ifconfig tun0 0.0.0.0
ifconfig: SIOCSIFADDR: Operation not permitted
Mon Feb 12 19:35:07 2018 us=632850 Linux ip addr del failed: external program exited with error status: 1
Mon Feb 12 19:35:07 2018 us=640846 SIGTERM[hard,] received, process exiting
Mon Feb 12 19:35:08 2018 us=137705 OpenVPN 2.4.4 mips-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD]
Mon Feb 12 19:35:08 2018 us=137904 library versions: OpenSSL 1.0.2n  7 Dec 2017, LZO 2.10
Mon Feb 12 19:35:08 2018 us=140462 Diffie-Hellman initialized with 2048 bit key
Mon Feb 12 19:35:08 2018 us=140964 No valid translation found for TLS cipher '!aNULL'
Mon Feb 12 19:35:08 2018 us=141289 No valid translation found for TLS cipher '!eNULL'
Mon Feb 12 19:35:08 2018 us=141663 No valid translation found for TLS cipher '!3DES'
Mon Feb 12 19:35:08 2018 us=141971 No valid translation found for TLS cipher '!MD5'
Mon Feb 12 19:35:08 2018 us=142488 No valid translation found for TLS cipher '!SHA'
Mon Feb 12 19:35:08 2018 us=142882 No valid translation found for TLS cipher '!PSK'
Mon Feb 12 19:35:08 2018 us=143256 No valid translation found for TLS cipher '!DSS'
Mon Feb 12 19:35:08 2018 us=143589 No valid translation found for TLS cipher '!RC4'
Mon Feb 12 19:35:08 2018 us=271765 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:35:08 2018 us=272099 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Feb 12 19:35:08 2018 us=272362 TLS-Auth MTU parms [ L:48124 D:1138 EF:112 EB:0 ET:0 EL:3 ]
Mon Feb 12 19:35:08 2018 us=306002 TUN/TAP device tun0 opened
Mon Feb 12 19:35:08 2018 us=306294 TUN/TAP TX queue length set to 100
Mon Feb 12 19:35:08 2018 us=306552 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Mon Feb 12 19:35:08 2018 us=306885 /sbin/ifconfig tun0 10.1.0.1 netmask 255.255.255.240 mtu 48000 broadcast 10.1.0.15
Mon Feb 12 19:35:08 2018 us=316582 Data Channel MTU parms [ L:48124 D:48124 EF:124 EB:8156 ET:0 EL:3 ]
Mon Feb 12 19:35:08 2018 us=318317 Could not determine IPv4/IPv6 protocol. Using AF_INET
Mon Feb 12 19:35:08 2018 us=318600 Socket Buffers: R=[87380->327680] S=[16384->327680]
Mon Feb 12 19:35:08 2018 us=318874 Listening for incoming TCP connection on [AF_INET][undef]:MYPORT
Mon Feb 12 19:35:08 2018 us=319139 TCPv4_SERVER link local (bound): [AF_INET][undef]:MYPORT
Mon Feb 12 19:35:08 2018 us=319364 TCPv4_SERVER link remote: [AF_UNSPEC]
Mon Feb 12 19:35:08 2018 us=319598 GID set to nogroup
Mon Feb 12 19:35:08 2018 us=319862 UID set to nobody
Mon Feb 12 19:35:08 2018 us=320110 MULTI: multi_init called, r=256 v=256
Mon Feb 12 19:35:08 2018 us=320406 IFCONFIG POOL: base=10.1.0.2 size=12, ipv6=0
Mon Feb 12 19:35:08 2018 us=320792 MULTI: TCP INIT maxclients=1024 maxevents=1028
Mon Feb 12 19:35:08 2018 us=339733 Initialization Sequence Completed

JW0914 · February 13, 2018, 1:20pm

Thanks for catching that, it's been corrected.

Two questions:

What is your LAN subnet (192.168.1.0/24 or 192.168.1.0/26)?
- Whichever it is, you'll need to update the server config or your firewall config, as the server config is 192.168.1.0/24, whereas the firewall config is 192.168.1.0/26.
When your client failed to connect, was it trying to connect while behind the router running the OpenVPN server?
- If no, please bump up the the client verbosity to 9 (verb 9) and the server to verbosity 7 (verb 7)
  - What OS is your client running?
  - Is vpn-client3.p12 located in the same directory as the client config?
- If yes, this is likely the issue... please try connecting a client that isn't behind the router and it should connect successfully
- When I created that wiki, I had a reason for setting server logging to log_append instead of just log, however I can't recall why.
  - In your server log, please change option log_append to option log
- Once all the changes have been made, please issue:
  - cd /etc/init.d ; ./firewall reload ; ./openvpn restart, then try reconnecting with the client. If it fails again, please post the server and client logs.

remenakb1 · February 14, 2018, 2:17am

Good catch! I will get these modified.

Yes it was trying to connect while behind my router running the OpenVPN server.

My only client (that isn't behind behind the router running the vpn server) I can test with while working on this is my iphone on the cell network, and I am still having issues on TCP I get a connection refused error and on UDP I get a server Poll timeout error.

I kind of think it might still be with my LAN subnet and IP addresses. When modifying those settings I realized I don't fully understand everything. There are a lot of IP references in the firewall and server config and I don't know how they all relate to each other, which ones match up with each other, or what they all mean.

For instance what is this IP supposed to match up with? Should it match my router IP? And then this needs to match the tules in the firewall (dest_ip)?

In your reply you said:

But I didn't have anything in my configs with 192.168.1.0, they were 192.168.1.1. Should they have been .0 or .1 to match my router IP? Maybe you saw the comment in the firewall that I didn't modify to .1

Maybe the issue is trying to connect with my iphone and the client config is wrong. I can try tomorrow from my work to see if I can connect from there to my VPN on my laptop there.

One more question since it is confusing me. In the guide it looks to me like the firewall is set to subnet 26 an the server config is set to subnet 24:

guide server:

 # Pushed Routes # 
#------------------------------------------------
    list    push                'route 192.168.1.0 255.255.255.0'
    list    push                'dhcp-option    DNS 192.168.1.1'
    list    push                'dhcp-option    WINS 192.168.1.1'
    list    push                'dhcp-option    DNS 208.67.222.123'
    list    push                'dhcp-option    DNS 208.67.220.123'
    list    push                'dhcp-option    NTP 129.6.15.30'

guide firewall:

config rule
    option  target          'ACCEPT'
    option  family          'ipv4'
    option  proto           'tcp udp'
    option  src             '*'
    option  src_ip          '10.1.0.0/28'
    option  dest_ip         '192.168.1.0/26'
    option  name            'Allow VPN0 -> LAN'
 
# Once Assigned VPN IP, Allow Forwarded -> LAN #
#------------------------------------------------
# LuCI: From IP range 10.1.0.0/28 in any zone To IP
# range 192.168.1.0/28  on this device (Accept Forward)
config rule
    option  target          'ACCEPT'
    option  proto           'tcp udp'
    option  family          'ipv4'
    option  src             '*'
    option  src_ip          '10.1.0.0/28'
    option  dest            '*'
    option  dest_ip         '192.168.1.0/26'
    option  name            'Allow Forwarded VPN0 -> LAN'

remenakb1 · February 14, 2018, 2:23am

One more thought.

Should the rules in my firewall be moved around? I have the rules for the VPN at the bottom of the firewall document.

remenakb1 · February 14, 2018, 2:38am

Wait. My latest attempt might have worked, even though I was (on my laptop) behind the router running the server. The latest client log looks like this:

Tue Feb 13 21:27:20 2018 us=535641 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 48104,tun-mtu 48000,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-server'
Tue Feb 13 21:27:20 2018 us=536642 TCP/UDP: Preserving recently used remote address: [AF_INET]MY IP AND PORT
Tue Feb 13 21:27:20 2018 us=536642 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Feb 13 21:27:20 2018 us=536642 Attempting to establish TCP connection with [AF_INET]MYIP AND PORT [nonblock]
Tue Feb 13 21:27:20 2018 us=536642 MANAGEMENT: >STATE:1518575240,TCP_CONNECT,,,,,,

Does that mean it connected?

JW0914 · February 15, 2018, 12:24am

You cannot connect to your VPN while behind the router the VPN is running on... that's an entirely different VPN setup (gateway redirect).

192.168.1.1 is an IP address, of which is contained within the 192.168.1.0/24 (or 192.168.1.0/26) subnet.

192.168.1.0/24: 192.168.1.0 - 192.168.1.255 with a netmask of 255.255.255.0
192.168.1.0/26: 192.168.1.0 - 192.168.1.63 with a netmask of 255.255.255.192
See Subnet Mask Cheat Sheet

Thanks for catching this as well, it's been corrected with the 192.168.1.0/24 LAN subnet reflected in both the firewall and server config.

Ideally, they should be in the order listed under [Firewall] Create Rules

No, as the client log will show an IP assigned, as well as state "Connected,Success"

Client Log (Connect Successful)

Wed Feb 14 18:13:36 2018 us=368902 MANAGEMENT: >STATE:1518653616,ASSIGN_IP,,10.10.3.5,,,,
Wed Feb 14 18:13:41 2018 us=872302 TEST ROUTES: 1/1 succeeded len=1 ret=1 a=0 u/d=up
Wed Feb 14 18:13:41 2018 us=872302 MANAGEMENT: >STATE:1518653621,ADD_ROUTES,,,,,,
Wed Feb 14 18:13:41 2018 us=872302 C:\WINDOWS\system32\route.exe ADD 192.168.3.0 MASK 255.255.255.192 10.10.3.1
Wed Feb 14 18:13:41 2018 us=880308 Route addition via service succeeded
Wed Feb 14 18:13:41 2018 us=880308 Initialization Sequence Completed
Wed Feb 14 18:13:41 2018 us=880308 MANAGEMENT: >STATE:1518653621,CONNECTED,SUCCESS,10.10.3.5,<WAN IP>,<Port #>,,

JW0914 · February 15, 2018, 2:55am

I'm not sure where it is you're going wrong (see below), but that wiki does work as written, as I've tested it well over 5x when users have had issues to ensure there wasn't an error in the wiki.

Connection refused error is due to your firewall or you're trying to connect to the wrong port.

Your new server config is missing option dev tun

dev tun specifies it's a tun, not tap, configuration
dev tun0 specifies the vpn interface is tun0

This is why your client log shows no output after
TUN not specified

Wed Feb 14 20:51:31 2018 MANAGEMENT: >STATE:1518663091,RESOLVE,,,,,,
Wed Feb 14 20:51:31 2018 Data Channel MTU parms [ L:48124 D:48124 EF:124 EB:8156 ET:0 EL:3 ]
Wed Feb 14 20:51:31 2018 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 48104,tun-mtu 48000,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client'
Wed Feb 14 20:51:31 2018 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 48104,tun-mtu 48000,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-server'
Wed Feb 14 20:51:31 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]<WAN IP>:<Port>
Wed Feb 14 20:51:31 2018 Socket Buffers: R=[65536->65536] S=[65536->65536]
Wed Feb 14 20:51:31 2018 Attempting to establish TCP connection with [AF_INET]<WAN IP>:<Port> [nonblock]
Wed Feb 14 20:51:31 2018 MANAGEMENT: >STATE:1518663091,TCP_CONNECT,,,,,,

TUN specified

 Wed Feb 14 20:57:48 2018 us=475062 MANAGEMENT: >STATE:1518663468,RESOLVE,,,,,,
 Wed Feb 14 20:57:48 2018 us=475062 Data Channel MTU parms [ L:48124 D:48124 EF:124 EB:8156 ET:0 EL:3 ]
 Wed Feb 14 20:57:48 2018 us=475062 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 48104,tun-mtu 48000,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client'
 Wed Feb 14 20:57:48 2018 us=475062 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 48104,tun-mtu 48000,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-server'
 Wed Feb 14 20:57:48 2018 us=475062 TCP/UDP: Preserving recently used remote address: [AF_INET]<WAN IP>:<Port>
 Wed Feb 14 20:57:48 2018 us=475062 Socket Buffers: R=[65536->65536] S=[65536->65536]
 Wed Feb 14 20:57:48 2018 us=475062 Attempting to establish TCP connection with [AF_INET]<WAN IP>:<Port> [nonblock]
 Wed Feb 14 20:57:48 2018 us=475062 MANAGEMENT: >STATE:1518663468,TCP_CONNECT,,,,,,
 Wed Feb 14 20:57:49 2018 us=475155 TCP connection established with [AF_INET]<WAN IP>:<Port>
 Wed Feb 14 20:57:49 2018 us=475155 TCP_CLIENT link local: (not bound)
 Wed Feb 14 20:57:49 2018 us=475155 TCP_CLIENT link remote: [AF_INET]<WAN IP>:<Port>
 Wed Feb 14 20:57:49 2018 us=475155 MANAGEMENT: >STATE:1518663469,WAIT,,,,,,
 Wed Feb 14 20:57:49 2018 us=490727 MANAGEMENT: >STATE:1518663469,AUTH,,,,,,
 Wed Feb 14 20:57:49 2018 us=490727 TLS: Initial packet from [AF_INET]<WAN IP>:<Port>, sid=5e956861 fff84884
 Wed Feb 14 20:57:49 2018 us=705315 VERIFY OK: depth=2, C=US, ST=US, L=Davinci, O=Sophos UTM, OU=Sophos, CN=Sophos UTM CA
 Wed Feb 14 20:57:49 2018 us=706322 VERIFY OK: depth=1, C=US, ST=US, L=Davinci, O=Sophos UTM, OU=LEDE, CN=WRT1900AC ICA
 Wed Feb 14 20:57:49 2018 us=707305 Validating certificate extended key usage
 Wed Feb 14 20:57:49 2018 us=707305 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
 Wed Feb 14 20:57:49 2018 us=707305 VERIFY EKU OK
 Wed Feb 14 20:57:49 2018 us=707305 VERIFY OK: depth=0, C=US, ST=US, L=Davinci, O=WRT1900AC, OU=LEDE, CN=WRT1900AC VPN (Admin)
 Wed Feb 14 20:57:49 2018 us=858311 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
 Wed Feb 14 20:57:49 2018 us=858311 [WRT1900AC VPN (Admin)] Peer Connection Initiated with [AF_INET]<WAN IP>:<Port>
 Wed Feb 14 20:57:50 2018 us=952107 MANAGEMENT: >STATE:1518663470,GET_CONFIG,,,,,,
 Wed Feb 14 20:57:50 2018 us=952107 SENT CONTROL [WRT1900AC VPN (Admin)]: 'PUSH_REQUEST' (status=1)
 Wed Feb 14 20:57:51 2018 us=30213 PUSH: Received control message: 'PUSH_REPLY,route 192.168.3.0 255.255.255.192,dhcp-option    DNS 192.168.3.1,dhcp-option    WINS 192.168.3.1,dhcp-option    DNS 208.67.222.222,dhcp-option    DNS 208.67.220.220,dhcp-option    NTP 129.6.15.30,sndbuf 393216,rcvbuf 393216,route-gateway 10.10.3.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.10.3.5 255.255.255.248,peer-id 0,cipher AES-256-GCM'
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: timers and/or timeouts modified
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: --sndbuf/--rcvbuf options modified
 Wed Feb 14 20:57:51 2018 us=30213 Socket Buffers: R=[65536->393216] S=[65536->393216]
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: --ifconfig/up options modified
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: route options modified
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: route-related options modified
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: peer-id set
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: adjusting link_mtu to 48127
 Wed Feb 14 20:57:51 2018 us=30213 OPTIONS IMPORT: data channel crypto options modified
 Wed Feb 14 20:57:51 2018 us=30213 Data Channel: using negotiated cipher 'AES-256-GCM'
 Wed Feb 14 20:57:51 2018 us=30213 Data Channel MTU parms [ L:48055 D:48055 EF:55 EB:8156 ET:0 EL:3 ]
 Wed Feb 14 20:57:51 2018 us=30213 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
 Wed Feb 14 20:57:51 2018 us=30213 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
 Wed Feb 14 20:57:51 2018 us=30213 interactive service msg_channel=796
 Wed Feb 14 20:57:51 2018 us=45803 ROUTE_GATEWAY 192.168.200.60/255.255.255.192 I=14 HWADDR=f0:1f:af:67:b4:66
 Wed Feb 14 20:57:51 2018 us=45803 open_tun
 Wed Feb 14 20:57:51 2018 us=45803 TAP-WIN32 device [OpenVPN] opened: \\.\Global\{996D8184-1BA5-4C63-A4FD-8EC46CE6E5EC}.tap
 Wed Feb 14 20:57:51 2018 us=45803 TAP-Windows Driver Version 9.21 
 Wed Feb 14 20:57:51 2018 us=45803 TAP-Windows MTU=1500
 Wed Feb 14 20:57:51 2018 us=45803 Set TAP-Windows TUN subnet mode network/local/netmask = 10.10.3.0/10.10.3.5/255.255.255.248 [SUCCEEDED]
 Wed Feb 14 20:57:51 2018 us=45803 Notified TAP-Windows driver to set a DHCP IP/netmask of 10.10.3.5/255.255.255.248 on interface {996D8184-1BA5-4C63-A4FD-8EC46CE6E5EC} [DHCP-serv: 10.10.3.6, lease-time: 31536000]
 Wed Feb 14 20:57:51 2018 us=45803 DHCP option string: 060cc0a8 0301d043 deded043 dcdc2c04 c0a80301 2a048106 0f1e
 Wed Feb 14 20:57:51 2018 us=61438 Successful ARP Flush on interface [13] {996D8184-1BA5-4C63-A4FD-8EC46CE6E5EC}
 Wed Feb 14 20:57:51 2018 us=77061 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
 Wed Feb 14 20:57:51 2018 us=77061 MANAGEMENT: >STATE:1518663471,ASSIGN_IP,,10.10.3.5,,,,
 Wed Feb 14 20:57:56 2018 us=450774 TEST ROUTES: 1/1 succeeded len=1 ret=1 a=0 u/d=up
 Wed Feb 14 20:57:56 2018 us=450774 MANAGEMENT: >STATE:1518663476,ADD_ROUTES,,,,,,
 Wed Feb 14 20:57:56 2018 us=450774 C:\WINDOWS\system32\route.exe ADD 192.168.3.0 MASK 255.255.255.192 10.10.3.1
 Wed Feb 14 20:57:56 2018 us=450774 Route addition via service succeeded
 Wed Feb 14 20:57:56 2018 us=450774 Initialization Sequence Completed
 Wed Feb 14 20:57:56 2018 us=450774 MANAGEMENT: >STATE:1518663476,CONNECTED,SUCCESS,10.10.3.5,<WAN IP>,<Port>,192.168.2.15,58294

psherman · February 15, 2018, 3:32am

@remenakb1 -- you cannot connect via UDP when your server is configured for option proto 'tcp'. It is one or the other. You can run 2 instances of the server, if you want. But any given instance will have defined a port and a protocol (tcp or udp).

JW0914 · February 15, 2018, 4:24am

They're using tcp currently for troubleshooting

remenakb1 · February 15, 2018, 1:12pm

First of all, thank you for sticking with me and helping me through this. I am learning and making progress. I trust that your wiki works and my problem is definitely something I did wrong. But debugging and struggling is how I learn.

Great catch on the dev tun option missing!

I went through all my setup files and checked for any inconsistencies. I have found some anomalies in the firewall. I am specifying some zones and forwarding configurations twice (not sure how, probably in the heat of debugging I copy pasted something wrong). I am going to clean up my firewall and see if this makes things work.

If I wanted to look at my server for logs to see why it would refuse the connection do I follow the steps you listed in the firewall logging tab item 3? Hopefully I won't need to after cleaning up the firewall.

I switched my server to udp and restarted it when I tried the UDP connection with my iphone.

JW0914 · February 15, 2018, 4:14pm

Yes, but that will simply log traffic going to the VPN port, and provided your firewall rules mirror those in the wiki, there should be no issue.

There is a simpler way to configure the rules for the VPN, which you may want to utilize, as, when I overhaul the wiki to put it inline with the new wiki guidelines, I'll be changing those rules to the ones below:

/etc/config/firewall

 # OpenVPN: Admin #
 #---------------------------------------------------
 config rule
     option  target          'ACCEPT'
     option  family          'ipv4'
     option  proto           'tcp udp'
     option  src             *
     option  dest_port       5000
     option  name            'Allow Forwarded OpenVPN Request -> <device>'

 config rule
     option  target          'ACCEPT'
     option  family          'ipv4'
     option  proto           'tcp udp'
     option  src             'vpn'
     option  src_ip          '10.1.0.0/28'
     option  dest_ip         '192.168.1.0/24'
     option  name            'Allow OpenVPN -> LAN'

 config rule
     option  target          'ACCEPT'
     option  family          'ipv4'
     option  proto           'tcp udp'
     option  src             'vpn'
     option  dest            *
     option  name            'Allow Forwarded OpenVPN -> <device>'

 config rule
     option  target          'ACCEPT'
     option  family          'ipv4'
     option  proto           'icmp'
     option  src             'vpn'
     option  src_ip          '10.1.0.0/28'
     option  dest            'lan'
     option  name            'Allow OpenVPN (ICMP) -> LAN'

 config rule
     option  target          'ACCEPT'
     option  family          'ipv4'
     option  proto           'icmp'
     list    icmp_type       'echo-request'
     option  src             'vpn'
     option  src_ip          '10.1.0.0/28'
     option  dest            'wan'
     option  name            'Allow OpenVPN (echo-request) -> WAN'

remenakb1 · February 16, 2018, 1:45am

Thank you for the updated firewall rules.

I now have everything matching the wiki and I still can not connect to the vpn server. Maybe I need to restore defaults on my device and start over. I did initially start with the guide here and then started over with your wiki, so maybe something was left over from that causing an issue.

remenakb1 · February 16, 2018, 8:12pm

I have a quick question. I am going through the wiki trying to understand things better than the first time and I am looking at the openssl.cnf file. One thing that I can not figure out is what the IP.1 address for the Certificate Authority Client. In the sample file it has it as:

[ alt_sophos ]
    IP.1                = 192.168.2.1
    IP.2                = 127.0.0.1
    DNS.1               = UTM.LEDE
    DNS.2               = your.ddns.com

Since the wiki doesn't say to modify this I assume I just leave it as is, but I keep wondering if that IP should match my router IP? I don't understand what this IP means, and have not been able to find anything with google searches or looking at openssl (probably looking in the wrong spot).

I also have the same question for the Intermediate Certificate Authority Clients.

[ alt_lede ]
    IP.1                = 192.168.2.2
    IP.2                = 127.0.0.1
    DNS.1               = LAN.LEDE

Are they just an alternate IP that the CA/ICA client could be on and if it isn't found there it goes to IP.2, the local host (127.0.0.1?

JW0914 · February 16, 2018, 8:42pm

IP.1 Should match the IP of the server it's being created for.
IP.2 Should be the loopback IP [127.0.0.1] if the server it's being created for has a WebUI, as this prevents browsers from barfing a certificate error when tunneling through SSH
- For example, any SSH session can be utilized to tunnel a connection to the WebAdmin (or any device for that matter).
  1. Doing so via PuTTY: Connection => SSH => Tunnels
    - Source port: 5000
      - This can be any arbitrary port
    - Destination: 192.168.1.1:443
      - IP address of WebUI, followed by port #
  2. Once connected via SSH, navigate to https://127.0.0.1:5000 which will load LuCI
DNS.1 should match the router's hostname.localdomain
- I believe the default hostname.localdomain is openwrt.lan (hostname may be wrong, but the default local domain is lan)
  - Hostname is garnished from /etc/config/system
  - Local Domain is garnished from /etc/config/dhcp

Certain OSes/servers require the CA and/or ICA to also have the loopback IP specified in their SAN (Sophos UTM / Sophos XG is one such OS), which is why it's in the SANs of the CA and ICA.

remenakb1 · February 18, 2018, 11:32am

Thank you for the information about what those mean.

I cleaned my router and started over a few times now. I tried the simple VPN server guide and JW's guide. I can't get either one to work. When trying to connect with my phone, on TCP I get a connection refused, and over UDP I get server poll timeout (using either guide).

I have learned a lot going through this, but I don't know ho to diagnose things any farther. I just wanted to update this thread. If anyone has any other ideas or things to try or ways to debug let me know.

Thanks for all the help.

JW0914 · February 18, 2018, 12:21pm

Please perform the steps under Troubleshooting