IVR - Logs says playing but hearing silence

Ponos · October 9, 2018, 8:23pm

Hello All,

I have a simple IVR configured to play an announcement then route to a ring group.

When I call the IVR I can see, from the logs, it’s playing the announcement however all I get is silence. I change to a system recording to rule out any format issues and I still hear silence. When I play the recording from System recordings I can hear the audio. For testing, I made the system recording ‘please-try-again’ the announcement on the IVR.

Appreciate any guidance.

Stephen

From the log:
– <SIP/User-1-000000e4> Playing ‘please-try-again.alaw’ (language ‘en’)

Full log:

Connected to Asterisk 13.22.0 currently running on pbx-1 (pid = 13628)
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Executing [35317058011@from-trunk:1] Set(“SIP/User-1-000000e4”, “__DIRECTION=INBOUND”) in new stack
– Executing [35317058011@from-trunk:2] Gosub(“SIP/User-1-000000e4”, “sub-record-check,s,1(in,35317058011,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/User-1-000000e4”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“SIP/User-1-000000e4”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“SIP/User-1-000000e4”, “NOW=1539115650”) in new stack
– Executing [s@sub-record-check:4] Set(“SIP/User-1-000000e4”, “__DAY=09”) in new stack
– Executing [s@sub-record-check:5] Set(“SIP/User-1-000000e4”, “__MONTH=10”) in new stack
– Executing [s@sub-record-check:6] Set(“SIP/User-1-000000e4”, “__YEAR=2018”) in new stack
– Executing [s@sub-record-check:7] Set(“SIP/User-1-000000e4”, “__TIMESTR=20181009-210730”) in new stack
– Executing [s@sub-record-check:8] Set(“SIP/User-1-000000e4”, “__FROMEXTEN=unknown”) in new stack
– Executing [s@sub-record-check:9] Set(“SIP/User-1-000000e4”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:10] NoOp(“SIP/User-1-000000e4”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/User-1-000000e4”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/User-1-000000e4”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/User-1-000000e4”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/User-1-000000e4”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/User-1-000000e4”, “1?sub-record-check,in,1”) in new stack
– Goto (sub-record-check,in,1)
– Executing [in@sub-record-check:1] NoOp(“SIP/User-1-000000e4”, “Inbound Recording Check to 35317058011”) in new stack
– Executing [in@sub-record-check:2] Set(“SIP/User-1-000000e4”, “FROMEXTEN=unknown”) in new stack
– Executing [in@sub-record-check:3] ExecIf(“SIP/User-1-000000e4”, “10?Set(FROMEXTEN=0862515151)”) in new stack
– Executing [in@sub-record-check:4] Gosub(“SIP/User-1-000000e4”, “recordcheck,1(dontcare,in,35317058011)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/User-1-000000e4”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/User-1-000000e4”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“SIP/User-1-000000e4”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“SIP/User-1-000000e4”, “”) in new stack
– Executing [35317058011@from-trunk:3] Set(“SIP/User-1-000000e4”, “CHANNEL(tonezone)=us”) in new stack
– Executing [35317058011@from-trunk:4] Set(“SIP/User-1-000000e4”, “__FROM_DID=35317058011”) in new stack
– Executing [35317058011@from-trunk:5] Set(“SIP/User-1-000000e4”, “returnhere=1”) in new stack
– Executing [35317058011@from-trunk:6] Gosub(“SIP/User-1-000000e4”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/User-1-000000e4”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/User-1-000000e4”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/User-1-000000e4”, “”) in new stack
– Executing [35317058011@from-trunk:7] Set(“SIP/User-1-000000e4”, “CDR(did)=35317058011”) in new stack
– Executing [35317058011@from-trunk:8] GotoIf(“SIP/User-1-000000e4”, “0?”) in new stack
– Executing [35317058011@from-trunk:9] ExecIf(“SIP/User-1-000000e4”, “1 ?Set(CALLERID(name)=0862515151)”) in new stack
– Executing [35317058011@from-trunk:10] Set(“SIP/User-1-000000e4”, “__MOHCLASS=”) in new stack
– Executing [35317058011@from-trunk:11] Set(“SIP/User-1-000000e4”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [35317058011@from-trunk:12] GotoIf(“SIP/User-1-000000e4”, “1?post-reverse-charge”) in new stack
– Goto (from-trunk,35317058011,14)
– Executing [35317058011@from-trunk:14] NoOp(“SIP/User-1-000000e4”, “”) in new stack
– Executing [35317058011@from-trunk:15] Set(“SIP/User-1-000000e4”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [35317058011@from-trunk:16] Set(“SIP/User-1-000000e4”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [35317058011@from-trunk:17] Set(“SIP/User-1-000000e4”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [35317058011@from-trunk:18] Set(“SIP/User-1-000000e4”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [35317058011@from-trunk:19] NoOp(“SIP/User-1-000000e4”, “CallerID Entry Point”) in new stack
– Executing [35317058011@from-trunk:20] Goto(“SIP/User-1-000000e4”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [s@ivr-1:1] Set(“SIP/User-1-000000e4”, “INVALID_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:2] Set(“SIP/User-1-000000e4”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [s@ivr-1:3] Set(“SIP/User-1-000000e4”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [s@ivr-1:4] Set(“SIP/User-1-000000e4”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-1:5] GotoIf(“SIP/User-1-000000e4”, “0?skip”) in new stack
– Executing [s@ivr-1:6] Answer(“SIP/User-1-000000e4”, “”) in new stack
– Executing [s@ivr-1:7] Wait(“SIP/User-1-000000e4”, “1”) in new stack
– Executing [s@ivr-1:8] Set(“SIP/User-1-000000e4”, “IVR_MSG=please-try-again”) in new stack
– Executing [s@ivr-1:9] Set(“SIP/User-1-000000e4”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:10] ExecIf(“SIP/User-1-000000e4”, “1?Background(please-try-again)”) in new stack
– <SIP/User-1-000000e4> Playing ‘please-try-again.alaw’ (language ‘en’)
– Executing [s@ivr-1:11] WaitExten(“SIP/User-1-000000e4”, “5,”) in new stack
– Timeout on SIP/User-1-000000e4, going to ‘t’
– Executing [t@ivr-1:1] Goto(“SIP/User-1-000000e4”, “ext-group,798,1”) in new stack
– Goto (ext-group,798,1)
– Executing [798@ext-group:1] GotoIf(“SIP/User-1-000000e4”, “0?cid”) in new stack
– Executing [798@ext-group:2] PlayTones(“SIP/User-1-000000e4”, “ring”) in new stack
– Executing [798@ext-group:3] Progress(“SIP/User-1-000000e4”, “”) in new stack
– Executing [798@ext-group:4] Macro(“SIP/User-1-000000e4”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/User-1-000000e4”, “TOUCH_MONITOR=1539115650.1606”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/User-1-000000e4”, “AMPUSER=0862515151”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/User-1-000000e4”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/User-1-000000e4”, “1?Set(REALCALLERIDNUM=0862515151)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/User-1-000000e4”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/User-1-000000e4”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/User-1-000000e4”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:8] ExecIf(“SIP/User-1-000000e4”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
– Executing [s@macro-user-callerid:9] GotoIf(“SIP/User-1-000000e4”, “1?report”) in new stack
– Goto (macro-user-callerid,s,16)
– Executing [s@macro-user-callerid:16] NoOp(“SIP/User-1-000000e4”, “Macro Depth is 1”) in new stack
– Executing [s@macro-user-callerid:17] GotoIf(“SIP/User-1-000000e4”, “1?report2:macroerror”) in new stack
– Goto (macro-user-callerid,s,18)
– Executing [s@macro-user-callerid:18] GotoIf(“SIP/User-1-000000e4”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:19] ExecIf(“SIP/User-1-000000e4”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [s@macro-user-callerid:20] Set(“SIP/User-1-000000e4”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:21] GotoIf(“SIP/User-1-000000e4”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,37)
– Executing [s@macro-user-callerid:37] Set(“SIP/User-1-000000e4”, “CALLERID(number)=0862515151”) in new stack
– Executing [s@macro-user-callerid:38] Set(“SIP/User-1-000000e4”, “CALLERID(name)=0862515151”) in new stack
– Executing [s@macro-user-callerid:39] GotoIf(“SIP/User-1-000000e4”, “0?cnum”) in new stack
– Executing [s@macro-user-callerid:40] Set(“SIP/User-1-000000e4”, “CDR(cnam)=0862515151”) in new stack
– Executing [s@macro-user-callerid:41] Set(“SIP/User-1-000000e4”, “CDR(cnum)=0862515151”) in new stack
– Executing [s@macro-user-callerid:42] Set(“SIP/User-1-000000e4”, “CHANNEL(language)=en”) in new stack
– Executing [798@ext-group:5] Macro(“SIP/User-1-000000e4”, “blkvm-setifempty,”) in new stack
– Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/User-1-000000e4”, “1?init”) in new stack
– Goto (macro-blkvm-setifempty,s,4)
– Executing [s@macro-blkvm-setifempty:4] Set(“SIP/User-1-000000e4”, “__BLKVM_CHANNEL=SIP/User-1-000000e4”) in new stack
– Executing [s@macro-blkvm-setifempty:5] Set(“SIP/User-1-000000e4”, “SHARED(BLKVM,SIP/User-1-000000e4)=TRUE”) in new stack
– Executing [s@macro-blkvm-setifempty:6] Set(“SIP/User-1-000000e4”, “GOSUB_RETVAL=TRUE”) in new stack
– Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/User-1-000000e4”, “”) in new stack
– Executing [798@ext-group:6] GotoIf(“SIP/User-1-000000e4”, “1?skipov”) in new stack
– Goto (ext-group,798,9)
– Executing [798@ext-group:9] Set(“SIP/User-1-000000e4”, “RRNODEST=”) in new stack
– Executing [798@ext-group:10] Set(“SIP/User-1-000000e4”, “__NODEST=798”) in new stack
– Executing [798@ext-group:11] GosubIf(“SIP/User-1-000000e4”, “0?sub-rgsetcid,s,1()”) in new stack
– Executing [798@ext-group:12] Set(“SIP/User-1-000000e4”, “__CWIGNORE=TRUE”) in new stack
– Executing [798@ext-group:13] Set(“SIP/User-1-000000e4”, “_CFIGNORE=TRUE”) in new stack
– Executing [798@ext-group:14] Set(“SIP/User-1-000000e4”, “_FORWARD_CONTEXT=block-cf”) in new stack
– Executing [798@ext-group:15] Gosub(“SIP/User-1-000000e4”, “sub-record-check,s,1(rg,798,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/User-1-000000e4”, “10?initialized”) in new stack
– Goto (sub-record-check,s,10)
– Executing [s@sub-record-check:10] NoOp(“SIP/User-1-000000e4”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/User-1-000000e4”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/User-1-000000e4”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/User-1-000000e4”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/User-1-000000e4”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/User-1-000000e4”, “0?sub-record-check,rg,1”) in new stack
– Executing [s@sub-record-check:18] NoOp(“SIP/User-1-000000e4”, “Generic rg Recording Check - 0862515151 798”) in new stack
– Executing [s@sub-record-check:19] Gosub(“SIP/User-1-000000e4”, “recordcheck,1(dontcare,rg,798)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/User-1-000000e4”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/User-1-000000e4”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“SIP/User-1-000000e4”, “”) in new stack
– Executing [s@sub-record-check:20] Return(“SIP/User-1-000000e4”, “”) in new stack
– Executing [798@ext-group:16] Set(“SIP/User-1-000000e4”, “RingGroupMethod=ringall”) in new stack
– Executing [798@ext-group:17] Set(“SIP/User-1-000000e4”, “__ALT_CONFIRM_MSG=”) in new stack
– Executing [798@ext-group:18] GotoIf(“SIP/User-1-000000e4”, “0?RGVQANNOUNCE:NORGVQANNOUNCE”) in new stack
– Goto (ext-group,798,21)
– Executing [798@ext-group:21] Macro(“SIP/User-1-000000e4”, “dial,30,Ttr,708-703”) in new stack
– Executing [s@macro-dial:1] NoOp(“SIP/User-1-000000e4”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
– Executing [s@macro-dial:2] ExecIf(“SIP/User-1-000000e4”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial:3] ExecIf(“SIP/User-1-000000e4”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial:4] ExecIf(“SIP/User-1-000000e4”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial:5] ExecIf(“SIP/User-1-000000e4”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial:6] AGI(“SIP/User-1-000000e4”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is ‘0862515151’ number is ‘0862515151’
dialparties.agi: CW Ignore is: TRUE
dialparties.agi: CF Ignore is: TRUE
dialparties.agi: CW IN_USE/BUSY is: 1
> dialparties.agi: USE_CONFIRMATION: ‘FALSE’
> dialparties.agi: RINGGROUP_INDEX: ‘’
dialparties.agi: Methodology of ring is ‘ringall’
– dialparties.agi: Added extension 708 to extension map
– dialparties.agi: Added extension 703 to extension map
– dialparties.agi: Extension 708 cf is disabled
– dialparties.agi: Extension 703 cf is disabled
– dialparties.agi: Extension 708 do not disturb is disabled
– dialparties.agi: Extension 703 do not disturb is disabled
> dialparties.agi: extnum 708 has: cw: 0; hascfb: 0 [] hascfu: 0 []
dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
dialparties.agi: Extension 708 has ExtensionState: 0
– dialparties.agi: Checking CW and CFB status for extension 708
– dialparties.agi: dbset CALLTRACE/708 to 0862515151
> dialparties.agi: extnum 703 has: cw: 0; hascfb: 0 [] hascfu: 0 []
dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
dialparties.agi: Extension 703 has ExtensionState: 4
– dialparties.agi: Checking CW and CFB status for extension 703
dialparties.agi: Extension 703 is not available to be called
– dialparties.agi: Filtered ARG3: 708
> dialparties.agi: NODEST: 798 adding M(auto-blkvm) to dialopts: TtrM(auto-blkvm)
> dialparties.agi: NODEST: 798 blkvm enabled macro already in dialopts: TtrM(auto-blkvm)
dialparties.agi: RVOL_MODE ‘’
dialparties.agi: RVOL is:
dialparties.agi: RVOLPARENT is:
– <SIP/User-1-000000e4>AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:9] NoOp(“SIP/User-1-000000e4”, “Returned from dialparties with groups to dial”) in new stack
– Executing [s@macro-dial:10] NoOp(“SIP/User-1-000000e4”, "ringall array ") in new stack
– Executing [s@macro-dial:11] Set(“SIP/User-1-000000e4”, “__FMGL_DIAL=”) in new stack
– Executing [s@macro-dial:12] Set(“SIP/User-1-000000e4”, “LOOPCNT=1”) in new stack
– Executing [s@macro-dial:13] Set(“SIP/User-1-000000e4”, “ITER=1”) in new stack
– Executing [s@macro-dial:14] Set(“SIP/User-1-000000e4”, “__EXTTOCALL=708”) in new stack
– Executing [s@macro-dial:15] NoOp(“SIP/User-1-000000e4”, “Working with 708”) in new stack
– Executing [s@macro-dial:16] ExecIf(“SIP/User-1-000000e4”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
– Executing [s@macro-dial:17] ExecIf(“SIP/User-1-000000e4”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
– Executing [s@macro-dial:18] Set(“SIP/User-1-000000e4”, “ITER=2”) in new stack
– Executing [s@macro-dial:19] GotoIf(“SIP/User-1-000000e4”, “0?ndloopbegin”) in new stack
– Executing [s@macro-dial:20] Macro(“SIP/User-1-000000e4”, “dial-ringall-predial-hook,”) in new stack
– Executing [s@macro-dial-ringall-predial-hook:1] MacroExit(“SIP/User-1-000000e4”, “”) in new stack
– Executing [s@macro-dial:21] ExecIf(“SIP/User-1-000000e4”, “0?Set(ds=SIP/708,30,trM(auto-blkvm)g)”) in new stack
– Executing [s@macro-dial:22] Dial(“SIP/User-1-000000e4”, “SIP/708,30,trM(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– SIP/708-000000e5 Internal Gosub(func-apply-sipheaders,s,1) start
– Executing [s@func-apply-sipheaders:1] NoOp(“SIP/708-000000e5”, “Applying SIP Headers to channel”) in new stack
– Executing [s@func-apply-sipheaders:2] Set(“SIP/708-000000e5”, “SIPHEADERKEYS=”) in new stack
– Executing [s@func-apply-sipheaders:3] ExecIf(“SIP/708-000000e5”, “0?Set(Rheader=1)”) in new stack
– Executing [s@func-apply-sipheaders:4] While(“SIP/708-000000e5”, “0”) in new stack
– Jumping to priority 7
– Executing [s@func-apply-sipheaders:8] ExecIf(“SIP/708-000000e5”, “0?SIPRemoveHeader(Alert-Info:)”) in new stack
– Executing [s@func-apply-sipheaders:9] Return(“SIP/708-000000e5”, “”) in new stack
== Spawn extension (from-internal, 798, 1) exited non-zero on ‘SIP/708-000000e5’
– SIP/708-000000e5 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
– Called SIP/708
– SIP/708-000000e5 is ringing
– SIP/708-000000e5 is ringing
== Spawn extension (macro-dial, s, 22) exited non-zero on ‘SIP/User-1-000000e4’ in macro ‘dial’
== Spawn extension (ext-group, 798, 21) exited non-zero on ‘SIP/User-1-000000e4’
– Executing [h@ext-group:1] Macro(“SIP/User-1-000000e4”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/User-1-000000e4”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“SIP/User-1-000000e4”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] NoOp(“SIP/User-1-000000e4”, "SIP/708-000000e5 monior file= ") in new stack
– Executing [s@macro-hangupcall:5] AGI(“SIP/User-1-000000e4”, “attendedtransfer-rec-restart.php,SIP/708-000000e5,”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
– <SIP/User-1-000000e4>AGI Script attendedtransfer-rec-restart.php completed, returning 0
– Executing [s@macro-hangupcall:6] Hangup(“SIP/User-1-000000e4”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘SIP/User-1-000000e4’ in macro ‘hangupcall’
== Spawn extension (ext-group, h, 1) exited non-zero on ‘SIP/User-1-000000e4’

arielgrin · October 9, 2018, 10:17pm

This sounds like a NAT issue. Is your FreePBX server behind a NAT device? Have you tried calling the IVR from an internal extension? You can use the feature code 7777 that simulates an inbound call.

Ponos · October 10, 2018, 3:34pm

Thank you for the suggestion.

So if I call the IVR from internal I can hear the recordings – all good.

Checked the NAT settings and as far as my understanding goes are configured correctly.

I can make inbound/outbound calls to any extension which uses the same SIP provider as the IVR

arielgrin · October 10, 2018, 8:18pm

So sound works correctly for an inbound call from an external caller that goes directly to an extension without going through the IVR?

Ponos · October 11, 2018, 2:42pm

Hi arielgrin, yes audio is perfect when I call an extension from external. Currently checking RTP port rage settings from the SIP provider.

arielgrin · October 11, 2018, 3:30pm

If audio works correctly and only the IVR is not working from external calls, the only thing I can think of is that the sound file is recorded in a format that can’t be transcoded. What codec are you using for your provider’s trunk and what codec is the audio file using?

Ponos · October 11, 2018, 3:54pm

When I call the IVR from an internal extension the file is ulaw
When I call the IVR from external the greeting is alaw

My SIP settings include both ulaw and alaw

Calling IVR from an internal extension:

Executing [s@ivr-1:8] Set(“SIP/781-0000014b”, “IVR_MSG=custom/austin-greetng&custom/austin-greetng”) in new stack
– Executing [s@ivr-1:9] Set(“SIP/781-0000014b”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:10] ExecIf(“SIP/781-0000014b”, “1?Background(custom/austin-greetng&custom/austin-greetng)”) in new stack
– <SIP/781-0000014b> Playing ‘custom**/austin-greetng.ulaw’** (language ‘en’)

Calling IVR from external:

-- SIP/Telecom-00000152 answered SIP/781-00000151
-- Channel SIP/Telecom-00000152 joined 'simple_bridge' basic-bridge <a1d47809-e44c-48df-aee9-2c7f05ae09f5>
-- Channel SIP/781-00000151 joined 'simple_bridge' basic-bridge <a1d47809-e44c-48df-aee9-2c7f05ae09f5>

[2018-10-11 16:48:19] WARNING[30283][C-000000d1]: chan_iax2.c:1240 jb_warning_output: Resyncing the jb. last_delay 0, this delay -365862569, threshold 1000, new offset 365862569
– Executing [s@ivr-1:7] Wait(“SIP/User-00000153”, “1”) in new stack
[2018-10-11 16:48:19] WARNING[30285][C-000000d1]: chan_iax2.c:1240 jb_warning_output: Resyncing the jb. last_delay 0, this delay -88563, threshold 1000, new offset 88563
– Executing [s@ivr-1:8] Set(“SIP/User-00000153”, “IVR_MSG=custom/austin-greetng&custom/austin-greetng”) in new stack
– Executing [s@ivr-1:9] Set(“SIP/User-00000153”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:10] ExecIf(“SIP/User-00000153”, “1?Background(custom/austin-greetng&custom/austin-greetng)”) in new stack
– <SIP/User-00000153> Playing ‘custom**/austin-greetng.alaw’** (language ‘en’)

Ponos · October 11, 2018, 3:56pm

Forgot to mention both a ulaw and an alaw version of the greeting exist on the server.

Ponos · October 11, 2018, 4:25pm

I have attached a Wreshark flow sequence (IP redacted) for an external call to the IVR

PitzKey · October 11, 2018, 7:01pm

Can you post your Trunk config?

Ponos · October 11, 2018, 7:18pm

Sure,

Outgoing:

username=User
type=peer
secret=*********
qualifyfreq=60
qualify=yes
nat=force_rport,comedia
insecure=very
host=sip.telcom.com
fromdomain=sip.telcom.com
dtmfmode=auto
disallow=all
context=from-trunk
canreinvite=no
allow=ulaw&alaw

Incoming:

type=peer
qualifyfreq=60
qualify=yes
nat=force_rport,comedia
host=sip.telcom.com
fromuser=User
fromdomain=sip.telcom.com
dtmfmode=auto
disallow=all
context=from-trunk
canreinvite=no
allow=ulaw&alaw

PitzKey · October 11, 2018, 7:22pm

The only difference I see between the external and internal call is, that the external call played the recording in alaw and the internet in ulaw.

So try changing this:

To:
allow=ulaw

(remove the &alaw)

Ponos · October 11, 2018, 7:41pm

OK, removed &alaw on both incoming and outgoing, unfortunately it did not resolve the issue.

I am going to have a troubleshooting session with our network admin tomorrow to step through this.

The sip provider indicated "Our RTP servers operate on ports UDP/16384 - 49151 ". My FreePBX is configured to use RTP 10000-20000 and I suspect the firewall is configured likewise.

cynjut · October 11, 2018, 9:45pm

Important theory note: your RTP range is for your end of the conversation, theirs is for theirs. Unlike traditional telephony, both legs, inbound and outbound, should be treated conceptually as separate and distinct beasts.

One-way audio is almost always a NAT issue or a codec issue. If you’ve narrowed down the codec side, the only other reasonable area of concern is something in the NAT setup. A SIP debug of the conversation (with an optional wireshark session) showing the addresses being used for the conversations (one inbound, one outbound) should give you some indication of where the traffic is getting lost.

system · October 18, 2018, 9:59pm

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