* 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

Advertisements