MOH falls back to tone on hold after 10-12 seconds

[asandborgh]

Hello everyone,

We have a CUCM cluster running 7.1.5 and an SRST SIP gateway remote streaming multicast MOH from flash.  The MOH works fine to the phones on-site but when a PSTN caller is put on hold they hear MOH for the first 10 to 12 seconds and then it changes to tone on hold.  We have noticed that in the debug ccm-m music there is a request from CUCM to change codecs (from 5 to 16) just before the event and have found the following in the SDL traces at about the same time:

009610431| 2011/04/19 21:47:24.473| 003| SdlSig    | MXAudioPathCheckTimer                 | waitInterfacesCapabilities    | MediaExchange(3,100,112,13702)  | SdlTimerService(3,100,3,1)      | (2,100,189,1).119257-(*:10.3.3.88)  | [R:HP - HP: 0, NP: 0, LP: 0, VLP: 0, LZP: 0 DBP: 0]
009610432| 2011/04/19 21:47:24.473| 003| SdlSig    | MXTimeout                             | waitInterfacesCapabilities    | MediaExchange(3,100,112,13702)  | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  | [R:NP - HP: 0, NP: 1, LP: 0, VLP: 0, LZP: 0 DBP: 0]
009610433| 2011/04/19 21:47:24.473| 003| SdlSig-S  | MXTimeout                             | waitInterfacesCapabilities    | MediaExchange(3,100,112,13702)  | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  |
009610434| 2011/04/19 21:47:24.473| 003| SdlSig    | MXErrorReport                         | waitInterfacesCapabilities    | MediaExchange(3,100,112,13702)  | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  | [R:NP - HP: 0, NP: 0, LP: 0, VLP: 0, LZP: 0 DBP: 0]error=0
009610435| 2011/04/19 21:47:24.474| 003| SdlSig-Q  | MXInterfaceEstablished                | waitStopped                   | MediaExchange(3,100,112,13702)  | AgenaInterface(3,100,187,18092) | (3,100,187,18092).1-(*:*)               |
009610436| 2011/04/19 21:47:24.474| 003| SdlSig-D  | MXInterfaceEstablished                | waitStopped                   | MediaExchange(3,100,112,13702)  | AgenaInterface(3,100,187,18092) | (3,100,187,18092).1-(*:*)               |
009610437| 2011/04/19 21:47:24.474| 003| SdlSig-Q  | MXTimeout                             | waitStopped                   | MediaExchange(3,100,112,13702)  | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  |
009610438| 2011/04/19 21:47:24.474| 003| SdlSig-D  | MXTimeout                             | waitStopped                   | MediaExchange(3,100,112,13702)  | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  |
009610439| 2011/04/19 21:47:24.474| 003| SdlSig    | AuConnectErrorInd                     | waitDisconnect                | MediaManager(3,100,107,11480)   | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  | [R:NP - HP: 0, NP: 2, LP: 0, VLP: 0, LZP: 0 DBP: 0]CI1=61432472 CI2=61432473 clearType=0
009610440| 2011/04/19 21:47:24.474| 003| Stopping  |                                       |                               | MediaManager(3,100,107,11480)   | MediaManager(3,100,107,11480)   |                                         | NumOfCurrentInstances: 2
009610441| 2011/04/19 21:47:24.474| 003| SdlSig    | MXInterfaceStopStreaming              | waitSDPResponse               | SIPInterface(3,100,50,7444)     | MediaExchange(3,100,112,13702)  | (2,100,189,1).119257-(*:10.3.3.88)  | [R:NP - HP: 0, NP: 2, LP: 0, VLP: 0, LZP: 0 DBP: 0]ClearType= 0StoppedBy= 0 DisconnecType= 0StopStreamingReason0
009610442| 2011/04/19 21:47:24.474| 003| SdlSig    | MXInterfaceStopStreaming              | waitForMXCapabilitiesorOfferorAnswer|

We do have the ccm-manager music bind command as well as the no mgcp timer command on the gateway.

Has anyone experienced this before?

Many thanks in advance for any help!

Art

[dijohn]

Can you make sure that the Region settings between the MOH server and the GW is G711?

[asandborgh]

Yes, already checked that.  The MOH server is in a G711

DP/region.  Thanks!

[phooghen]

Not sure if it can help, but it can explain the behaviour:

From:

https://www.ciscotaccc.com/kaidara-advisor/voice/showcase?case=K14447008

There are several reasons for Cisco CallManager to play Tone on Hold  (ToH) to an endpoint that has been configured for Music on Hold (MoH):

• One reason is a mismatch between the codec configuration used by the  MoH server and the region in which the endpoint is registered. For  example, the MoH server advertised only a capability of G.711 mu-law. If  an endpoint is in another region enforcing the G.729 codec, the Cisco  CallManager chooses ToH because a stream cannot be played to this  endpoint.
• If location-based connection admission control is being used and  there is no bandwidth available, then Cisco CallManager sends ToH  rather than MoH.
• If there are no available audio streams, it is because the MoH  server has a finite number of unicast streams it can generate. Exceeding  this limit causes Cisco CallManager to play ToH.

Pierre

[dijohn]

I don't think its the bandwidth limitation. Don't think Multicast MOH is accounted in Location bandwidth calculation...

But it's weird that, it plays TOH after a few seconds.

Probably you could do "debug ccm-manager moh" to find out whats going wrong!

/divin

[dijohn]

Can you please point me to a entire trace file?

[asandborgh]

Tried debug ccm-manager moh all and a number of others already but they didn't provide much direction, although that one led us to see the change of codec 10 seconds in.  The fact that it falls back to tone on hold indicates that CCM is making the call, but what is causing it to change is the mystery.  I will post complete debugs early next week when I have access again.  The really confusing things is that for the 10 seconds it works fine.  I would have expected it to be tone from the beginning or dead silence, but having music for a bit and then tone is quite beyond the normal MOH issues....

Thanks for the responses!

Art

[dijohn]

If it was upto me, I would have opened a TAC case by now