Master Slave determination in CUCM

cgeorgia4 · ‎05-16-2014

Hi all,

I have attached a single H245 negotiation between CUCM 9.1 and an H323 gateway

Can somebody explain to me why the CUCM does not send a masterslavedetermination message (with a terminaltype and a statusDeterminationNumber) just like the gateway does ? Instead it's only the gateway that sends it and then CUCM sends a masterslavedeterminationack saying that the gateway is the master. Consequently the gateway sends an MSDack to CUCM declaring CUCM as the slave.

This happens ALL the time. Normally the MSD is random but in this scenario obviously it is not. I have done more than a dozen calls using the same gateway and same PSTN number and the gateway always is elected as master and CUCM as slave

I have taken traces from both CUCM and gateway and I can confirm that the CUCM NEVER sends a masterslavedetermination message but only a masterslavedeterminationack.

Regards

Brian Meade · ‎05-16-2014

I think you're just missing some debug output here. The gateway sends a masterslavedeterminationack in response to something so most likely the gateway didn't print the masterslavedetermination it received in the debugs to the monitor buffer getting overloaded.

Here's what I would try:

Disable console logging and monitor logging

no logging console

no logging monitor

Turn on sequence numbers so we can see if anything is lost:

service sequence-numbers

Set up a large logging buffer

logging buffered 5000000

Then clear the log and run your debugs again. Use "show log" to view the output.

Also CallManager traces would be useful if you can attach those as well.

cgeorgia4 · ‎05-16-2014

Hi Brian,

Yes it sends an ACK but I can assure you there is nothing in the logs showing that a callmanager sends a masterslavedetermination. I thought the same as you and I also checked the cucm traces (set to detailed level) and I still see the same scenario. CUCM doesnt send anything and the gateway sends an masteslavedeterminationack back. It cannot be a coincidence that both sides show the same exact thing.

And it's not the first time I see it.

I have another site where I have different set of CUCM / gateway and I see both sides sending masterslavedetermination messages just fine and in that scenario the master / slave election is indeed random. In the above scenario the gateway is always elected as master.

Regards

Brian Meade · ‎05-16-2014

The ACK has to be in response to something though. I'm not sure if maybe H.245 allows an MSDAck to be sent before MSD to force election or something like that. Never heard of something like that. I still think we're just missing it in the logs. I lose MSDs in H.245 debugs all the time. I'd like to see the CallManager traces if you can post those so I can see what's going on with each individual process when this happens.

cgeorgia4 · ‎05-19-2014

I agree with you Brian. That's what I expected to see also but I don't. Hence my question on this forum. I attached the cucm traces in detailed level from CUCM where you see the call from beginning to end. The issue is still the same

Just grep for the following string and you will see all the H245 messages related to this call

H245ASN - TtPid=(100837)

You will see that the masterslavedetermination from cucm to the gateway is missing. As I said the fact that I dont see it either on the gw logs or in the cucm logs indicates that the message is not there :)

If you want more details on the call here they are

Incoming CI: 43250205

Outgoing CI: 43250206

H323 guid: 9304E310DE6211E3BC9DC0203267F2A3

I also get the same when I take a sniffer capture in CUCM

Regards,

Ayodeji Okanlawon · ‎05-19-2014

This trace is abbreviated and hence there is no way to know what is what...I cant even find the Ttpid number in the trace...I agree with Brian though, what will the gateway be sending msdACK to? It has to be to something it received..Please send the full cucm trace for the call..It is easier to trace h245 negotiation on cucm that on the gateway..

Please rate all useful posts

Brian Meade · ‎05-19-2014

Not much I can do with that trace without the detailed SDL communication so I can see the process to process data.

cgeorgia4 · ‎05-19-2014

Sorry guys I have put the wrong file. Here it is attached. You can also see the screenshot of the sniffer capture I have uploaded which shows the same issue

I removed the calling / called number and the phone information from the trace

Edit: I read a bit the H245 standard and I think that the ACK is not necessarily a response to an MSD but merely indicates who is the master and who is the slave.

--------------------------------------------------

Master-Slave Determination Acknowledge

This is used to confirm whether the terminal is the master terminal or the slave terminal, as
indicated by decision. When decision is of type master, the terminal receiving this message is the
master terminal and when decision is of type slave, it is the slave terminal

------------------------------------

What I don't understand is why cucm instructs immediately the gateway to be master and does not send an MSD message.

Thanks for looking into this

Regards

Brian Meade · ‎05-19-2014

Is this device just added as an H.323 gateway? Any non-standard options enabled on it?

Reason I ask is because of the behavior I'm seeing here.

The initial connect request shows the H.323 gateway has a DTMF preference of 4 which is OOB and RFC2833. There shouldn't be any possibility to set a DTMF preference on an H.323 gateway in CUCM. Usually it will always be 1 for No Preference:

24376366.001 |10:01:13.743 |AppInfo |SIG-MediaManager-(271101)::wait_AuConnectRequest, CI(43250205,43250206), capCount(0,8), mcNodeId(0,0), xferMode(7,4), reConnectType(0), mrid (0, 0) IFCreated(0 0) proIns(0 0), AC(0,0), party1DTMF(4 1 0 1 0) party2DTMF(1 3 0 1 0),reConnFlag=0, connType(3,3), IFHand(0,0),MTP(0,0),MRGL(dbabad1d-4435-a96b-0f75-53d9a58a1578,dbabad1d-4435-a96b-0f75-53d9a58a1578) videoCap(0 0), mmCallType(0),FS(0,0), IpAddrMode(0 0) aPid(2, 189, 116386), bPid(2, 58, 17176045) EOType(0 0) MOHAnnConnType(0 0) honorCodec(0 0)

Since H.323 gateways can't do RFC2833, that is immediately stripped out:

24376366.004 |10:01:13.743 |AppInfo |DET-MediaManager-(271101)::getAllow2833FortheCall, 2833 is not allowed for the call

After the incoming terminalCapabilitySet and incoming masterSlaveDetermination, CUCM detects some sort of problem with the codec list:

24376454.013 |10:01:13.759 |AppInfo |RegionsServer: applyCodecFilterIfNeeded - no codecs remained after filtering so restored original 0 caps

This may be because of that DTMF issue or because of the audio codec preference list you have applied.

To resolve, CUCM has to disconnect the 2 call legs and reconnect them:

24376459.002 |10:01:13.759 |AppInfo |DET-MediaManager-(271101)::handle_AuDisconnectRequest, mrid(0,0) ci(4325020543250206) size(1), dt(0)

24376470.001 |10:01:13.759 |AppInfo |SIG-MediaCoordinator-wait_AuReConnectRequest, reConnectType(0)

On the reconnect, we see both sides have no DTMF preference selected and out of band only for DTMF advertisement:

24376472.001 |10:01:13.759 |AppInfo |SIG-MediaManager-(271102)::wait_AuConnectRequest, CI(43250205,43250206), capCount(6,8), mcNodeId(0,0), xferMode(7,4), reConnectType(0), mrid (0, 0) IFCreated(1 1) proIns(100837 136690), AC(0,0), party1DTMF(1 1 0 1 0) party2DTMF(1 1 0 1 0),reConnFlag=1, connType(3,3), IFHand(0,0),MTP(0,0),MRGL(dbabad1d-4435-a96b-0f75-53d9a58a1578,dbabad1d-4435-a96b-0f75-53d9a58a1578) videoCap(0 0), mmCallType(0),FS(0,0), IpAddrMode(0 0) aPid(2, 189, 116386), bPid(2, 58, 17176045) EOType(0 0) MOHAnnConnType(0 0) honorCodec(0 0)

CUCM then sends out its terminalCapabilitySet and sends the terminalCapabilitySetAck

The MasterSlaveDetermination process is then de-queued:

Msdse process gets the MsdseDetermineRequest:

This results in an SDLError as Msdse does not know what to do with an incoming MsdseDetermineRequest while in the "incomingAwaitingResponse" state:

When that happens, CUCM defaults to electing itself as master and thus sends out the masterSlaveDeterminationAck:

24376524.001 |10:01:13.765 |AppInfo |H245ASN - TtPid=(100837) -Outgoing #964924 -value MultimediaSystemControlMessage ::= response : masterSlaveDeterminationAck :
{
decision master : NULL
}

The gateway confirms it will act as slave:

24376525.001 |10:01:13.767 |AppInfo |H245ASN - TtPid=(100837) [0xa02cf850 1444 bytes] -Incoming #1078721 -value MultimediaSystemControlMessage ::= response : masterSlaveDeterminationAck :
{
decision slave : NULL
}

Since CUCM is master, it then selects the codec and sends the first outgoing openLogicalChannel having selected G.711ulaw for the call:

24376537.003 |10:01:13.767 |AppInfo |H245ASN - TtPid=(100837) -Outgoing #964925 -value MultimediaSystemControlMessage ::= request : openLogicalChannel :
{
forwardLogicalChannelNumber 1,
forwardLogicalChannelParameters
{
dataType audioData : g711Ulaw64k : 20,
multiplexParameters h2250LogicalChannelParameters :
{
sessionID 1,
mediaControlChannel unicastAddress : iPAddress :
{
network '0A2F0623'H,
tsapIdentifier 4001
},
silenceSuppression FALSE
}
}
}

So it looks like possibly the initial connection, disconnection, reconnection process is putting the Master Slave Determination into a strange state it doesn't have a rule for which results in CUCM assuming the role of master without sending a masterSlaveDetermination. To resolve the issue, we need to determine the reason for the connect, disconnect, reconnect behavior which is most likely due to either that DTMF preference or the audio codec preference list applied.

cgeorgia4 · ‎05-20-2014

Hi Brian,

Thanks for looking into the traces much appreciated. Good catch this DTMF issue must be relevant indeed. Although I don't really know where is it coming from. The gateway does seem to advertise both DTFM as you see in the cucm traces but that's after the wait_AuConnectRequest message where is shows the DTMF mismatch. So it has to be something in CUCM right ?

Just a small correction. The party receiving the MSD which contains the MASTER, is actually the master so in the above scenario the CUCM is the slave (it received the MSD with slave) and the GW is the master.

The config I have could not have been simpler. I am using one device pool (gw and sccp phone are in the same DP) and one region (Default) so there should not be cap mismatch.

The dialpeer I al hitting is number 10 and it is below

dial-peer voice 10 voip
description *** TO CUCM-Prod Sub ***
preference 1
destination-pattern XXXXXXXXXXX
voice-class codec 1
voice-class h323 1
session target ipv4:10.47.6.35
dtmf-relay h245-alphanumeric
no vad

As you can see the DTMF is indeed OOB (although not RFC2833). The show voice call status shows I am hitting this one

CallID CID ccVdb Port Slot/DSP:Ch Called # Codec MLPP Dial-peers

0x57FCB 7A2 0x48CC9634 0/3/0:15.2 0/1:2 XXXXXXX g711ulaw 1/10

GW has nothing I can see that could influence that. Attached 3 images of the config

I am really not sure why would cucm elect the GW as a MASTER without an MSD. There must be some part of the config that influences that but I cannot figure out which

Brian Meade · ‎05-20-2014

I did indeed have those backward on which side was slave/master.

It looks like the standards allow for a device to skip sending a masterSlaveDetermination if a masterSlaveDetermination has already been received. Both still have to send a masterSlaveDeterminationAck though.

" Each terminal generates a random number and sends it in the
Master/Slave Determination message. Which terminal is the master is
determined by comparison of the terminal types and the random
numbers. If both endpoints send Master/Slave Determination, both
endpoints will reach the same conclusion about who is master. If one
endpoint receives Master/Slave Determination before sending its own,
it makes the determination. In any case each terminal sends
Master/Slave Determination Ack indicating its conclusion.
Master/Slave Determination Reject is sent if the random numbers
chosen by the two endpoints are the same; when this message is
received, Master/Slave Determination is sent again with a new random
number."

from http://tools.ietf.org/html/draft-rfced-info-lantz-00

Looking at some other H.323 traces I have for 9.1, it looks like this is now the case.

As for why it always is selecting the gateway as master, I wonder if the default terminalType change in 9.x. Might need to place an outbound test call in order to determine that.

Ayodeji Okanlawon · ‎05-27-2014

Brian,

Excellent explanation and thanks for digging this out. Good to know.

Please rate all useful posts