VPN Server not working

[eric_fri]

I’ve had FreePBX running with the VPN server and my Sangoma phones since 2017 without issue. Recently I upgraded the modules and got the prompt to rebuild my certs and I followed it. Then everything broke. I’ve found this bug report [[FREEPBX-22276] OpenVPN asking to rebuild certs after Critical Update - Sangoma Issue Tracker](issues freepbx org/browse/FREEPBX-22276) Sorry, can’t post links.

and gone through all the steps to rebuild my certs but I’m still having trouble.

As-is, my phones will connect if I disable the VPN but once the VPN is on, they say they connect to the server, as reported by both the phone and the Sys admin module, but no traffic will flow.

I take the exact same config and load it into my Windows OpenVPN client and it connects and traffic flows without issue.

I have purged and rebuilt the config so many times, checked my firewall, watched the logs and I can’t find the issue. The phones are a mix of S500, S505, and S405. I’ve updated them to the latest firmware.

Does anybody have any suggestions on what I could be missing?

[shahin (Shahin NAZIR)]

Hi @eric_fri
I think ( guess ) your All other Services and settings are correct:

• PBX Firewall --> Extra Services --> OpenVPN allowed form Internet/ Local/ Other networks ?
• EPM --> Provisioning settings and Phones without VPN, going to take over configs from your PBX?
• OpenVPN service Running and If your PBX is behind a firewall you will also need to make sure port 1194 UCP/TCP is opened to your PBX.

Pls check this wiki : https://wiki.freepbx.org/display/FDT/Connecting+Remote+Phone+to+VPN

I think your phones can not resolve DNS and OpenVPN certificate and Hostname. Before i have seen with only Privet DNS sometimes can not Run OpneVPN. Thats why try to ADD at list one or two PUBLIC DNS servers 8.8.8.8 or 1.1.1.1 on your Phone DHCP server rot 2nd or 3rd DNS name.

Also you can follow and from FreePBX CLI logs?
# tail -f /var/log/httpd/access_log | grep -i Sangoma

Thanks.

[eric_fri]

Hi Shahin,

Thanks for the reply.

• PBX Firewall - I’ve tried fully disabling it, no difference. OpenVPN is allowed from Internet, Local, and Other.
• Provisioning without VPN works just fine.
• VPN port is open. And the VPN works, as proven by using both a Windows and Mac client with the phone’s config files.

The phone is using Google’s DNS.

Here are the logs after a factory reset of the phone.

x.x.x.x - httpusername [23/Mar/2021:10:53:19 -0700] "GET /cfg0500.xml HTTP/1.1" 200 727 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:27 -0700] "GET /cfg005058505d67.xml HTTP/1.1" 200 63130 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:31 -0700] "GET /images/formatted/bg-sangoma-S500-s500-bg-image.jpg HTTP/1.1" 200 40423 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:32 -0700] "GET /images/formatted/bg-sangoma-S500-s500-bg-image.jpg HTTP/1.1" 200 40423 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:34 -0700] "GET /ringtones/formatted/ring4.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:34 -0700] "GET /ringtones/formatted/ring5.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:34 -0700] "GET /ringtones/formatted/ring6.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:35 -0700] "GET /ringtones/formatted/ring7.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:35 -0700] "GET /ringtones/formatted/ring8.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:35 -0700] "GET /ringtones/formatted/ring9.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:35 -0700] "GET /ringtones/formatted/ring10.bin HTTP/1.1" 404 228 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:35 -0700] "GET /cfg201-states.xml HTTP/1.1" 200 6016 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:53:38 -0700] "GET /sangoma/2/fw500.rom HTTP/1.1" 200 17999194 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:30 -0700] "GET /factory0500.bin HTTP/1.1" 404 213 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:30 -0700] "GET /cfg0500.xml HTTP/1.1" 200 727 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:32 -0700] "GET /005058505d67.cfg HTTP/1.1" 404 214 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:32 -0700] "GET /cfg005058505d67 HTTP/1.1" 404 213 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:33 -0700] "GET /cfg005058505d67.xml HTTP/1.1" 200 63130 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:36 -0700] "GET /images/formatted/bg-sangoma-S500-s500-bg-image.jpg HTTP/1.1" 200 40423 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:38 -0700] "GET /images/formatted/bg-sangoma-S500-s500-bg-image.jpg HTTP/1.1" 200 40423 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:39 -0700] "GET /ringtones/formatted/ring4.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring5.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring6.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring7.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring8.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring9.bin HTTP/1.1" 404 227 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:40 -0700] "GET /ringtones/formatted/ring10.bin HTTP/1.1" 404 228 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:41 -0700] "GET /cfg201-states.xml HTTP/1.1" 200 6016 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"
x.x.x.x - httpusername [23/Mar/2021:10:54:41 -0700] "GET /sangoma/2/fw500.rom HTTP/1.1" 200 17999194 "-" "Sangoma S500 2.0.4.79 00:50:58:50:5d:67"

[shahin (Shahin NAZIR)]

Hi @eric_fri
This S500 ( 005058505d67 ) is in your location ? If yes try to call on your WEB browser XML file.
http://IP_Address_:Port/cfg005058505d67.xml ( you can change http to https:// if you are using secure provisioning )

And could you pls send screenshot of EPM → Extension Mapping → 005058505d67
should be like this

If everything looks correct, try to remove 005058505d67 from Extension Mapping page and RE-Create it again. After that you should see a new config file in /tftpboot/005058505d67.xml with new created date and time.

[eric_fri]

The PBX is hosted with CyberLynk and the phones are on my local LAN. If I use my OpenVPN client on my Windows machine and request the config file it downloads without a problem. I will do some more testing, but I believe the phone downloads the config just fine, attempts to connect to the VPN, which gets an IP but disconnects.

Here are the logs from /var/log/messages

Mar 23 11:08:59 freepbx openvpn: Tue Mar 23 11:08:59 2021 x.x.x.x:61006 VERIFY OK: depth=0, CN=client24
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 x.x.x.x:61006 [client24] Peer Connection Initiated with [AF_INET]x.x.x.x:61006
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 OPTIONS IMPORT: reading client specific options from: ccd/client24
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 MULTI: Learn: 10.8.0.201 → client24/x.x.x.x:61006
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 MULTI: primary virtual IP for client24/x.x.x.x:61006: 10.8.0.201
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 PUSH: Received control message: ‘PUSH_REQUEST’
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 SENT CONTROL [client24]: ‘PUSH_REPLY,route x.x.y.y 255.255.255.128,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.8.0.201 255.255.255.0,peer-id 0,cipher AES-256-GCM’ (status=1)
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 Data Channel: using negotiated cipher ‘AES-256-GCM’
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 Outgoing Data Channel: Cipher ‘AES-256-GCM’ initialized with 256 bit key
Mar 23 11:09:00 freepbx openvpn: Tue Mar 23 11:09:00 2021 client24/x.x.x.x:61006 Incoming Data Channel: Cipher ‘AES-256-GCM’ initialized with 256 bit key
Mar 23 11:09:01 freepbx openvpn: Tue Mar 23 11:09:01 2021 client24/x.x.x.x:61006 IP packet with unknown IP version=0 seen
Mar 23 11:10:32 freepbx openvpn: Tue Mar 23 11:10:32 2021 client24/x.x.x.x:61006 SIGTERM[soft,remote-exit] received, client-instance exiting

And the syslog from the phone itself.

[03-22 20:31:59 50:5d:67] vpn_log_file_length is 0, st_size is 0
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 OpenVPN 2.2.2 mips-linux [SSL] [LZO2] [EPOLL] [eurephia] built on Jun 21 2014
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 NOTE: OpenVPN 2.1 requires ‘–script-security 2’ or higher to call user-defined scripts or executables
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 WARNING: file ‘/hlcfg/vpn/keys/sysadmin_client24.key’ is group or others accessible
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 LZO compression initialized
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Socket Buffers: R=[126976->131072] S=[126976->131072]
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Local Options hash (VER=V4): ‘41690919’
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Expected Remote Options hash (VER=V4): ‘530fdded’
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 UDPv4 link local: [undef]
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 UDPv4 link remote: x.x.x.x:1194
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 TLS: Initial packet from x.x.x.x:1194, sid=c9829b33 6231b379
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 VERIFY OK: depth=1, /CN=FreePBX
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Validating certificate key usage
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 ++ Certificate has key usage 00a0, expects 00a0
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 VERIFY KU OK
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 Validating certificate extended key usage
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 VERIFY EKU OK
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:41 2021 VERIFY OK: depth=0, /CN=server1
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 Data Channel Encrypt: Cipher ‘BF-CBC’ initialized with 128 bit key
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 Data Channel Encrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 Data Channel Decrypt: Cipher ‘BF-CBC’ initialized with 128 bit key
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 Data Channel Decrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 Control Channel: TLSv1, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-SHA, 2048 bit RSA
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:43 2021 [server1] Peer Connection Initiated with x.x.x.x:1194
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:46 2021 SENT CONTROL [server1]: ‘PUSH_REQUEST’ (status=1)
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 PUSH: Received control message: ‘PUSH_REPLY,route x.x.y.y 255.255.255.128,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.8.0.2 255.255.255.0’
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 OPTIONS IMPORT: timers and/or timeouts modified
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 OPTIONS IMPORT: --ifconfig/up options modified
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 OPTIONS IMPORT: route options modified
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 OPTIONS IMPORT: route-related options modified
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 ROUTE default_gateway=192.168.8.1
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 TUN/TAP device tun0 opened
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 TUN/TAP TX queue length set to 100
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 /sbin/ifconfig tun0 10.8.0.2 netmask 255.255.255.0 mtu 1500 broadcast 10.8.0.255
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:47 2021 /sbin/route add -net x.x.y.y netmask 255.255.255.128 gw 10.8.0.1
[03-22 20:31:59 50:5d:67] OpenVPN: Mon Mar 22 20:31:48 2021 Initialization Sequence Completed

In the EPM, the phone works if I turn the VPN off (but only after deleting the config and rebuilding), as the phone will try to connect to the VPN but ultimately fails.

The part I find really odd is that it was working perfectly before the CERT update, at which point everything broke.

[shahin (Shahin NAZIR)]

Hi Eric,

Pls try to check below thinks for verify your SSL Certification.
** /etc/asterisk/keys/ and /etc/asterisk/keys/integration/ folder, you must see your NEW certification there.
** Same certification ^^ path check FreePBX web page → Settings → Advance Settings ( Must your new certificate path mach and correct )
** Try to check your PBX FQDN name via ( SSL Checker ) or ( https://www.digicert.com/help/ )
Could be your NEW SSL certificate root chain is broken or faulty… Or your phones doesn’t supports this NEW SSL certificate ?

[eric_fri]

This is what I see in /etc/asterisk/keys

drwxrwxr-x. 5 asterisk asterisk 4096 Dec 16 2019 .
drwxrwxr-x. 5 asterisk asterisk 12288 Mar 22 19:43 …
-rw-rw-r–. 1 asterisk asterisk 1024 Dec 13 2019 .rnd
drwxr-xr-x 2 asterisk asterisk 4096 Dec 13 2019 _account
-rw-rw-r-- 1 asterisk asterisk 237 Nov 17 2019 ca.cfg
-rw-rw-r-- 1 asterisk asterisk 1850 Nov 17 2019 ca.crt
-rw-rw-r-- 1 asterisk asterisk 3243 Nov 17 2019 ca.key
drwxr-xr-x 2 asterisk asterisk 4096 Dec 13 2019 freepbx.mydomain.ca
-rw------- 1 asterisk asterisk 2789 Mar 13 02:02 freepbx.mydomain-ca-bundle.crt
-rw------- 1 asterisk asterisk 2215 Mar 13 02:02 freepbx.mydomain.crt
-rw------- 1 asterisk asterisk 3272 Mar 13 02:02 freepbx.mydomain.key
-rw------- 1 asterisk asterisk 8278 Mar 13 02:02 freepbx.mydomain.pem
drwxrwxr-x. 2 asterisk asterisk 4096 Mar 13 02:02 integration

/etc/asterisk/keys/integration

drwxrwxr-x. 2 asterisk asterisk 4096 Mar 13 02:02 .
drwxrwxr-x. 5 asterisk asterisk 4096 Dec 16 2019 …
-rw------- 1 asterisk asterisk 8278 Mar 13 02:02 certificate.pem
-rw------- 1 asterisk asterisk 2215 Mar 13 02:02 webserver.crt
-rw------- 1 asterisk asterisk 3272 Mar 13 02:02 webserver.key

System → Advanced → HTTPS TLS Certificate Location = /etc/asterisk/keys/integration/certificate.pem
System → Advanced → HTTPS TLS Private Key Location = /etc/asterisk/keys/integration/webserver.key

[eric_fri]

I finally figured out my issue. In the VPN server, routing for my PBXs public IP was enabled and when the phone got that routing information it lost all connectivity to the PBX. Turning the routing off fixed it.