FreePBX Broke after recent FPL server upgrade

carlyle705 · February 3, 2020, 4:40am

I have been struggling with this for many days, any help would be very appreciated

My Version: FreePBX 14.0.13.24
I have 4 FPL lines (FPL = FreePhoneLine.ca)

I have been using then for more than 5 years without issue till recent Fongo server upgrade.

The symptom is very strange, I can call Fongo numbers but cannot call anything else, even tool-free numbers. Incoming calls are fine.

A successful call log is like this:
[2020-02-02 16:18:58] VERBOSE[16574][C-000000e9] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“SIP/FreePhoneLine2-00000189”, “”) in new stack
[2020-02-02 16:18:58] VERBOSE[16574][C-000000e9] app_stack.c: Spawn extension (from-trunk, 2263361434, 1) exited non-zero on ‘SIP/FreePhoneLine2-00000189’
[2020-02-02 16:18:58] VERBOSE[16574][C-000000e9] app_stack.c: SIP/FreePhoneLine2-00000189 Internal Gosub(func-apply-sipheaders,s,1(6)) complete GOSUB_RETVAL=
[2020-02-02 16:18:58] VERBOSE[16574][C-000000e9] app_dial.c: Called SIP/FreePhoneLine2/12263361434
[2020-02-02 16:18:58] VERBOSE[16574][C-000000e9] app_dial.c: SIP/FreePhoneLine2-00000189 answered SIP/106-00000188

A failed call log is like this:
[2020-02-02 17:11:32] VERBOSE[23768][C-000000ed] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“SIP/FreePhoneLine2-00000190”, “”) in new stack
[2020-02-02 17:11:32] VERBOSE[23768][C-000000ed] app_stack.c: Spawn extension (from-trunk, 8002632263, 1) exited non-zero on ‘SIP/FreePhoneLine2-00000190’
[2020-02-02 17:11:32] VERBOSE[23768][C-000000ed] app_stack.c: SIP/FreePhoneLine2-00000190 Internal Gosub(func-apply-sipheaders,s,1(6)) complete GOSUB_RETVAL=
[2020-02-02 17:11:32] VERBOSE[23768][C-000000ed] app_dial.c: Called SIP/FreePhoneLine2/18002632263
[2020-02-02 17:11:33] VERBOSE[11660][C-000000ed] chan_sip.c: Got SIP response 484 “Address Incomplete” back from 208.65.240.44:5060
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s@macro-dialout-trunk:34] NoOp(“SIP/106-0000018f”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 28”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s@macro-dialout-trunk:35] GotoIf(“SIP/106-0000018f”, “0?continue,1:s-CHANUNAVAIL,1”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx_builtins.c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set(“SIP/106-0000018f”, “RC=28”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto(“SIP/106-0000018f”, “28,1”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx_builtins.c: Goto (macro-dialout-trunk,28,1)
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [28@macro-dialout-trunk:1] Goto(“SIP/106-0000018f”, “s-INVALIDNMBR,1”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx_builtins.c: Goto (macro-dialout-trunk,s-INVALIDNMBR,1)
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:1] NoOp(“SIP/106-0000018f”, “Dial failed due to trunk reporting Address Incomplete - giving up”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:2] Progress(“SIP/106-0000018f”, “”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:3] Playback(“SIP/106-0000018f”, “ss-noservice,noanswer”) in new stack
[2020-02-02 17:11:33] VERBOSE[23768][C-000000ed] file.c: <SIP/106-0000018f> Playing ‘ss-noservice.ulaw’ (language ‘en’)
[2020-02-02 17:11:35] VERBOSE[23768][C-000000ed] pbx.c: Executing [h@from-internal:1] Macro(“SIP/106-0000018f”, “hangupcall”) in new stack
[2020-02-02 17:11:35] VERBOSE[23768][C-000000ed] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“SIP/106-0000018f”, “1?theend”) in new stack
[2020-02-02 17:11:35] VERBOSE[23768][C-000000ed] pbx_builtins.c: Goto (macro-hangupcall,s,3)

channel.c:5091 ast_prod: Prodding channel ‘SIP/106-000001d2’ failed

For a failed call will get “The number you have dialed is not in service, please check the number and try again” error message.

PitzKey · February 3, 2020, 7:06am

From the log it seems to be a proper 11 digit number, but it gets rejected by your SIP Provider. You’ll need to check with them.

jfinstrom · February 3, 2020, 5:30pm

See if they want it as e164
instead of 14805551212 send +14805551212

carlyle705 · February 4, 2020, 5:53am

I have tried, but didn’t work. Please see the logs below:

[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_stack.c: SIP/FreePhoneLine2-000001f4 Internal Gosub(func-apply-sipheaders,s,1(6)) start
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“SIP/FreePhoneLine2-000001f4”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“SIP/FreePhoneLine2-000001f4”, “Applying SIP Headers to channel SIP/FreePhoneLine2-000001f4”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“SIP/FreePhoneLine2-000001f4”, “TECH=SIP”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“SIP/FreePhoneLine2-000001f4”, “SIPHEADERKEYS=”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:5] While(“SIP/FreePhoneLine2-000001f4”, “0”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_while.c: Jumping to priority 13
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“SIP/FreePhoneLine2-000001f4”, “”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_stack.c: Spawn extension (from-trunk, 8002632263, 1) exited non-zero on ‘SIP/FreePhoneLine2-000001f4’
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_stack.c: SIP/FreePhoneLine2-000001f4 Internal Gosub(func-apply-sipheaders,s,1(6)) complete GOSUB_RETVAL=
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_dial.c: Called SIP/FreePhoneLine2/+18002632263
[2020-02-03 21:50:17] VERBOSE[11660][C-00000127] chan_sip.c: Got SIP response 484 “Address Incomplete” back from 208.65.240.44:5060
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@macro-dialout-trunk:34] NoOp(“SIP/106-000001f3”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 28”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s@macro-dialout-trunk:35] GotoIf(“SIP/106-000001f3”, “0?continue,1:s-CHANUNAVAIL,1”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx_builtins.c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set(“SIP/106-000001f3”, “RC=28”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto(“SIP/106-000001f3”, “28,1”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx_builtins.c: Goto (macro-dialout-trunk,28,1)
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [28@macro-dialout-trunk:1] Goto(“SIP/106-000001f3”, “s-INVALIDNMBR,1”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx_builtins.c: Goto (macro-dialout-trunk,s-INVALIDNMBR,1)
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:1] NoOp(“SIP/106-000001f3”, “Dial failed due to trunk reporting Address Incomplete - giving up”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:2] Progress(“SIP/106-000001f3”, “”) in new stack
[2020-02-03 21:50:17] VERBOSE[8509][C-00000127] pbx.c: Executing [s-INVALIDNMBR@macro-dialout-trunk:3] Playback(“SIP/106-000001f3”, “ss-noservice,noanswer”) in new stack

Stewart1 · February 4, 2020, 6:07am

Possibly the call is being rejected because the caller ID you are sending is in a format that they no longer accept.

Do you have another way of making a call on FPL that does work e.g. softphone, mobile app, ATA or IP phone connecting directly? If so, compare the outgoing INVITEs to see what is different.

Also, your working example seems a bit strange, because the time between initiating the call and it being answered is less than one second. Is 12263361434 answered automatically e.g. by an IVR?

carlyle705 · February 4, 2020, 6:10am

Hi Stewart,

Thanks for the reply:-)

12263361434 is Fongo’s company number and it is answered by IVR.

Here is the INVITE captured from wireshark, using FPL windows app which works:

Capture1

I know it uses 10 digit number instead of 11 digit, I have tried to send both 10 and 11 digit number but none of them worked. If I call Fongo numbers, it doesn’t matter 10/11 digit number I send, it always worked.

carlyle705 · February 5, 2020, 4:20am

Resolved!

[Stewart1] [jfinstrom] [PitzKey]: Thank you so much for all of your help!

Note:

FPL doesn’t allow customized caller ID anymore when you make a outgoing call to non-Fongo-FPL numbers. You have to use standard 11-digit/10-digit number format.
In FreePBX, this can be implemented by disable Intra-Company for the outbound route and set Force Trunk CID on each trunk.
When you call a non-Fongo number, only the caller ID will show up on the callee
When you call a Fongo number, the caller’s name will show up on callee

Stewart1 · February 5, 2020, 5:08am

While you certainly don’t want a trunk to a VoSP to be marked Intra-Company, Force Trunk CID is a drastic measure that you shouldn’t use unless needed. For example, on calls forwarded to your mobile, it would prevent you from passing the number of the original caller.

On a typical system, the Outbound CID for each extension should be in the proper format. Then, if not overridden by the Outbound Route or trunk, that number should be accepted by the VoSP and displayed to the called party.

doublej · February 5, 2020, 3:18pm

Hi
I found this out last night, when i did some updates on FreePBX, all outgoing calls were getting the “The number you have dialed is not in service, please check the number and try again” error message.
After some trials i found i could call from one extension but another would cause the error message. I checked the Caller ID and saw that the one that functions had an empty Caller ID field and the problem extension had a defined field.
I think this was when i was testing the Caller ID i had left it this number and i’m guessing with the new STIR/SHAKEN coming from the CRTC this year that fongo has started forcing the caller ID to match the account number.
I removed the defined number in the Caller ID and things started working again. Wish google had found this thread a little faster. Could have had an hour or 2 more of sleep!

system · February 12, 2020, 3:18pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.