Hello,
I have setup my Inbound Routes and Time Conditions if I set my Time Conditions to a ring a ring group everything is fine and the phones rings as expected when I call my number. As soon as I set my Time Conditions to ring the IVR’s I have setup and call my number all I get is silence. I looked at the asterisk console in verbose mode as I was calling in and I got the below response. I am able to playback my welcome system recording from the GUI with no issues. I’m not sure what to check next, any help is appreciated.
[2018-03-05 22:05:03] NOTICE[6440]: chan_sip.c:29574 check_rtp_timeout: Disconnecting call 'SIP/Flowroute-0000000b' for lack of RTP activity in 31 seconds -- Executing [17705026119@from-trunk:1] NoOp("SIP/Flowroute-0000000c", "Catch-All DID Match - Found 17705026119 - You probably want a DID for this.") in new stack -- Executing [17705026119@from-trunk:2] Log("SIP/Flowroute-0000000c", "WARNING,Friendly Scanner from 216.115.69.144;branch=z9hG4bKa6d5.fbd04f019ea8e1e47ba522784405befd.0") in new stack [2018-03-05 22:05:03] WARNING[30599][C-0000000c]: Ext. 17705026119:2 @ from-trunk: Friendly Scanner from 216.115.69.144;branch=z9hG4bKa6d5.fbd04f019ea8e1e47ba522784405befd.0 -- Executing [17705026119@from-trunk:3] Set("SIP/Flowroute-0000000c", "__FROM_DID=17705026119") in new stack -- Executing [17705026119@from-trunk:4] Goto("SIP/Flowroute-0000000c", "ext-did,s,1") in new stack -- Goto (ext-did,s,1) -- Executing [s@ext-did:1] Set("SIP/Flowroute-0000000c", "__DIRECTION=INBOUND") in new stack -- Executing [s@ext-did:2] Gosub("SIP/Flowroute-0000000c", "sub-record-check,s,1(in,s,dontcare)") in new stack -- Executing [s@sub-record-check:1] GotoIf("SIP/Flowroute-0000000c", "0?initialized") in new stack -- Executing [s@sub-record-check:2] Set("SIP/Flowroute-0000000c", "__REC_STATUS=INITIALIZED") in new stack -- Executing [s@sub-record-check:3] Set("SIP/Flowroute-0000000c", "NOW=1520287503") in new stack -- Executing [s@sub-record-check:4] Set("SIP/Flowroute-0000000c", "__DAY=05") in new stack -- Executing [s@sub-record-check:5] Set("SIP/Flowroute-0000000c", "__MONTH=03") in new stack -- Executing [s@sub-record-check:6] Set("SIP/Flowroute-0000000c", "__YEAR=2018") in new stack -- Executing [s@sub-record-check:7] Set("SIP/Flowroute-0000000c", "__TIMESTR=20180305-220503") in new stack -- Executing [s@sub-record-check:8] Set("SIP/Flowroute-0000000c", "__FROMEXTEN=unknown") in new stack -- Executing [s@sub-record-check:9] Set("SIP/Flowroute-0000000c", "__MON_FMT=wav") in new stack -- Executing [s@sub-record-check:10] NoOp("SIP/Flowroute-0000000c", "Recordings initialized") in new stack -- Executing [s@sub-record-check:11] ExecIf("SIP/Flowroute-0000000c", "0?Set(ARG3=dontcare)") in new stack -- Executing [s@sub-record-check:12] Set("SIP/Flowroute-0000000c", "REC_POLICY_MODE_SAVE=") in new stack -- Executing [s@sub-record-check:13] ExecIf("SIP/Flowroute-0000000c", "0?Set(REC_STATUS=NO)") in new stack -- Executing [s@sub-record-check:14] GotoIf("SIP/Flowroute-0000000c", "2?checkaction") in new stack -- Goto (sub-record-check,s,17) -- Executing [s@sub-record-check:17] GotoIf("SIP/Flowroute-0000000c", "1?sub-record-check,in,1") in new stack -- Goto (sub-record-check,in,1) -- Executing [in@sub-record-check:1] NoOp("SIP/Flowroute-0000000c", "Inbound Recording Check to s") in new stack -- Executing [in@sub-record-check:2] Set("SIP/Flowroute-0000000c", "FROMEXTEN=unknown") in new stack -- Executing [in@sub-record-check:3] ExecIf("SIP/Flowroute-0000000c", "11?Set(FROMEXTEN=Unavailable)") in new stack -- Executing [in@sub-record-check:4] Gosub("SIP/Flowroute-0000000c", "recordcheck,1(dontcare,in,s)") in new stack -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/Flowroute-0000000c", "Starting recording check against dontcare") in new stack -- Executing [recordcheck@sub-record-check:2] Goto("SIP/Flowroute-0000000c", "dontcare") in new stack -- Goto (sub-record-check,recordcheck,3) -- Executing [recordcheck@sub-record-check:3] Return("SIP/Flowroute-0000000c", "") in new stack -- Executing [in@sub-record-check:5] Return("SIP/Flowroute-0000000c", "") in new stack -- Executing [s@ext-did:3] Gosub("SIP/Flowroute-0000000c", "app-blacklist-check,s,1()") in new stack -- Executing [s@app-blacklist-check:1] GotoIf("SIP/Flowroute-0000000c", "0?blacklisted") in new stack -- Executing [s@app-blacklist-check:2] Set("SIP/Flowroute-0000000c", "CALLED_BLACKLIST=1") in new stack -- Executing [s@app-blacklist-check:3] Return("SIP/Flowroute-0000000c", "") in new stack -- Executing [s@ext-did:4] ExecIf("SIP/Flowroute-0000000c", "0?Set(__FROM_DID=s)") in new stack -- Executing [s@ext-did:5] Set("SIP/Flowroute-0000000c", "CDR(did)=17705026119") in new stack -- Executing [h@ivr-2:1] Hangup("SIP/Flowroute-0000000b", "") in new stack == Spawn extension (ivr-2, h, 1) exited non-zero on 'SIP/Flowroute-0000000b' -- SIP/Flowroute-0000000b Internal Gosub(crm-hangup,s,1) start -- Executing [s@crm-hangup:1] NoOp("SIP/Flowroute-0000000b", "Sending Hangup to CRM") in new stack -- Executing [s@crm-hangup:2] NoOp("SIP/Flowroute-0000000b", "HANGUP CAUSE: 44") in new stack -- Executing [s@crm-hangup:3] ExecIf("SIP/Flowroute-0000000b", "0?Set(__CRM_VOICEMAIL=)") in new stack -- Executing [s@crm-hangup:4] NoOp("SIP/Flowroute-0000000b", "MASTER CHANNEL: 1520287472.14 = 1520287472.14") in new stack -- Executing [s@crm-hangup:5] GotoIf("SIP/Flowroute-0000000b", "0?return") in new stack -- Executing [s@crm-hangup:6] Set("SIP/Flowroute-0000000b", "__CRM_HANGUP=1") in new stack -- Executing [s@crm-hangup:7] AGI("SIP/Flowroute-0000000b", "sangomacrm.agi") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi -- Executing [s@ext-did:6] ExecIf("SIP/Flowroute-0000000c", "1 ?Set(CALLERID(name)=Unavailable)") in new stack -- Executing [s@ext-did:7] Set("SIP/Flowroute-0000000c", "__MOHCLASS=") in new stack -- Executing [s@ext-did:8] Set("SIP/Flowroute-0000000c", "__REVERSAL_REJECT=FALSE") in new stack -- Executing [s@ext-did:9] GotoIf("SIP/Flowroute-0000000c", "1?post-reverse-charge") in new stack -- Goto (ext-did,s,11) -- Executing [s@ext-did:11] NoOp("SIP/Flowroute-0000000c", "") in new stack -- Executing [s@ext-did:12] Set("SIP/Flowroute-0000000c", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack -- Executing [s@ext-did:13] Set("SIP/Flowroute-0000000c", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack -- Executing [s@ext-did:14] Set("SIP/Flowroute-0000000c", "CALLERID(name-pres)=allowed_not_screened") in new stack -- Executing [s@ext-did:15] Set("SIP/Flowroute-0000000c", "CALLERID(num-pres)=allowed_not_screened") in new stack -- Executing [s@ext-did:16] NoOp("SIP/Flowroute-0000000c", "CallerID Entry Point") in new stack -- Executing [s@ext-did:17] Set("SIP/Flowroute-0000000c", "__CRM_DIRECTION=INBOUND") in new stack -- Executing [s@ext-did:18] Set("SIP/Flowroute-0000000c", "__CRM_SOURCE=Unavailable") in new stack -- Executing [s@ext-did:19] Set("SIP/Flowroute-0000000c", "__CRM_LINKEDID=1520287503.15") in new stack -- Executing [s@ext-did:20] ExecIf("SIP/Flowroute-0000000c", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack -- Executing [s@ext-did:21] Goto("SIP/Flowroute-0000000c", "timeconditions,1,1") in new stack -- Goto (timeconditions,1,1) -- Executing [1@timeconditions:1] Set("SIP/Flowroute-0000000c", "DB(TC/1/INUSESTATE)=INUSE") in new stack -- Executing [1@timeconditions:2] Set("SIP/Flowroute-0000000c", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack -- Executing [1@timeconditions:3] NoOp("SIP/Flowroute-0000000c", "TIMENOW: 17:05,Mon, 5,Mar,America/New_York") in new stack -- Executing [1@timeconditions:4] NoOp("SIP/Flowroute-0000000c", "TIMEMATCHED: TRUE") in new stack -- Executing [1@timeconditions:5] GotoIfTime("SIP/Flowroute-0000000c", "10:00-18:00,mon-sat,*,*,America/New_York?truestate") in new stack -- Goto (timeconditions,1,14) -- Executing [1@timeconditions:14] GotoIf("SIP/Flowroute-0000000c", "0?falsegoto") in new stack -- Executing [1@timeconditions:15] ExecIf("SIP/Flowroute-0000000c", "0?Set(DB(TC/1)=)") in new stack -- Executing [1@timeconditions:16] Set("SIP/Flowroute-0000000c", "DEVICE_STATE(Custom:TC1)=NOT_INUSE") in new stack -- Executing [1@timeconditions:17] ExecIf("SIP/Flowroute-0000000c", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack -- Executing [1@timeconditions:18] GotoIf("SIP/Flowroute-0000000c", "1?ivr-2,s,1") in new stack -- Goto (ivr-2,s,1) -- Executing [s@ivr-2:1] Set("SIP/Flowroute-0000000c", "INVALID_LOOPCOUNT=0") in new stack -- Executing [s@ivr-2:2] Set("SIP/Flowroute-0000000c", "_IVR_CONTEXT_ivr-2=") in new stack -- Executing [s@ivr-2:3] Set("SIP/Flowroute-0000000c", "_IVR_CONTEXT=ivr-2") in new stack -- Executing [s@ivr-2:4] Set("SIP/Flowroute-0000000c", "__IVR_RETVM=") in new stack -- Executing [s@ivr-2:5] GotoIf("SIP/Flowroute-0000000c", "0?skip") in new stack -- Executing [s@ivr-2:6] Answer("SIP/Flowroute-0000000c", "") in new stack -- <SIP/Flowroute-0000000b>AGI Script sangomacrm.agi completed, returning 0 -- Executing [s@crm-hangup:8] Return("SIP/Flowroute-0000000b", "") in new stack == Spawn extension (ivr-2, h, 1) exited non-zero on 'SIP/Flowroute-0000000b' -- SIP/Flowroute-0000000b Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL= -- Executing [s@ivr-2:7] Wait("SIP/Flowroute-0000000c", "1") in new stack [2018-03-05 22:05:04] WARNING[6440]: chan_sip.c:4065 retrans_pkt: Retransmission timeout reached on transmission [email protected] for seqno 393112 (Critical Response) -- See Packet timed out after 31999ms with no response -- Executing [s@ivr-2:8] Set("SIP/Flowroute-0000000c", "IVR_MSG=custom/IVR-welcome") in new stack -- Executing [s@ivr-2:9] Set("SIP/Flowroute-0000000c", "TIMEOUT(digit)=3") in new stack -- Digit timeout set to 3.000 -- Executing [s@ivr-2:10] ExecIf("SIP/Flowroute-0000000c", "1?Background(custom/IVR-welcome)") in new stack -- <SIP/Flowroute-0000000c> Playing 'custom/IVR-welcome.slin' (language 'en') -- Executing [s@ivr-2:11] WaitExten("SIP/Flowroute-0000000c", "5,") in new stack -- Timeout on SIP/Flowroute-0000000c, going to 't' -- Executing [t@ivr-2:1] Playback("SIP/Flowroute-0000000c", "no-valid-responce-transfering") in new stack -- <SIP/Flowroute-0000000c> Playing 'no-valid-responce-transfering.slin' (language 'en') -- Executing [t@ivr-2:2] Goto("SIP/Flowroute-0000000c", "ext-local,vmb208,1") in new stack -- Goto (ext-local,vmb208,1) -- Executing [vmb208@ext-local:1] Macro("SIP/Flowroute-0000000c", "vm,208,BUSY,") in new stack -- Executing [s@macro-vm:1] Macro("SIP/Flowroute-0000000c", "user-callerid,SKIPTTL") in new stack -- Executing [s@macro-user-callerid:1] Set("SIP/Flowroute-0000000c", "TOUCH_MONITOR=1520287503.15") in new stack -- Executing [s@macro-user-callerid:2] Set("SIP/Flowroute-0000000c", "AMPUSER=Unavailable") in new stack -- Executing [s@macro-user-callerid:3] GotoIf("SIP/Flowroute-0000000c", "0?report") in new stack -- Executing [s@macro-user-callerid:4] ExecIf("SIP/Flowroute-0000000c", "1?Set(REALCALLERIDNUM=Unavailable)") in new stack -- Executing [s@macro-user-callerid:5] Set("SIP/Flowroute-0000000c", "AMPUSER=") in new stack -- Executing [s@macro-user-callerid:6] GotoIf("SIP/Flowroute-0000000c", "0?limit") in new stack -- Executing [s@macro-user-callerid:7] Set("SIP/Flowroute-0000000c", "AMPUSERCIDNAME=") in new stack -- Executing [s@macro-user-callerid:8] ExecIf("SIP/Flowroute-0000000c", "0?Set(__CIDMASQUERADING=TRUE)") in new stack -- Executing [s@macro-user-callerid:9] GotoIf("SIP/Flowroute-0000000c", "1?report") in new stack -- Goto (macro-user-callerid,s,16) -- Executing [s@macro-user-callerid:16] NoOp("SIP/Flowroute-0000000c", "Macro Depth is 2") in new stack -- Executing [s@macro-user-callerid:17] GotoIf("SIP/Flowroute-0000000c", "1?report2:macroerror") in new stack -- Goto (macro-user-callerid,s,19) -- Executing [s@macro-user-callerid:19] GotoIf("SIP/Flowroute-0000000c", "1?continue") in new stack -- Goto (macro-user-callerid,s,37) -- Executing [s@macro-user-callerid:37] Set("SIP/Flowroute-0000000c", "CALLERID(number)=Unavailable") in new stack -- Executing [s@macro-user-callerid:38] Set("SIP/Flowroute-0000000c", "CALLERID(name)=Unavailable") in new stack -- Executing [s@macro-user-callerid:39] GotoIf("SIP/Flowroute-0000000c", "0?cnum") in new stack -- Executing [s@macro-user-callerid:40] Set("SIP/Flowroute-0000000c", "CDR(cnam)=Unavailable") in new stack -- Executing [s@macro-user-callerid:41] Set("SIP/Flowroute-0000000c", "CDR(cnum)=Unavailable") in new stack -- Executing [s@macro-user-callerid:42] Set("SIP/Flowroute-0000000c", "CHANNEL(language)=en") in new stack -- Executing [s@macro-vm:2] Set("SIP/Flowroute-0000000c", "VMGAIN=") in new stack -- Executing [s@macro-vm:3] Macro("SIP/Flowroute-0000000c", "blkvm-check,") in new stack -- Executing [s@macro-blkvm-check:1] Set("SIP/Flowroute-0000000c", "GOSUB_RETVAL=") in new stack -- Executing [s@macro-blkvm-check:2] ExecIf("SIP/Flowroute-0000000c", "0?Set(GOSUB_RETVAL=TRUE)") in new stack -- Executing [s@macro-blkvm-check:3] MacroExit("SIP/Flowroute-0000000c", "") in new stack -- Executing [s@macro-vm:4] GotoIf("SIP/Flowroute-0000000c", "1?vmx,1") in new stack -- Goto (macro-vm,vmx,1) -- Executing [vmx@macro-vm:1] Set("SIP/Flowroute-0000000c", "__EXTTOCALL=208") in new stack -- Executing [vmx@macro-vm:2] Set("SIP/Flowroute-0000000c", "__CRM_VOICEMAIL=208") in new stack -- Executing [vmx@macro-vm:3] Set("SIP/Flowroute-0000000c", "MEXTEN=208") in new stack -- Executing [vmx@macro-vm:4] Set("SIP/Flowroute-0000000c", "MMODE=BUSY") in new stack -- Executing [vmx@macro-vm:5] Set("SIP/Flowroute-0000000c", "RETVM=") in new stack -- Executing [vmx@macro-vm:6] Set("SIP/Flowroute-0000000c", "MODE=busy") in new stack -- Executing [vmx@macro-vm:7] Macro("SIP/Flowroute-0000000c", "get-vmcontext,208") in new stack -- Executing [s@macro-get-vmcontext:1] Set("SIP/Flowroute-0000000c", "VMCONTEXT=default") in new stack -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/Flowroute-0000000c", "0?200:300") in new stack -- Goto (macro-get-vmcontext,s,300) -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/Flowroute-0000000c", "") in new stack -- Executing [vmx@macro-vm:8] Set("SIP/Flowroute-0000000c", "MODE=busy") in new stack -- Executing [vmx@macro-vm:9] NoOp("SIP/Flowroute-0000000c", "MODE IS: busy") in new stack -- Executing [vmx@macro-vm:10] GotoIf("SIP/Flowroute-0000000c", "1?chknomsg") in new stack -- Goto (macro-vm,vmx,12) -- Executing [vmx@macro-vm:12] GotoIf("SIP/Flowroute-0000000c", "0?s-BUSY,1") in new stack -- Executing [vmx@macro-vm:13] GotoIf("SIP/Flowroute-0000000c", "1?notdirect") in new stack -- Goto (macro-vm,vmx,15) -- Executing [vmx@macro-vm:15] NoOp("SIP/Flowroute-0000000c", "Checking if ext 208 is enabled: ") in new stack -- Executing [vmx@macro-vm:16] GotoIf("SIP/Flowroute-0000000c", "1?s-BUSY,1") in new stack -- Goto (macro-vm,s-BUSY,1) -- Executing [s-BUSY@macro-vm:1] NoOp("SIP/Flowroute-0000000c", "BUSY voicemail") in new stack -- Executing [s-BUSY@macro-vm:2] Macro("SIP/Flowroute-0000000c", "get-vmcontext,208") in new stack -- Executing [s@macro-get-vmcontext:1] Set("SIP/Flowroute-0000000c", "VMCONTEXT=default") in new stack -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/Flowroute-0000000c", "0?200:300") in new stack -- Goto (macro-get-vmcontext,s,300) -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/Flowroute-0000000c", "") in new stack -- Executing [s-BUSY@macro-vm:3] VoiceMail("SIP/Flowroute-0000000c", "208@default,b") in new stack -- <SIP/Flowroute-0000000c> Playing 'vm-theperson.ulaw' (language 'en') [2018-03-05 22:05:34] NOTICE[6440]: chan_sip.c:29574 check_rtp_timeout: Disconnecting call 'SIP/Flowroute-0000000c' for lack of RTP activity in 31 seconds == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on 'SIP/Flowroute-0000000c' in macro 'vm' == Spawn extension (ext-local, vmb208, 1) exited non-zero on 'SIP/Flowroute-0000000c' -- Executing [h@ext-local:1] Macro("SIP/Flowroute-0000000c", "hangupcall,") in new stack -- Executing [s@macro-hangupcall:1] GotoIf("SIP/Flowroute-0000000c", "1?theend") in new stack -- Goto (macro-hangupcall,s,3) -- Executing [s@macro-hangupcall:3] ExecIf("SIP/Flowroute-0000000c", "0?Set(CDR(recordingfile)=)") in new stack -- Executing [s@macro-hangupcall:4] NoOp("SIP/Flowroute-0000000c", " monior file= ") in new stack -- Executing [s@macro-hangupcall:5] AGI("SIP/Flowroute-0000000c", "attendedtransfer-rec-restart.php,,") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php -- <SIP/Flowroute-0000000c>AGI Script attendedtransfer-rec-restart.php completed, returning 0 -- Executing [s@macro-hangupcall:6] Hangup("SIP/Flowroute-0000000c", "") in new stack == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/Flowroute-0000000c' in macro 'hangupcall' == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/Flowroute-0000000c' -- SIP/Flowroute-0000000c Internal Gosub(crm-hangup,s,1) start -- Executing [s@crm-hangup:1] NoOp("SIP/Flowroute-0000000c", "Sending Hangup to CRM") in new stack -- Executing [s@crm-hangup:2] NoOp("SIP/Flowroute-0000000c", "HANGUP CAUSE: 44") in new stack -- Executing [s@crm-hangup:3] ExecIf("SIP/Flowroute-0000000c", "1?Set(__CRM_VOICEMAIL=FAILED)") in new stack -- Executing [s@crm-hangup:4] NoOp("SIP/Flowroute-0000000c", "MASTER CHANNEL: 1520287503.15 = 1520287503.15") in new stack -- Executing [s@crm-hangup:5] GotoIf("SIP/Flowroute-0000000c", "0?return") in new stack -- Executing [s@crm-hangup:6] Set("SIP/Flowroute-0000000c", "__CRM_HANGUP=1") in new stack -- Executing [s@crm-hangup:7] AGI("SIP/Flowroute-0000000c", "sangomacrm.agi") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi -- <SIP/Flowroute-0000000c>AGI Script sangomacrm.agi completed, returning 0 -- Executing [s@crm-hangup:8] Return("SIP/Flowroute-0000000c", "") in new stack == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/Flowroute-0000000c' -- SIP/Flowroute-0000000c Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL= [2018-03-05 22:05:35] WARNING[6440]: chan_sip.c:4065 retrans_pkt: Retransmission timeout reached on transmission [email protected] for seqno 659127 (Critical Response) -- See Packet timed out after 31999ms with no response freepbx*CLI>