Call Forward from CCM issue

[admin_2]

Ok, I already know this is a CCM issue, but has to do with Unity and integration and all of that so I figured I'd throw it out here...<br><br>I have a Unity 3.0.3 box with TSP 3.0.4, CCM 3.1.2c SPB, ES17.<br><br>We are having an issue where a caller dials internally to a phone (only 20 out of over 500 phones are affected, in random number ranges, in random partitions, with random calling search spaces; the only common factors are Unity and CCM servers) which has 2 lines, one in Partition A, one in Partition B. Line 1 has a Busy CFWD to Line 2 and a NA to Voicemail (4200) Line 2 has a CFWD Busy/NA to Unity. Internally everything works great, when line 1 is unanswered I roll into the appropriate box. When I dial this as a DID, the line rings, but when it rolls to VM I get the Opening Greeting (i.e.- No integration) Here the CCM Trace:<br><br>a call to extension 4221 shows the following:<br>04/11/2002 01:29:46.354 Cisco CallManager|<br> StationD: 9371694 <br> CallInfo <br> callingPartyName='No Name Available' <br> callingParty= <br> cgpnVoiceMailbox= <br> calledPartyName='Pat Rollins ' <br> calledParty=4221 <br> cdpnVoiceMailbox=2364221 <br> originalCalledPartyName='Pat Rollins ' <br> originalCalledParty=4221 <br> originalCdpnVoiceMailbox=2364221 <br> originalCdpnRedirectReason=2 <br> lastRedirectingPartyName='Pat Rollins ' <br> lastRedirectingParty=4221 <br> lastRedirectingVoiceMailbox=2364221 <br> lastRedirectingReason=2 <br> callType=3(Forward) <br> lineInstance=1 <br> callReference=33606503<br><br>A call to Extension 4034 however shows:<br>04/11/2002 01:30:36.277 Cisco CallManager|<br> StationD: 9371694 <br> CallInfo <br> callingPartyName='No Name Available' <br> callingParty= cgpnVoiceMailbox= <br> calledPartyName='Voicemail' <br> calledParty=4034 <br> cdpnVoiceMailbox= <br> originalCalledPartyName='Voicemail' <br> originalCalledParty=4034 <br> originalCdpnVoiceMailbox= <br> originalCdpnRedirectReason=0 <br> lastRedirectingPartyName='Voicemail' <br> lastRedirectingParty=4200 <br> lastRedirectingVoiceMailbox= <br> lastRedirectingReason=2 <br> callType=3(Forward) <br> lineInstance=1 <br> callReference=33606510<br><br>Obviously the missing "cdpnVoiceMailbox" value is causing the problem but when I look at CCMAdmin I can see the correct VMBox listed, and I can look at the SQL dbase and see it there as well and it is all correct.<br><br>TAC has been looking at this, but their advice is to reboot the CCM servers, and I would like to know if anyone has run into this before? I am trying to think of what the root cause could be. Any ideas out there?<br><br>

[#2]

After an upgrade to Unity 3.1.3a this problem is still occurring. I could really use any/all opinions as TAC is apparently baffled by this behavior. Scenario in brief, on a 2 line 7940, line 1 is in partition 1, with CFWD N/A to Unity with CSS_Internal1 (All internal partitions) line 2 is in partition 2, with CFWD Busy/NA to Unity with CSS_Internal1 also.
When an EXTERNAL caller dials the DID of the phone and are FWD to Unity they receive the opening greeting. When line 1 is in use and they are FWD from line 2, they reach the correct subscriber box. Both lines have the same Voicemail box configured in CCM, and both use the same CSS to reach Unity. More details are in the original post.

Thanks.

[#3]

Here's a capture from the Call Viewer Utility:

"1","Internal","Direct","0","2","4069"," "," "
"2","Internal","Fwd(Unconditional)","0","2","2364069","6001","2364069"
"3","Internal","Fwd(Unconditional)","0","2","2364069","2364322","2364069"

Call 1 was the call from the PSTN (did not integrate); Call 2 was from an ICT (did integrate properly); Call 3 was from a phone on-cluster (did integrate properly)

I tried changing the Extension of the MBox to just 4069 instead of 2364069, and that had no effect on the issue.

I also tried leaving the extension as 2364069 and adding an alternate extension of 4069, but that didn't help either.

I see that it appears to be a direct call to Vmail but the strange thing is that if I CallFWD/All line1 to line2, and the calls forward that way to Unity on a B/NA, it integrates properly, which is fine for the 2 line 7940's and 60's as a workaround, but the 7910's are out of luck at this point. There are about 50 out of 400 users being affected by this issue. Some are deci$ion makers so I need to fix this.

Thanks all

[#4]

SkinnyTSP traces would help, but they are probably only going to show that the call info was not sent. I'd think that maybe some detailed CCM traces would shed some light. If you need some help isolating Unity as the culprit, I can help out. It sounds like that has already been done.

Steve Olivier
Software Engineer
Cisco Systems

[#5]

Here's what the TSP trace shows:

09:31:49:671,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationDisplayText: 4200
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationCallStateMessage: callState = 4 (RingIn) lineInstance = 1 callReference = 33604119
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationCallInfoMessage Size = 376 (2.4 = 132; 3.0 = 208; 3.1 = 376)
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] StationCallInfoMessage: CalledID = 4069 CallerID = nCallType = 3 (ForwardCall)
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] More CallInfo: CalledVM = CallerVM = RedirectReason = 0 (NotForwarded)
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] CallInfo Names: CalledName = Voicemail CallerName = No Name Available
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Bogus Forwarded Call from a VoiceMail Port Detected: Changing CallType to Direct
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationSetLampMessage: stimulus = 9 (Line) stimulusInstance = 1 lampMode = 5 (LampBlink)
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationDisplayNotify - IGNORED
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationDisplayPromptStatus - IGNORED
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A4] [Device 5] Incoming Skinny Message: StationSelectSoftKeys - IGNORED
09:31:49:875,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,26,[Thread 0x000010A4] [Device 5] CAvTapiCallHandler::SendNewCall: hdCall 10917 on Original call
09:31:49:876,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,26,[Thread 0x000010A4] [Device 5] CAvTapiCallHandler::SendCallState: dwCallState 00000002 (LINECALLSTATE_OFFERING) dwCallStateMode 00000000 on Original call (Prev CallState 00000001)

----------

Here's one that looks like it integrated properly from an internal phone:

13:59:20:890,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationClearNotify - IGNORED
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationSetRingerMessage: ringMode = 1 - IGNORED
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationSetLampMessage: stimulus = 9 (Line) stimulusInstance = 1 lampMode = 2 (LampOn)
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationCallStateMessage: callState = 1 (OffHook) lineInstance = 1 callReference = 33609753
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationActivateCallPane - IGNORED
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationStopToneMessage
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationOpenReceiveChannelMessage: ms = 20 compressionType = 11
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationStopToneMessage
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationCallStateMessage: callState = 5 (Connected) lineInstance = 1 callReference = 33609753
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationCallInfoMessage Size = 376 (2.4 = 132; 3.0 = 208; 3.1 = 376)
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] StationCallInfoMessage: CalledID = 4069 CallerID = 4322 nCallType = 1 (InBoundCall)
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] More CallInfo: CalledVM = 2364069 CallerVM = 2364322 RedirectReason = 15 (ForwardAll)
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] CallInfo Names: CalledName = Diane Junes CallerName = CIT Test
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationSelectSoftKeys - IGNORED
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationDisplayPromptStatus - IGNORED
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,12,[Thread 0x000010A8] [Device 6] Incoming Skinny Message: StationStartMediaTransmission: multicastIpAddr = 23FC100A multicastPortNumber = 0000634A milisecondPacketSize = 20 compressionType = 11
13:59:21:016,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,26,[Thread 0x000010A8] [Device 6] CAvTapiCallHandler::SendCallState: dwCallState 00000100 (LINECALLSTATE_CONNECTED) dwCallStateMode 00000000 on Original call (Prev CallState 00000002)
13:59:21:015,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,11,[Thread 0x0000198C] [Device 6] TSPI_lineMonitorDigits hdCall 12929 dwDigitModes 2
13:59:21:203,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,11,[Thread 0x00000A38] [Device 6] TSPI_lineGetCallStatus hdCall 12929
13:59:21:204,AvCiscoTsp_MC,114,-1,-1,SkinnyTSP,26,[Thread 0x00000A38] [Device 6] CAvTapiLine::GetCallState: dwCallState 00000100 (LINECALLSTATE_CONNECTED)

[#6]

Forgive me, but now I am a little confused. Is 4069 a DN of any Unity voice mail port? The TSP thinks that it is.

Steve Olivier
Software Engineer
Cisco Systems

[#7]

No, 4060 is not a DN of a VM port anywhere in the system. The DN for Port 1 of Unity is 4220, the rest of the DN's are in the 6XXX range.

4060 is the line number of one of the affected phones.
2364060 is the VMBox number of that line.

The big Q is/Q's are:

Why is Unity not seeing the integration properly?
Why is this ONLY happening from PSTN Calls that hit the phone on partition1 (Internal and WAN calls as well as PSTN calls that hit line2 integrate properly)?

We have eliminated the 6608 gateway these come in on, as the problem is also affecting DID's that are coming in on a 3640.

[#8]

I was actually asking about 4069, but still it looks weird. Let me check into the TSP code a bit on Thursday morning. I know that the TSP used to look at the called number and if that called number matched a known TSP port DN (known by a request that is sent to CCM from the TSP after registration), then the call would be marked as direct. We had to do this if some one directly called port 1, port 1 was busy and it forwarded to port 2.

At any rate, It would also be helpful to get a look at TSP traces at intialization time (restarting Unity). If that is something that can be done, let me know. I can take a look at those traces. I'm concerned as to why the TSP thinks the call was forwarded from another one of its busy ports if 4069 is not a VM DN.

Steve Olivier
Software Engineer
Cisco Systems

[#9]

If you don't get many answsers here, you might try your luck at this forum http://www.cisco.com/go/netpro/

There's probably more CCM folks cruising that forum than here.

Steve Olivier
Software Engineer
Cisco Systems