Tips & Tricks to Troubleshoot Issues
Server Logs
When seeking support, it will often be helpful to know what shows up in the log files found in /var/log/asterisk/sangomartapi/
By default, the log levels in these files are set to 'warn'. There will be times when these will need to be set to debug.
The level settings for the log files can be found in /etc/asterisk/sangomartapi-logger.conf
After adjusting these, the sangomartapi service will need to be reloaded with "fwconsole reload" or "fwconsole pm2 --restart sangomartapi"
When debugging is no longer needed, it is recommended to set the levels back to "warn" to avoid wasted disk space.
Troubleshoot Client Login Issues
Logins fail due to "Invalid Credentials". This message is expected if:
The sangomaconnect module license is invalid/expired
The user does not have the webrtc option enabled in their user settings, in the sangomaconnect tab
Enabling this setting should create an entry in the webrtc_clients database table, so make sure this exists. The device number(shadow extension) is the 98(prefix)+extension
The shadow extension should be included in /etc/asterisk/pjsip.endpoint.conf, which will have webrtc=yes
The login credentials are not valid
Make sure the user can log into UCP with the same credentials used when trying to log in to the Sangoma Phone desktop client. While UCP access is not required, this can be a helpful test when trying to test user login credentials.
To further troubleshoot unexpected login failures that may or may not result in an "Invalid Credentials" error:
Make sure you are not seeing "Invalid status code 500" related to dphoneApiProxy in /var/log/asterisk/sangomartapi/rtapi.log. One cause of this could be when the dphone API from the restapps module is not working correctly. For example:
example of rtapi.log
2021-11-08T19:10:59.882Z app req: SID-1001 {"method":"login","params":{"extension":"301","password":"301","generateJwt":true},"id":1,"jsonrpc":"2.0"}
2021-11-08T19:11:00.831Z auth.login() error for extension [301]: Error: Invalid status code 500
at ClientRequest.<anonymous> (/usr/src/freepbx/sangomartapi/node/lib/dphoneApiProxy.js:91:12)
at Object.onceWrapper (events.js:315:30)
at emitOne (events.js:116:13)
at ClientRequest.emit (events.js:211:7)
at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:552:21)
at HTTPParser.parserOnHeadersComplete (_http_common.js:119:17)
at TLSSocket.socketOnData (_http_client.js:454:20)
at emitOne (events.js:116:13)
at TLSSocket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
at readableAddChunk (_stream_readable.js:250:11)
at TLSSocket.Readable.push (_stream_readable.js:208:10)
at TLSWrap.onread (net.js:601:20)
From previous event:
at Object.module.exports.send (/usr/src/freepbx/sangomartapi/node/lib/dphoneApiProxy.js:59:9)
at /usr/src/freepbx/sangomartapi/node/lib/rtapi/lib/session.js:88:26
From previous event:
at _authenticate (/usr/src/freepbx/sangomartapi/node/lib/rt api/lib/session.js:84:27)
at module.exports.authenticate (/usr/src/freepbx/sangomartapi/node/lib/rtapi/lib/session.js:34:10)
at module.exports.login (/usr/src/freepbx/sangomartapi/node/lib/rtapi/lib/auth.js:93:18)
at executeFn (/usr/src/freepbx/sangomartapi/node/lib/rtapi/index.js:169:16)
at bound (domain.js:301:14)
at runBound (domain.js:314:12)
at runCallback (timers.js:810:20)
at tryOnImmediate (timers.js:768:5)
at processImmediate [as _immediateCallback] (timers.js:745:5)
From previous event:
at exec1 (/usr/src/freepbx/sangomartapi/node/lib/rtapi/lib/jsonrpc.js:115:4)
at module.exports.execute (/usr/src/freepbx/sangomartapi/node/lib/rtapi/lib/jsonrpc.js:90:11)
at RealTimeApi.self.execute (/usr/src/freepbx/sangomartapi/node/lib/rtapi/index.js:531:13)
at EventEmitter.<anonymous> (/usr/src/freepbx/sangomartapi/node/rtapi/rtapi.js:142:10)
at emitTwo (events.js:126:13)
at EventEmitter.emit (events.js:214:7)
at WebSocket.<anonymous> (/usr/src/freepbx/sangomartapi/node/rtapi/wsif.js:60:11)
at emitOne (events.js:116:13)
at WebSocket.emit (events.js:211:7)
at Receiver.receiverOnMessage (/usr/src/freepbx/sangomartapi/node/node_modules/ws/lib/websocket.js:834:20)
at emitOne (events.js:116:13)
at Receiver.emit (events.js:211:7)
at Receiver.dataMessage (/usr/src/freepbx/sangomartapi/node/node_modules/ws/lib/receiver.js:437:14)
at Receiver.getData (/usr/src/freepbx/sangomartapi/node/node_modules/ws/lib/receiver.js:367:17)
at Receiver.startLoop (/usr/src/freepbx/sangomartapi/node/node_modules/ws/lib/receiver.js:143:22)
at Receiver._write (/usr/src/freepbx/sangomartapi/node/node_modules/ws/lib/receiver.js:78:10)
at doWrite (_stream_writable.js:396:12)
at writeOrBuffer (_stream_writable.js:382:5)
at Receiver.Writable.write (_stream_writable.js:290:11)
2021-11-08T19:11:00.832Z app res: {"sessionId":"SID-1001","response":{"jsonrpc":"2.0","error":{"code":-32602,"message":"Invalid method parameter(s) for: l
ogin","data":"Login failed."},"id":1}}
To troubleshoot this:
Make sure the restapps module is up to date and enabled
Look at the /var/log/asterisk/dpmapps.log(needs to be enabled in Advanced Options) for clues
Try other dphoneApps to see if they are also having problems
Make sure the Realtime API is reachable over the secure restapps port from a web browser, by going to:
https://[Sangoma Phone Desktop Client Host Address]:[Sangoma Phone Desktop Client Service Port]/rtapiws
Going to that address from a browser should lead you to a page where you only see text saying "Bad Request". This means the connection to the realtime api is working, but you get that message since no request is being made.
If you don't see that message, it could be a port forwarding issue, but first it's worth trying to restart apache, and sangomartapi
# apachectl restart
# fwconsole pm2 --restart sangomartapi
You should also check the contents of /etc/httpd/conf.d/ssl.conf. You should see the following lines included in the VirtualHost entry for the port you have selected to be your Sangoma Phone Desktop Client Service secure port.
Snippet /etc/httpd/conf.d/ssl.conf
<Location /rtapiws>
RequestHeader set X-Real-IP %{REMOTE_ADDR}s
ProxyPass ws://127.0.0.1:6006/rtapiws disablereuse=on
ProxyPassReverse ws://127.0.0.1:6006/rtapiws
</Location>
<Location /sipws>
RequestHeader set X-Real-IP %{REMOTE_ADDR}s
ProxyPass ws://127.0.0.1:6006/sipws disablereuse=on
ProxyPassReverse ws://127.0.0.1:6006/sipws
</Location>
Make sure sangomartapi and the related modules listed above are up-to-date and enabled.
At this time, those modules include the list found here: How to Setup Sangoma Phone Desktop on the PBX#Modules
Incoming Calls to Sangoma Phone Fails
Consider checking the system's hostname.
Symptoms
Login is successful on the Sangoma Phone app. Outbound calls work fine.
Inbound calls fail. A packet trace will show a 503 unavailable response.
asterisk will show a registration for the shadow extension/contact (98 + ext), but the status will be unavailable:
pjsip show aors
97932482*CLI> pjsip show aors
Aor: <Aor..............................................> <MaxContact>
Contact: <Aor/ContactUri............................> <Hash....> <Status> <RTT(ms)..>
==========================================================================================
Aor: 98313 1
Contact: 98313/sip:ufqe1ren@127.0.0.1:51200;transport ab20fc67b9 Unavail
A shadow extension registration will look successful, but it will quickly get a status of Unavailable. For the shadow extension, registrations will come from 127.0.0.1 since they are being proxied by sangomartapi
pjsip set logger host 127.0.0.1
== WebSocket connection from '127.0.0.1:44066' for protocol 'sip' accepted using version '13' <--- Received SIP request (647 bytes) from WS:127.0.0.1:44066 ---> REGISTER sip:97932.dep.pbxacttest.com:2443 SIP/2.0 Via: SIP/2.0/WSS 48kraflecjhs.invalid;branch=z9hG4bK1561605 Max-Forwards: 69 To: <sip:98313@97932.dep.pbxacttest.com:2443> From: <sip:98313@97932.dep.pbxacttest.com:2443>;tag=j6tijnm3j3 Call-ID: b6fcclj6rnrth92ed62uj1 CSeq: 1 REGISTER Contact: <sip:i981r73s@48kraflecjhs.invalid;transport=ws>;+sip.ice;reg-id=1;+sip.instance="<urn:uuid:39cb9110-e0ac-4a04-bd9f-49d2580c892c>";expires=600 Expires: 600 Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS,REFER,INFO,NOTIFY Supported: path,gruu,outbound User-Agent: Sangoma macOS Softphone 3.1.0 Content-Length: 0 <--- Transmitting SIP response (505 bytes) to WS:127.0.0.1:44066 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/WSS 48kraflecjhs.invalid;rport=44066;received=127.0.0.1;branch=z9hG4bK1561605 Call-ID: b6fcclj6rnrth92ed62uj1 From: <sip:98313@97932.dep.pbxacttest.com>;tag=j6tijnm3j3 To: <sip:98313@97932.dep.pbxacttest.com>;tag=z9hG4bK1561605 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1639073091/e083eb3aa29c15917184ff0bde5cd151",opaque="371c195c0e4dfb12",algorithm=md5,qop="auth" Server: FPBX-15.0.17.63(16.20.0) Content-Length: 0 <--- Received SIP request (939 bytes) from WS:127.0.0.1:44066 ---> REGISTER sip:97932.dep.pbxacttest.com:2443 SIP/2.0 Via: SIP/2.0/WSS 48kraflecjhs.invalid;branch=z9hG4bK3934304 Max-Forwards: 69 To: <sip:98313@97932.dep.pbxacttest.com:2443> From: <sip:98313@97932.dep.pbxacttest.com:2443>;tag=j6tijnm3j3 Call-ID: b6fcclj6rnrth92ed62uj1 CSeq: 2 REGISTER Authorization: Digest algorithm=MD5, username="98313", realm="asterisk", nonce="1639073091/e083eb3aa29c15917184ff0bde5cd151", uri="sip:97932.dep.pbxacttest.com:2443", response="3d3256eb5800698295cb7f7a2953e0ad", opaque="371c195c0e4dfb12", qop=auth, cnonce="2a75nkl08g4m", nc=00000001 Contact: <sip:i981r73s@48kraflecjhs.invalid;transport=ws>;+sip.ice;reg-id=1;+sip.instance="<urn:uuid:39cb9110-e0ac-4a04-bd9f-49d2580c892c>";expires=600 Expires: 600 Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS,REFER,INFO,NOTIFY Supported: path,gruu,outbound User-Agent: Sangoma macOS Softphone 3.1.0 Content-Length: 0 -- Added contact 'sip:i981r73s@127.0.0.1:44066;transport=WS' to AOR '98313' with expiration of 600 seconds <--- Transmitting SIP response (466 bytes) to WS:127.0.0.1:44066 ---> SIP/2.0 200 OK Via: SIP/2.0/WSS 48kraflecjhs.invalid;rport=44066;received=127.0.0.1;branch=z9hG4bK3934304 Call-ID: b6fcclj6rnrth92ed62uj1 From: <sip:98313@97932.dep.pbxacttest.com>;tag=j6tijnm3j3 To: <sip:98313@97932.dep.pbxacttest.com>;tag=z9hG4bK3934304 CSeq: 2 REGISTER Date: Thu, 09 Dec 2021 18:04:52 GMT Contact: <sip:i981r73s@127.0.0.1:44066;transport=WS>;expires=599 Expires: 600 Server: FPBX-15.0.17.63(16.20.0) Content-Length: 0 <--- Transmitting SIP request (450 bytes) to WS:127.0.0.1:44066 ---> OPTIONS sip:i981r73s@127.0.0.1:44066;transport=WS SIP/2.0 Via: SIP/2.0/WS 127.0.0.1:8088;rport;branch=z9hG4bKPjc6d376a0-e46e-46f8-86d5-d9c6fbd46d68;alias From: <sip:98313@97932>;tag=69826e43-4f00-4c82-8b90-9a0360b0861c To: <sip:i981r73s@127.0.0.1> Contact: <sip:98313@97932:5060;transport=ws> Call-ID: 424f2716-27ba-41ee-b540-27bf1f24f0e7 CSeq: 43613 OPTIONS Max-Forwards: 70 User-Agent: FPBX-15.0.17.63(16.20.0) Content-Length: 0 <--- Transmitting SIP request (661 bytes) to WS:127.0.0.1:44066 ---> NOTIFY sip:i981r73s@127.0.0.1:44066;transport=WS SIP/2.0 Via: SIP/2.0/WS 127.0.0.1:8088;rport;branch=z9hG4bKPj70bb8160-9c06-4075-b9ba-f94e1f01cd7a;alias From: <sip:98313@97932>;tag=abfa1acf-68aa-41ed-b160-840ea24b8ec1 To: <sip:i981r73s@127.0.0.1> Contact: <sip:98313@97932:5060;transport=ws> Call-ID: cfe9c9b4-aa0b-473b-91d2-5b78c3cbcf94 CSeq: 63330 NOTIFY Subscription-State: terminated Event: message-summary Allow-Events: presence, dialog, message-summary, refer Max-Forwards: 70 User-Agent: FPBX-15.0.17.63(16.20.0) Content-Type: application/simple-message-summary Content-Length: 48 Messages-Waiting: no Voice-Message: 0/0 (0/0) -- Contact 98313/sip:i981r73s@127.0.0.1:44066;transport=WS is now Unreachable. RTT: 0.000 msec 97932*CLI>
The reason the shadow extension would get an Unreachable status is because the OPTIONS packet that is sent after registration never got an OK response. When looking at the packet trace above, look at the host values in the From and Contact header of the OPTIONS packet. Notice that it only has "97932", instead of "97932.dep.pbxacttest.com" like the other packets. This particular issue was resolved by setting the full HOSTNAME. While the problem was happening, the system only had "97932" in Admin→System Admin→Hostname(and /etc/hosts). Changing the Hostname value to "97932.dep.pbxacttest.com" resolved the issue.
Troubleshoot Issues with Contact Searching, or Playing Voicemail
If searching for Contacts unexpectedly leads to no results, or there are issues playing Voicemail messages:
Make sure "Sangoma Phone Desktop Client Host Address" is set to a valid address, found in Admin→SangomaConnect→Settings
Contacts must exist for the Internal/External groups in Admin→Contact Manager
Check that the user is entering the same Host Address that is set in SangomaConnect's Settings when logging in
Login Host should be [Sangoma Phone Desktop Client Host Address]:[Sangoma Phone Desktop Client Service port]
Make sure the PBX's HTTPS SSL certificate's common name also matches the Sangoma Phone Desktop Client Host Address