Music on Hold: randomly not working for incoming calls

1

Hello everyone,

Thank you very much for the great product and for all the advice available from the community.

I setup a VPS with freepbx last August and I kept an eye on it to make sure that everything was working fine before going live in my company.
In all this months I never experienced a problem, no downtime, no apparent intrusion attempt (I allow only specific IP, custom port and a few more recommendations from this forum and some experience with website and mail VPS).

My trunk is with voip.ms and it works all the time.
The only issue I am experiencing so far is with music on hold.
I use it as a ringtone for a group and sometimes caller hears the music, sometimes ringing, sometimes nothing.
In the MOH folder I have only 1 file.

Looking at Full log appears that the system starts MOH every time so I really don’t understant where the issue is. Maybe on voip.ms side?

Thanks a lot

Fab

Blockquote

[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:2] Set(“SIP/101-00000099”, “TECH=SIP”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“SIP/101-00000099”, “SIPHEADERKEYS=”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:4] While(“SIP/101-00000099”, “0”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_while.c: Jumping to priority 9
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:10] Return(“SIP/101-00000099”, “”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_stack.c: Spawn extension (from-internal, 333, 1) exited non-zero on ‘SIP/101-00000099’
_musiconhold.c: Started music on hold, class ‘default’, on channel 'SIP/voipms-00000097’2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_stack.c: SIP/101-00000099 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_stack.c: SIP/114-0000009a Internal Gosub(func-apply-sipheaders,s,1) start
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp(“SIP/114-0000009a”, “Applying SIP Headers to channel SIP/114-0000009a”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:2] Set(“SIP/114-0000009a”, “TECH=SIP”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“SIP/114-0000009a”, “SIPHEADERKEYS=”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:4] While(“SIP/114-0000009a”, “0”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_while.c: Jumping to priority 9
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] pbx.c: Executing [s@func-apply-sipheaders:10] Return(“SIP/114-0000009a”, “”) in new stack
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_stack.c: Spawn extension (from-internal, 333, 1) exited non-zero on ‘SIP/114-0000009a’
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_stack.c: SIP/114-0000009a Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: Called SIP/103
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: Called SIP/101
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: Called SIP/114
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] res_musiconhold.c: Started music on hold, class ‘default’, on channel ‘SIP/voipms-00000097’
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: SIP/114-0000009a connected line has changed. Saving it until answer for SIP/voipms-00000097
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: SIP/101-00000099 connected line has changed. Saving it until answer for SIP/voipms-00000097
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: SIP/103-00000098 connected line has changed. Saving it until answer for SIP/voipms-00000097
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 106
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 108
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 101
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 114
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 106
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 108
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 103
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 114
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80114[ext-local] new state Ringing for Notify User 101
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80114[ext-local] new state Ringing for Notify User 108
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80114[ext-local] new state Ringing for Notify User 106
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80114[ext-local] new state Ringing for Notify User 103
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 106
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 108
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 101
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80103[ext-local] new state Ringing for Notify User 114 (queued)
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: SIP/103-00000098 is ringing
[2019-05-02 02:44:48] VERBOSE[31203][C-0000002b] app_dial.c: SIP/101-00000099 is ringing
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 106
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 108
[2019-05-02 02:44:48] VERBOSE[12603] chan_sip.c: Extension Changed *80101[ext-local] new state Ringing for Notify User 103

Blockquote

2

One more thing that is kind of consistent:

Calling a few times in a row without picking up the call I almost always have this result:

1st call: music
2nd call: music
3rd call: ring
4th call: silence (phones always ring)’
5th call: music

I don’t know anymore

Fab

3

Looking for differences:

Are you using Zulu for your phones?
What’s going on with extension 114 in the second example?

4

Hi,

Thanks for your reply.
Zulu is disabled. Ext 114 was ringing I assume (in another building from where I am troubleshooting). To make sure of what is happening with the phones I left only ext 103 (that is beside me) in the ring group unfortunately with same behaviour.
The other thing that happens is that if the pbx is idle (no calls) for many hours, the first caller doesn’t hear any music (or ring)

Is running me crazy a little. If nothing works I will go with the IVR, no problem there.
I contacted voip.ms but I am not sure how much they can help, I don’t use 5060 for trunk but the optional port from voip.ms, vps is VULTR, voip.ms server ping from vps is below 1ms. My ext ping to VPS is less then 20ms

Thanks for your help

5

One more thing,

Everything is up to date, centos and freepbx
I am using HAAST by Telium in free version for now (will upgrade when live).
Extensions phones are Grandstream GXP2160

Thanks

6

Try searching for “early media” and see if it helps. There are lots of threads about using it, and it may help you in some of your cases.

You might be running into a problem with the exterior router(s) losing their NAT sessions. The “doesn’t work after a long pause” thing is common in that scenario. Make sure, also, that your exterior routers are set up to forward NAT traffic correctly. You may or may not “need” this to be done, but it is a belt-and-suspenders precaution you can take to possibly prevent some of the edge cases out there.

7

Can you set Force Answer to yes in the Inbound routes and check. This may resolve your issue if its because of early media.

Thanks

1 Like
8

I’ll test tonight and tomorrow.
Deeply appreciate all the help

Thank you

Fab

9

It worked!

Thanks a lot Sandesh, I have been on this every evening for the last 2 weeks.

Thanks you very much

Fab

10

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