Call on hold disconnects after 90 seconds

benrooke · May 7, 2019, 1:30pm

Re posting this as another thread was closed.

I have an issue with calls on hold disconnecting after 90 seconds. I suspect it has something to do with the fact there is no MOH so the line is silent but the RTP hold timeout is set to 500. My provider has stated it is definitely being disconnected at the PBX…

i have taken music on hold off all trunks and groups i can find.

here is the log. can someone shed a little light on where i may start looking?

[2019-04-26 12:11:51] VERBOSE[8290] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘77.108.132.8’
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:1] Set(“PJSIP/To-Brightstar-0000025e”, “__DIRECTION=INBOUND”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:2] Gosub(“PJSIP/To-Brightstar-0000025e”, “sub-record-check,s,1(in,03301276352,dontcare)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:1] GotoIf(“PJSIP/To-Brightstar-0000025e”, “0?initialized”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:2] Set(“PJSIP/To-Brightstar-0000025e”, “__REC_STATUS=INITIALIZED”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:3] Set(“PJSIP/To-Brightstar-0000025e”, “NOW=1556277111”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:4] Set(“PJSIP/To-Brightstar-0000025e”, “__DAY=26”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:5] Set(“PJSIP/To-Brightstar-0000025e”, “__MONTH=04”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:6] Set(“PJSIP/To-Brightstar-0000025e”, “__YEAR=2019”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:7] Set(“PJSIP/To-Brightstar-0000025e”, “__TIMESTR=20190426-121151”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:8] Set(“PJSIP/To-Brightstar-0000025e”, “__FROMEXTEN=unknown”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:9] Set(“PJSIP/To-Brightstar-0000025e”, “__MON_FMT=wav”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:10] NoOp(“PJSIP/To-Brightstar-0000025e”, “Recordings initialized”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:11] ExecIf(“PJSIP/To-Brightstar-0000025e”, “0?Set(ARG3=dontcare)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:12] Set(“PJSIP/To-Brightstar-0000025e”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:13] ExecIf(“PJSIP/To-Brightstar-0000025e”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:14] GotoIf(“PJSIP/To-Brightstar-0000025e”, “2?checkaction”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@sub-record-check:17] GotoIf(“PJSIP/To-Brightstar-0000025e”, “1?sub-record-check,in,1”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [in@sub-record-check:1] NoOp(“PJSIP/To-Brightstar-0000025e”, “Inbound Recording Check to 03301276352”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [in@sub-record-check:2] Set(“PJSIP/To-Brightstar-0000025e”, “FROMEXTEN=unknown”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [in@sub-record-check:3] ExecIf(“PJSIP/To-Brightstar-0000025e”, “11?Set(FROMEXTEN=03333442801)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [in@sub-record-check:4] Gosub(“PJSIP/To-Brightstar-0000025e”, “recordcheck,1(dontcare,in,03301276352)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“PJSIP/To-Brightstar-0000025e”, “Starting recording check against dontcare”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“PJSIP/To-Brightstar-0000025e”, “dontcare”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“PJSIP/To-Brightstar-0000025e”, “”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [in@sub-record-check:5] Return(“PJSIP/To-Brightstar-0000025e”, “”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:3] Set(“PJSIP/To-Brightstar-0000025e”, “CHANNEL(tonezone)=uk”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:4] Set(“PJSIP/To-Brightstar-0000025e”, “__FROM_DID=03301276352”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:5] Set(“PJSIP/To-Brightstar-0000025e”, “returnhere=1”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:6] Gosub(“PJSIP/To-Brightstar-0000025e”, “app-blacklist-check,s,1()”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“PJSIP/To-Brightstar-0000025e”, “0?blacklisted”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@app-blacklist-check:2] Set(“PJSIP/To-Brightstar-0000025e”, “CALLED_BLACKLIST=1”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [s@app-blacklist-check:3] Return(“PJSIP/To-Brightstar-0000025e”, “”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:7] Set(“PJSIP/To-Brightstar-0000025e”, “CDR(did)=03301276352”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:8] GotoIf(“PJSIP/To-Brightstar-0000025e”, “0?”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:9] ExecIf(“PJSIP/To-Brightstar-0000025e”, “0 ?Set(CALLERID(name)=03333442801)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:10] Set(“PJSIP/To-Brightstar-0000025e”, “CHANNEL(musicclass)=none”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:11] Set(“PJSIP/To-Brightstar-0000025e”, “__MOHCLASS=none”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:12] Set(“PJSIP/To-Brightstar-0000025e”, “__REVERSAL_REJECT=FALSE”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:13] GotoIf(“PJSIP/To-Brightstar-0000025e”, “1?post-reverse-charge”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (from-pstn,03301276352,15)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:15] NoOp(“PJSIP/To-Brightstar-0000025e”, “”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:16] Set(“PJSIP/To-Brightstar-0000025e”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:17] Set(“PJSIP/To-Brightstar-0000025e”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:18] Set(“PJSIP/To-Brightstar-0000025e”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:19] Set(“PJSIP/To-Brightstar-0000025e”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:20] NoOp(“PJSIP/To-Brightstar-0000025e”, “CallerID Entry Point”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [03301276352@from-pstn:21] Goto(“PJSIP/To-Brightstar-0000025e”, “ext-trunk,2,1”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (ext-trunk,2,1)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [2@ext-trunk:1] Set(“PJSIP/To-Brightstar-0000025e”, “TDIAL_SUFFIX=@SBC_Link”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [2@ext-trunk:2] Set(“PJSIP/To-Brightstar-0000025e”, “TDIAL_STRING=PJSIP”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [2@ext-trunk:3] Set(“PJSIP/To-Brightstar-0000025e”, “DIAL_TRUNK=2”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [2@ext-trunk:4] Goto(“PJSIP/To-Brightstar-0000025e”, “ext-trunk,tdial,1”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (ext-trunk,tdial,1)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:1] Set(“PJSIP/To-Brightstar-0000025e”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:2] GotoIf(“PJSIP/To-Brightstar-0000025e”, “1?nomax”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx_builtins.c: Goto (ext-trunk,tdial,4)
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:4] ExecIf(“PJSIP/To-Brightstar-0000025e”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:5] ExecIf(“PJSIP/To-Brightstar-0000025e”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:6] Set(“PJSIP/To-Brightstar-0000025e”, “DIAL_NUMBER=03301276352”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:7] GosubIf(“PJSIP/To-Brightstar-0000025e”, “0?sub-flp-2,s,1()”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:8] Set(“PJSIP/To-Brightstar-0000025e”, “OUTNUM=03301276352”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:9] Set(“PJSIP/To-Brightstar-0000025e”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] pbx.c: Executing [tdial@ext-trunk:10] Dial(“PJSIP/To-Brightstar-0000025e”, “PJSIP/03301276352@SBC_Link,300,T”) in new stack
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] app_dial.c: Called PJSIP/03301276352@SBC_Link
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] app_dial.c: PJSIP/SBC_Link-0000025f is making progress passing it to PJSIP/To-Brightstar-0000025e
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] app_dial.c: PJSIP/SBC_Link-0000025f is making progress passing it to PJSIP/To-Brightstar-0000025e
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] app_dial.c: PJSIP/SBC_Link-0000025f is ringing
[2019-04-26 12:11:51] VERBOSE[20693][C-0000012f] app_dial.c: PJSIP/SBC_Link-0000025f is ringing
[2019-04-26 12:11:59] VERBOSE[20693][C-0000012f] app_dial.c: PJSIP/SBC_Link-0000025f answered PJSIP/To-Brightstar-0000025e
[2019-04-26 12:11:59] VERBOSE[20701][C-0000012f] bridge_channel.c: Channel PJSIP/SBC_Link-0000025f joined ‘simple_bridge’ basic-bridge <bcdd1917-49ce-45da-ba93-a98ed1cffcfe>
[2019-04-26 12:11:59] VERBOSE[20693][C-0000012f] bridge_channel.c: Channel PJSIP/To-Brightstar-0000025e joined ‘simple_bridge’ basic-bridge <bcdd1917-49ce-45da-ba93-a98ed1cffcfe>
[2019-04-26 12:12:03] VERBOSE[20693][C-0000012f] res_musiconhold.c: Started music on hold, class ‘none’, on channel ‘PJSIP/To-Brightstar-0000025e’
[2019-04-26 12:12:03] WARNING[20693][C-0000012f] format_wav.c: Read failed (type)
[2019-04-26 12:12:03] WARNING[20693][C-0000012f] file.c: Unable to open format wav
[2019-04-26 12:12:03] WARNING[20693][C-0000012f] res_musiconhold.c: Unable to open file ‘/var/lib/asterisk/moh/.nomusic_reserved/silence’: No such file or directory
[2019-04-26 12:12:03] VERBOSE[20693][C-0000012f] res_musiconhold.c: Stopped music on hold on PJSIP/To-Brightstar-0000025e
[2019-04-26 12:13:33] VERBOSE[20693][C-0000012f] bridge_channel.c: Channel PJSIP/To-Brightstar-0000025e left ‘simple_bridge’ basic-bridge <bcdd1917-49ce-45da-ba93-a98ed1cffcfe>
[2019-04-26 12:13:33] VERBOSE[20693][C-0000012f] pbx.c: Spawn extension (ext-trunk, tdial, 10) exited non-zero on ‘PJSIP/To-Brightstar-0000025e’
[2019-04-26 12:13:33] VERBOSE[20701][C-0000012f] bridge_channel.c: Channel PJSIP/SBC_Link-0000025f left ‘simple_bridge’ basic-bridge <bcdd1917-49ce-45da-ba93-a98ed1cffcfe>

I have been told that the offending item is

[2019-04-26 12:12:03] WARNING[20693][C-0000012f] res_musiconhold.c: Unable to open file ‘/var/lib/asterisk/moh/.nomusic_reserved/silence’: No such file or directory

however, if MOH is disabled does this matter? if so how do i change it?

cynjut · May 7, 2019, 5:41pm

My guess:

No file, no traffic.
No traffic, NAT RTP hole closes in router.
No RTP, SIP disconnects.

You need something (even comfort noise) from the system through the router to keep the traffic flowing.

Stewart1 · May 7, 2019, 10:34pm

I don’t know whether this will help, but my system does have an empty silence.wav file in that directory.

Try:

cd /var/lib/asterisk/moh/.nomusic_reserved
touch silence.wav
chown asterisk. silence.wav

Otherwise, try Settings -> Asterisk SIP Settings:
RTP Keep Alive: 10

If still no luck, create real music file consisting of 5 minutes of silence and try that.

system · May 14, 2019, 10:34pm

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