Incoming call via ringing group - speech 3-5 sec. speech delay

mxbmaddin · July 8, 2021, 8:22am

For incoming calls via a ringing group, the speech is delayed by approx. 3-5 sec. in both directions.
If I set an extension directly in the inbound route, it works fine. Outbound calls also work fine.
PBX is up to date.
Does anyone have any idea?

Thanks!
Regards
Martin

cynjut · July 8, 2021, 3:04pm

Without logs, no.

mxbmaddin · July 8, 2021, 3:25pm

Hi cynjut,
what log would you need for further analysis?
Sorry, I am unfortunately still a beginner in freepbx

Thanks for your support!

Regards
Martin

mxbmaddin · July 8, 2021, 3:38pm

I hope you can do something with this…

6100[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:1] Set("PJSIP/Sipgate_Trunking-00000011", "__DIRECTION=INBOUND") in new stack
6101[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:2] Gosub("PJSIP/Sipgate_Trunking-00000011", "sub-record-check,s,1(in,496095xxxxxx,dontcare)") in new stack
6102[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?initialized") in new stack
6103[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/Sipgate_Trunking-00000011", "__REC_STATUS=INITIALIZED") in new stack
6104[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/Sipgate_Trunking-00000011", "NOW=1625758279") in new stack
6105[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/Sipgate_Trunking-00000011", "__DAY=08") in new stack
6106[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/Sipgate_Trunking-00000011", "__MONTH=07") in new stack
6107[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/Sipgate_Trunking-00000011", "__YEAR=2021") in new stack
6108[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/Sipgate_Trunking-00000011", "__TIMESTR=20210708-173119") in new stack
6109[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/Sipgate_Trunking-00000011", "__FROMEXTEN=unknown") in new stack
6110[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/Sipgate_Trunking-00000011", "__MON_FMT=wav") in new stack
6111[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/Sipgate_Trunking-00000011", "Recordings initialized") in new stack
6112[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ARG3=dontcare)") in new stack
6113[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/Sipgate_Trunking-00000011", "REC_POLICY_MODE_SAVE=") in new stack
6114[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(REC_STATUS=NO)") in new stack
6115[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/Sipgate_Trunking-00000011", "2?checkaction") in new stack
6116[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,s,17)
6117[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?sub-record-check,in,1") in new stack
6118[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,in,1)
6119[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [in@sub-record-check:1] NoOp("PJSIP/Sipgate_Trunking-00000011", "Inbound Recording Check to 496095xxxxxx") in new stack
6120[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [in@sub-record-check:2] Set("PJSIP/Sipgate_Trunking-00000011", "FROMEXTEN=unknown") in new stack
6121[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [in@sub-record-check:3] ExecIf("PJSIP/Sipgate_Trunking-00000011", "11?Set(FROMEXTEN=xxxxxxx5587)") in new stack
6122[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [in@sub-record-check:4] Gosub("PJSIP/Sipgate_Trunking-00000011", "recordcheck,1(dontcare,in,496095xxxxxx)") in new stack
6123[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/Sipgate_Trunking-00000011", "Starting recording check against dontcare") in new stack
6124[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/Sipgate_Trunking-00000011", "dontcare") in new stack
6125[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
6126[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6127[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [in@sub-record-check:5] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6128[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:3] Set("PJSIP/Sipgate_Trunking-00000011", "CHANNEL(tonezone)=de") in new stack
6129[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:4] Set("PJSIP/Sipgate_Trunking-00000011", "__FROM_DID=496095xxxxxx") in new stack
6130[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:5] Set("PJSIP/Sipgate_Trunking-00000011", "returnhere=1") in new stack
6131[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:6] Gosub("PJSIP/Sipgate_Trunking-00000011", "app-blacklist-check,s,1()") in new stack
6132[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?blacklisted") in new stack
6133[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@app-blacklist-check:2] Set("PJSIP/Sipgate_Trunking-00000011", "CALLED_BLACKLIST=1") in new stack
6134[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [s@app-blacklist-check:3] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6135[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:7] Set("PJSIP/Sipgate_Trunking-00000011", "CDR(did)=496095xxxxxx") in new stack
6136[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:8] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?") in new stack
6137[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:9] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0 ?Set(CALLERID(name)=xxxxxxx5587)") in new stack
6138[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:10] Set("PJSIP/Sipgate_Trunking-00000011", "__MOHCLASS=") in new stack
6139[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:11] Set("PJSIP/Sipgate_Trunking-00000011", "__REVERSAL_REJECT=FALSE") in new stack
6140[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:12] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?post-reverse-charge") in new stack
6141[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (from-pstn,496095xxxxxx,14)
6142[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:14] NoOp("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6143[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:15] Set("PJSIP/Sipgate_Trunking-00000011", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
6144[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:16] Set("PJSIP/Sipgate_Trunking-00000011", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
6145[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:17] Set("PJSIP/Sipgate_Trunking-00000011", "CALLERID(name-pres)=allowed_not_screened") in new stack
6146[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:18] Set("PJSIP/Sipgate_Trunking-00000011", "CALLERID(num-pres)=allowed_not_screened") in new stack
6147[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:19] NoOp("PJSIP/Sipgate_Trunking-00000011", "CallerID Entry Point") in new stack
6148[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:20] Set("PJSIP/Sipgate_Trunking-00000011", "__CRM_DIRECTION=INBOUND") in new stack
6149[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:21] Set("PJSIP/Sipgate_Trunking-00000011", "__CRM_SOURCE=xxxxxxx5587") in new stack
6150[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:22] Set("PJSIP/Sipgate_Trunking-00000011", "__CRM_LINKEDID=1625758279.17") in new stack
6151[2021-07-08 17:31:19] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:23] AGI("PJSIP/Sipgate_Trunking-00000011", "agi://127.0.0.1/sangomacrm.agi,true") in new stack
6152[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: <PJSIP/Sipgate_Trunking-00000011>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
6153[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:24] ExecIf("PJSIP/Sipgate_Trunking-00000011", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
6154[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [496095xxxxxx@from-pstn:25] Goto("PJSIP/Sipgate_Trunking-00000011", "ext-group,98,1") in new stack
6155[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (ext-group,98,1)
6156[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?cid") in new stack
6157[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:2] PlayTones("PJSIP/Sipgate_Trunking-00000011", "ring") in new stack
6158[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:3] Progress("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6159[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:4] Macro("PJSIP/Sipgate_Trunking-00000011", "user-callerid,") in new stack
6160[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/Sipgate_Trunking-00000011", "TOUCH_MONITOR=1625758279.17") in new stack
6161[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/Sipgate_Trunking-00000011", "AMPUSER=xxxxxxx5587") in new stack
6162[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:3] Set("PJSIP/Sipgate_Trunking-00000011", "HOTDESCKCHAN=Sipgate_Trunking-00000011") in new stack
6163[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:4] Set("PJSIP/Sipgate_Trunking-00000011", "HOTDESKEXTEN=Sipgate_Trunking") in new stack
6164[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/Sipgate_Trunking-00000011", "HOTDESKCALL=0") in new stack
6165[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:6] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HOTDESKCALL=1)") in new stack
6166[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:7] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(CALLERID(name)=)") in new stack
6167[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?report") in new stack
6168[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:9] ExecIf("PJSIP/Sipgate_Trunking-00000011", "1?Set(REALCALLERIDNUM=xxxxxxx5587)") in new stack
6169[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/Sipgate_Trunking-00000011", "AMPUSER=") in new stack
6170[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:11] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?limit") in new stack
6171[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:12] Set("PJSIP/Sipgate_Trunking-00000011", "AMPUSERCIDNAME=") in new stack
6172[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
6173[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:14] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?report") in new stack
6174[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-user-callerid,s,23)
6175[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:23] NoOp("PJSIP/Sipgate_Trunking-00000011", "Macro Depth is 1") in new stack
6176[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:24] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?report2:macroerror") in new stack
6177[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-user-callerid,s,25)
6178[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?continue") in new stack
6179[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:26] ExecIf("PJSIP/Sipgate_Trunking-00000011", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
6180[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:27] Set("PJSIP/Sipgate_Trunking-00000011", "__TTL=64") in new stack
6181[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:28] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?continue") in new stack
6182[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-user-callerid,s,44)
6183[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:44] Set("PJSIP/Sipgate_Trunking-00000011", "CALLERID(number)=xxxxxxx5587") in new stack
6184[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:45] Set("PJSIP/Sipgate_Trunking-00000011", "CALLERID(name)=xxxxxxx5587") in new stack
6185[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:46] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?cnum") in new stack
6186[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:47] Set("PJSIP/Sipgate_Trunking-00000011", "CDR(cnam)=xxxxxxx5587") in new stack
6187[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:48] Set("PJSIP/Sipgate_Trunking-00000011", "CDR(cnum)=xxxxxxx5587") in new stack
6188[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-user-callerid:49] Set("PJSIP/Sipgate_Trunking-00000011", "CHANNEL(language)=de_DE") in new stack
6189[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:5] Macro("PJSIP/Sipgate_Trunking-00000011", "blkvm-setifempty,") in new stack
6190[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?init") in new stack
6191[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-blkvm-setifempty,s,4)
6192[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:4] Set("PJSIP/Sipgate_Trunking-00000011", "__BLKVM_CHANNEL=PJSIP/Sipgate_Trunking-00000011") in new stack
6193[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:5] Set("PJSIP/Sipgate_Trunking-00000011", "SHARED(BLKVM,PJSIP/Sipgate_Trunking-00000011)=TRUE") in new stack
6194[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:6] Set("PJSIP/Sipgate_Trunking-00000011", "GOSUB_RETVAL=TRUE") in new stack
6195[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:7] MacroExit("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6196[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:6] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?skipov") in new stack
6197[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (ext-group,98,9)
6198[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:9] Set("PJSIP/Sipgate_Trunking-00000011", "RRNODEST=") in new stack
6199[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:10] Set("PJSIP/Sipgate_Trunking-00000011", "__NODEST=98") in new stack
6200[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:11] GosubIf("PJSIP/Sipgate_Trunking-00000011", "0?sub-rgsetcid,s,1()") in new stack
6201[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:12] Gosub("PJSIP/Sipgate_Trunking-00000011", "sub-record-check,s,1(rg,98,dontcare)") in new stack
6202[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "11?initialized") in new stack
6203[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,s,10)
6204[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/Sipgate_Trunking-00000011", "Recordings initialized") in new stack
6205[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ARG3=dontcare)") in new stack
6206[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/Sipgate_Trunking-00000011", "REC_POLICY_MODE_SAVE=") in new stack
6207[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(REC_STATUS=NO)") in new stack
6208[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/Sipgate_Trunking-00000011", "2?checkaction") in new stack
6209[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,s,17)
6210[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?sub-record-check,rg,1") in new stack
6211[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:18] NoOp("PJSIP/Sipgate_Trunking-00000011", "Generic rg Recording Check - xxxxxxx5587 98") in new stack
6212[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:19] Gosub("PJSIP/Sipgate_Trunking-00000011", "recordcheck,1(dontcare,rg,98)") in new stack
6213[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/Sipgate_Trunking-00000011", "Starting recording check against dontcare") in new stack
6214[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/Sipgate_Trunking-00000011", "dontcare") in new stack
6215[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
6216[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6217[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@sub-record-check:20] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6218[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:13] Set("PJSIP/Sipgate_Trunking-00000011", "RingGroupMethod=ringall") in new stack
6219[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:14] Set("PJSIP/Sipgate_Trunking-00000011", "__ALT_CONFIRM_MSG=") in new stack
6220[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:15] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?RGVQANNOUNCE:NORGVQANNOUNCE") in new stack
6221[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (ext-group,98,18)
6222[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [98@ext-group:18] Macro("PJSIP/Sipgate_Trunking-00000011", "dial,300,HhTtrQ(NO_ANSWER),31-32-33") in new stack
6223[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:1] NoOp("PJSIP/Sipgate_Trunking-00000011", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
6224[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:2] Set("PJSIP/Sipgate_Trunking-00000011", "__CRM_SOURCE=xxxxxxx5587") in new stack
6225[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:3] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ALERT_INFO=)") in new stack
6226[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:4] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ALERT_INFO=)") in new stack
6227[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:5] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ALERT_INFO=)") in new stack
6228[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:6] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(CHANNEL(musicclass)=)") in new stack
6229[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:7] AGI("PJSIP/Sipgate_Trunking-00000011", "agi://127.0.0.1/dialparties.agi") in new stack
6230[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Starting New Dialparties.agi
6231[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Caller ID name is 'xxxxxxx5587' number is 'xxxxxxx5587'
6232[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: CW Ignore is:
6233[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: CF Ignore is:
6234[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: CW IN_USE/BUSY is: 1
6235[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Ringgroup confirm is :
6236[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Methodology of ring is 'ringall'
6237[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 31 to extension map
6238[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 32 to extension map
6239[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 33 to extension map
6240[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 31 cf is disabled
6241[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 32 cf is disabled
6242[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 33 cf is disabled
6243[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 31 do not disturb is disabled
6244[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 32 do not disturb is disabled
6245[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 33 do not disturb is disabled
6246[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/31
6247[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/31/sip:[email protected]:43850;line=onmt9j1i
6248[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/31 to xxxxxxx5587
6249[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/32
6250[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/32/sip:[email protected]:5060;line=38602
6251[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/32 to xxxxxxx5587
6252[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/33
6253[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/33/sip:[email protected]:5060
6254[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/33 to xxxxxxx5587
6255[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: Filtered ARG3: 31-32-33
6256[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: RVOL_MODE ''
6257[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: RVOL is:
6258[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: agi://127.0.0.1/dialparties.agi: RVOLPARENT is:
6259[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] res_agi.c: <PJSIP/Sipgate_Trunking-00000011>AGI Script agi://127.0.0.1/dialparties.agi completed, returning 0
6260[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:8] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?normdial") in new stack
6261[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-dial,s,11)

mxbmaddin · July 8, 2021, 3:40pm

6262[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:11] NoOp("PJSIP/Sipgate_Trunking-00000011", "Returned from dialparties with groups to dial") in new stack
6263[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:12] NoOp("PJSIP/Sipgate_Trunking-00000011", "ringall array ") in new stack
6264[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:13] Set("PJSIP/Sipgate_Trunking-00000011", "__FMGL_DIAL=") in new stack
6265[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:14] Set("PJSIP/Sipgate_Trunking-00000011", "LOOPCNT=3") in new stack
6266[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:15] Set("PJSIP/Sipgate_Trunking-00000011", "ITER=1") in new stack
6267[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:16] Set("PJSIP/Sipgate_Trunking-00000011", "__EXTTOCALL=31") in new stack
6268[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:17] NoOp("PJSIP/Sipgate_Trunking-00000011", "Working with 31") in new stack
6269[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:18] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6270[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:19] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6271[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:20] Set("PJSIP/Sipgate_Trunking-00000011", "ITER=2") in new stack
6272[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:21] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?ndloopbegin") in new stack
6273[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-dial,s,16)
6274[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:16] Set("PJSIP/Sipgate_Trunking-00000011", "__EXTTOCALL=32") in new stack
6275[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:17] NoOp("PJSIP/Sipgate_Trunking-00000011", "Working with 32") in new stack
6276[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:18] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6277[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:19] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6278[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:20] Set("PJSIP/Sipgate_Trunking-00000011", "ITER=3") in new stack
6279[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:21] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?ndloopbegin") in new stack
6280[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-dial,s,16)
6281[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:16] Set("PJSIP/Sipgate_Trunking-00000011", "__EXTTOCALL=33") in new stack
6282[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:17] NoOp("PJSIP/Sipgate_Trunking-00000011", "Working with 33") in new stack
6283[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:18] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6284[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:19] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
6285[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:20] Set("PJSIP/Sipgate_Trunking-00000011", "ITER=4") in new stack
6286[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:21] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?ndloopbegin") in new stack
6287[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:22] Macro("PJSIP/Sipgate_Trunking-00000011", "dial-ringall-predial-hook,") in new stack
6288[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6289[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:23] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(CWRING=r(callwaiting)):Set(CWRING=)") in new stack
6290[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:24] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(ds=PJSIP/31/sip:[email protected]:43850;line=onmt9j1i&PJSIP/32/sip:[email protected]:5060;line=38602&PJSIP/33/sip:[email protected]:5060,300,HhtrQ(NO_ANSWER)M(auto-blkvm)g)") in new stack
6291[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-dial:25] Dial("PJSIP/Sipgate_Trunking-00000011", "PJSIP/31/sip:[email protected]:43850;line=onmt9j1i&PJSIP/32/sip:[email protected]:5060;line=38602&PJSIP/33/sip:[email protected]:5060,300,HhtrQ(NO_ANSWER)M(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
6292[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/31-00000012 Internal Gosub(func-apply-sipheaders,s,1) start
6293[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/31-00000012", "Applying SIP Headers to channel") in new stack
6294[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:2] Set("PJSIP/31-00000012", "SIPHEADERKEYS=") in new stack
6295[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:3] While("PJSIP/31-00000012", "0") in new stack
6296[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_while.c: Jumping to priority 7
6297[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:8] Set("PJSIP/31-00000012", "CALLERID(num)=") in new stack
6298[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:9] Set("PJSIP/31-00000012", "__CLIP=") in new stack
6299[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:10] Set("PJSIP/31-00000012", "__CLIP=") in new stack
6300[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:11] Set("PJSIP/31-00000012", "__CLIP=") in new stack
6301[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:12] Set("PJSIP/31-00000012", "PJSIP_HEADER(add,P-Preferred-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6302[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:13] Set("PJSIP/31-00000012", "PJSIP_HEADER(add,P-Asserted-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6303[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:14] Return("PJSIP/31-00000012", "") in new stack
6304[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: Spawn extension (from-internal, 98, 1) exited non-zero on 'PJSIP/31-00000012'
6305[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/31-00000012 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
6306[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/32-00000013 Internal Gosub(func-apply-sipheaders,s,1) start
6307[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/32-00000013", "Applying SIP Headers to channel") in new stack
6308[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:2] Set("PJSIP/32-00000013", "SIPHEADERKEYS=") in new stack
6309[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:3] While("PJSIP/32-00000013", "0") in new stack
6310[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_while.c: Jumping to priority 7
6311[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:8] Set("PJSIP/32-00000013", "CALLERID(num)=") in new stack
6312[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:9] Set("PJSIP/32-00000013", "__CLIP=") in new stack
6313[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:10] Set("PJSIP/32-00000013", "__CLIP=") in new stack
6314[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:11] Set("PJSIP/32-00000013", "__CLIP=") in new stack
6315[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:12] Set("PJSIP/32-00000013", "PJSIP_HEADER(add,P-Preferred-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6316[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:13] Set("PJSIP/32-00000013", "PJSIP_HEADER(add,P-Asserted-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6317[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:14] Return("PJSIP/32-00000013", "") in new stack
6318[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: Spawn extension (from-internal, 98, 1) exited non-zero on 'PJSIP/32-00000013'
6319[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/32-00000013 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
6320[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/33-00000014 Internal Gosub(func-apply-sipheaders,s,1) start
6321[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/33-00000014", "Applying SIP Headers to channel") in new stack
6322[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:2] Set("PJSIP/33-00000014", "SIPHEADERKEYS=") in new stack
6323[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:3] While("PJSIP/33-00000014", "0") in new stack
6324[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_while.c: Jumping to priority 7
6325[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:8] Set("PJSIP/33-00000014", "CALLERID(num)=") in new stack
6326[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:9] Set("PJSIP/33-00000014", "__CLIP=") in new stack
6327[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:10] Set("PJSIP/33-00000014", "__CLIP=") in new stack
6328[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:11] Set("PJSIP/33-00000014", "__CLIP=") in new stack
6329[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:12] Set("PJSIP/33-00000014", "PJSIP_HEADER(add,P-Preferred-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6330[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:13] Set("PJSIP/33-00000014", "PJSIP_HEADER(add,P-Asserted-Identity)=<sip:@sipconnect.sipgate.de>") in new stack
6331[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] pbx.c: Executing [s@func-apply-sipheaders:14] Return("PJSIP/33-00000014", "") in new stack
6332[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: Spawn extension (from-internal, 98, 1) exited non-zero on 'PJSIP/33-00000014'
6333[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/33-00000014 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
6334[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: Called PJSIP/31/sip:[email protected]:43850;line=onmt9j1i
6335[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: Called PJSIP/32/sip:[email protected]:5060;line=38602
6336[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: Called PJSIP/33/sip:[email protected]:5060
6337[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184
6338[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
6339[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio CoS mark 5
6340[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184
6341[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
6342[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio CoS mark 5
6343[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184
6344[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
6345[2021-07-08 17:31:20] VERBOSE[15900] netsock2.c: Using SIP RTP Audio CoS mark 5
6346[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/33-00000014 connected line has changed. Saving it until answer for PJSIP/Sipgate_Trunking-00000011
6347[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/32-00000013 connected line has changed. Saving it until answer for PJSIP/Sipgate_Trunking-00000011
6348[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/31-00000012 connected line has changed. Saving it until answer for PJSIP/Sipgate_Trunking-00000011
6349[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/33-00000014 is ringing
6350[2021-07-08 17:31:20] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/31-00000012 is ringing
6351[2021-07-08 17:31:21] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/32-00000013 is ringing
6352[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] app_dial.c: PJSIP/33-00000014 answered PJSIP/Sipgate_Trunking-00000011
6353[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:1] Set("PJSIP/33-00000014", "__MACRO_RESULT=") in new stack
6354[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:2] Set("PJSIP/33-00000014", "CFIGNORE=") in new stack
6355[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:3] Set("PJSIP/33-00000014", "MASTER_CHANNEL(CFIGNORE)=") in new stack
6356[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:4] Set("PJSIP/33-00000014", "FORWARD_CONTEXT=from-internal") in new stack
6357[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:5] Set("PJSIP/33-00000014", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
6358[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:6] Macro("PJSIP/33-00000014", "blkvm-clr,") in new stack
6359[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-clr:1] Set("PJSIP/33-00000014", "SHARED(BLKVM,PJSIP/Sipgate_Trunking-00000011)=") in new stack
6360[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-clr:2] Set("PJSIP/33-00000014", "GOSUB_RETVAL=") in new stack
6361[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("PJSIP/33-00000014", "") in new stack
6362[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:7] ExecIf("PJSIP/33-00000014", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=33/sip:[email protected]:5060)") in new stack
6363[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-auto-blkvm:8] ExecIf("PJSIP/33-00000014", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=)") in new stack
6364[2021-07-08 17:31:24] VERBOSE[17522][C-00000004] bridge_channel.c: Channel PJSIP/33-00000014 joined 'simple_bridge' basic-bridge <4425ebff-dc20-4328-9ac0-a75f306f9b4b>
6365[2021-07-08 17:31:24] VERBOSE[17483][C-00000004] bridge_channel.c: Channel PJSIP/Sipgate_Trunking-00000011 joined 'simple_bridge' basic-bridge <4425ebff-dc20-4328-9ac0-a75f306f9b4b>
6366[2021-07-08 17:31:37] VERBOSE[17522][C-00000004] bridge_channel.c: Channel PJSIP/33-00000014 left 'simple_bridge' basic-bridge <4425ebff-dc20-4328-9ac0-a75f306f9b4b>
6367[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] bridge_channel.c: Channel PJSIP/Sipgate_Trunking-00000011 left 'simple_bridge' basic-bridge <4425ebff-dc20-4328-9ac0-a75f306f9b4b>
6368[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] app_macro.c: Spawn extension (macro-dial, s, 25) exited non-zero on 'PJSIP/Sipgate_Trunking-00000011' in macro 'dial'
6369[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Spawn extension (ext-group, 98, 18) exited non-zero on 'PJSIP/Sipgate_Trunking-00000011'
6370[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [h@ext-group:1] Macro("PJSIP/Sipgate_Trunking-00000011", "hangupcall,") in new stack
6371[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?theend") in new stack
6372[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-hangupcall,s,3)
6373[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(CDR(recordingfile)=)") in new stack
6374[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/Sipgate_Trunking-00000011", "PJSIP/33-00000014 montior file= ") in new stack
6375[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/Sipgate_Trunking-00000011", "1?skipagi") in new stack
6376[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx_builtins.c: Goto (macro-hangupcall,s,7)
6377[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6378[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/Sipgate_Trunking-00000011' in macro 'hangupcall'
6379[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'PJSIP/Sipgate_Trunking-00000011'
6380[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/Sipgate_Trunking-00000011 Internal Gosub(crm-hangup,s,1) start
6381[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/Sipgate_Trunking-00000011", "Sending Hangup to CRM") in new stack
6382[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/Sipgate_Trunking-00000011", "HANGUP CAUSE: 16") in new stack
6383[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/Sipgate_Trunking-00000011", "0?Set(__CRM_VOICEMAIL=)") in new stack
6384[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/Sipgate_Trunking-00000011", "MASTER CHANNEL: 1625758279.17 = 1625758279.17") in new stack
6385[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/Sipgate_Trunking-00000011", "0?return") in new stack
6386[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/Sipgate_Trunking-00000011", "__CRM_HANGUP=1") in new stack
6387[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/Sipgate_Trunking-00000011", "agi://127.0.0.1/sangomacrm.agi") in new stack
6388[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] res_agi.c: <PJSIP/Sipgate_Trunking-00000011>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
6389[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/Sipgate_Trunking-00000011", "") in new stack
6390[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] app_stack.c: Spawn extension (ext-group, h, 1) exited non-zero on 'PJSIP/Sipgate_Trunking-00000011'
6391[2021-07-08 17:31:37] VERBOSE[17483][C-00000004] app_stack.c: PJSIP/Sipgate_Trunking-00000011 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

cynjut · July 8, 2021, 4:08pm

Not really.

First, use pastebin.freepbx.org for posting logs.

Second, you still haven’t told us what the problem actually is.

There are at least three ways to interpret your original problem.

When you talk, the person listening doesn’t hear what you said for three seconds.
When you answer the call, there’s no audio going out for three seconds, after which everything is fine.
When you call out, the you don’t hear the first three second of the other end’s conversation for three seconds.
3a) When you call out, the person at the other end doesn’t hear you for the first three second.
3b) You lose the first three second of any annoucements the system makes.

There are more - lots more - and each of them has a different set of four or five things to look at. It’s like when you take you car into the garage and all you tell the mechanic is “my wife hears a noise when she drives the car.”

mxbmaddin · July 9, 2021, 5:10am

Hi cynjut,
sorry it was not understandable

Log
sorry, ich can’t post links as newbie
Scenario
Incoming calls through ringing group
no matter who is talking, the other person hears it 3-5 seconds later… from the beginning to the end of the call… nothing is lost either, it is simply delayed on both sides (transmitter and receiver)
The problem is only if I configure a ring group as destination in the inbound route… if I directly select an extension it works fine.

I hope the problem is clearer now.

Thank you for your support!

Regards
Martin

cynjut · July 10, 2021, 1:17pm

Theres’s a link on great debug you can search for that will give you a lit of good detail. I can’t post it right now, I’m on my phone.

There’s nothing inherently different between a call to an extension and a ring group. Once the call is established, you should be good to go. The logs should be able to tell you what is happening, and sngrep can show you the call flow.

As a wild guess, I’d start with DNS, but that should give you problems everywhere.

system · August 10, 2021, 1:17pm

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