Single extension hangsup after 32 seconds

Bradbpw · May 24, 2022, 8:10pm

I have a single extension, on the same LAN as the PBX, that will hangup outgoing calls at exactly 32 seconds. Incoming calls work fine and using the same extension on Sangoma Connect on my cell phone works fine. It’s just outgoing calls from a single Sangoma S705. Here is the call log, the hangup happens at 10:37:49

(Truncated due to length)

[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:26] GotoIf("PJSIP/9008-000008bd", "0?limit") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:27] ExecIf("PJSIP/9008-000008bd", "1?Set(GROUP(concurrency_limit)=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:28] ExecIf("PJSIP/9008-000008bd", "0?Set(CHANNEL(language)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:29] NoOp("PJSIP/9008-000008bd", "Macro Depth is 1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:30] GotoIf("PJSIP/9008-000008bd", "1?report2:macroerror") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-user-callerid,s,31)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:31] GotoIf("PJSIP/9008-000008bd", "1?continue") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-user-callerid,s,50)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:50] Set("PJSIP/9008-000008bd", "CALLERID(number)=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:51] Set("PJSIP/9008-000008bd", "CALLERID(name)=Brad Phillips") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:52] GotoIf("PJSIP/9008-000008bd", "0?cnum") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:53] Set("PJSIP/9008-000008bd", "CDR(cnam)=Brad Phillips") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:54] Set("PJSIP/9008-000008bd", "CDR(cnum)=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-user-callerid:55] Set("PJSIP/9008-000008bd", "CHANNEL(language)=en") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:2] Gosub("PJSIP/9008-000008bd", "sub-record-check,s,1(out,8337243577,force)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/9008-000008bd", "0?initialized") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/9008-000008bd", "__REC_STATUS=INITIALIZED") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/9008-000008bd", "NOW=1653406633") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/9008-000008bd", "__DAY=24") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/9008-000008bd", "__MONTH=05") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/9008-000008bd", "__YEAR=2022") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/9008-000008bd", "__TIMESTR=20220524-103713") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/9008-000008bd", "__FROMEXTEN=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/9008-000008bd", "__MON_FMT=wav") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/9008-000008bd", "Recordings initialized") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/9008-000008bd", "0?Set(ARG3=dontcare)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/9008-000008bd", "REC_POLICY_MODE_SAVE=") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/9008-000008bd", "0?Set(REC_STATUS=NO)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/9008-000008bd", "3?checkaction") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (sub-record-check,s,17)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/9008-000008bd", "1?sub-record-check,out,1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (sub-record-check,out,1)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:1] NoOp("PJSIP/9008-000008bd", "Outbound Recording Check from 9008 to 8337243577") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:2] Set("PJSIP/9008-000008bd", "RECMODE=force") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:3] ExecIf("PJSIP/9008-000008bd", "0?Goto(routewins)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:4] ExecIf("PJSIP/9008-000008bd", "1?Goto(routewins)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (sub-record-check,out,7)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:7] Gosub("PJSIP/9008-000008bd", "recordcheck,1(force,out,8337243577)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/9008-000008bd", "Starting recording check against force") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/9008-000008bd", "force") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (sub-record-check,recordcheck,5)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:5] Set("PJSIP/9008-000008bd", "__REC_POLICY_MODE=FORCE") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:6] GotoIf("PJSIP/9008-000008bd", "1?startrec") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:16] NoOp("PJSIP/9008-000008bd", "Starting recording: out, 8337243577") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:17] Set("PJSIP/9008-000008bd", "__CALLFILENAME=out-8337243577-9008-20220524-103713-1653406633.51615") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:18] MixMonitor("PJSIP/9008-000008bd", "2022/05/24/out-8337243577-9008-20220524-103713-1653406633.51615.wav,abi(LOCAL_MIXMON_ID),") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:19] Set("PJSIP/9008-000008bd", "__MIXMON_ID=0x7f23740474d0") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:20] Set("PJSIP/9008-000008bd", "__RECORD_ID=PJSIP/9008-000008bd") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:21] Set("PJSIP/9008-000008bd", "__REC_STATUS=RECORDING") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:22] Set("PJSIP/9008-000008bd", "CDR(recordingfile)=out-8337243577-9008-20220524-103713-1653406633.51615.wav") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [recordcheck@sub-record-check:23] Return("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [out@sub-record-check:8] Return("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:3] ExecIf("PJSIP/9008-000008bd", "0 ?Set(CDR(accountcode)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:4] Set("PJSIP/9008-000008bd", "_ROUTEID=4") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:5] Set("PJSIP/9008-000008bd", "_ROUTENAME=SIP-STATION") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:6] Set("PJSIP/9008-000008bd", "MOHCLASS=default") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:7] ExecIf("PJSIP/9008-000008bd", "0?Set(TRUNKCIDOVERRIDE=5159789010)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:8] Set("PJSIP/9008-000008bd", "_CALLERIDNAMEINTERNAL=Brad Phillips") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:9] Set("PJSIP/9008-000008bd", "_CALLERIDNUMINTERNAL=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:10] Set("PJSIP/9008-000008bd", "_EMAILNOTIFICATION=FALSE") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:11] Set("PJSIP/9008-000008bd", "_NODEST=") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [8337243577@from-internal:12] Macro("PJSIP/9008-000008bd", "dialout-trunk,3,8337243577,,off") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:1] Set("PJSIP/9008-000008bd", "DIAL_TRUNK=3") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/9008-000008bd", "0?Set(DIAL_OPTIONS=tr)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/9008-000008bd", "0?sub-pincheck,s,1()") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERID(num)=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/9008-000008bd", "0?disabletrunk,1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:6] Set("PJSIP/9008-000008bd", "DIAL_NUMBER=8337243577") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:7] Set("PJSIP/9008-000008bd", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:8] Set("PJSIP/9008-000008bd", "OUTBOUND_GROUP=OUT_3") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:9] Set("PJSIP/9008-000008bd", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/9008-000008bd", "1?nomax") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-dialout-trunk,s,12)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/9008-000008bd", "0?skipoutcid") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("PJSIP/9008-000008bd", "outbound-callerid,3") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/9008-000008bd", "9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/9008-000008bd", "off") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:6] Set("PJSIP/9008-000008bd", "HOTDESCKCHAN=9008-000008bd") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:7] Set("PJSIP/9008-000008bd", "HOTDESKEXTEN=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:8] Set("PJSIP/9008-000008bd", "HOTDESKCALL=0") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:9] ExecIf("PJSIP/9008-000008bd", "0?Set(HOTDESKCALL=1)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:10] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERID(name)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:11] Set("PJSIP/9008-000008bd", "ALLOWTHISROUTE=NO") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:12] ExecIf("PJSIP/9008-000008bd", "0?Set(ALLOWTHISROUTE=YES)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:13] ExecIf("PJSIP/9008-000008bd", "0?Hangup()") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:14] ExecIf("PJSIP/9008-000008bd", "0?Set(REALCALLERIDNUM=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:15] ExecIf("PJSIP/9008-000008bd", "0?Set(AMPUSER=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:16] GotoIf("PJSIP/9008-000008bd", "1?normcid") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-outbound-callerid,s,20)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:20] Set("PJSIP/9008-000008bd", "USEROUTCID=5159789010") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:21] Set("PJSIP/9008-000008bd", "EMERGENCYCID=") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/9008-000008bd", "0?Set(EMERGENCYCID=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:23] Set("PJSIP/9008-000008bd", "TRUNKOUTCID=5156509140") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:24] GotoIf("PJSIP/9008-000008bd", "1?trunkcid") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-outbound-callerid,s,30)
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:30] ExecIf("PJSIP/9008-000008bd", "1?Set(CALLERID(all)=5156509140)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:31] ExecIf("PJSIP/9008-000008bd", "1?Set(CALLERID(all)=5159789010)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:32] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERID(all)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:33] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERID(all)=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:34] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERID(all)=9008)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:35] Set("PJSIP/9008-000008bd", "TIOHIDE=no") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:36] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:37] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:38] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:39] ExecIf("PJSIP/9008-000008bd", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:40] Set("PJSIP/9008-000008bd", "CDR(outbound_cnum)=5159789010") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-outbound-callerid:41] Set("PJSIP/9008-000008bd", "CDR(outbound_cnam)=") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/9008-000008bd", "1?sub-flp-3,s,1()") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-flp-3:1] ExecIf("PJSIP/9008-000008bd", "0?Set(TARGET_FLP_3=5158337243577)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-flp-3:2] GotoIf("PJSIP/9008-000008bd", "0?match") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-flp-3:3] Return("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:15] Set("PJSIP/9008-000008bd", "OUTNUM=8337243577") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:16] Set("PJSIP/9008-000008bd", "custom=SIP/fpbx-1-nxivK8e5bb4a") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/9008-000008bd", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/9008-000008bd", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("PJSIP/9008-000008bd", "dialout-trunk-predial-hook,") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/9008-000008bd", "0?skipcrm") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:21] Set("PJSIP/9008-000008bd", "__CRM_DIRECTION=OUTBOUND") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:22] Set("PJSIP/9008-000008bd", "__CRM_DESTINATION=8337243577") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:23] Set("PJSIP/9008-000008bd", "__CRM_SOURCE=9008") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("PJSIP/9008-000008bd", "sangomacrm.agi") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2022-05-24 10:37:13] VERBOSE[7312][C-0000061a] app_mixmonitor.c: Begin MixMonitor Recording PJSIP/9008-000008bd
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] res_agi.c: <PJSIP/9008-000008bd>AGI Script sangomacrm.agi completed, returning 0
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:25] Set("PJSIP/9008-000008bd", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("PJSIP/9008-000008bd", "CRM Finished") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("PJSIP/9008-000008bd", "0?bypass,1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("PJSIP/9008-000008bd", "1?Set(CONNECTEDLINE(num,i)=8337243577)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("PJSIP/9008-000008bd", "1?Set(CONNECTEDLINE(name,i)=CID:5159789010)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("PJSIP/9008-000008bd", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)5159789010)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("PJSIP/9008-000008bd", "0?customtrunk") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:32] ExecIf("PJSIP/9008-000008bd", "0?Set(DIAL_TRUNK_OPTIONS=t)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:33] Set("PJSIP/9008-000008bd", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-dialout-trunk:34] Dial("PJSIP/9008-000008bd", "SIP/fpbx-1-nxivK8e5bb4a/8337243577,300,Ttb(func-apply-sipheaders^s^1,(3))U(sub-send-obroute-email^8337243577^8337243577^3^1653406633^^5159789010)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] netsock2.c: Using SIP RTP TOS bits 184
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] netsock2.c: Using SIP RTP CoS mark 5
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] app_stack.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd Internal Gosub(func-apply-sipheaders,s,1(3)) start
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "Applying SIP Headers to channel SIP/fpbx-1-nxivK8e5bb4a-000004cd") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "TECH=SIP") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "SIPHEADERKEYS=Alert-Info") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "1") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:6] Set("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "sipheader=unset") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "1?SIPRemoveHeader(Alert-Info:)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?SIPAddHeader(Alert-Info:unset)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:12] ExecIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?Set(PJSIP_HEADER(add,Alert-Info)=unset)") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:13] EndWhile("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@func-apply-sipheaders:14] Return("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "") in new stack
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] app_stack.c: Spawn extension (from-pstn, 8337243577, 1) exited non-zero on 'SIP/fpbx-1-nxivK8e5bb4a-000004cd'
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] app_stack.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd Internal Gosub(func-apply-sipheaders,s,1(3)) complete GOSUB_RETVAL=
[2022-05-24 10:37:13] VERBOSE[7311][C-0000061a] app_dial.c: Called SIP/fpbx-1-nxivK8e5bb4a/8337243577
[2022-05-24 10:37:15] VERBOSE[7311][C-0000061a] app_dial.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd is making progress passing it to PJSIP/9008-000008bd
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] app_dial.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd answered PJSIP/9008-000008bd
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] app_stack.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd Internal Gosub(sub-send-obroute-email,s,1(8337243577,8337243577,3,1653406633,,5159789010)) start
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-send-obroute-email:1] GotoIf("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "0?sendEmail") in new stack
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-send-obroute-email:2] NoOp("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "email notifications disabled..exiting.") in new stack
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@sub-send-obroute-email:3] Return("SIP/fpbx-1-nxivK8e5bb4a-000004cd", "") in new stack
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] app_stack.c: Spawn extension (from-pstn, , 1) exited non-zero on 'SIP/fpbx-1-nxivK8e5bb4a-000004cd'
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] app_stack.c: SIP/fpbx-1-nxivK8e5bb4a-000004cd Internal Gosub(sub-send-obroute-email,s,1(8337243577,8337243577,3,1653406633,,5159789010)) complete GOSUB_RETVAL=
[2022-05-24 10:37:17] VERBOSE[7389][C-0000061a] bridge_channel.c: Channel SIP/fpbx-1-nxivK8e5bb4a-000004cd joined 'simple_bridge' basic-bridge <dd1603f7-ecae-4b0b-aa68-2d08d190aa23>
[2022-05-24 10:37:17] VERBOSE[7311][C-0000061a] bridge_channel.c: Channel PJSIP/9008-000008bd joined 'simple_bridge' basic-bridge <dd1603f7-ecae-4b0b-aa68-2d08d190aa23>
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] bridge_channel.c: Channel PJSIP/9008-000008bd left 'simple_bridge' basic-bridge <dd1603f7-ecae-4b0b-aa68-2d08d190aa23>
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] app_macro.c: Spawn extension (macro-dialout-trunk, s, 34) exited non-zero on 'PJSIP/9008-000008bd' in macro 'dialout-trunk'
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Spawn extension (from-internal, 8337243577, 12) exited non-zero on 'PJSIP/9008-000008bd'
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [h@from-internal:1] Macro("PJSIP/9008-000008bd", "hangupcall") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/9008-000008bd", "1?theend") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2022-05-24 10:37:49] VERBOSE[7389][C-0000061a] bridge_channel.c: Channel SIP/fpbx-1-nxivK8e5bb4a-000004cd left 'simple_bridge' basic-bridge <dd1603f7-ecae-4b0b-aa68-2d08d190aa23>
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/9008-000008bd", "0?Set(CDR(recordingfile)=)") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/9008-000008bd", "SIP/fpbx-1-nxivK8e5bb4a-000004cd montior file= /var/spool/asterisk/monitor/2022/05/24/out-8337243577-9008-20220524-103713-1653406633.51615.wav") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/9008-000008bd", "0?skipagi") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:6] AGI("PJSIP/9008-000008bd", "attendedtransfer-rec-restart.php,SIP/fpbx-1-nxivK8e5bb4a-000004cd,/var/spool/asterisk/monitor/2022/05/24/out-8337243577-9008-20220524-103713-1653406633.51615.wav") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] res_agi.c: <PJSIP/9008-000008bd>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/9008-000008bd' in macro 'hangupcall'
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/9008-000008bd'
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] app_stack.c: PJSIP/9008-000008bd Internal Gosub(crm-hangup,s,1) start
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/9008-000008bd", "Sending Hangup to CRM") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/9008-000008bd", "HANGUP CAUSE: 16") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/9008-000008bd", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/9008-000008bd", "MASTER CHANNEL: 1653406633.51615 = 1653406633.51615") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/9008-000008bd", "0?return") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/9008-000008bd", "__CRM_HANGUP=1") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/9008-000008bd", "sangomacrm.agi") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] res_agi.c: <PJSIP/9008-000008bd>AGI Script sangomacrm.agi completed, returning 0
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/9008-000008bd", "") in new stack
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/9008-000008bd'
[2022-05-24 10:37:49] VERBOSE[7311][C-0000061a] app_stack.c: PJSIP/9008-000008bd Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2022-05-24 10:37:49] VERBOSE[7312][C-0000061a] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2022-05-24 10:37:49] VERBOSE[7312][C-0000061a] app_mixmonitor.c: End MixMonitor Recording PJSIP/9008-000008bd

Any ideas why this is happening or how to solve it?

comtech · May 24, 2022, 8:12pm

https://www.google.com/search?q=freepbx+call+disconnects+after+30+seconds&oq=freepbx+call+disconnects+after+30+seconds&aqs=chrome..69i57j0l5.7714j0j1&sourceid=chrome&ie=UTF-8

david55 · May 24, 2022, 8:53pm

One really needs the PJSIP protocol logs, but I would say that the phone is sending a public address in its Contact header, but the router isn’t prepared to accept that as the destination of the Ack from Asterisk. If this were the other way round it would be because of not setting local networks correctly, so check for equivalent options on the phone.

Bradbpw · May 24, 2022, 10:01pm

Can you tell me how to get the PJSIP protocol logs?

david55 · May 24, 2022, 10:02pm

Make sure you have the full log working, then enter “pjsip set logger on” into the Asterisk CLI.

Bradbpw · May 25, 2022, 1:56pm

Thanks for the help. I ended up getting the problem fixed by rebooting my PBX.

system · June 25, 2022, 1:56pm

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