Category: Cisco Call Manager



This is another attempt to share what I’ve researched in my personal time with other Engineers simply because  I have benefited  a lot  from reading  other people’s blogs also.  My  hope is that this post is useful to someone out there.

Not too long ago, I wrote a post about  the boot process of Cisco jabber for windows which can be found    here.  In continuation of this entry, I thought I’d add share some more  information on how to read the logs that are generated  when  two people who are  on  Cisco Jabbber clients start chatting or sharing screenshots with each other.

Knowing what to expect in these logs could prove very important if a client complains to you that when he sends chat message to someone the message is never delivered.  Anyway, before I start talking too much, lets begin.

Lets starting of by talking about the trace file  that should be  used when looking into the chat messages or picture exchange between tw0 people on jabber clients.   In this regard, the best trace to collect is the XCP Connnecton Manager traces.  It is also advisable to set the trace level to detailed before attempting to collect the trace file. So the question is,  ‘why the XCP Connection manager trace’ ? Well the XCP Connection Manager  helps jabber clients to connect to the IM and Presence Server. It is sort of like an intermediary.

Now that we have that under our belt, the nex thing to know is how to differnciate one chat message for another in a massive pile of traces.

There are several things unique to every chat conversation:

1)   The sender and the receiver’s jabber ID  (JID)

2)  Every message has a Unique ID which is used to identify a message as it is transported across multiple  IM and presence servers en-route to it’s destination or jabber user.

When reading jabber traces, the same rule that applies to phones and call-manager applies here too:  and that is, you will mostly only find the logs for a given jabber client on the server that it is registered to.  This is true for the XCP Connection Manager traces.  What I’m trying to say here is that sometimes you have to collect logs from multiple IM and presence servers but most of the interesting logs will piled up in one server.

Now that we understand that, let talk briefly about the message flow.

For every chat message/ conversation there are several  messages that are exchanged  in the following order.

1) One of the very first messages is the   “IN FROM CLIENT” message. This is the trace line that tells us that someone has sent a message via the XCP Connection Manager  to the IM and presence server using a jabber client.

2)   “OUT TO SERVER” message. This means that the message has now been transferred to the IM and Presence server’s internal processes so that  a destination for the message can be calculatated or derived. It is at this stage that components like the XCP Router kicks in.

3) ” IN FROM SERVER” message. This is the message that  instructs an IM and presence node to deliver a message to a particular XMPP client. i.e jabber.  Please note that if jabber clients are chatting with each other but they are not registered to the same IM and Presence node, you will never see an  “OUT TO SERVER” and an ” IN FROM SERVER” message together on any single node for one conversation going in one direction (i.e from sender to receiver).

4)   Then there is the  “OUT TO CLIENT ” message. This is one of the final messages you will see in the logs when a message is about to be  delivered to  a recipient jabber client.

Ok now that we’ve discussed this matter at length, let take a look at some logs.

In the logs below, user2@voiceinitiate.com sends a message to  User1@voiceinitiate.comand a message ID of 52a46470:00000990:0000010c is assigned to the message

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

[IN FROM CLIENT state:6]: <message id=’uid:52a46470:00000990:0000010c to=’user1@voiceinitiate.com’ type=’chat’><body>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at work</body><thread>connect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

The Jabber session manager  (cm-1_jsm-1) that is running on server “subcup.voiceinitiate.com”,  informs us that this  message is being sent out to the server’s internal processes for analysis and message delivery

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1.subcup-voiceinitiate-com [OUT TO SERVER(3)]: from=‘user2@voiceinitiate.com/jabber_22990 id=’uid:52a46470:00000990:0000010c to=’user1@voiceinitiate

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

In the  output below, the  Jabber session manager  (cm-1_jsm-1) that is running on server “pubcup.voiceinitiate.com”,  informs us that it has received a request to deliver   message to user1@voiceinitiate.com to user2@voiceinitiate.com

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1.pubcup-voiceinitiate-com [IN FROM SERVER]: from=’user2@voiceinitiate.com/jabber_22990′ id=’uid:52a46470:00000990:0000010c’ to=’user1@voiceinitiate.com’ type=chat’ xml:lang=’en’><body>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at work</body>connect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

In the logs below, we see that the  message is delivered to the recipient jabber client.

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1_xmppd-1 [OUT TO CLIENT]: <message from=’user2@voiceinitiate.com/jabber_22990′ id=’uid:52a46470:00000990:0000010c’ to=’user1@voiceinitiate.com type=chat xml:lang=’en’>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at workconnect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

Ok so now that we know how text/ chat messages flow within the server(s), how about when we send a screen-shot to someone via jabber? Well  the snapshot below shows me sending a picture from one jabber client to another . I will not show you the full message follow because we already have a general idea of what to expect. However, what  I will show here is the actual traces that showed what was happening in the background as the picture  was being sent.

Let me first of show you the  actual screen-shot  that I took while the picture was being transferred between jabber clients. Pay special attention to the name of the file and see if you can see  that same file name in the the logs below.

jabber

cm-1_jsmcp-1_xmppd-1 [OUT TO CLIENT]: <iq from=’user1@voiceinitiate.com/wbxconnect’ id=’uid:52a45b16:00004d03:000001a7‘ to=user2@voiceinitiate.com/jabber_22990′ type=’set’ xml:lang=’en’>Successfully sent file user1@voiceinitiate.com_20131208_150328.png(13613 bytes)’.</x></jingle></iq>

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

The logs above withe XCP Connections Manager logs. Now the presence Engine logs are even more interesting. Check out the logs below that even tells you were the file was saved on the computer hard-drive.

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

system.pe.jabber 1308670 INFO ClientEmComponent::onPacket() – PACKET RECEIVED::  <message from=’user1@voiceinitiate.com/wbxconnect’ to=’user2@voiceinitiate.com type=’chat’ xml:lang=’en’> xmlns=’http://webex.com/connect/imcmd’/>Subject&lt;body xmlns=’http://www.w3.org/1999/xhtml’>&lt;img alt=’Screen capture contenteditable=’false’ id=user1@voiceinitiate.com_20131208_150328.png’ name=‘connect_screen_capture src=’file:///C:/Documents%20and%20Settings/user1/My%20Documents/MyJabberFiles/user1@voiceinitiate.com/user1@voiceinitiate.com_20131208_150328.png/></body></html></message>

Anyway, I hope that what has been shared here today will come in handy to someone down the line.

All the best

Maxwell

Advertisements

* Hint:Please note that some of the screenshots and outputs in this post have been recreated in a lab

* Hint:Please double-click the snapshots to zoom into them. 

This is another interesting case that  I  recently worked on with a colleague of mine.  The topology below represents a high level overview of what the client’s network looks like. The complaint was that users could call local numbers but all international calls were failing to connect.  That got us thinking . . .  our first question was, if local calls are working fine, and international call are not, then what is the difference between both calls

The snap-shot below shows how the sip messages were flowing for the working local calls .
Working call

If you compare the sip messages of the working call above with the non-working international call below, you will see that the difference is that the messages below contains a ‘ 183 session progress message‘.

Failed call

So based on the above, the question that now presents itself is:  why did the Cisco Unified Boarder element send a bye message to the Cisco Call Manager when the remote phone that is out in the cloud was actually ringing? Does this make sense;  Strange isn’t it?

Ok so we know from our experience as Engineers  that when a call fails,  there is normally some sort of error message, failure or cause code of some sort. In the trace output below, you will see that I have actually highlighted the error -code that was in the  ‘ bye‘ message that we saw in the call-flow diagram above.

As we can see,  the sip protocol informs us that the call failed with  a cause of: ‘Reason: Q.850;cause=65‘ . If you do a Google search for cause code 65 will probably find something related to a codec/capability  negotiation issue; which might lead one to think about transcoding. Please have a try for yourself; do a Google search and see what you come up with.

::::::::::::::::::::::::::::::::::::::::::::::::

Sent:
BYE sip:447578332431@192.168.0.10:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.20.8:5060;branch=z9hG4bK8052F20C7
From: <sip:00412256731@192.168.0.20>;tag=FAA7C024-667
To: “maxwell o” <sip:447578332431@192.168.0.10>;tag=342693~12b9673c-9ebc-4b8c-b0db-46b8d985386a-34835506
Date: Mon, 30 Sep 2013 12:44:02 gmt
Call-ID: fa88da80-24917212-28046-2212b0a@192.168.0.10
User-Agent: Cisco-SIPGateway/IOS-15.2.4.M1
Max-Forwards: 70
Timestamp: 1380545045
CSeq: 101 BYE
Reason: Q.850;cause=65
P-RTP-Stat: PS=19,OS=4480,PR=25,OR=4000,PL=0,JI=0,LA=0,DU=34270069
Content-Length: 0

::::::::::::::::::::::::::::::::::::::::::::::::

Did you carry out the Google search, did it show something related to codec?  if so, then I’m pleased to inform you that answer is  incorrect 🙂 lol . . . just joking :-). I have been mislead by so many error codes in the past that I no longer trust them completely.

On a more serious note, lets take a look at what RFC: 3262(click on this link) has to say about this; and I quote:

 If the UAS had placed a session description in any reliable
   provisional response that is unacknowledged when the INVITE is
   accepted, the UAS MUST delay sending the 2xx until the provisional
   response is acknowledged.  Otherwise, the reliability of the 1xx
   cannot be guaranteed, and reliability is needed for proper operation
   of the offer/answer exchange.

::::::::::::::::::::::::::::::::::::::::::::::::

So the question is, what does the above mean? Lets start of by explaining what a ‘provisional response’ is:

A very simplified definition of provisional responses is that ‘ they are 1xx responses within a Sip Dialogue/ conversation’. The snap-shot below provides  a quick glance at examples of Provisional Responses.

(source: http://en.wikipedia.org/wiki/List_of_SIP_response_codes#1xx.E2.80.94Provisional_Responses)

1xxreal

However, the definition above still does not explain what a ‘ reliable   provisional response’ is.

As simplified definition of a ‘ reliable provisional response’ is that :    a provisional response becomes reliable when the Sending User Agent Server (UAS) expects an acknowledgement back from the receiving User agent (UA)

With these definitions under out belt, it is now easy to understand what the RFC copied above was trying to say. The RFC is basically pointing out the importance of receiving an acknowledgement from the remote end when the reliable response mechanism is being used. It can actually stop a call from completing if not handled properly.

Lets take a time-out  to quickly take a look  at the SIP-message-flow the copied below. Did you notice the use  of the PRACK?     :

(Source: ‘ borrowed’ form Cisco )

good call flow

I guess at this point, the Sip-call-flow diagram of the failed international  call makes so much more sense now? I guess we can see the cause of the failure now? Basically, the Cisco Unified boarder element sent a bye message to the call-manager because the call manager never sent an ACK message to the ‘183 session progress message‘ it sent to call-manager.

To be honest, this should not have happened though: The Cisco CUBE algorithm was clearly not following the relevant SIP RFC stipulations. But then again who does? I will not explain why the Cisco CUBE was not following RFC stipulations because this post would become too long and boring.

Anyway, here is what we did to solve the problem:

We modified the ‘ sip profile’ attached to the sip trunk so that it would support the sending of RACK ( Provisional Response Acknowledgement)messages to all  Provisional Response messages coming from cube(i.e  18x sip messages).

Here are the steps:

1) go to cucm admin page

2) find the sip profile that your sip trunk is using.

3) then go to device  > device Setting > SIP Profile

4) enable ‘ send PRACK for all 1xx messages

5) reset the sip trunk

6) make sure your sip dial-peer on the cube that is pointing at cucm has something like this in config line:

dial-peer voice 20 voip
  voice-class sip rel1xx require 100rel

Send PRACK

Well as soon as we did this, all the calls started connecting fine.

However, we were having ringing / ring-back issues on international calls such that when an international call was made, the caller could not hear the remote phone ringing.

If you encounter this in your network, here is what you could do resolve it.

On the cucm:

:::::::::::::::::::::::::::::::::::

1) go to cucm admin page

2) find the sip profile that your sip trunk is using.

3) then go to device  > device Setting > SIP Profile

4) tick the check box for ‘ disable early medial for 180’

5) reset the sip trunk

6 on your Cisco Cube you should have a config on your inbound and outbound dial-peer similar to this(if you found that the service provider was not sending the audio or media in 183 /180 message):

dial-peer voice 20 voip
 voice-class sip block 183 sdp absent
voice-class sip block 180 sdp absent (use this single line with care)

see the diagram below for further details .   .    .

local ringback

Hope you have found this entry entertaining and contributory to your quest for knowledge and your day-to-day battles between Man and Machine.

A special thank you goes out  Mike Jones for his contributions to this case which has now led to this publication.

Mike can be found at uk.linkedin.com/pub/michael-cunliffe-jones/46/6b6/2a6/

All the best folks,

Regards

Maxwell


* Hint: Please click on the picture(s) in order to maximize it

 * Hint:Please note that some of the screenshots and outputs in this post have been recreated in a lab

So this was an interesting case that landed on my desk from one of our very technical clients who basically use us solely for escalation.   The client has a third party PBX integrated with Cisco Call-manager via multiple SIP  trunks. One of the things that the client uses the PBX for is that when calls come into Cisco Call-manager, it is sent to the PBX where there are operators who answer calls and forward the calls  on if need be.  However, the client noticed that whenever the agents forwarded calls to his phone that is registered on call-manager,  there was always an extra ‘0’ zero in the beginning of the Caller-ID of the calling-number.   The client wanted to know where this extra zero was being added to the number.  The client went on to say that there was always an extra zero on every call regardless of whether the call originated internally or externally.

My shift was coming to an end and there were so many gateways and trunks everywhere that I didn’t even know how the offending calls entered the network. As a result, I felt we would spend more time trying to rummage through Docs or configurations on call-manager as opposed to just  grabbing a few traces and looking at it. With this thought in mind, I placed a test call from my mobile phone into the company and asked the operator to forward my call on to an internal user.

I collected traces from all the servers in the cluster and since I knew the time-of-call, called and calling number, it was easy to find my call in the traces.  Here is what I found:

From  the traces below  we see a back-hauled signal   to   the Call-manager from Ip address 10.x0.xx.9.. This is the originating MGCP  gateway where my call entered the network .

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

05/17/2013 15:27:34.337 CCM|MGCPBhHandler 10.x0.xx.9  – TCP msg available from Device|<CLID::StandAloneCluster><ct::4,100,135,1.808082><IP::10.X0.XX.9 ><LVL::Detailed>

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

After that, the gateway at  10.x0.xx.9  sends  or backhauls the calling number and called number to call-manager

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

05/17/2013 15:27:34.337 CCM|In  Message — PriEuroSetupMsg — Protocol= PriEuroProtocol|

05/17/2013 15:27:34.337 CCM|Ie – Ni2BearerCapabilityIe — IEData= 04 03 90 90 A3 |

05/17/2013 15:27:34.337 CCM|Ie – Q931ChannelIdIe — IEData= 18 03 A9 83 9B |

05/17/2013 15:27:34.338 CCM|Ie – Q931CallingPartyIe — IEData= 6C 0C 21 83 37 38 32 31 31 37 33 31 34 33 |<CLID::StandAloneCluster><

05/17/2013 15:27:34.338 CCM|Ie – Q931CalledPartyIe — IEData= 70 07 81 37 37 33 33 31 31 |<CLID::StandAloneCluster><

 

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

From the above we can see that the telephone number are written in ASIC  format so 37 37 33 33 31 31  is basically equal to  773311  :

From the above  I was able to confirm that this was my call because:

The calling   number  was  7821173143

The called   number ended with    773311

The apparent incompleteness of the called-number is perfectly normal because the client subscribes to  ‘direct Inward Dial ’ service.

From the below, we see that after the call was received from the gateway,  the call-manager looked at the configured digit-manipulation on the gateway and applied it to the calling and called number. Hence we see that   the incoming-calling-number  was changed from 7821173143 to 07821173143.

In the second line we can see the call-manager announcing the newly ‘globalised’ (globalizeIncomingCgpn)  in-coming-calling number as 07821173143

 

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

CCM|SPROCPri::globalizeIncomingCgpn – Adding prefix: 0, Digits to strip: 0, Cgpn Transformation CSS: |

05/17/2013 15:27:34.338 CCM|SPROC :: stripAndPrependDigits– The number 7821173143 is prepended with prefix 0, updated number=07821173143|

15:27:34.338 CCM|SPROCPri::globalizeIncomingCgpn – Globalized Cgpn = 07821173143

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

The snapshot below shows the digit manipulation that is configured on the gateway.  Notice that nothing is applied to it? Then why did the trace show that the calling-number had been changed from 7821173143 to 07821173143. well  did you notice that  digit manipulation was set to default?  Default means:  ‘if there is no digit manipulation configurations on the gateway, apply  the digit manipulation that is configurations on the device-pool and if there is nothing  on the device-pool, check the Call-manger Service parameters ’.

GW-mani

On this occasion, there was also no digit manipulation configured on the gateway so call-manager manipulated the digits based on service parameters. Based on the  service parameter configuration below,  we see that  whenever a  call that is classified as national comes into call-manager, a extra leading Zero (0) is added to the number.

service parameter

The next thing that the call-manger  has to do is to find a route to the destination number of 773311 so it invokes digit analysis by triggering a digit analysis request (daReq).

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

05/17/2013 15:27:34.343 CCM|Digit Analysis: wait_DaReq: daReq.

CCM|Digit analysis: match(pi=”2″, fqcn=””, cn=”07821173143“, , dd=”773311

 

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

From the trace below we find that the call-manager has found the a match for 773311

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

 

 

05/17/2013 15:27:34.343 CCM|Digit analysis: match(pi=”2″, fqcn=””, cn=”07821173143″,dd=”773311

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

Now  call-manager needs to  process the call according to the match.  In the trace below, we  notice the following:

1)      That the match is located at partition called  ‘GW-INCOMING’

2)      That  called number was changed from 773311 to 3311.

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

 

 

05/17/2013 15:27:34.343 CCM|Digit analysis: analysis results|<CLID::StandAloneCluster><

05/17/2013 15:27:34.344 CCM||PretransformCallFingPartyNumber=07821173143

|CallingPartyNumber=07821173143

|DialingPartition=GW-INCOMING

|DialingPattern=3311

|FullyQualifiedCalledPartyNumber=3311

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

After noticing  that the called-number had been changed,  I jumped on call-manager to confirm what happened  in the traces as it was now clear that a digit manipulation had just taken place because 773311  had just changed to  3311 . So I searched  call-manager for the pattern that was just matched and I found a translation-pattern.

From the screenshot below, we can confirm that the dialed number matched the translation patter ‘77.3311’. We also see that the reason why the digit changed to 3311 was because the digit manipulated that was configured on the translation-pattern was configured to drop all the digits  before 3311

 

 Translationpatt

 

 

Once again call manager tries to get the call to the intended destination by running the new called-number of 3311 through the digit analysis process and in the progress, call manager discovers that number  has a Call-forward-all  (cfa) value of   7165871 configured

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

callKey= 0x37D0D,

ssKey = 0, recordStatus 0,

 dnPattern =  3311, dnPartition =

cfa     = 7165871, cfaToVM     = 0, cfaCss     = PA

cfb     = , cfbToVM     = 0, cfbCss     = PA

cfna    = , cfnaToVM    =

cfur    = 7165871, cfurToVM

cfurInt = 7165871, cfurI

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

So based on the above, our Called or dialed number has just changed from 3311 to 7165871 because it had a (cfa) call-forward-all configured with a value of 7165871.

Therefore, call manager tried to forward the call by first of all carrying out a digit analysis in order to find a match or route.

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

5/17/2013 15:27:34.348 CCM|Forwarding – initiateCFA – CFA, callKey= 0x37D0D|

05/17/2013 15:27:34.350 CCM|Digit analysis: match(pi=”1″, fqcn=””, cn=”07821173143“,dd=”7165871

As can be seen below,   call-manager finds a match for the number it was looking for.

05/17/2013 15:27:34.350 CCM|Digit analysis: match(pi=”1″, fqcn=””, cn=”07821173143, dd=”7165871

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

 

 

Now  let’s see what matches  the call-manager found below.

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

|CallingPartyNumber=007821173143

|DialingPartition=SIP-Internal

|DialingPattern=716.XXXX

|FullyQualifiedCalledPartyNumber=7165871

|PotentialMatches=NoPotentialMatchesExist

|PretransformDigitString=7165871

|PretransformPositionalMatchList=716:5871

|CollectedDigits=5871

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

From the above, we can see that while call-manager was trying to find out how to get to 7165871 by finding something that matched it, it found pattern 716.XXXX in partition ‘SIP-Internal ’.

Hello!? Did you notice that the calling number has changed from   07821173143’ to ‘007821173143’ ? if you didn’t  take another look above

 

If you did then that is good. AS soon as I noticed this,  I wanted to confirm what I had just seen in the logs above  so I logged unto call manager web page  and searched for 716.XXXX.  The number was configured as a route-pattern but there was more to it: check out the  screenshot of the configuration below

 

routpatterntoproutpatternbuttom 

 At this point my job was pretty much done.  I confirmed that the route pattern was responsible for sending calls to the PBX by checking the route list. I also confirmed that this route pattern  is the route-pattern  that was responsible for sending the calls to the PBX with an extra zero. It was the root cause of the problem. So the cause of the problem was Cisco call manager and not the PBX.   All I did was to remove the prefix of Zero and the problem was resolved. The client was very happy and straight away dropped another problem that needed solving on my lap. . .  lol     🙂     from frying pan to fire 😉

Anyway, I  hope you enjoyed this case as much as I did

Cheers


* Hint: Please click on the picture in order to maximize it

I thought I’d simply add this blog entry because I have found this topic being talked about all over the internet yet I have never found one person shedding full light on    the solution (I’ve probably not looked hard enough). I suspect people could not readily provide the answer to the problem because it’s very rarely requested for by end users. In fact I have only been asked to do this once in my entire existence on this planet and I did scratch my head when I was first asked to do it . The question sounds very daft, but let me ask it; how do you switch off the call-waiting sound or alert tone a user  hears on a Cisco IP-phone running on Cisco Call-manager when a second call comes in during an active call? Were you expecting me to ask about how you can build a server from scratch? : – )

If that question caught you off-guard, well take solace in the fact that you are not the first to be caught off-guard  by this one.  : – )  Try your luck and ask a CCIE lol.

Anyway, to cut a long story short, in order to do this:

1)      Log unto CUCM admin page

2)      Go to service parameters and select call-manager

3)      Scroll through the parameters and you will see a parameter called ‘Ring Setting of Busy Station’

4)      Just set the setting to ‘ flash only’

Ring setting of Busy Station

In my case, I had to reset the Jabber clients in order for the jabber client to pick up the config.

Cheers


* Hint: If this video becomes  fuzzy or unclear, please just switch to HD mode.

* Hint:Please note that some of the screenshots and outputs in this post have been recreated in a lab

* Hint: Please click on the pictures in order to maximize them

As we  know, the problem of one-way audio is very popular in the word of  IP telephony and when it occurs, everyone thinks its the telephony system that’s got a problem. However, 90% of the time, it’s the underlying network that’s causing the problem.   This video entry is geared towards providing a method for determining whether the phones in a a call are actually sending audio packets when users are complaining of one-way audio or no audio at all.


* Hint: Please click on the pictures in order to maximize them

 

So after working for a client on a Meeting-Place related issue, this particular case took centre stage in our closing remarks/ conversation. The client complained that every now and then, Cisco Tomcat Service would crash and results in the problems listed below:

1)      Admin and end-Users cannot log into Call-Manager web pages when the server fails. The client noted that even after a Cisco Tomcat Service restart, the time required to load a Call-Manager page would continuously degrade/increase  as time elapses.

2)      The client also informed me that their corporate directory also crashes when the Tomcat service crashes.

I then decided to do a quick diagnostic test on the server’s CLI by issuing ‘utils diagnose test After issuing the command, I got the output below:

admin: utils diagnose test
Log file: platform/log/diag2.log
Starting diagnostic test(s)
===========================
test – disk_space : Passed (available: 24897 MB, used: 11727 MB)
skip – disk_files : This module must be run directly and off hours
test – service_manager : Passed
test – tomcat : Passed
test – tomcat_deadlocks : Passed
test – tomcat_keystore : Passed
test – tomcat_connectors : Passed
test – tomcat_threads : Passed
test – tomcat_memory : Passed
test – tomcat_sessions : FailedThe following web applications have an unusually large number of active sessions: axl. Please collect all of the Tomcat logs for root cause analysis: file get activelog tomcat/logs/*
test – validate_network : Passed
test – validate_network_adv: Passed
test – raid : Passed
test – system_info : Passed (Collected system information in diagnostic log)
test – ntp_reachability : Passed
test – ntp_clock_drift : Passed
test – ntp_stratum : Passed
skip – sdl_fragmentation : This module must be run directly and off hours
skip – sdi_fragmentation : This module must be run directly and off hours
test – ipv6_networking : Passed
Diagnostics Completed

At this stage, I was quite happy that the diagnostic test had not only discovered the location of the problem, but had also pointed me in the right direction with regards to collecting the appropriate logs.  However, I had one problem with the output: If I followed the directions of the output and issued the command; ‘ file get activelog tomcat/logs/*’ ,  I would essentially be pulling all the logs in that directory when I only really needed the ‘.hprof ’  file.

As can be seen in the screenshot below, I then decided that the best thing to do was to collect the specific ‘.hprof’ file for the specified time-stamp.

rtmt

The next phase was to pass the .hprof file through Eclipse Memory Analyser as can been seen in the screenshot below.

The steps followed were

i)                    Click file menu

ii)                   Select open heap dump

iii)                 Select the ‘.hprof’ file extracted from CUCM using RTMT

iv)                 Then click finish.

eclipse

leak1

leak2

So from the screenshot above, when the trace heap-file was analysed, com.rsa.sslj.xcu was seen to be consuming over 75.81% of memory heap. I had already been combing the internet and doing Bug-scrubs on Cisco’s Bug Tool Kit so I was sure I had hit bug CSCty36110

 

I double checked the bug’s details (screenshot below) at Cisco’s website and it confirmed my conclusion. It stated that if I see ‘com.rsa.sslj.x.cu’ as being the major cause of the Tomcat Crash when analyzing the trace, I should know that I am hitting bug CSCty36110.

It was at this point that I recommended an upgrade of CUCM to version 8.6.2.22900.9 as it is a version that has the fix

Another case had been seen to its end and I was relaxed.

 

toolkit

 


If you are visiting for the first time then I would like to say welcome to Voice Initiate. It is a place where experiences are shared and discussed.  As we all know, working in technology is all about being introduced to new things on an almost daily basis. For me, it’s like being in a perpetual state of initiation.

If you are reading this blog then I’m sure you can relate when I say that I came into the IP telephony world not knowing that I would have to learn programming too, but working on Contact Centers dictates  that  you must- so retreat was never an option. . . it’s an endless battle but we love it anyway.

This blog is an account of the joys and challenges faced by a Unified Communications NOC Engineer. This is a  place where both failure and success is discussed openly.

Advice and contributions are always welcomed.  My hope is that this blogs brings a sense of thrill to fellow bloggers and initiates alike and a sense of nostalgia to those that have seen the joys and challenges that we now speak of .

Cheers!

maxwell.osagie@yahoo.com

%d bloggers like this: