FreePBX 15 plus SPA-3102 trunk

VinceIgna · July 26, 2020, 4:05pm

Hello FreePBX Community!

I am a new user, and I have a problem with my FreePBX Setup with a trunk connected to a Linksys SPA-3102.

As I’ve read a lot of posts and resolutions, I see that you guys always ask for the complete logs. Since I cannot attach files yet (since I’m new the system wouldn’t allow me ) I am just pasting it here sorry in advance.

Thanks!

Vince

VinceIgna · July 26, 2020, 5:07pm

[2020-07-26 15:45:01] VERBOSE[7399] res_pjsip/pjsip_configuration.c: Endpoint pstn_fx1 is now Reachable

[2020-07-26 15:45:01] VERBOSE[7399] res_pjsip/pjsip_options.c: Contact pstn_fx1/sip:192.168.1.30:5062 is now Reachable. RTT: 12.198 msec

[2020-07-26 15:45:36] VERBOSE[7399] res_pjsip/pjsip_options.c: Contact 801/sip:[email protected]:10488;rinstance=2135507fa28fafae is now Unreachable. RTT: 0.000 msec

[2020-07-26 15:45:41] VERBOSE[7399] res_pjsip/pjsip_configuration.c: Endpoint 802 is now Reachable

[2020-07-26 15:45:41] VERBOSE[7399] res_pjsip/pjsip_options.c: Contact 802/sip:[email protected]:43101;rinstance=037bd6add28d5857 is now Reachable. RTT: 1032.115 msec

[2020-07-26 15:46:33] VERBOSE[7399] res_pjsip/pjsip_configuration.c: Endpoint 801 is now Reachable

[2020-07-26 15:46:33] VERBOSE[7399] res_pjsip/pjsip_options.c: Contact 801/sip:[email protected]:10488;rinstance=2135507fa28fafae is now Reachable. RTT: 120.160 msec

[2020-07-26 15:48:36] VERBOSE[7399] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘192.168.1.152’

[2020-07-26 15:48:36] VERBOSE[7399] netsock2.c: Using SIP RTP Audio TOS bits 184

[2020-07-26 15:48:36] VERBOSE[7399] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.

[2020-07-26 15:48:36] VERBOSE[7399] netsock2.c: Using SIP RTP Audio CoS mark 5

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] Macro(“PJSIP/802-00000000”, “user-callerid,LIMIT,EXTERNAL,”) in new stack

[2020-07-26 15:48:36] WARNING[13181][C-00000001] app_macro.c: Macro() is deprecated and will be removed from a future version of Asterisk.

[2020-07-26 15:48:36] WARNING[13181][C-00000001] app_macro.c: Dialplan should be updated to use Gosub instead.

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] Set(“PJSIP/802-00000000”, “TOUCH_MONITOR=1595778516.0”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] Set(“PJSIP/802-00000000”, “AMPUSER=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] GotoIf(“PJSIP/802-00000000”, “0?report”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/802-00000000”, “1?Set(REALCALLERIDNUM=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] Set(“PJSIP/802-00000000”, “AMPUSER=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] GotoIf(“PJSIP/802-00000000”, “0?limit”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] Set(“PJSIP/802-00000000”, “AMPUSERCIDNAME=Vince iPhone - 802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] ExecIf(“PJSIP/802-00000000”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:9] GotoIf(“PJSIP/802-00000000”, “0?report”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:10] Set(“PJSIP/802-00000000”, “AMPUSERCID=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:11] Set(“PJSIP/802-00000000”, “__DIAL_OPTIONS=HhTtr”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:12] Set(“PJSIP/802-00000000”, “CALLERID(all)=“Vince iPhone - 802” <802>”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:13] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERID(all)=EXTERNAL)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:14] GotoIf(“PJSIP/802-00000000”, “0?limit”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:15] ExecIf(“PJSIP/802-00000000”, “1?Set(GROUP(concurrency_limit)=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:16] ExecIf(“PJSIP/802-00000000”, “0?Set(CHANNEL(language)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:17] NoOp(“PJSIP/802-00000000”, “Macro Depth is 1”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:18] GotoIf(“PJSIP/802-00000000”, “1?report2:macroerror”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,19)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:19] GotoIf(“PJSIP/802-00000000”, “1?continue”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,38)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:38] Set(“PJSIP/802-00000000”, “CALLERID(number)=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:39] Set(“PJSIP/802-00000000”, “CALLERID(name)=Vince iPhone - 802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:40] GotoIf(“PJSIP/802-00000000”, “0?cnum”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:41] Set(“PJSIP/802-00000000”, “CDR(cnam)=Vince iPhone - 802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:42] Set(“PJSIP/802-00000000”, “CDR(cnum)=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:43] Set(“PJSIP/802-00000000”, “CHANNEL(language)=en”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] Gosub(“PJSIP/802-00000000”, “sub-record-check,s,1(out,909178XXXXXX,dontcare)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/802-00000000”, “0?initialized”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] Set(“PJSIP/802-00000000”, “__REC_STATUS=INITIALIZED”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] Set(“PJSIP/802-00000000”, “NOW=1595778516”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] Set(“PJSIP/802-00000000”, “__DAY=26”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] Set(“PJSIP/802-00000000”, “__MONTH=07”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] Set(“PJSIP/802-00000000”, “__YEAR=2020”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] Set(“PJSIP/802-00000000”, “__TIMESTR=20200726-154836”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] Set(“PJSIP/802-00000000”, “__FROMEXTEN=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:9] Set(“PJSIP/802-00000000”, “__MON_FMT=wav”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:10] NoOp(“PJSIP/802-00000000”, “Recordings initialized”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:11] ExecIf(“PJSIP/802-00000000”, “0?Set(ARG3=dontcare)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:12] Set(“PJSIP/802-00000000”, “REC_POLICY_MODE_SAVE=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:13] ExecIf(“PJSIP/802-00000000”, “0?Set(REC_STATUS=NO)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:14] GotoIf(“PJSIP/802-00000000”, “3?checkaction”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (sub-record-check,s,17)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:17] GotoIf(“PJSIP/802-00000000”, “1?sub-record-check,out,1”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (sub-record-check,out,1)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/802-00000000”, “Outbound Recording Check from 802 to 909178XXXXXX”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] Set(“PJSIP/802-00000000”, “RECMODE=dontcare”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/802-00000000”, “1?Goto(routewins)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (sub-record-check,out,7)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] Gosub(“PJSIP/802-00000000”, “recordcheck,1(dontcare,out,909178XXXXXX)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/802-00000000”, “Starting recording check against dontcare”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] Goto(“PJSIP/802-00000000”, “dontcare”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] Return(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] Return(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/802-00000000”, “0 ?Set(CDR(accountcode)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] Set(“PJSIP/802-00000000”, “MOHCLASS=default”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] Set(“PJSIP/802-00000000”, “_NODEST=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] Macro(“PJSIP/802-00000000”, “dialout-trunk,2,09178XXXXXX,off”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] Set(“PJSIP/802-00000000”, “DIAL_TRUNK=2”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] ExecIf(“PJSIP/802-00000000”, “0?Set(DIAL_OPTIONS=Hhtr)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] GosubIf(“PJSIP/802-00000000”, “0?sub-pincheck,s,1()”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERID(num)=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] GotoIf(“PJSIP/802-00000000”, “0?disabletrunk,1”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] Set(“PJSIP/802-00000000”, “DIAL_NUMBER=09178XXXXXX”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] Set(“PJSIP/802-00000000”, “DIAL_TRUNK_OPTIONS=HhTtr”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] Set(“PJSIP/802-00000000”, “OUTBOUND_GROUP=OUT_2”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:9] Set(“PJSIP/802-00000000”, “DIAL_TRUNK_OPTIONS=T”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:10] GotoIf(“PJSIP/802-00000000”, “0?nomax”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:11] GotoIf(“PJSIP/802-00000000”, “0?chanfull”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:12] GotoIf(“PJSIP/802-00000000”, “0?skipoutcid”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:13] Macro(“PJSIP/802-00000000”, “outbound-callerid,2”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/802-00000000”, “802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] NoOp(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] NoOp(“PJSIP/802-00000000”, “off”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERPRES(name-pres)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERPRES(num-pres)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] ExecIf(“PJSIP/802-00000000”, “0?Set(REALCALLERIDNUM=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] ExecIf(“PJSIP/802-00000000”, “0?Set(AMPUSER=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] GotoIf(“PJSIP/802-00000000”, “1?normcid”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-outbound-callerid,s,12)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:12] Set(“PJSIP/802-00000000”, “USEROUTCID=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:13] Set(“PJSIP/802-00000000”, “EMERGENCYCID=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:14] Set(“PJSIP/802-00000000”, “TRUNKOUTCID=hidden”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:15] GotoIf(“PJSIP/802-00000000”, “1?trunkcid”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-outbound-callerid,s,21)

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:21] ExecIf(“PJSIP/802-00000000”, “1?Set(CALLERID(all)=hidden)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:22] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERID(all)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:23] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERID(all)=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:24] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERID(all)=802)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:25] Set(“PJSIP/802-00000000”, “TIOHIDE=no”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:26] ExecIf(“PJSIP/802-00000000”, “1?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack

[2020-07-26 15:48:36] WARNING[13181][C-00000001] func_callerid.c: CALLERPRES is deprecated. Use CALLERID(name-pres) or CALLERID(num-pres) instead.

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:27] ExecIf(“PJSIP/802-00000000”, “1?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:28] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:29] ExecIf(“PJSIP/802-00000000”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:30] Set(“PJSIP/802-00000000”, “CDR(outbound_cnum)=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:31] Set(“PJSIP/802-00000000”, “CDR(outbound_cnam)=hidden”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:14] GosubIf(“PJSIP/802-00000000”, “0?sub-flp-2,s,1()”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:15] Set(“PJSIP/802-00000000”, “OUTNUM=09178XXXXXX”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:16] Set(“PJSIP/802-00000000”, “custom=PJSIP”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:17] ExecIf(“PJSIP/802-00000000”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:18] ExecIf(“PJSIP/802-00000000”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:19] Macro(“PJSIP/802-00000000”, “dialout-trunk-predial-hook,”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] MacroExit(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:20] GotoIf(“PJSIP/802-00000000”, “0?skipcrm”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:21] Set(“PJSIP/802-00000000”, “__CRM_DIRECTION=OUTBOUND”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:22] Set(“PJSIP/802-00000000”, “__CRM_DESTINATION=09178XXXXXX”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:23] Set(“PJSIP/802-00000000”, “__CRM_SOURCE=802”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:24] AGI(“PJSIP/802-00000000”, “agi://127.0.0.1/sangomacrm.agi”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] res_agi.c: <PJSIP/802-00000000>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:25] Set(“PJSIP/802-00000000”, “CHANNEL(hangup_handler_push)=crm-hangup,s,1”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:26] NoOp(“PJSIP/802-00000000”, “CRM Finished”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:27] GotoIf(“PJSIP/802-00000000”, “0?bypass,1”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:28] ExecIf(“PJSIP/802-00000000”, “1?Set(CONNECTEDLINE(num,i)=09178XXXXXX)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:29] ExecIf(“PJSIP/802-00000000”, “0?Set(CONNECTEDLINE(name,i)=CID:)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:30] ExecIf(“PJSIP/802-00000000”, “1?Set(CONNECTEDLINE(name,i)=CID:(Hidden))”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:31] GotoIf(“PJSIP/802-00000000”, “0?customtrunk”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:32] ExecIf(“PJSIP/802-00000000”, “0?Set(DIAL_TRUNK_OPTIONS=)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:33] Dial(“PJSIP/802-00000000”, “PJSIP/[email protected]_fx1,300,Tb(func-apply-sipheaders^s^1,(2))”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_stack.c: PJSIP/pstn_fx1-00000001 Internal Gosub(func-apply-sipheaders,s,1(2)) start

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] ExecIf(“PJSIP/pstn_fx1-00000001”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] NoOp(“PJSIP/pstn_fx1-00000001”, “Applying SIP Headers to channel PJSIP/pstn_fx1-00000001”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] Set(“PJSIP/pstn_fx1-00000001”, “TECH=PJSIP”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] Set(“PJSIP/pstn_fx1-00000001”, “SIPHEADERKEYS=”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] While(“PJSIP/pstn_fx1-00000001”, “0”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_while.c: Jumping to priority 13

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:14] Return(“PJSIP/pstn_fx1-00000001”, “”) in new stack

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_stack.c: Spawn extension (from-pstn, 909178XXXXXX, 1) exited non-zero on ‘PJSIP/pstn_fx1-00000001’

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_stack.c: PJSIP/pstn_fx1-00000001 Internal Gosub(func-apply-sipheaders,s,1(2)) complete GOSUB_RETVAL=

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_dial.c: Called PJSIP/[email protected]_fx1

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] app_dial.c: PJSIP/pstn_fx1-00000001 answered PJSIP/802-00000000

[2020-07-26 15:48:36] VERBOSE[13194][C-00000001] bridge_channel.c: Channel PJSIP/pstn_fx1-00000001 joined ‘simple_bridge’ basic-bridge <c49e7851-9ccd-403b-9785-ee3dc9f7b044>

[2020-07-26 15:48:36] VERBOSE[13181][C-00000001] bridge_channel.c: Channel PJSIP/802-00000000 joined ‘simple_bridge’ basic-bridge <c49e7851-9ccd-403b-9785-ee3dc9f7b044>

[2020-07-26 15:48:38] WARNING[13181][C-00000001] res_rtp_asterisk.c: RTP Read too short

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] bridge_channel.c: Channel PJSIP/802-00000000 left ‘simple_bridge’ basic-bridge <c49e7851-9ccd-403b-9785-ee3dc9f7b044>

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] app_macro.c: Spawn extension (macro-dialout-trunk, s, 33) exited non-zero on ‘PJSIP/802-00000000’ in macro ‘dialout-trunk’

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Spawn extension (from-internal, 909178XXXXXX, 6) exited non-zero on ‘PJSIP/802-00000000’

[2020-07-26 15:48:44] VERBOSE[13194][C-00000001] bridge_channel.c: Channel PJSIP/pstn_fx1-00000001 left ‘simple_bridge’ basic-bridge <c49e7851-9ccd-403b-9785-ee3dc9f7b044>

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] Macro(“PJSIP/802-00000000”, “hangupcall”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/802-00000000”, “1?theend”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-hangupcall,s,3)

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/802-00000000”, “0?Set(CDR(recordingfile)=)”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] NoOp(“PJSIP/802-00000000”, "PJSIP/pstn_fx1-00000001 montior file= ") in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] GotoIf(“PJSIP/802-00000000”, “1?skipagi”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx_builtins.c: Goto (macro-hangupcall,s,7)

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] Hangup(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘PJSIP/802-00000000’ in macro ‘hangupcall’

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/802-00000000’

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] app_stack.c: PJSIP/802-00000000 Internal Gosub(crm-hangup,s,1) start

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/802-00000000”, “Sending Hangup to CRM”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:2] NoOp(“PJSIP/802-00000000”, “HANGUP CAUSE: 16”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/802-00000000”, “0?Set(__CRM_VOICEMAIL=)”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:4] NoOp(“PJSIP/802-00000000”, “MASTER CHANNEL: 1595778516.0 = 1595778516.0”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:5] GotoIf(“PJSIP/802-00000000”, “0?return”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:6] Set(“PJSIP/802-00000000”, “__CRM_HANGUP=1”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:7] AGI(“PJSIP/802-00000000”, “agi://127.0.0.1/sangomacrm.agi”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] res_agi.c: <PJSIP/802-00000000>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] pbx.c: Executing [[email protected]:8] Return(“PJSIP/802-00000000”, “”) in new stack

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/802-00000000’

[2020-07-26 15:48:44] VERBOSE[13181][C-00000001] app_stack.c: PJSIP/802-00000000 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

VinceIgna · July 26, 2020, 6:15pm

I wish to attach screenshots too of my routes and trunk settings but cannot attach.

Just let me know what you need will manually type here unless it’s the PBX logs

Stewart1 · July 26, 2020, 8:04pm

In your first post, the log showed the SPA immediately “answering” the call and was hung up 6 seconds later.

This may be a misconfiguration in the SPA with it set up for two-stage dialing and/or requesting a PIN. Did you hear a dial tone or beeps from the SPA? If you can’t spot this, post a screenshot of the SPA’s PSTN page. You should be able to just drag the file into the compose window to attach it.

It appears that you dialed 90917xxxxxxx and 0917xxxxxxx was sent to the trunk. Is your system set up to require 9 before an outside number? That’s not recommended but sometimes used for compatibility with a legacy system. I couldn’t make sense of the 0917xxxxxxx. What country is the SPA in? If US (Calling to Verizon Wireless), what’s the 0 for and where should it be removed? If Italy, it seems like one digit too many for a Palermo number.

If you need to post another log from FreePBX, paste it at pastebin.freepbx.org and post the link here.

VinceIgna · July 27, 2020, 6:41am

Hello Stewart1,

Thank you for looking into this. It’s either I am near the end or way off course but based on how I understood your reply it looks like FreePBX was able to pass it to SPA and it’s just the SPA not letting the call through.

I have a very big favor to ask, the number I used to dial is my mobile number/s, as such it may become googleable . Can you please remove the last 4 digits in your response. I assure you, doing a string search “0917846” or “0917857” will be unique for these logs moving forward and you’ll be able to find instances when you search. Will remove from my posts/replies also. Thanks much in advance.

I am based in the Philippines. From any direct (non-pbx) phone we can dial 0917XXX-XXXX directly. I guess I am in the old mindset back when I was working at an office that you need to dial “9” for outside calls. So I implemented this thinking this is how it should be done. So are you saying that I don’t need prefix “9” anymore for an outside line?

I’ve just been following guides (plural) co’z as there’s no complete guide for outbound route and trunk for version FreePBX 15 with pjsip and an SPA trunk. As such I needed to stitch together various guides. As you can see I am a noob and just trying to get my feet wet.

I had a beautifully formatted version of this reply with a bunch of pictures using your method laying down all information (including FreePBX trunk and outbound rules settings) but apparently new users can only paste one picture so will just post as much as I can capture of the PSTN page which you may need to zoom in to view.

Regarding the SPA, I actually don’t hear any thing from my “softphone” iOS app at all. There was a time that it was saying “could not be completed as dialed” or “all circuits are busy now” and authentication errors which were seen in the logs but due to constant tinkering it seems to have been “resolved” or it could also be that I strayed so much from what the correct way should be that the logs don’t report it anymore lol

Your name looked familiar as I saw one of your solutions by putting the SIP domain of the outbound route pjsip advanced settings.

Sincerely,

Vince

mcgrathr · July 27, 2020, 2:13pm

Probably problems becomes from gateway dialplan .

It’s feasible gateway “Dial Plan” mode could be the causes since dial patterns must be coincident between both systems (FreePBX trunk pattern and gateway dialplan), that why figure on trace “HANGUP CAUSE: 16” .

A simple way is to enable SPA3102 PSTN “one stage dialing” to "yes" so any dial patterns from Voip-To-PSTN GW are dialed directly to SPA3102 analog line.

Otherwise you should match FreePBX dial pattern with SPA3102 “Dial Plan : “ pattern.

VinceIgna · July 27, 2020, 3:00pm

Hello @mcgrathr,

Good day to you

One stage dialing plan is already set to “yes” even before but one thing I noticed with your screenshot is that your dial plan is all “(xx.)” instead of mine where dial plan 2 is set to my phone number. Could this be causing the issue?

Also, one thing that I recently thought off while parsing through @Stewart1’s response could this Dial Plan in Line 1 tab be the PIN he’s mentioning? I post the text co’z I cannot paste more than one picture into my responses.

(*xx|[3469]11|0|00|[2-9]xxxxxx|1xxx[2-9]xxxxxxS0|xxxxxxxxxxxx.)

@Stewart1, thanks for granting my request

Thanks much!

Sincerely,

Vince

mcgrathr · July 27, 2020, 5:16pm

Dial Plan parameter value it doesn’t matter if “one stage dialing” option is set to “yes”, by the way same for “pin” if “VOIP Caller Auth Method” is set to “None” (according to screenshot).
I suggest to leave “one stage dialing = yes” therefore any kind dial pattern from FreePBX will pass through to PSTN line, if so you will note “line” indicator on SPA3102 will starts flashing.
Another tip:
“Info” tab PSTN Line status “Last Called PSTN Number: “ you will see last number dialed, this value will updated after PSTN line have released, for each test you try it need to refresh page.

VinceIgna · July 27, 2020, 6:28pm

Hello @mcgrathr,

I checked and nothing has been dialed at all. The last called for both Voip and PSTN number is blank.

So given all of this, is there something else we need to look into?

So far we are sure that FreePBX is able to communicate with SPA right?

So we have narrowed down the issue to the SPA not being able to process the request is this correct too?

If both are “Yes” then I am half happy now that the PBX side has been configured properly. and that we just need to focus on SPA further. I hope the SPA side isn’t hopeless. This is along with OBiTalk were the only two cheap ones but both have dropped POTS SIP gateway products. Here in the Philippines landlines still have a big use as such people still have them along with mobiles.

Regards,

Vince

Stewart1 · July 27, 2020, 6:49pm

I see two issues. First, the SPA likely isn’t physically connected properly to the landline, because it shows 0 volts. Temporarily unplug the cord from the Line jack and connect it to an analog phone. If you don’t get a dial tone, check the wiring or otherwise troubleshoot the connection.

Also, in your first log, the call disconnected after 6 seconds. That’s too short for an automatic disconnect caused by a SIP timeout or lack of RTP. Unless you hung up at that point, the SPA must have signaled a disconnect.

At the Asterisk command prompt, type
pjsip set logger on
and make another (failing) test call. Paste the relevant section of the Asterisk log (which will now include a SIP trace) at pastebin.freepbx.org and post the link here.

VinceIgna · July 27, 2020, 7:57pm

Hi @Stewart1,

Sorry I just disconnected that since we needed to call someone. Also I disconnect it co’z it heats up and I’m worried. Since it’s not yet used productively I disconnect it. Rest assured the test attempts done previously were done with the PSTN connected to SPA.

Also, I have the right polarity phone cable to ensure that the voltage is positive.

Will do as instructed re pjsip logger on and will use pastebin once i’m able to obtain it.

Thanks very much for your response.

Sincerely,

Vince

mcgrathr · July 27, 2020, 8:00pm

First of all it seems no PSTN line is connected, Line voltage is 0 volts, should first solve this issue.

Q.
So far we are sure that FreePBX is able to communicate with SPA right?
A.
That’s upon to FreePBX trunk configuration and it suppose have done well and verbose pasted it seems nothing to be wrong.
As no detect PSTN line connected it seems at this stage troubles comes from SPA3102.

VinceIgna · July 28, 2020, 6:11am

Hello @Stewart1,

I got the pastebin link but apparently I cannot also paste links being a new user and all geesh new users are put on a short leash here then again it may be for the better So I am including the text of the pastebin link into the screencapture of the SPA with line voltage for your reference below.

One thing I noticed though in the screenshot above the “Registration State” has a value of “failed”

Thanks much again for looking into this

Sincerely,

Vince

Stewart1 · July 28, 2020, 7:27am

OK, I see two problems. One is that G.729 is being selected and is not working for some reason, but since you wouldn’t want to use it anyhow, just turn it off. On your SessionTalk, disable G729 or move it down in the list. It’s probably best to put ulaw (may be called PCMU or G711u) first.

On the SPA Audio Configuration section, set the Preferred Codec to G711u and disable all the codecs that have Enable settings.

However, the more serious problem can be seen on lines 4034 and 4043 – the SPA is sending its loopback address for contact and audio. I’ve never seen this before and don’t know what might be wrong. Just a guess, is the SPA connected via the Ethernet port? It should be connected via the Internet port. To be able to access its web interface from WAN side, you must enable WAN Web Server on the Router tab, WAN Setup. And of course you need proper IP address setup, etc.

If that’s not your issue, please post screenshots of the router section, the System tab and the NAT-related section of the SIP tab.

The Registration failed notice is trivial – your trunk is statically configured so it doesn’t need registration. Under Proxy and Registration, just set Register to no.

If you paste another log or otherwise need to post a link, just replace the last dot with %2E, for example
pastebin.freepbx%2Eorg/view/3ad2b038
This can be pasted into any browser and will work as a link; with Chrome browser you can just triple-click to select the text, then right-click and select Go to …

VinceIgna · July 28, 2020, 8:15am

Hello @Stewart1,

Thanks for taking time to replying and helping me get through this issue

The only reason i selected G.729 (on the SPA or vice-versa) is because it’s the only one I see in the FreePBX codecs (see below) from trunk → pjsip settings → codecs. I was under the assumption that the codecs should be aligned on both sides (FreePBX and SPA) Will this be ok that I don’t see G711u in the list below? Also, sorry about this, but what is Session Talk?

Also, I can confirm it is via the ethernet port only, I can switch this to internet port too but my rationale was that I don’t need to access my line via the internet. So we really need the network connection be to the internet port huh? At any rate for the purposes of isolation I will put network connection to ethernet instead. also, I actually disabled its routing as seen below may be this is the cause of what you were seeing? As you can see it made this 192.168.2.30 by itself while my FreePBX is using the LAN address of SPA of 192.168.1.30.

Noted on the Pastebin URL workaround and Registration topic thanks for the clarifications, will put registration to “No” as per your advise.

Sincerely,

Vince

VinceIgna · July 28, 2020, 3:14pm

Hello @Stewart1,

I already plugged the ethernet cable previously connected to the ethernet port to the Internet port. I initially had doubts whether I could manage SPA using only a cable plugged into the internet port. I guess I learned something new

Good news is I am able to now paste multiple pictures. Yipee! but before I do a test, can you please help me review some of the SPA settings?

Also, please see above screen capture the preferred codec need to be changed to G711? or is it Line 1 tab codec as seen below. I have a pending question from 2 replies ago regarding G.711 which isn’t supported in the trunk pjsip codecs. I was actually surprised that there aren’t a lot of codecs supported. I mean I was expecting an encyclopedic selection of codecs.

Thanks very much in advance!

Sincerely,

Vince

Stewart1 · July 28, 2020, 3:36pm

In various devices and software, the G.711 u-law codec is known as PCMU, ulaw or G711u. They all mean the same thing.

Likewise, the G.711 A-law codec is known as PCMA, alaw or G711a. They all mean the same thing.

Either of the above is suitable as the preferred codec, both for the SPA and the softphone.

Assuming that the SPA shows as Available in Asterisk, try another test (with pjsip logger enabled) and we’ll take a look.

VinceIgna · July 28, 2020, 6:10pm

Hello @Stewart1!

Success!!! I was able to make a successful call to a landline and a mobile phone. Yipee Thank you soooo much!

The landline call was to number 8962XXXX see pastebin link below is for the landline call.

https://pastebin.freepbx%2Eorg/view/ac37d7b7

However, while reading the logs I see some “forbidden” is this normal?

Also, is there a way to make the call connect faster? it takes 5+ seconds before you hear any ring are the “forbidden” seen in the logs contributing to this? At any rate, this is just a nice to have and I am already happy as is

Sincerely,

Vince

Stewart1 · July 29, 2020, 5:32am

Set Register to no for the PSTN Line and that should eliminate the Forbidden, though it won’t help the delay.

Unfortunately, there is considerable overhead for the SPA to wait for dial tone and dial the 11 digits, about 3.2 seconds with default settings. You could try setting it to dial faster and see whether it’s still reliable. For example, set PSTN Dial Digit Len to .07/.06 or maybe even .06/.05
I don’t know whether the wait for dial tone can be fractional – try setting PSTN Dialing Delay to 0.2 If that’s not accepted, it’s conceivable that 0 will work, if your line provides dial tone instantly.

You could eliminate this delay by using a SIP trunk, though I don’t know a good provider to recommend for Philippines. The A-Z providers I use charge (US) $0.09 to $0.11 per minute, even on their cheapest routes.

If you have good mobile data coverage, a SIP app may be a good way to receive calls.

VinceIgna · July 29, 2020, 11:27am

Dear @Stewart1,

I will try those suggested values out.

However, I hope it’s ok but can you help me with the inward dialing too? Currently, this is the inbound route config:

Is the “Set Destination” where I put all the extensions which will ring if the number listed in DID number is called?

Thanks much again

Sincerely,

Vince