Inbound SIP trunk fails, Inbound PSTN (analog) works. AGI Script sangomacrm.agi completed, returning 4

[echo5 (Jeff)]

FreePBX: 14.1-1.sng7.x86_64
Asterisk: 13.29.2-1.sng7.x86_64

I have an Analog card (AEX800) where inbound and outbound calls work. Inbound routes to IVR just fine.
I have a Digium SIP trunk and inbound calls reach the PBX but get an error greeting “The number you have dialed is not in service”

I ran asterisk -rvvvvv and watched the trace of inbound calls from the analog pstn trunk and the digium sip trunk. Everything appears the same until the AGI Script sangomacrm.agi line.

Analog (good/working)
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
– <DAHDI/25-1>AGI Script sangomacrm.agi completed, returning 0
– Executing [s@from-pstn:25] ExecIf(“DAHDI/25-1”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [s@from-pstn:26] Goto(“DAHDI/25-1”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)

SIP (bad/fails to route to IVR)
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
== Begin MixMonitor Recording PJSIP/digium-siptrunk-0000000d
– <PJSIP/digium-siptrunk-0000000d>AGI Script sangomacrm.agi completed, returning 4
== Spawn extension (from-pstn, XXXXXXXXXX, 24) exited non-zero on ‘PJSIP/digium-siptrunk-0000000d’
– Executing [h@from-pstn:1] Macro(“PJSIP/digium-siptrunk-0000000d”, “hangupcall,”) in new stack

Being a Linux person I know return 0 is good and return 4 (or anything non-zero) is bad…but it doesn’t say why.

The inbound analog truck calls to go IVR, the SIP trunk inbound fails. The Digium trunk delivers a CID that is +1XXXXXXXXXX whereas the analog has a CID of XXXXXXXXXX. That doesn’t seem to be it.

Why wont the inbound SIP calls go to IVR? I have the route defined to go to IVR. But the sangomacrm.agi appears to be the breakpoint where the inbound SIP call goes off the rails.

What am I missing?

[echo5 (Jeff)]

I tried deleting the PJSIP trunk and re-adding it as SIP, per the instructions on Digium’s site:
https://support.digium.com/community/s/article/How-to-configure-a-Digium-SIP-Trunking-account-with-AsteriskNOW-and-FreePBX

Same failure. The call is send down my SIP trunk from Digium. FreePBX gets it, I see it in asterisk -rvvvv. It processes the inbound call and again it hits the " sangomacrm.agi completed, returning 4"

-- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi

== Begin MixMonitor Recording SIP/digium-siptrunk-00000000
– <SIP/digium-siptrunk-00000000>AGI Script sangomacrm.agi completed, returning 4
== Spawn extension (from-trunk, XXXXXXXXXX, 24) exited non-zero on ‘SIP/digium-siptrunk-00000000’
– Executing [h@from-trunk:1] Macro(“SIP/digium-siptrunk-00000000”, “hangupcall,”) in new stack

Why in the bleeping does sangomacrm.agi return a 4 on a SIP or PJSIP inbound but returns a 0 and successfully routes the call to IVR for an inbound analog call?!?!?!?!?!

[echo5 (Jeff)]

Okay…I disabled the CRM module and that wasn’t it. It still fails.

Inbound from analog-pstn routes to IVR 1.
Inbound from digium sip trunk fails to route to IVR 1. Call gets “The number you have diailed…” error recording.

Working:
– Executing [recordcheck@sub-record-check:3] Return(“DAHDI/25-1”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“DAHDI/25-1”, “”) in new stack
– Executing [s@from-pstn:4] Set(“DAHDI/25-1”, “CHANNEL(tonezone)=us”) in new stack
– Executing [s@from-pstn:5] ExecIf(“DAHDI/25-1”, “1?Set(__FROM_DID=s)”) in new stack
– Executing [s@from-pstn:6] Set(“DAHDI/25-1”, “returnhere=1”) in new stack
– Executing [s@from-pstn:7] Gosub(“DAHDI/25-1”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/25-1”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“DAHDI/25-1”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“DAHDI/25-1”, “”) in new stack
– Executing [s@from-pstn:8] Set(“DAHDI/25-1”, “CDR(did)=s”) in new stack
– Executing [s@from-pstn:9] GotoIf(“DAHDI/25-1”, “0?”) in new stack
– Executing [s@from-pstn:10] ExecIf(“DAHDI/25-1”, “0 ?Set(CALLERID(name)=0987654321)”) in new stack
– Executing [s@from-pstn:11] Set(“DAHDI/25-1”, “__MOHCLASS=”) in new stack
– Executing [s@from-pstn:12] Set(“DAHDI/25-1”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [s@from-pstn:13] GotoIf(“DAHDI/25-1”, “1?post-reverse-charge”) in new stack
– Goto (from-pstn,s,15)
– Executing [s@from-pstn:15] NoOp(“DAHDI/25-1”, “”) in new stack
– Executing [s@from-pstn:16] Set(“DAHDI/25-1”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [s@from-pstn:17] Set(“DAHDI/25-1”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [s@from-pstn:18] Set(“DAHDI/25-1”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [s@from-pstn:19] Set(“DAHDI/25-1”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [s@from-pstn:20] NoOp(“DAHDI/25-1”, “CallerID Entry Point”) in new stack
– Executing [s@from-pstn:21] Goto(“DAHDI/25-1”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [s@ivr-1:1] Set(“DAHDI/25-1”, “TIMEOUT_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:2] Set(“DAHDI/25-1”, “INVALID_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:3] Set(“DAHDI/25-1”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [s@ivr-1:4] Set(“DAHDI/25-1”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [s@ivr-1:5] Set(“DAHDI/25-1”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-1:6] GotoIf(“DAHDI/25-1”, “0?skip”) in new stack
– Executing [s@ivr-1:7] Answer(“DAHDI/25-1”, “”) in new stack
– Executing [s@ivr-1:8] Set(“DAHDI/25-1”, “IVR_MSG=custom/ivmintrojj”) in new stack
– Executing [s@ivr-1:9] Set(“DAHDI/25-1”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:10] ExecIf(“DAHDI/25-1”, “1?Background(custom/ivmintrojj)”) in new stack
– <DAHDI/25-1> Playing ‘custom/ivmintrojj.slin’ (language ‘en’)
== Spawn extension (ivr-1, s, 10) exited non-zero on ‘DAHDI/25-1’
– Executing [h@ivr-1:1] Hangup(“DAHDI/25-1”, “”) in new stack
== Spawn extension (ivr-1, h, 1) exited non-zero on ‘DAHDI/25-1’
– Hanging up on ‘DAHDI/25-1’
– Hungup ‘DAHDI/25-1’

Failing:
– Executing [recordcheck@sub-record-check:3] Return(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
– Executing [1234567890@from-pstn:4] Set(“PJSIP/digium-siptrunk-0000001f”, “CHANNEL(tonezone)=us”) in new stack
– Executing [1234567890@from-pstn:5] Set(“PJSIP/digium-siptrunk-0000001f”, “__FROM_DID=1234567890”) in new stack
– Executing [1234567890@from-pstn:6] Set(“PJSIP/digium-siptrunk-0000001f”, “returnhere=1”) in new stack
– Executing [1234567890@from-pstn:7] Gosub(“PJSIP/digium-siptrunk-0000001f”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“PJSIP/digium-siptrunk-0000001f”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“PJSIP/digium-siptrunk-0000001f”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
– Executing [1234567890@from-pstn:8] Set(“PJSIP/digium-siptrunk-0000001f”, “CDR(did)=8588002052”) in new stack
– Executing [1234567890@from-pstn:9] GotoIf(“PJSIP/digium-siptrunk-0000001f”, “0?”) in new stack
– Executing [1234567890@from-pstn:10] ExecIf(“PJSIP/digium-siptrunk-0000001f”, “0 ?Set(CALLERID(name)=0987654321)”) in new stack
– Executing [1234567890@from-pstn:11] Set(“PJSIP/digium-siptrunk-0000001f”, “__MOHCLASS=”) in new stack
– Executing [1234567890@from-pstn:12] Set(“PJSIP/digium-siptrunk-0000001f”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [1234567890@from-pstn:13] GotoIf(“PJSIP/digium-siptrunk-0000001f”, “1?post-reverse-charge”) in new stack
– Goto (from-pstn,1234567890,15)
– Executing [1234567890@from-pstn:15] NoOp(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
– Executing [1234567890@from-pstn:16] Set(“PJSIP/digium-siptrunk-0000001f”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [1234567890@from-pstn:17] Set(“PJSIP/digium-siptrunk-0000001f”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [1234567890@from-pstn:18] Set(“PJSIP/digium-siptrunk-0000001f”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [1234567890@from-pstn:19] Set(“PJSIP/digium-siptrunk-0000001f”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [1234567890@from-pstn:20] NoOp(“PJSIP/digium-siptrunk-0000001f”, “CallerID Entry Point”) in new stack
– Executing [1234567890@from-pstn:21] Goto(“PJSIP/digium-siptrunk-0000001f”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [s@ivr-1:1] Set(“PJSIP/digium-siptrunk-0000001f”, “TIMEOUT_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:2] Set(“PJSIP/digium-siptrunk-0000001f”, “INVALID_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:3] Set(“PJSIP/digium-siptrunk-0000001f”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [s@ivr-1:4] Set(“PJSIP/digium-siptrunk-0000001f”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [s@ivr-1:5] Set(“PJSIP/digium-siptrunk-0000001f”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-1:6] GotoIf(“PJSIP/digium-siptrunk-0000001f”, “0?skip”) in new stack
– Executing [s@ivr-1:7] Answer(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
== Spawn extension (ivr-1, s, 7) exited non-zero on ‘PJSIP/digium-siptrunk-0000001f’
– Executing [h@ivr-1:1] Hangup(“PJSIP/digium-siptrunk-0000001f”, “”) in new stack
== Spawn extension (ivr-1, h, 1) exited non-zero on ‘PJSIP/digium-siptrunk-0000001f’

I don’t get why the pjsip trunk inboound route won’t work.

[arielgrin]

In general, when you receive that particular message it means that there isn’t a matching inbound route for the incoming call so it can’t be routed to any destination and that is why you receive that message.

[echo5 (Jeff)]

I’ve changed the inbound route to an extension for testing. The inbound call rings to the extension for 1/2 of 1 ring and terminates.

So it routes where it is told and the call does come down the SIP trunk from Digium. For some reason regardless of destination of IVR or extension the call gets hung up as the last step in the process.

Outbound calls on that same trunk work fine.

[echo5 (Jeff)]

Here is a pastebin of the inbound call that fails.
It is set to extension 1001 destination.
Outbound calls on the trunk work fine.
Inbound calls ring the extension for half a ring and immediately hang up.
When set to destination IVR the hangup occurs as it goes to either play the IVR recording but instead hangs up.

Pastebin: https://pastebin.com/NYhZcegk

[arielgrin]

Maybe a codec mismatch?