I am trying to connecting my hosted FreePBX server to my Telnyx SIP Trunk. I’m using IP as a credential method, and no authentication on FreePBX for connecting the trunk (ip authentication). I have an Avaya 9621G phone logged into the FreePBX (even though when the extension is called it says it is “unavailable”), that I am trying to call the outside world (PSTN). When making a call after setting up my SIP trunk connection, and outbound rules, I get the following problem -> “Circuits are busy now, please try again later”. When checking the asterisk logs this is what I found.
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-dialout-trunk:34] Dial(“PJSIP/2000-00000044”, “PJSIP/PHONENUM@SIPPER,300,Tb(func-apply-sipheaders^s^1,(1))U(sub-send-obroute-email^PHONENUM^PHONENUM^1^ENUM^SIPPER^DID)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] app_stack c: PJSIP/SIPPER-00000045 Internal Gosub(func-apply-sipheaders,s,1(1)) start
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/SIPPER-00000045”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/SIPPER-00000045”, “Applying SIP Headers to channel PJSIP/SIPPER-00000045”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:3] Set(“PJSIP/SIPPER-00000045”, “TECH=PJSIP”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:4] Set(“PJSIP/SIPPER-00000045”, “SIPHEADERKEYS=Alert-Info”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/SIPPER-00000045”, “1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:6] Set(“PJSIP/SIPPER-00000045”, “sipheader=unset”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:7] ExecIf(“PJSIP/SIPPER-00000045”, “0?SIPRemoveHeader(Alert-Info:)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:8] ExecIf(“PJSIP/SIPPER-00000045”, “1?Set(PJSIP_HEADER(remove,Alert-Info)=)”) in new stack
[2021-10-28 14:12:24] ERROR[10738] res_pjsip_header_funcs c: No headers had been previously added to this session.
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:9] ExecIf(“PJSIP/SIPPER-00000045”, “0?Set(sipheader=;info=unset)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:10] ExecIf(“PJSIP/SIPPER-00000045”, “0?Set(sipheader=unset)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:11] ExecIf(“PJSIP/SIPPER-00000045”, “0?SIPAddHeader(Alert-Info:unset)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:12] ExecIf(“PJSIP/SIPPER-00000045”, “0?Set(PJSIP_HEADER(add,Alert-Info)=unset)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:13] EndWhile(“PJSIP/SIPPER-00000045”, “”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/SIPPER-00000045”, “0”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@func-apply-sipheaders:14] Return(“PJSIP/SIPPER-00000045”, “”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] app_stack c: Spawn extension (from-pstn, PHONENUM, 1) exited non-zero on ‘PJSIP/SIPPER-00000045’
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] app_stack c: PJSIP/SIPPER-00000045 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] app_dial c: Called PJSIP/PHONENUM@SIPPER
[2021-10-28 14:12:24] ERROR[18232] res_pjsip_outbound_authenticator_digest c: Endpoint: ‘SIPPER’: There were no auth ids available
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] app_dial c: Everyone is busy/congested at this time (1:0/0/1)
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-dialout-trunk:35] NoOp(“PJSIP/2000-00000044”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 21”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-dialout-trunk:36] GotoIf(“PJSIP/2000-00000044”, “0?continue,1:s-CHANUNAVAIL,1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx_builtins c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set(“PJSIP/2000-00000044”, “RC=21”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto(“PJSIP/2000-00000044”, “21,1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx_builtins c: Goto (macro-dialout-trunk,21,1)
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [21@macro-dialout-trunk:1] Goto(“PJSIP/2000-00000044”, “continue,1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx_builtins c: Goto (macro-dialout-trunk,continue,1)
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [continue@macro-dialout-trunk:1] NoOp(“PJSIP/2000-00000044”, “TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 21 - failing through to other trunks”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [continue@macro-dialout-trunk:2] ExecIf(“PJSIP/2000-00000044”, “1?Set(CALLERID(number)=2000)”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [1PHONENUM@from-internal:13] Macro(“PJSIP/2000-00000044”, “outisbusy,”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-outisbusy:1] Progress(“PJSIP/2000-00000044”, “”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-outisbusy:2] GotoIf(“PJSIP/2000-00000044”, “0?emergency,1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-outisbusy:3] GotoIf(“PJSIP/2000-00000044”, “0?intracompany,1”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] pbx c: Executing [s@macro-outisbusy:4] Playback(“PJSIP/2000-00000044”, “all-circuits-busy-now&please-try-call-later, noanswer”) in new stack
[2021-10-28 14:12:24] VERBOSE[9314][C-00000027] file c: <PJSIP/2000-00000044> Playing ‘all-circuits-busy-now g722’ (language ‘en’)
[2021-10-28 14:12:26] VERBOSE[9314][C-00000027] file c: <PJSIP/2000-00000044> Playing ‘please-try-call-later ulaw’ (language ‘en’)
The line with
[2021-10-28 14:12:24] ERROR[18232] res_pjsip_outbound_authenticator_digest c: Endpoint: ‘SIPPER’: There were no auth ids available
is odd to me, because I’m not using the regular auth, it is based on both parties knowing each others IP address.
I’m not sure what other logs I could check to debug this problem. Any suggestions would be helpful.