[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] netsock2.c: Using SIP RTP TOS bits 184
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] netsock2.c: Using SIP RTP CoS mark 5
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:1] Macro("SIP/102-00000010", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/102-00000010", "TOUCH_MONITOR=1637766965.16") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/102-00000010", "AMPUSER=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:3] Set("SIP/102-00000010", "HOTDESCKCHAN=102-00000010") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:4] Set("SIP/102-00000010", "HOTDESKEXTEN=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/102-00000010", "HOTDESKCALL=0") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:6] ExecIf("SIP/102-00000010", "0?Set(HOTDESKCALL=1)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:7] ExecIf("SIP/102-00000010", "0?Set(CALLERID(name)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("SIP/102-00000010", "0?report") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:9] ExecIf("SIP/102-00000010", "1?Set(REALCALLERIDNUM=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/102-00000010", "AMPUSER=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:11] GotoIf("SIP/102-00000010", "0?limit") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:12] Set("SIP/102-00000010", "AMPUSERCIDNAME=Secretary") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("SIP/102-00000010", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:14] GotoIf("SIP/102-00000010", "0?report") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:15] Set("SIP/102-00000010", "AMPUSERCID=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:16] Set("SIP/102-00000010", "__DIAL_OPTIONS=HhTtr") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:17] Set("SIP/102-00000010", "CALLERID(all)="Secretary" <102>") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:18] ExecIf("SIP/102-00000010", "0?Set(CUSDIAL=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)="Secretary" <102>)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:20] GotoIf("SIP/102-00000010", "0?limit") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:21] ExecIf("SIP/102-00000010", "1?Set(GROUP(concurrency_limit)=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:22] ExecIf("SIP/102-00000010", "0?Set(CHANNEL(language)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:23] NoOp("SIP/102-00000010", "Macro Depth is 1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:24] GotoIf("SIP/102-00000010", "1?report2:macroerror") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-user-callerid,s,25)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("SIP/102-00000010", "1?continue") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-user-callerid,s,44)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:44] Set("SIP/102-00000010", "CALLERID(number)=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:45] Set("SIP/102-00000010", "CALLERID(name)=Secretary") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:46] GotoIf("SIP/102-00000010", "0?cnum") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:47] Set("SIP/102-00000010", "CDR(cnam)=Secretary") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:48] Set("SIP/102-00000010", "CDR(cnum)=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-user-callerid:49] Set("SIP/102-00000010", "CHANNEL(language)=ru") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:2] Gosub("SIP/102-00000010", "sub-record-check,s,1(out,61552,dontcare)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/102-00000010", "0?initialized") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:2] Set("SIP/102-00000010", "__REC_STATUS=INITIALIZED") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:3] Set("SIP/102-00000010", "NOW=1637766965") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:4] Set("SIP/102-00000010", "__DAY=24") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:5] Set("SIP/102-00000010", "__MONTH=11") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:6] Set("SIP/102-00000010", "__YEAR=2021") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:7] Set("SIP/102-00000010", "__TIMESTR=20211124-201605") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:8] Set("SIP/102-00000010", "__FROMEXTEN=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:9] Set("SIP/102-00000010", "__MON_FMT=wav") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/102-00000010", "Recordings initialized") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/102-00000010", "0?Set(ARG3=dontcare)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:12] Set("SIP/102-00000010", "REC_POLICY_MODE_SAVE=") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/102-00000010", "0?Set(REC_STATUS=NO)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/102-00000010", "3?checkaction") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/102-00000010", "1?sub-record-check,out,1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (sub-record-check,out,1)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [out@sub-record-check:1] NoOp("SIP/102-00000010", "Outbound Recording Check from 102 to 61552") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [out@sub-record-check:2] Set("SIP/102-00000010", "RECMODE=dontcare") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [out@sub-record-check:3] ExecIf("SIP/102-00000010", "1?Goto(routewins)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (sub-record-check,out,7)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [out@sub-record-check:7] Gosub("SIP/102-00000010", "recordcheck,1(dontcare,out,61552)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/102-00000010", "Starting recording check against dontcare") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/102-00000010", "dontcare") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [out@sub-record-check:8] Return("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:3] ExecIf("SIP/102-00000010", "0 ?Set(CDR(accountcode)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:4] Set("SIP/102-00000010", "_ROUTEID=2") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:5] Set("SIP/102-00000010", "_ROUTENAME=gorod_outside") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:6] Set("SIP/102-00000010", "MOHCLASS=default") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:7] Set("SIP/102-00000010", "_CALLERIDNAMEINTERNAL=Secretary") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:8] Set("SIP/102-00000010", "_CALLERIDNUMINTERNAL=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:9] Set("SIP/102-00000010", "_EMAILNOTIFICATION=FALSE") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:10] Set("SIP/102-00000010", "_NODEST=") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [61552@from-internal:11] Macro("SIP/102-00000010", "dialout-trunk,2,61552,,off") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:1] Set("SIP/102-00000010", "DIAL_TRUNK=2") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("SIP/102-00000010", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("SIP/102-00000010", "0?sub-pincheck,s,1()") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("SIP/102-00000010", "0?Set(CALLERID(num)=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("SIP/102-00000010", "0?disabletrunk,1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:6] Set("SIP/102-00000010", "DIAL_NUMBER=61552") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:7] Set("SIP/102-00000010", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:8] Set("SIP/102-00000010", "OUTBOUND_GROUP=OUT_2") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:9] Set("SIP/102-00000010", "DIAL_TRUNK_OPTIONS=T") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("SIP/102-00000010", "1?nomax") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-dialout-trunk,s,12)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("SIP/102-00000010", "0?skipoutcid") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("SIP/102-00000010", "outbound-callerid,2") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("SIP/102-00000010", "102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("SIP/102-00000010", "off") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:6] Set("SIP/102-00000010", "HOTDESCKCHAN=102-00000010") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:7] Set("SIP/102-00000010", "HOTDESKEXTEN=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:8] Set("SIP/102-00000010", "HOTDESKCALL=0") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:9] ExecIf("SIP/102-00000010", "0?Set(HOTDESKCALL=1)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:10] ExecIf("SIP/102-00000010", "0?Set(CALLERID(name)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:11] Set("SIP/102-00000010", "ALLOWTHISROUTE=NO") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:12] ExecIf("SIP/102-00000010", "0?Set(ALLOWTHISROUTE=YES)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:13] ExecIf("SIP/102-00000010", "0?Hangup()") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:14] ExecIf("SIP/102-00000010", "0?Set(REALCALLERIDNUM=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:15] ExecIf("SIP/102-00000010", "0?Set(AMPUSER=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:16] GotoIf("SIP/102-00000010", "1?normcid") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-outbound-callerid,s,20)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:20] Set("SIP/102-00000010", "USEROUTCID=") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:21] Set("SIP/102-00000010", "EMERGENCYCID=") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("SIP/102-00000010", "0?Set(EMERGENCYCID=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:23] Set("SIP/102-00000010", "TRUNKOUTCID=") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:24] GotoIf("SIP/102-00000010", "1?trunkcid") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-outbound-callerid,s,30)
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:30] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:31] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:32] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:33] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:34] ExecIf("SIP/102-00000010", "0?Set(CALLERID(all)=102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:35] Set("SIP/102-00000010", "TIOHIDE=no") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:36] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:37] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:38] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:39] ExecIf("SIP/102-00000010", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:40] Set("SIP/102-00000010", "CDR(outbound_cnum)=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-outbound-callerid:41] Set("SIP/102-00000010", "CDR(outbound_cnam)=Secretary") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("SIP/102-00000010", "0?sub-flp-2,s,1()") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:15] Set("SIP/102-00000010", "OUTNUM=61552") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:16] Set("SIP/102-00000010", "custom=SIP/42004") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("SIP/102-00000010", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("SIP/102-00000010", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("SIP/102-00000010", "dialout-trunk-predial-hook,") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("SIP/102-00000010", "0?skipcrm") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:21] Set("SIP/102-00000010", "__CRM_DIRECTION=OUTBOUND") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:22] Set("SIP/102-00000010", "__CRM_DESTINATION=61552") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:23] Set("SIP/102-00000010", "__CRM_SOURCE=102") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("SIP/102-00000010", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] res_agi.c: <SIP/102-00000010>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:25] Set("SIP/102-00000010", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("SIP/102-00000010", "CRM Finished") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("SIP/102-00000010", "0?bypass,1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("SIP/102-00000010", "1?Set(CONNECTEDLINE(num,i)=61552)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("SIP/102-00000010", "1?Set(CONNECTEDLINE(name,i)=CID:102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("SIP/102-00000010", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("SIP/102-00000010", "0?customtrunk") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:32] ExecIf("SIP/102-00000010", "0?Set(DIAL_TRUNK_OPTIONS=)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:33] Set("SIP/102-00000010", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-dialout-trunk:34] Dial("SIP/102-00000010", "SIP/42004/61552,300,Tb(func-apply-sipheaders^s^1,(2))U(sub-send-obroute-email^61552^61552^2^1637766965^Secretary^102)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] netsock2.c: Using SIP RTP TOS bits 184
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] netsock2.c: Using SIP RTP CoS mark 5
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] app_stack.c: SIP/42004-00000011 Internal Gosub(func-apply-sipheaders,s,1(2)) start
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/42004-00000011", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/42004-00000011", "Applying SIP Headers to channel SIP/42004-00000011") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/42004-00000011", "TECH=SIP") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/42004-00000011", "SIPHEADERKEYS=Alert-Info") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/42004-00000011", "1") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:6] Set("SIP/42004-00000011", "sipheader=unset") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("SIP/42004-00000011", "1?SIPRemoveHeader(Alert-Info:)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("SIP/42004-00000011", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("SIP/42004-00000011", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("SIP/42004-00000011", "0?SIPAddHeader(Alert-Info:unset)") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:11] EndWhile("SIP/42004-00000011", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/42004-00000011", "0") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] pbx.c: Executing [s@func-apply-sipheaders:12] Return("SIP/42004-00000011", "") in new stack
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] app_stack.c: Spawn extension (from-trunk, 61552, 1) exited non-zero on 'SIP/42004-00000011'
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] app_stack.c: SIP/42004-00000011 Internal Gosub(func-apply-sipheaders,s,1(2)) complete GOSUB_RETVAL=
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Audio is at 19646
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding codec ulaw to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding codec alaw to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding codec gsm to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding codec g726 to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding codec g722 to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] chan_sip.c: Reliably Transmitting (NAT) to 192.168.20.240:5060:
INVITE sip:61552@192.168.20.240:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK1488c35a;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>
Contact: <sip:102@192.168.20.254:5060>
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 102 INVITE
User-Agent: FPBX-15.0.17.34(16.17.0)
Date: Wed, 24 Nov 2021 15:16:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 358

v=0
o=root 1017704685 1017704685 IN IP4 192.168.20.254
s=Asterisk PBX 16.17.0
c=IN IP4 192.168.20.254
t=0 0
m=audio 19646 RTP/AVP 0 8 3 111 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] app_dial.c: Called SIP/42004/61552
[2021-11-24 20:16:05] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK1488c35a;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 102 INVITE
User-Agent: AddPac AP1100F 8.41.092
Content-Length: 0

<------------->
[2021-11-24 20:16:05] VERBOSE[2615] chan_sip.c: --- (8 headers 0 lines) ---
[2021-11-24 20:16:05] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK1488c35a;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>;tag=8261d508a4
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 102 INVITE
Supported: timer, replaces, early-session
User-Agent: AddPac AP1100F 8.41.092
Contact: sip:61552@192.168.20.240
Content-Type: application/sdp
Content-Length: 252

v=0
o=61552 1637784962 1637784962 IN IP4 192.168.20.240
s=AddPac Gateway SDP
c=IN IP4 192.168.20.240
t=1637784962 0
m=audio 23034 RTP/AVP 0 101
a=ptime:20
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15
a=sendrecv
<------------->
[2021-11-24 20:16:05] VERBOSE[2615] chan_sip.c: --- (11 headers 11 lines) ---
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] sip/route.c: sip_route_dump: route/path hop: <sip:61552@192.168.20.240>
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Got SDP version 1637784962 and unique parts [61552 1637784962 IN IP4 192.168.20.240]
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Found RTP audio format 0
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Found RTP audio format 101
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Found audio description format PCMU for ID 0
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Found audio description format telephone-event for ID 101
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g726|g722), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2021-11-24 20:16:05] VERBOSE[2615][C-00000009] chan_sip.c: Peer audio RTP is at port 192.168.20.240:23034
[2021-11-24 20:16:05] VERBOSE[9119][C-00000009] app_dial.c: SIP/42004-00000011 is making progress passing it to SIP/102-00000010
[2021-11-24 20:16:07] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK1488c35a;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>;tag=8261d508a4
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 102 INVITE
Supported: timer, replaces, early-session
User-Agent: AddPac AP1100F 8.41.092
Contact: sip:61552@192.168.20.240
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 252

v=0
o=61552 1637784964 1637784964 IN IP4 192.168.20.240
s=AddPac Gateway SDP
c=IN IP4 192.168.20.240
t=1637784964 0
m=audio 23034 RTP/AVP 0 101
a=ptime:20
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15
a=sendrecv
<------------->
[2021-11-24 20:16:07] VERBOSE[2615] chan_sip.c: --- (12 headers 11 lines) ---
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Comparing SDP version 1637784962 -> 1637784964 and unique parts [61552 1637784962 IN IP4 192.168.20.240] -> [61552 1637784964 IN IP4 192.168.20.240]
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Found RTP audio format 0
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Found RTP audio format 101
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Found audio description format PCMU for ID 0
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Found audio description format telephone-event for ID 101
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g726|g722), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Peer audio RTP is at port 192.168.20.240:23034
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] sip/route.c: sip_route_dump: route/path hop: <sip:61552@192.168.20.240>
[2021-11-24 20:16:07] VERBOSE[2615][C-00000009] chan_sip.c: Transmitting (NAT) to 192.168.20.240:5060:
ACK sip:61552@192.168.20.240 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK6e7b04b1;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>;tag=8261d508a4
Contact: <sip:102@192.168.20.254:5060>
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 102 ACK
User-Agent: FPBX-15.0.17.34(16.17.0)
Content-Length: 0


---
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] app_dial.c: SIP/42004-00000011 answered SIP/102-00000010
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] app_stack.c: SIP/42004-00000011 Internal Gosub(sub-send-obroute-email,s,1(61552,61552,2,1637766965,Secretary,102)) start
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-send-obroute-email:1] GotoIf("SIP/42004-00000011", "0?sendEmail") in new stack
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-send-obroute-email:2] NoOp("SIP/42004-00000011", "email notifications disabled..exiting.") in new stack
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] pbx.c: Executing [s@sub-send-obroute-email:3] Return("SIP/42004-00000011", "") in new stack
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] app_stack.c: Spawn extension (from-trunk, , 1) exited non-zero on 'SIP/42004-00000011'
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] app_stack.c: SIP/42004-00000011 Internal Gosub(sub-send-obroute-email,s,1(61552,61552,2,1637766965,Secretary,102)) complete GOSUB_RETVAL=
[2021-11-24 20:16:07] VERBOSE[9192][C-00000009] bridge_channel.c: Channel SIP/42004-00000011 joined 'simple_bridge' basic-bridge <8a0b6ee7-f012-4514-8342-d4aee31e2a54>
[2021-11-24 20:16:07] VERBOSE[9119][C-00000009] bridge_channel.c: Channel SIP/102-00000010 joined 'simple_bridge' basic-bridge <8a0b6ee7-f012-4514-8342-d4aee31e2a54>
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] bridge_channel.c: Channel SIP/102-00000010 left 'simple_bridge' basic-bridge <8a0b6ee7-f012-4514-8342-d4aee31e2a54>
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] app_macro.c: Spawn extension (macro-dialout-trunk, s, 34) exited non-zero on 'SIP/102-00000010' in macro 'dialout-trunk'
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Spawn extension (from-internal, 61552, 11) exited non-zero on 'SIP/102-00000010'
[2021-11-24 20:16:11] VERBOSE[9192][C-00000009] bridge_channel.c: Channel SIP/42004-00000011 left 'simple_bridge' basic-bridge <8a0b6ee7-f012-4514-8342-d4aee31e2a54>
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [h@from-internal:1] Macro("SIP/102-00000010", "hangupcall") in new stack
[2021-11-24 20:16:11] VERBOSE[9192][C-00000009] chan_sip.c: Scheduling destruction of SIP dialog '401456b645f94ec63210efbc6a318d08@192.168.20.254:5060' in 6400 ms (Method: INVITE)
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/102-00000010", "1?theend") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2021-11-24 20:16:11] VERBOSE[9192][C-00000009] chan_sip.c: Reliably Transmitting (NAT) to 192.168.20.240:5060:
BYE sip:61552@192.168.20.240 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK61b99481;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>;tag=8261d508a4
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 103 BYE
User-Agent: FPBX-15.0.17.34(16.17.0)
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/102-00000010", "0?Set(CDR(recordingfile)=)") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/102-00000010", "SIP/42004-00000011 montior file= ") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("SIP/102-00000010", "1?skipagi") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@macro-hangupcall:7] Hangup("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/102-00000010' in macro 'hangupcall'
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000010'
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] app_stack.c: SIP/102-00000010 Internal Gosub(crm-hangup,s,1) start
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/102-00000010", "Sending Hangup to CRM") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/102-00000010", "HANGUP CAUSE: 16") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/102-00000010", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/102-00000010", "MASTER CHANNEL: 1637766965.16 = 1637766965.16") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/102-00000010", "0?return") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:6] Set("SIP/102-00000010", "__CRM_HANGUP=1") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:7] AGI("SIP/102-00000010", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2021-11-24 20:16:11] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK61b99481;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as79c58986
To: <sip:61552@192.168.20.240:5060>;tag=8261d508a4
Call-ID: 401456b645f94ec63210efbc6a318d08@192.168.20.254:5060
CSeq: 103 BYE
User-Agent: AddPac AP1100F 8.41.092
Content-Length: 0

<------------->
[2021-11-24 20:16:11] VERBOSE[2615] chan_sip.c: --- (8 headers 0 lines) ---
[2021-11-24 20:16:11] VERBOSE[2615] chan_sip.c: Really destroying SIP dialog '401456b645f94ec63210efbc6a318d08@192.168.20.254:5060' Method: INVITE
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] res_agi.c: <SIP/102-00000010>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] pbx.c: Executing [s@crm-hangup:8] Return("SIP/102-00000010", "") in new stack
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000010'
[2021-11-24 20:16:11] VERBOSE[9119][C-00000009] app_stack.c: SIP/102-00000010 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] netsock2.c: Using SIP RTP TOS bits 184
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] netsock2.c: Using SIP RTP CoS mark 5
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:1] Macro("SIP/102-00000012", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/102-00000012", "TOUCH_MONITOR=1637766981.18") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/102-00000012", "AMPUSER=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:3] Set("SIP/102-00000012", "HOTDESCKCHAN=102-00000012") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:4] Set("SIP/102-00000012", "HOTDESKEXTEN=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/102-00000012", "HOTDESKCALL=0") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:6] ExecIf("SIP/102-00000012", "0?Set(HOTDESKCALL=1)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:7] ExecIf("SIP/102-00000012", "0?Set(CALLERID(name)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("SIP/102-00000012", "0?report") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:9] ExecIf("SIP/102-00000012", "1?Set(REALCALLERIDNUM=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/102-00000012", "AMPUSER=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:11] GotoIf("SIP/102-00000012", "0?limit") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:12] Set("SIP/102-00000012", "AMPUSERCIDNAME=Secretary") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("SIP/102-00000012", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:14] GotoIf("SIP/102-00000012", "0?report") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:15] Set("SIP/102-00000012", "AMPUSERCID=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:16] Set("SIP/102-00000012", "__DIAL_OPTIONS=HhTtr") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:17] Set("SIP/102-00000012", "CALLERID(all)="Secretary" <102>") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:18] ExecIf("SIP/102-00000012", "0?Set(CUSDIAL=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)="Secretary" <102>)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:20] GotoIf("SIP/102-00000012", "0?limit") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:21] ExecIf("SIP/102-00000012", "1?Set(GROUP(concurrency_limit)=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:22] ExecIf("SIP/102-00000012", "0?Set(CHANNEL(language)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:23] NoOp("SIP/102-00000012", "Macro Depth is 1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:24] GotoIf("SIP/102-00000012", "1?report2:macroerror") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-user-callerid,s,25)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("SIP/102-00000012", "1?continue") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-user-callerid,s,44)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:44] Set("SIP/102-00000012", "CALLERID(number)=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:45] Set("SIP/102-00000012", "CALLERID(name)=Secretary") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:46] GotoIf("SIP/102-00000012", "0?cnum") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:47] Set("SIP/102-00000012", "CDR(cnam)=Secretary") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:48] Set("SIP/102-00000012", "CDR(cnum)=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-user-callerid:49] Set("SIP/102-00000012", "CHANNEL(language)=ru") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:2] Gosub("SIP/102-00000012", "sub-record-check,s,1(out,42020,dontcare)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/102-00000012", "0?initialized") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:2] Set("SIP/102-00000012", "__REC_STATUS=INITIALIZED") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:3] Set("SIP/102-00000012", "NOW=1637766981") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:4] Set("SIP/102-00000012", "__DAY=24") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:5] Set("SIP/102-00000012", "__MONTH=11") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:6] Set("SIP/102-00000012", "__YEAR=2021") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:7] Set("SIP/102-00000012", "__TIMESTR=20211124-201621") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:8] Set("SIP/102-00000012", "__FROMEXTEN=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:9] Set("SIP/102-00000012", "__MON_FMT=wav") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/102-00000012", "Recordings initialized") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/102-00000012", "0?Set(ARG3=dontcare)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:12] Set("SIP/102-00000012", "REC_POLICY_MODE_SAVE=") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/102-00000012", "0?Set(REC_STATUS=NO)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/102-00000012", "3?checkaction") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/102-00000012", "1?sub-record-check,out,1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (sub-record-check,out,1)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [out@sub-record-check:1] NoOp("SIP/102-00000012", "Outbound Recording Check from 102 to 42020") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [out@sub-record-check:2] Set("SIP/102-00000012", "RECMODE=dontcare") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [out@sub-record-check:3] ExecIf("SIP/102-00000012", "1?Goto(routewins)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (sub-record-check,out,7)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [out@sub-record-check:7] Gosub("SIP/102-00000012", "recordcheck,1(dontcare,out,42020)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/102-00000012", "Starting recording check against dontcare") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/102-00000012", "dontcare") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [out@sub-record-check:8] Return("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:3] ExecIf("SIP/102-00000012", "0 ?Set(CDR(accountcode)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:4] Set("SIP/102-00000012", "_ROUTEID=2") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:5] Set("SIP/102-00000012", "_ROUTENAME=gorod_outside") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:6] Set("SIP/102-00000012", "MOHCLASS=default") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:7] Set("SIP/102-00000012", "_CALLERIDNAMEINTERNAL=Secretary") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:8] Set("SIP/102-00000012", "_CALLERIDNUMINTERNAL=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:9] Set("SIP/102-00000012", "_EMAILNOTIFICATION=FALSE") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:10] Set("SIP/102-00000012", "_NODEST=") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [42020@from-internal:11] Macro("SIP/102-00000012", "dialout-trunk,2,42020,,off") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:1] Set("SIP/102-00000012", "DIAL_TRUNK=2") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("SIP/102-00000012", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("SIP/102-00000012", "0?sub-pincheck,s,1()") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("SIP/102-00000012", "0?Set(CALLERID(num)=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("SIP/102-00000012", "0?disabletrunk,1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:6] Set("SIP/102-00000012", "DIAL_NUMBER=42020") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:7] Set("SIP/102-00000012", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:8] Set("SIP/102-00000012", "OUTBOUND_GROUP=OUT_2") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:9] Set("SIP/102-00000012", "DIAL_TRUNK_OPTIONS=T") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("SIP/102-00000012", "1?nomax") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-dialout-trunk,s,12)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("SIP/102-00000012", "0?skipoutcid") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("SIP/102-00000012", "outbound-callerid,2") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("SIP/102-00000012", "102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("SIP/102-00000012", "off") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:6] Set("SIP/102-00000012", "HOTDESCKCHAN=102-00000012") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:7] Set("SIP/102-00000012", "HOTDESKEXTEN=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:8] Set("SIP/102-00000012", "HOTDESKCALL=0") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:9] ExecIf("SIP/102-00000012", "0?Set(HOTDESKCALL=1)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:10] ExecIf("SIP/102-00000012", "0?Set(CALLERID(name)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:11] Set("SIP/102-00000012", "ALLOWTHISROUTE=NO") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:12] ExecIf("SIP/102-00000012", "0?Set(ALLOWTHISROUTE=YES)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:13] ExecIf("SIP/102-00000012", "0?Hangup()") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:14] ExecIf("SIP/102-00000012", "0?Set(REALCALLERIDNUM=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:15] ExecIf("SIP/102-00000012", "0?Set(AMPUSER=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:16] GotoIf("SIP/102-00000012", "1?normcid") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-outbound-callerid,s,20)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:20] Set("SIP/102-00000012", "USEROUTCID=") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:21] Set("SIP/102-00000012", "EMERGENCYCID=") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("SIP/102-00000012", "0?Set(EMERGENCYCID=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:23] Set("SIP/102-00000012", "TRUNKOUTCID=") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:24] GotoIf("SIP/102-00000012", "1?trunkcid") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-outbound-callerid,s,30)
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:30] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:31] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:32] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:33] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:34] ExecIf("SIP/102-00000012", "0?Set(CALLERID(all)=102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:35] Set("SIP/102-00000012", "TIOHIDE=no") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:36] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:37] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:38] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:39] ExecIf("SIP/102-00000012", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:40] Set("SIP/102-00000012", "CDR(outbound_cnum)=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-outbound-callerid:41] Set("SIP/102-00000012", "CDR(outbound_cnam)=Secretary") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("SIP/102-00000012", "0?sub-flp-2,s,1()") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:15] Set("SIP/102-00000012", "OUTNUM=42020") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:16] Set("SIP/102-00000012", "custom=SIP/42004") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("SIP/102-00000012", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("SIP/102-00000012", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("SIP/102-00000012", "dialout-trunk-predial-hook,") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("SIP/102-00000012", "0?skipcrm") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:21] Set("SIP/102-00000012", "__CRM_DIRECTION=OUTBOUND") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:22] Set("SIP/102-00000012", "__CRM_DESTINATION=42020") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:23] Set("SIP/102-00000012", "__CRM_SOURCE=102") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("SIP/102-00000012", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] res_agi.c: <SIP/102-00000012>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:25] Set("SIP/102-00000012", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("SIP/102-00000012", "CRM Finished") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("SIP/102-00000012", "0?bypass,1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("SIP/102-00000012", "1?Set(CONNECTEDLINE(num,i)=42020)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("SIP/102-00000012", "1?Set(CONNECTEDLINE(name,i)=CID:102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("SIP/102-00000012", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("SIP/102-00000012", "0?customtrunk") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:32] ExecIf("SIP/102-00000012", "0?Set(DIAL_TRUNK_OPTIONS=)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:33] Set("SIP/102-00000012", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-dialout-trunk:34] Dial("SIP/102-00000012", "SIP/42004/42020,300,Tb(func-apply-sipheaders^s^1,(2))U(sub-send-obroute-email^42020^42020^2^1637766981^Secretary^102)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] netsock2.c: Using SIP RTP TOS bits 184
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] netsock2.c: Using SIP RTP CoS mark 5
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_stack.c: SIP/42004-00000013 Internal Gosub(func-apply-sipheaders,s,1(2)) start
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/42004-00000013", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/42004-00000013", "Applying SIP Headers to channel SIP/42004-00000013") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/42004-00000013", "TECH=SIP") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/42004-00000013", "SIPHEADERKEYS=Alert-Info") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/42004-00000013", "1") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:6] Set("SIP/42004-00000013", "sipheader=unset") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("SIP/42004-00000013", "1?SIPRemoveHeader(Alert-Info:)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("SIP/42004-00000013", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("SIP/42004-00000013", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("SIP/42004-00000013", "0?SIPAddHeader(Alert-Info:unset)") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:11] EndWhile("SIP/42004-00000013", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/42004-00000013", "0") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@func-apply-sipheaders:12] Return("SIP/42004-00000013", "") in new stack
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_stack.c: Spawn extension (from-trunk, 42020, 1) exited non-zero on 'SIP/42004-00000013'
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_stack.c: SIP/42004-00000013 Internal Gosub(func-apply-sipheaders,s,1(2)) complete GOSUB_RETVAL=
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Audio is at 12396
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding codec ulaw to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding codec alaw to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding codec gsm to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding codec g726 to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding codec g722 to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] chan_sip.c: Reliably Transmitting (NAT) to 192.168.20.240:5060:
INVITE sip:42020@192.168.20.240:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>
Contact: <sip:102@192.168.20.254:5060>
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
User-Agent: FPBX-15.0.17.34(16.17.0)
Date: Wed, 24 Nov 2021 15:16:21 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 356

v=0
o=root 866194226 866194226 IN IP4 192.168.20.254
s=Asterisk PBX 16.17.0
c=IN IP4 192.168.20.254
t=0 0
m=audio 12396 RTP/AVP 0 8 3 111 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_dial.c: Called SIP/42004/42020
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: Retransmitting #1 (NAT) to 192.168.20.240:5060:
INVITE sip:42020@192.168.20.240:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>
Contact: <sip:102@192.168.20.254:5060>
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
User-Agent: FPBX-15.0.17.34(16.17.0)
Date: Wed, 24 Nov 2021 15:16:21 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 356

v=0
o=root 866194226 866194226 IN IP4 192.168.20.254
s=Asterisk PBX 16.17.0
c=IN IP4 192.168.20.254
t=0 0
m=audio 12396 RTP/AVP 0 8 3 111 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
User-Agent: AddPac AP1100F 8.41.092
Content-Length: 0

<------------->
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: --- (8 headers 0 lines) ---
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
Supported: timer, replaces, early-session
User-Agent: AddPac AP1100F 8.41.092
Contact: sip:42020@192.168.20.240
Content-Type: application/sdp
Content-Length: 252

v=0
o=42020 1637784978 1637784978 IN IP4 192.168.20.240
s=AddPac Gateway SDP
c=IN IP4 192.168.20.240
t=1637784978 0
m=audio 23038 RTP/AVP 0 101
a=ptime:20
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15
a=sendrecv
<------------->
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: --- (11 headers 11 lines) ---
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] sip/route.c: sip_route_dump: route/path hop: <sip:42020@192.168.20.240>
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Got SDP version 1637784978 and unique parts [42020 1637784978 IN IP4 192.168.20.240]
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Found RTP audio format 0
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Found RTP audio format 101
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Found audio description format PCMU for ID 0
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Found audio description format telephone-event for ID 101
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g726|g722), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Peer audio RTP is at port 192.168.20.240:23038
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_dial.c: SIP/42004-00000013 is making progress passing it to SIP/102-00000012
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
Supported: timer, replaces, early-session
User-Agent: AddPac AP1100F 8.41.092
Contact: sip:42020@192.168.20.240
Content-Type: application/sdp
Content-Length: 252

v=0
o=42020 1637784978 1637784978 IN IP4 192.168.20.240
s=AddPac Gateway SDP
c=IN IP4 192.168.20.240
t=1637784978 0
m=audio 23038 RTP/AVP 0 101
a=ptime:20
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15
a=sendrecv
<------------->
[2021-11-24 20:16:21] VERBOSE[2615] chan_sip.c: --- (11 headers 11 lines) ---
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] sip/route.c: sip_route_dump: route/path hop: <sip:42020@192.168.20.240>
[2021-11-24 20:16:21] VERBOSE[2615][C-0000000a] chan_sip.c: Comparing SDP version 1637784978 -> 1637784978 and unique parts [42020 1637784978 IN IP4 192.168.20.240] -> [42020 1637784978 IN IP4 192.168.20.240]
[2021-11-24 20:16:21] VERBOSE[9231][C-0000000a] app_dial.c: SIP/42004-00000013 is making progress passing it to SIP/102-00000012
[2021-11-24 20:16:23] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK10737e98;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 INVITE
Supported: timer, replaces, early-session
User-Agent: AddPac AP1100F 8.41.092
Contact: sip:42020@192.168.20.240
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 252

v=0
o=42020 1637784980 1637784980 IN IP4 192.168.20.240
s=AddPac Gateway SDP
c=IN IP4 192.168.20.240
t=1637784980 0
m=audio 23038 RTP/AVP 0 101
a=ptime:20
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15
a=sendrecv
<------------->
[2021-11-24 20:16:23] VERBOSE[2615] chan_sip.c: --- (12 headers 11 lines) ---
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Comparing SDP version 1637784978 -> 1637784980 and unique parts [42020 1637784978 IN IP4 192.168.20.240] -> [42020 1637784980 IN IP4 192.168.20.240]
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Found RTP audio format 0
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Found RTP audio format 101
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Found audio description format PCMU for ID 0
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Found audio description format telephone-event for ID 101
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g726|g722), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Peer audio RTP is at port 192.168.20.240:23038
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] sip/route.c: sip_route_dump: route/path hop: <sip:42020@192.168.20.240>
[2021-11-24 20:16:23] VERBOSE[2615][C-0000000a] chan_sip.c: Transmitting (NAT) to 192.168.20.240:5060:
ACK sip:42020@192.168.20.240 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK54db7326;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Contact: <sip:102@192.168.20.254:5060>
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 102 ACK
User-Agent: FPBX-15.0.17.34(16.17.0)
Content-Length: 0


---
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] app_dial.c: SIP/42004-00000013 answered SIP/102-00000012
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] app_stack.c: SIP/42004-00000013 Internal Gosub(sub-send-obroute-email,s,1(42020,42020,2,1637766981,Secretary,102)) start
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-send-obroute-email:1] GotoIf("SIP/42004-00000013", "0?sendEmail") in new stack
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-send-obroute-email:2] NoOp("SIP/42004-00000013", "email notifications disabled..exiting.") in new stack
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@sub-send-obroute-email:3] Return("SIP/42004-00000013", "") in new stack
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] app_stack.c: Spawn extension (from-trunk, , 1) exited non-zero on 'SIP/42004-00000013'
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] app_stack.c: SIP/42004-00000013 Internal Gosub(sub-send-obroute-email,s,1(42020,42020,2,1637766981,Secretary,102)) complete GOSUB_RETVAL=
[2021-11-24 20:16:23] VERBOSE[9250][C-0000000a] bridge_channel.c: Channel SIP/42004-00000013 joined 'simple_bridge' basic-bridge <f0503510-cfe2-45b3-ad93-0112b30d71bb>
[2021-11-24 20:16:23] VERBOSE[9231][C-0000000a] bridge_channel.c: Channel SIP/102-00000012 joined 'simple_bridge' basic-bridge <f0503510-cfe2-45b3-ad93-0112b30d71bb>
[2021-11-24 20:16:27] VERBOSE[2615] chan_sip.c: Reliably Transmitting (NAT) to 192.168.20.240:5060:
OPTIONS sip:192.168.20.240 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK59a055ad;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.20.254>;tag=as53cfa9fe
To: <sip:192.168.20.240>
Contact: <sip:Unknown@192.168.20.254:5060>
Call-ID: 0ce9ff3708002178112fc1480b3aca08@192.168.20.254:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-15.0.17.34(16.17.0)
Date: Wed, 24 Nov 2021 15:16:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2021-11-24 20:16:27] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK59a055ad;rport
From: "Unknown" <sip:Unknown@192.168.20.254>;tag=as53cfa9fe
To: <sip:192.168.20.240>
Call-ID: 0ce9ff3708002178112fc1480b3aca08@192.168.20.254:5060
CSeq: 102 OPTIONS
User-Agent: AddPac AP1100F 8.41.092
Accept: application/sdp
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, REFER, NOTIFY
Content-Length: 0

<------------->
[2021-11-24 20:16:27] VERBOSE[2615] chan_sip.c: --- (10 headers 0 lines) ---
[2021-11-24 20:16:27] VERBOSE[2615] chan_sip.c: Really destroying SIP dialog '0ce9ff3708002178112fc1480b3aca08@192.168.20.254:5060' Method: OPTIONS
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] bridge_channel.c: Channel SIP/102-00000012 left 'simple_bridge' basic-bridge <f0503510-cfe2-45b3-ad93-0112b30d71bb>
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] app_macro.c: Spawn extension (macro-dialout-trunk, s, 34) exited non-zero on 'SIP/102-00000012' in macro 'dialout-trunk'
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Spawn extension (from-internal, 42020, 11) exited non-zero on 'SIP/102-00000012'
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [h@from-internal:1] Macro("SIP/102-00000012", "hangupcall") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/102-00000012", "1?theend") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2021-11-24 20:16:40] VERBOSE[9250][C-0000000a] bridge_channel.c: Channel SIP/42004-00000013 left 'simple_bridge' basic-bridge <f0503510-cfe2-45b3-ad93-0112b30d71bb>
[2021-11-24 20:16:40] VERBOSE[9250][C-0000000a] chan_sip.c: Scheduling destruction of SIP dialog '580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060' in 6400 ms (Method: INVITE)
[2021-11-24 20:16:40] VERBOSE[9250][C-0000000a] chan_sip.c: Reliably Transmitting (NAT) to 192.168.20.240:5060:
BYE sip:42020@192.168.20.240 SIP/2.0
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK05213ed2;rport
Max-Forwards: 70
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 103 BYE
User-Agent: FPBX-15.0.17.34(16.17.0)
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/102-00000012", "0?Set(CDR(recordingfile)=)") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/102-00000012", "SIP/42004-00000013 montior file= ") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("SIP/102-00000012", "1?skipagi") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@macro-hangupcall:7] Hangup("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/102-00000012' in macro 'hangupcall'
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000012'
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] app_stack.c: SIP/102-00000012 Internal Gosub(crm-hangup,s,1) start
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/102-00000012", "Sending Hangup to CRM") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/102-00000012", "HANGUP CAUSE: 16") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/102-00000012", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/102-00000012", "MASTER CHANNEL: 1637766981.18 = 1637766981.18") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/102-00000012", "0?return") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:6] Set("SIP/102-00000012", "__CRM_HANGUP=1") in new stack
[2021-11-24 20:16:40] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:7] AGI("SIP/102-00000012", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2021-11-24 20:16:40] VERBOSE[2615] chan_sip.c: 
<--- SIP read from UDP:192.168.20.240:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.20.254:5060;branch=z9hG4bK05213ed2;rport
From: "Secretary" <sip:102@192.168.20.254>;tag=as5af741da
To: <sip:42020@192.168.20.240:5060>;tag=92616709a4
Call-ID: 580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060
CSeq: 103 BYE
User-Agent: AddPac AP1100F 8.41.092
Content-Length: 0

<------------->
[2021-11-24 20:16:40] VERBOSE[2615] chan_sip.c: --- (8 headers 0 lines) ---
[2021-11-24 20:16:40] VERBOSE[2615] chan_sip.c: Really destroying SIP dialog '580ae07d6ae6d43e11bf178344c2cc3c@192.168.20.254:5060' Method: INVITE
[2021-11-24 20:16:41] VERBOSE[9231][C-0000000a] res_agi.c: <SIP/102-00000012>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-11-24 20:16:41] VERBOSE[9231][C-0000000a] pbx.c: Executing [s@crm-hangup:8] Return("SIP/102-00000012", "") in new stack
[2021-11-24 20:16:41] VERBOSE[9231][C-0000000a] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000012'
[2021-11-24 20:16:41] VERBOSE[9231][C-0000000a] app_stack.c: SIP/102-00000012 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
