Your call cannot be completed as dialed - IAX2

[rnrstar (Todd Schacherl)]

I’m trying to get two Freepbx systems to talk over an IAX2 trunk and I’m not having much success. Both systems are behind firewalls, one a Fortinet 60E and the other is a Meraki MX64. I’ve opened UDP 4569 ports on both and pointed them to their respective servers internally.

When I try to dial an extension on the other system I get the message, “your call cannot be completed as dialed, please check the number and dial again.”

I’ve created an outbound route that looks for 5XXX and points to the AIX trunk. On the other system it’s similar except the dial pattern uses 4XXX.

I see nothing on the receiving system as far as the asterisk logs. On the calling server’s logs I see the following:

[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [5001@from-internal:1] Macro(“SIP/4003-000081a0”, “user-callerid,LIMIT”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/4003-000081a0”, “TOUCH_MONITOR=1595002616.33903”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/4003-000081a0”, “AMPUSER=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:3] Set(“SIP/4003-000081a0”, “HOTDESCKCHAN=4003-000081a0”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:4] Set(“SIP/4003-000081a0”, “HOTDESKEXTEN=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/4003-000081a0”, “HOTDESKCALL=0”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:6] ExecIf(“SIP/4003-000081a0”, “0?Set(HOTDESKCALL=1)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:7] ExecIf(“SIP/4003-000081a0”, “0?Set(CALLERID(name)=)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/4003-000081a0”, “0?report”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:9] ExecIf(“SIP/4003-000081a0”, “1?Set(REALCALLERIDNUM=4003)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/4003-000081a0”, “AMPUSER=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:11] GotoIf(“SIP/4003-000081a0”, “0?limit”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:12] Set(“SIP/4003-000081a0”, “AMPUSERCIDNAME=Todd Schacherl”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“SIP/4003-000081a0”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:14] GotoIf(“SIP/4003-000081a0”, “0?report”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:15] Set(“SIP/4003-000081a0”, “AMPUSERCID=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:16] Set(“SIP/4003-000081a0”, “__DIAL_OPTIONS=Ttr”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:17] Set(“SIP/4003-000081a0”, “CALLERID(all)=“Todd Schacherl” <4003>”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:18] GotoIf(“SIP/4003-000081a0”, “0?limit”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:19] ExecIf(“SIP/4003-000081a0”, “1?Set(GROUP(concurrency_limit)=4003)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:20] ExecIf(“SIP/4003-000081a0”, “0?Set(CHANNEL(language)=)”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:21] NoOp(“SIP/4003-000081a0”, “Macro Depth is 1”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:22] GotoIf(“SIP/4003-000081a0”, “1?report2:macroerror”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (macro-user-callerid,s,23)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:23] GotoIf(“SIP/4003-000081a0”, “1?continue”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (macro-user-callerid,s,42)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:42] Set(“SIP/4003-000081a0”, “CALLERID(number)=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:43] Set(“SIP/4003-000081a0”, “CALLERID(name)=Todd Schacherl”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:44] GotoIf(“SIP/4003-000081a0”, “0?cnum”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:45] Set(“SIP/4003-000081a0”, “CDR(cnam)=Todd Schacherl”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:46] Set(“SIP/4003-000081a0”, “CDR(cnum)=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@macro-user-callerid:47] Set(“SIP/4003-000081a0”, “CHANNEL(language)=en”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [5001@from-internal:2] Set(“SIP/4003-000081a0”, “ROUTEUSER=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [5001@from-internal:3] Set(“SIP/4003-000081a0”, “ROUTEUSER=4003”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [5001@from-internal:4] GotoIf(“SIP/4003-000081a0”, “1?notblind”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (from-internal,5001,7)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [5001@from-internal:7] GotoIf(“SIP/4003-000081a0”, “1?restrictedroute-98c6f2c2287f4c73cea3d40ae7ec3ff2,5001,2:outbound-allroutes,5001,2”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (restrictedroute-98c6f2c2287f4c73cea3d40ae7ec3ff2,5001,2)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Channel ‘SIP/4003-000081a0’ sent to invalid extension: context,exten,priority=restrictedroute-98c6f2c2287f4c73cea3d40ae7ec3ff2,5001,2
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [i@restrictedroute-98c6f2c2287f4c73cea3d40ae7ec3ff2:1] Goto(“SIP/4003-000081a0”, “bad-number,s,1”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (bad-number,s,1)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [s@bad-number:1] Goto(“SIP/4003-000081a0”, “11,1”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx_builtins.c: Goto (bad-number,11,1)
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:1] ResetCDR(“SIP/4003-000081a0”, “”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:2] NoCDR(“SIP/4003-000081a0”, “”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:3] Progress(“SIP/4003-000081a0”, “”) in new stack
[2020-07-17 09:16:56] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:4] Wait(“SIP/4003-000081a0”, “1”) in new stack
[2020-07-17 09:16:57] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:5] Playback(“SIP/4003-000081a0”, “silence/1&cannot-complete-as-dialed&check-number-dial-again,noanswer”) in new stack
[2020-07-17 09:16:57] VERBOSE[17876][C-00008042] file.c: <SIP/4003-000081a0> Playing ‘silence/1.ulaw’ (language ‘en’)
[2020-07-17 09:16:58] VERBOSE[17876][C-00008042] file.c: <SIP/4003-000081a0> Playing ‘cannot-complete-as-dialed.ulaw’ (language ‘en’)
[2020-07-17 09:17:00] VERBOSE[17876][C-00008042] file.c: <SIP/4003-000081a0> Playing ‘check-number-dial-again.ulaw’ (language ‘en’)
[2020-07-17 09:17:03] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:6] Wait(“SIP/4003-000081a0”, “1”) in new stack
[2020-07-17 09:17:04] VERBOSE[17876][C-00008042] pbx.c: Executing [11@bad-number:7] Congestion(“SIP/4003-000081a0”, “20”) in new stack
[2020-07-17 09:17:04] WARNING[17876][C-00008042] channel.c: Prodding channel ‘SIP/4003-000081a0’ failed
[2020-07-17 09:17:04] VERBOSE[17876][C-00008042] pbx.c: Spawn extension (bad-number, 11, 7) exited non-zero on ‘SIP/4003-000081a0’
[2020-07-17 09:17:08] VERBOSE[2287] chan_iax2.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
[2020-07-17 09:17:08] VERBOSE[2287] chan_iax2.c: Timestamp: 00004ms SCall: 16375 DCall: 00000 72.202.234.98:4569
[2020-07-17 09:17:08] VERBOSE[2287] chan_iax2.c:
[2020-07-17 09:17:08] VERBOSE[2287] chan_iax2.c: Tx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG
[2020-07-17 09:17:08] VERBOSE[2287] chan_iax2.c: Timestamp: 00004ms SCall: 00001 DCall: 16375 72.202.234.98:4569
[2020-07-17 09:17:08] VERBOSE[2288] chan_iax2.c: Rx-Frame Retry[ No] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
[2020-07-17 09:17:08] VERBOSE[2288] chan_iax2.c: Timestamp: 00004ms SCall: 16375 DCall: 00001 72.202.234.98:4569
[2020-07-17 09:17:35] VERBOSE[2278] chan_iax2.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
[2020-07-17 09:17:35] VERBOSE[2278] chan_iax2.c: Timestamp: 00003ms SCall: 12548 DCall: 00000 72.202.234.98:4569

I ran the following nmap command from the calling server and this is what I see:

nmap -sU -Pn -p 4569 72.XXX.XXX.98

Starting Nmap 5.51 ( http://nmap.org ) at 2020-07-17 08:32 PDT
Nmap scan report for wsip-72-XXX-XXX-98.lv.lv.cox.net (72.XXX.XXX.98)
Host is up.
PORT STATE SERVICE
4569/udp open|filtered unknown

Nmap done: 1 IP address (1 host up) scanned in 2.19 seconds

Here is what my IAX configurations look like,

PBX 1 v13.0.197.22:
Outgoing:
Trunk Name: 2Redmoon
Peer Details:
host=70.XXX.XXX.126
username=rmuser
secret=[redacted]
type=peer
qualify=yes
trunk=no
requirecalltoken=no

Incoming:
User Context: tivuser
User details:
secret=[redacted]
type=user
context=from-internal

PBX2 v13.0.197.23:
Outgoing:
Trunk Name: toTivoli
Peer Details:
host=72.XXX.XXX.98
username=tivuser
secret=[redacted]
type=peer
qualify=yes
trunk=no
requirecalltoken=no

Incoming:
User Context: rmuser
User details:
secret=[redacted]
type=user
context=from-internal

[Stewart1 (Stewart)]

The calling server didn’t even try to access the trunk, because you have some restriction module (Extension Routes, Class of Service) in place that seems to be denying access from 4003 to the Outbound Route that matches 5001.

[wmoon (Walter Moon)]

Once you get past the issue Stewart1 mentioned, you might want to try tweaking your configs to match closer to what’s mentioned in this older ticket(and the wiki info mentioned within) if you’re still facing issues.

IAX trunk between 2 freepbx servers

Hi, All the configuration is case sensitive. First Server: Trunk Name: Second Server Trunk Name: SECOND-SERVER Peer details: host=ip_second_server username=FIRST-SERVER secret=some_secret type=friend context=from-internal transfer=no allow=alaw&ulaw disallow=all Second Server: Trunk Name: First Server Trunk Name: FIRST-SERVER Peer details: host=ip_first_server username=SECOND-SERVER secret=some_secret type=friend context=from-internal transfer=no allow=alaw&ulaw disallow=all There is…

[rnrstar (Todd Schacherl)]

Thanks Stewart! That was it. The setting for allowed trunks was not checked for the iax trunk. Was not aware of that setting.