Troubleshooting the Message Waiting Indicator

The message waiting indicator (MWI) is one of the most important and basic features of any voice mail system. Sometimes, because of many factors, the subscriber does not see the correct MWI changes on the phone. This could be because somehow Cisco CME and Cisco UE got out of sync with each other concerning the MWI status for subscribers. (For example, perhaps Cisco CME was reloaded and it does not keep track of MWI state across reloads.) This section discusses MWI configuration and troubleshooting MWI-related issues.

MWI Operation

With Cisco CME deployments, Cisco UE uses what is called a callout mechanism to change MWI status on the phone. In this mechanism, Cisco CME defines two special extensions: the MWI ON and MWI OFF DNs. These extension definitions have a very specific number format.

For example, the pattern can be 2222.... for the MWI ON DN and 2221.... for the MWI OFF DN, where 2222 and 2221 are prefixes, and the number of dots is equal to the length of the extensions in your Cisco CME dial plan. If Cisco UE must turn on MWI for extension 6001, it places an outgoing call to number 22226001. Cisco CME terminates the call on the MWI ON DN (because the called number matches the dial peer for the MWI ON DN). Cisco CME processes the called number of the call and extracts extension 6001 from it, which is matched by the four dots defined on the MWI ON DN. It then finds all the phones with appearances of extension 6001 on them (there can be several if 6001 is a shared line), and then sends an SCCP MWI ON message to each of the phones. A similar sequence of steps is followed to turn off an MWI lamp by Cisco UE outcalling to the MWI OFF DN. For example, 22216001 is used to turn off MWI for extension 6001.

You can test the operation of your MWI DNs on Cisco CME by dialing the MWI DN prefix followed by the extension from any phone. For example, if you dial 22226001 from any phone, you should see the MWI light activated on phones with extension 6001. This verifies that your MWI DNs are correctly configured and operational.

When you choose the patterns for MWI DNs, keep in mind that such a pattern must not overlap with any other extension or dial peer patterns configured on Cisco CME. Those configurations can interfere with the MWI calls that come from Cisco UE, effectively breaking MWI operation. Also look for any Cisco IOS translation rules that might translate the called numbers for the MWI DN call. This also breaks the MWI operation.

Now that you understand the mechanism between Cisco CME and Cisco UE for turning MWI on or off, the next step is to investigate what happens inside the Cisco UE software components to affect MWI when a voice message is left in or deleted from a mailbox.

When a new message is left in a mailbox, or a subscriber deletes the last new message in the mailbox, the voice mail system has to change the MWI state on the subscriber's phone. However, the voice mail back-end component does not have access to any call control mechanism to place the outcall to Cisco CME. Instead, it depends on the CRS component, which contains a SIP stack for call control. However, there is no direct interface between the voice mail back end and the CRS component.

The CRS component, as discussed in Chapter 3, can start applications on three kinds of triggers:

To affect MWI changes, the voice mail system (internally) sends an HTTP trigger to the CRS software. A system-level CRS application called ciscomwiapplication, with an associated script called setMWI.aef, exists and is configured to respond to this HTTP request.

When voice mail sends an HTTP request specifying the extension for MWI operation and the state to be set (ON or OFF), this CRS application starts up and places a call to the appropriate Cisco CME MWI ON or OFF DN using the parameters passed.

Verifying MWI Configuration

For MWI to work correctly, it is important that the configurations on Cisco CME and Cisco UE are correct and match. To verify the configuration, use the commands shown in Example 21-49.

Example 21-49. MWI DN Configuration

ccme#show telephony-service ephone-dn ephone-dn 20 number 7701 preference 0 secondary 9 huntstop call-forward busy 5800 call-forward noan 5800 timeout 10 hold-alert 30 originator ephone-dn 21 number 7010 preference 0 secondary 9 huntstop ephone-dn 22 number 7011 preference 0 secondary 9 huntstop call-forward busy 5800 call-forward noan 5800 timeout 10 ephone-dn 23 number 7012 preference 0 secondary 9 huntstop ephone-dn 50 number 2222.... preference 0 secondary 9 huntstop mwi on ephone-dn 51 number 2221.... preference 0 secondary 9 huntstop mwi off ephone-dn 61 number 6001 preference 0 secondary 9 huntstop call-forward all 5800 call-forward busy 5800 call-forward noan 5800 timeout 10

On Cisco UE, ensure that the ciscomwiapplication CRS application is created and configured properly, as shown in Example 21-50.

Example 21-50. MWI Application Configuration on Cisco UE

cue#show ccn application Name: ciscomwiapplication Description: ciscomwiapplication Script: setmwi.aef ID number: 0 Enabled: yes Maximum number of sessions: 1 strMWI_OFF_DN: 2221 strMWI_ON_DN: 2222 CallControlGroupID: 0 Name: voicemail Description: voicemail Script: voicebrowser.aef ID number: 1 Enabled: yes Maximum number of sessions: 1 logoutUri: http://localhost/voicemail/vxmlscripts/m bxLogout.jsp uri: http://localhost/voicemail/vxmlscripts/l ogin.vxml Name: autoattendant Description: autoattendant Script: aa.aef ID number: 2 Enabled: yes Maximum number of sessions: 1 MaxRetry: 3 operExtn: 7701 welcomePrompt: AAWelcome.wav Name: promptmgmt Description: promptmgmt Script: promptmgmt.aef ID number: 3 Enabled: yes Maximum number of sessions: 1

You can also verify the current MWI DN settings in the Cisco UE sysDB settings, as shown in Example 21-51. Note that in the output of both the Cisco UE show ccn application (Example 21-50) and show sysdb (Example 21-51) commands, MWI DNs appear without the dots. This does not mean that they are without dots on Cisco CME. (See the output of the show telephony-service ephone-dn command shown earlier in Example 21-49.)

Example 21-51. Verifying MWI DN Configuration on Cisco UE in sysDB

cue#show sysdb /sw/apps/ccn/wf/applications/craAesop/applications/ ciscomwiapplication app/applicationId 0 app/applicationType Cisco Script Application app/description ciscomwiapplication app/enabled 1 app/maxSessions 8 app/script setmwi.aef app/aeAccess 0 app/aeEnd 1 cfgVars/strMWI_OFF_DN 2221 cfgVars/strMWI_ON_DN 2222 cfgVars/CallControlGroupID 0 cfgVarsType/strMWI_OFF_DN java.lang.String cfgVarsType/strMWI_ON_DN java.lang.String cfgVarsType/CallControlGroupID java.lang.Integer

There can be some inconsistency between the Cisco CME and Cisco UE MWI DN configurations if the Cisco CME configuration is changed directly through the Cisco CME GUI or via Cisco IOS CLI. If you see that an inconsistency exists, synchronize both configurations. You can achieve this by navigating to the Administration > Synchronize Information screen in the GUI, as shown in Figure 21-6.

Figure 21-6. Synchronizing MWI Information

If there are any inconsistencies between the Cisco CME and Cisco UE configurations with respect to MWI DNs or other fields, these are listed on the Administration > Synchronize Information page. You must synchronize the information on this screen for the MWI mechanism to work correctly. After you synchronize the information, the MWIs are not automatically refreshed at that time.

You can refresh the MWI states on subscribers' phones in two ways:

You can perform both operations via the GUI by navigating to the Voice Mail > Message Waiting Indicators > Refresh screen.

Note

Cisco UE sends an MWI update every time there is a new message in a subscriber's mailbox, not just when there is a state change in a mailbox. Also, Cisco UE does not have the capability to synchronize MWI states automatically at a configured time (or midnight routines), so manual synchronization is a must in case the states get out of synchronization.

One other configuration that can affect MWI operation is the SIP gateway address configuration in Cisco UE. This should point to the Cisco CME with which Cisco UE is integrated. You can verify this setting by using the show ccn subsystem sip Cisco UE CLI command.

Tracing MWI

This section investigates which traces to turn on to troubleshoot MWI-related problems, as well as how to interpret the traces to verify that all the subsystems involved in MWI operation are working correctly. The following trace commands are used to troubleshoot problems in this area:

In the traces shown in Example 21-52, extension 5010 has received a new voice message, so the voice mail system sets the MWI state for this extension to true (the ON state). This action by the voice mail system results in an HTTP trigger being sent to the CRS software component, as discussed in the previous sections. In the third line in Example 21-52, you can see the HTTP message going to port 8080, passing the extension number (5010 in this example) and the desired state of the MWI (1 for ON).

Example 21-52. Voice Mail Back End Sends an HTTP Trigger to Turn on MWI

cue#show trace buffer tail 2487 10/01 14:26:54.309 voicemail mwi "setMessageWaiting" 0x0000000000000000 5010, true 2487 10/01 14:26:54.309 voicemail mwi " job state" adding job 1792 10/01 14:26:54.309 voicemail mwi "job state" http://localhost: 8080/ mwiapp?extn=5010&state=1 2317 10/01 14:26:54.316 ACCN APMG 0 TASK_CREATED:Application task created: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Application Trigger=ContactApplicationTrigger[time=1065018436314,contact=HttpContact[id=54, type=Cisco Http Contact,implId=null,active=true,state=CONTACT_RECEIVED, inbound=true,handled=false, locale=en_US,aborting=false,app=App[name=ciscomwiapplication,type=Cisco Script Application,id=0,desc=ciscomwiapplication,enabled=true,max=8,valid=true, optional=[cfgVars=[Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script= setmwi.aef]],task=null,session=null,seqNum=-1,time=1065018436314,req=org.apache. tomcat.facade.HttpServletRequestFacade@7ce36091]],Task id=16,000,000,031,Task Class=com.cisco.wfframework.engine.core.WFEngineWorkflowDebugTask,New Task Class=com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper 2317 10/01 14:26:54.317 ACCN APMG 0 APP_SESSION_ACTIVE:Active application session: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Application Trigger=ContactApplicationTrigger[time=1065018436314,contact=HttpContact[id=54, type=Cisco Http

As shown in the preceding trace, CRS starts its outcalling application in response to the HTTP trigger received from the voice mail component. Example 21-53.is the step-by-step trace of the CRS application executing this operation.

Example 21-53. MWI Application Starts Executing as a Result of the HTTP Trigger

cue#show trace buffer tail 2317 10/01 14:26:54.318 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=0,Step Class=com.cisco.wfframework.steps.core. StepStart,Step Description=Start 2317 10/01 14:26:54.319 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=1,Step Class=com.cisco.wf.steps.ivr.AcceptStep,Step Description=Accept (contact: --Triggering Contact--) 2317 10/01 14:26:54.319 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=111,Step Class=com.cisco.wf.steps.http. GetHttpHeaderStep,Step Description=Get Http Contact Info (contact: --Triggering Contact--) 2317 10/01 14:26:54.320 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=142,Step Class=com.cisco.wfframework.steps.core. StepIf,Step Description=If ( mwistatus != "0" ) Then 2317 10/01 14:26:54.320 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=143,Step Class=com.cisco.wfframework.steps.core. StepAssign,Step Description=Set strMWI_DN = strMWI_ON_DN 2317 10/01 14:26:54.321 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=144,Step Class=com.cisco.wfframework.steps.core. StepAssign,Step Description=Set mwiOn = true 2317 10/01 14:26:54.321 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=78,Step Class=com.cisco.wfframework.steps.core.StepIf, Step Description=If ( mwistatus != "" ) Then 2317 10/01 14:26:54.322 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=83,Step Class=com.cisco.wfframework.steps.core.StepIf, Step Description=If ( strDeviceNum != "" ) Then 2317 10/01 14:26:54.322 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=84,Step Class=com.cisco.wfframework.steps.core. StepAssign,Step Description=Set strMWI_CompleteNum = strMWI_DN + strDeviceNum 2317 10/01 14:26:54.322 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=189,Step Class=com.cisco.wf.steps.ivr.MWIStep,Step Description=Set Message Waiting Indicator (DN: strDeviceNum) 2317 10/01 14:26:54.323 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=193,Step Class=com.cisco.wfframework.steps.core. StepComment,Step Description=/* Don't return fail since ... */ 2317 10/01 14:26:54.323 ACCN APMG 0 EXECUTING_STEP:Executing a step: Application=App[name=ciscomwiapplication,type=Cisco Script Application,id=0, desc=ciscomwiapplication,enabled=true,max=8,valid=true,optional=[cfgVars= [Lcom.cisco.wfapi.util.WFNameValuePair;@6786a090,script=setmwi.aef]],Task id=16,000,000,031,Step id=175,Step Class=com.cisco.wf.steps.ivr.CreateCallStep, Step Description=Place Call (to strMWI_CompleteNum ) 2317 10/01 14:26:54.329 ACCN SIPL 0 --- send message --- to 1.3.6.29:5060

As a result of the last step, which sets up a call to the value contained in strMWI_CompleteNum, you can see in the traces shown in Example 21-54 that a SIP INVITE message is sent from Cisco UE to Cisco CME to change the state of the MWI lamp.

Example 21-54. Application Execution Results in a SIP Outcall to Cisco CME

cue#trace ccn stacksip dbug cue#show trace buffer tail INVITE sip:22225010@1.3.6.29;user=phone SIP/2.0 Via: SIP/2.0/UDP 1.3.6.129:5060 From: "Cisco SIP Channel5" ;tag=5bed1e99-272 To: Call-ID: c91b8616-270@1.3.6.129:5060 CSeq: 51 INVITE Contact: sip:outbound-0@1.3.6.129:5060 User-Agent: Jasmin UA / ver 1.1 Accept: application/sdp Content-Type: application/sdp Content-Length: 216 v=0 o=CiscoSystemsSIP-Workflow-App-UserAgent 2792 2792 IN IP4 1.3.6.129 s=SIP Call c=IN IP4 1.3.6.129 t=0 0 m=audio 16906 RTP/AVP 0 111 a=rtpmap:0 pcmu/8000 a=rtpmap:111 telephone-event/8000 a=fmtp:111 0-11 2272 10/01 14:26:54.335 ACCN SIPL 0 receive 357 from 1.3.6.29:5060 2273 10/01 14:26:54.336 ACCN SIPL 0 not found header for Date 2273 10/01 14:26:54.336 ACCN SIPL 0 not found header for Allow-Events 2273 10/01 14:26:54.336 ACCN SIPL 0 ------- SIP/2.0 100 Trying Via: SIP/2.0/UDP 1.3.6.129:5060 From: "Cisco SIP Channel5" ;tag=5bed1e99-272 To: ;tag=EFCE8-E51 Date: Fri, 01 Mar 2002 00:16:22 GMT Call-ID: c91b8616-270@1.3.6.129:5060 Server: Cisco-SIPGateway/IOS-12.x CSeq: 51 INVITE Allow-Events: telephone-event Content-Length: 0

In the traces shown in Example 21-55, Cisco CME sends a 1 "80 Ringing" message to Cisco UE, indicating that the call terminated on a valid MWI DN and that the MWI request is being processed.

Example 21-55. MWI Call Goes to Alerting State and Disconnects

cue#trace ccn stacksip dbug cue#show trace buffer tail SIP/2.0 180 Ringing Via: SIP/2.0/UDP 1.3.6.129:5060 From: "Cisco SIP Channel5" ;tag=5bed1e99-272 To: ;tag=EFCE8-E51 Date: Fri, 01 Mar 2002 00:16:22 GMT Call-ID: c91b8616-270@1.3.6.129:5060 Server: Cisco-SIPGateway/IOS-12.x CSeq: 51 INVITE Allow: UPDATE Allow-Events: telephone-event Contact: Content-Length: 0 ......... CANCEL sip:22225010@1.3.6.29;user=phone SIP/2.0 Via: SIP/2.0/UDP 1.3.6.129:5060 From: :"Cisco SIP Channel5" ;tag=5bed1e99-272 To: Call-ID: c91b8616-270@1.3.6.129:5060 CSeq: 51 CANCEL Max-Forwards: 50 Content-Length: 0

At this point, Cisco UE has finished notifying Cisco CME about a change in MWI status. It is now the responsibility of the Cisco CME call control software to complete the MWI notification to the IP phone to turn the lamp on or off. To troubleshoot this portion of the transaction, turn on the debug ephone mwi or debug ephone detail traces in Cisco IOS software. The traces in Example 21-56 show the SCCP messages sent by Cisco CME to the phone(s) for turning MWI on and off.

Example 21-56. SIP Outcall from Cisco UE Results in an SCCP MWI Message to the IP Phone

ccme#debug ephone state ccme#debug ephone mwi ............ Jun 11 05:51:57.663: calling [private] called [22225010] Jun 11 05:51:57.663: SkinnyTryCall to 5010 instance 1 start at 0SkinnyTryCall to 5010 instance 1 match DN 1 Jun 11 05:51:57.663: Phone 0 DN 1 MWI on 0 messages Jun 11 05:51:57.667: ephone-1[1]:Set MWI line 1 to ON count 0 Jun 11 05:51:57.667: ephone-1[1]:Set MWI line 0 to ON count 0 Jun 11 05:51:57.667: UpdateCallState DN 10 chan 1 operating in mode 1 Jun 11 05:52:01.874: ephone-1[1]:ONHOOK (internal) Jun 11 05:52:01.874: ephone-1[1]:call clean up this DN 1 chan 1 was calling other DN -1 chan 1 Jun 11 05:52:01.874: this ephone-1 other ephone-(-1) other DN state UNKNOWN Jun 11 05:52:01.878: ephone-1[1]:CloseReceive Jun 11 05:52:01.878: ephone-1[1]:StopMedia Jun 11 05:52:01.878: DN 1 chan 1 End Voice_Mode Jun 11 05:52:01.878: ephone-1[1]:SetCallState line 1 DN 1 chan 1 ref 13 TsOnHook Jun 11 05:52:01.882: ephone-1[1]:SpeakerPhoneOnHook Jun 11 05:52:01.886: ephone-1[1]:SpeakerPhoneOnHook

Troubleshooting Voice Mail VPIM Networking
Related

Категории