FreePBX loosing trunk with VOIP.ms

Dashrender

I have a VOIP.ms trunk in ChicagoX connected to my FreePBX hosted on Vultr NJ.

Got a call that everyone was getting an all circuits are busy message when trying to call out. Checked VOIP.ms and the trunk wasn't registered.

So I stopped and started the trunk on VOIP.ms and it did come back, but the client complained that sound quality was horrible.

So I rebooted. After 15 mins, everything came back.

Now onto the logs.

[2018-04-23 10:56:21] VERBOSE[14225] res_pjsip/pjsip_configuration.c: Contact MY_SIP_Trunk/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2018-04-23 10:56:21] VERBOSE[14225] res_pjsip/pjsip_configuration.c: Endpoint MY_SIP_Trunk is now Unreachable
[2018-04-23 10:57:18] VERBOSE[12146] res_pjsip/pjsip_configuration.c: Contact MY_SIP_Trunk/sip:[email protected]:5060 is now Reachable.  RTT: 545.524 msec
[2018-04-23 10:57:18] VERBOSE[12146] res_pjsip/pjsip_configuration.c: Endpoint MY_SIP_Trunk is now Reachable
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-dialout-trunk:31] Dial("PJSIP/1250-00003ce7", "PJSIP/140267xxxxx@MY_SIP_Trunk,300,Tb(func-apply-sipheaders^s^1)") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_stack.c: PJSIP/MY_SIP_Trunk-00003ce8 Internal Gosub(func-apply-sipheaders,s,1) start
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("PJSIP/MY_SIP_Trunk-00003ce8", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("PJSIP/MY_SIP_Trunk-00003ce8", "Applying SIP Headers to channel") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/MY_SIP_Trunk-00003ce8", "SIPHEADERKEYS=") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@func-apply-sipheaders:4] While("PJSIP/MY_SIP_Trunk-00003ce8", "0") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_while.c: Jumping to priority 8
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@func-apply-sipheaders:9] Return("PJSIP/MY_SIP_Trunk-00003ce8", "") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_stack.c: Spawn extension (from-pstn, 4026776460, 1) exited non-zero on 'PJSIP/MY_SIP_Trunk-00003ce8'
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_stack.c: PJSIP/MY_SIP_Trunk-00003ce8 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_dial.c: Called PJSIP/140267xxxxx@MY_SIP_Trunk
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-dialout-trunk:32] NoOp("PJSIP/1250-00003ce7", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 21") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-dialout-trunk:33] GotoIf("PJSIP/1250-00003ce7", "0?continue,1:s-CHANUNAVAIL,1") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx_builtins.c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set("PJSIP/1250-00003ce7", "RC=21") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto("PJSIP/1250-00003ce7", "21,1") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx_builtins.c: Goto (macro-dialout-trunk,21,1)
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [21@macro-dialout-trunk:1] Goto("PJSIP/1250-00003ce7", "continue,1") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx_builtins.c: Goto (macro-dialout-trunk,continue,1)
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [continue@macro-dialout-trunk:1] NoOp("PJSIP/1250-00003ce7", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 21 - failing through to other trunks") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [continue@macro-dialout-trunk:2] ExecIf("PJSIP/1250-00003ce7", "1?Set(CALLERID(number)=1250)") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [4026776460@from-internal:8] Macro("PJSIP/1250-00003ce7", "outisbusy,") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-outisbusy:1] Progress("PJSIP/1250-00003ce7", "") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-outisbusy:2] GotoIf("PJSIP/1250-00003ce7", "0?emergency,1") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-outisbusy:3] GotoIf("PJSIP/1250-00003ce7", "0?intracompany,1") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] pbx.c: Executing [s@macro-outisbusy:4] Playback("PJSIP/1250-00003ce7", "all-circuits-busy-now&please-try-call-later, noanswer") in new stack
[2018-04-23 11:03:04] VERBOSE[3329][C-00001ebe] file.c: <PJSIP/1250-00003ce7> Playing 'all-circuits-busy-now.ulaw' (language 'en')

This is what appears to be relevant to the issue. The first drop was at 10:54 AM, but it came back in under a min and the logs show a few more calls on this same trunk with no issue. Then at 11:03:04 the system started giving busy signals. I could find not log entries showing this trunk as unavailable, just the errors as shown here.

I can provide more if it's helpful.

Dashrender

JB suggested that this is related to an as yet unresolved issue with pjsip.

To that end, I have changed this trunk from pjsip to sip.

Being as this is an intermittent issue (3 times in the last month, reboot always fixes), only time will tell if sip fixes it.

In the meantime I'm still curious if the logs are in any way helpful?