Troubleshooting the TUI and VXML Browser

The main interface used to interact with a voice mail system such as Cisco UE is the Telephony User Interface (TUI). When a call arrives at a voice mail system, the system starts playing specific prompts depending on the call type (for example, an external caller, a subscriber, or a call forwarded into voice mail). To interact with the system, the user presses DTMF digits on his phone's keypad, and the voice mail system responds by playing more prompts until the end of the session. This is implemented using a Voice Extensible Markup Language (VXML) browser, also called a voice browser. Think of the voice browser as a web browser that fetches VXML scripts instead of HTML pages over HTTP. VXML is mainly used for voice-based interactive systems such as interactive voice response (IVR) and voice mail. In Cisco UE, the voice browser fetches VXML scripts over HTTP from an internal web server and interprets them to implement the TUI. The Tomcat web server uses Java Server Pages (JSP) to query the voice mail back-end databases to build VXML scripts, depending on the call information and subscriber's mailbox properties.

Sometimes it may be necessary to troubleshoot this aspect of the caller voice mail system interaction, because the caller might hear unexpected prompts or no prompts at all after pressing a digit. When this situation occurs, it is quite possible that the digit pressed on the phone (and translated to a SIP NOTIFY message) did not reach the CRS application or the voice browser software components of the Cisco UE voice mail application.

To understand what is happening if this situation arises, it is useful to troubleshoot the voice browser's operation. It is very difficult to be specific about common problems encountered in this area, so instead this section uses an example of an active TUI session to Cisco UE and discusses the salient aspects of the trace output. Showing how the TUI session should work helps you understand how to troubleshoot any problem that might arise in this area.

You can use the same tracing techniques to troubleshoot any issues with response time for DTMF from the voice mail system. For example, if you feel that the voice mail system's response to DTMF digits pressed on a phone is too slow, you can view the response time in these traces. Look at the time stamp at which the digit arrives at the voice mail application and the time stamp at which the next prompt is played. A large delay between the two time stamps might point to a performance issue on the Cisco UE system.

Example 21-24 shows a voice browser trace for a call forwarded to Cisco UE voice mail. You can use task ID (Task:18000000082, in this case) to differentiate between multiple simultaneous calls. This task ID is generated from the CRS Workflow infrastructure. As discussed in the preceding section, the calling, called, and original called numbers are important for the proper functioning of voice mail. Because voice mail is implemented using a VXML voice browser software component, these Call Information fields have to be passed to the voice browser. As you can see in the voice browser trace in Example 21-24, the voice browser receives all these Call Information fields.

Example 21-24. Start of Voice Browser Traces

cue#trace ccn vbroswercore dbug
cue#show trace buffer tail
2702 10/10 12:31:10.338 ACCN VBRW 0 Task:18000000082 Here is the
 DefaultCompilationConfig set in the JVM en_US
2702 10/10 12:31:10.338 ACCN VBRW 0 Task:18000000082 DefaultCompilationConfig will
 be set to en_US
2702 10/10 12:31:10.338 ACCN VBRW 0 Task:18000000082 DefaultCompilationConfig is
 now set to JVM en_US
2702 10/10 12:31:10.341 ACCN VBRW 0 Task:18000000082 enterLevel: SESSION_LEVEL
2702 10/10 12:31:10.341 ACCN VBRW 0 callContact.getSessionID() = 5000000007
2702 10/10 12:31:10.341 ACCN VBRW 0 Task:18000000082 VoiceBrowser sessionid:
 5000000007, taskid: 18000000082
2702 10/10 12:31:10.341 ACCN VBRW 0 callContact.getCallingNumber() = 6003 
2702 10/10 12:31:10.341 ACCN VBRW 0 callContact.getDNIS() = null
2702 10/10 12:31:10.341 ACCN VBRW 0 callContact.getDNIS() = null
2702 10/10 12:31:10.341 ACCN VBRW 0 callContact.getCalledNumber() = 5800 
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getANIIIDigits() = null
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getUserToUserInfo() = null
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getRDNIS() = null

The first trace line shown in Example 21-25 is important, especially when calls are forwarded into voice mail. The LastRedirectingNumber field comes into play when a call to an extension on Cisco CME is forwarded on busy or no-answer to voice mail. This identifies the original extension dialed and, hence, is the extension associated with the mailbox for which this message must be left.

If a value for the callContact.getLastRedirectedNumber() field is present in the trace, you can safely assume that this was a forwarded call and not a direct call to voice mail. This is shown in Example 21-25.

Example 21-25. Voice Browser Trace Showing the Last Redirected Number

cue#show trace buffer tail
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getLastRedirectedNumber() = 5010 
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getRDNIS() = null
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getLastRedirectedNumber() = 5010
2702 10/10 12:31:10.342 ACCN VBRW 0 callContact.getSessionID() = 5000000007
2702 10/10 12:31:10.348 ACCN VBRW 0 Task:18000000082 VBContext::pushLang language
 = en_US
2702 10/10 12:31:10.348 ACCN VBRW 0 Task:18000000082 VBContext::pushLang Adding
 new language : en_US
2702 10/10 12:31:10.348 ACCN VBRW 0 Task:18000000082

After processing the call information, the voice browser starts the first VXML script, login.vxml, which is the top-level login script for the voice mail system. Depending on the type of call, either the external caller login script (if it is a forwarded call, the script to leave a message is executed) or the subscriber login script (if it is a direct call, the user is asked to identify himself) is executed next, as shown in Example 21-26.

Example 21-26. Voice Browser Executing a Login Script

cue#show trace buffer tail
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082
 VoiceBrowser.invokeApplication(level:0): [URI=http://localhost/voicemail/ 
 vxmlscripts/login.vxml fragment=null] 
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082 enterScope: application
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082 enterLevel: APPLICATION_LEVEL
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082 Got document:
 http://localhost/voicemail/vxmlscripts/login.vxml from cache.
............
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082 enterLevel: APPLICATION_LEVEL
2702 10/10 12:31:10.349 ACCN VBRW 0 Task:18000000082
 VoiceBrowser.invokeRootDocument: [URI=http://localhost/voicemail/vxmlscripts/
 systemLangID.jsp fragment=null]
2702 10/10 12:31:10.357 ACCN VBRW 0 Task:18000000082 Fetch: HTTP 200 OK
2702 10/10 12:31:10.357 ACCN VBRW 0 Task:18000000082 Fetch: HTTP Response is not
 from Cache
2702 10/10 12:31:10.358 ACCN VBRW 0 Task:18000000082 Browser:
 com.cisco.voicebrowser.browser.CookieSet@3df95571: 1 cookies:
 JSESSIONID=mqh3bxs2a1;Path=/voicemail;Domain=localhost
2702 10/10 12:31:10.358 ACCN VBRW 0 Task:18000000082 Successfully fetched bytes:
 239, duration(s): 0.0090, URI: http://localhost/voicemail/vxmlscripts/
 systemLangID.jsp

This call is a forwarded call, so the caller login script to leave a message in a mailbox is executed. This interchange is shown in Example 21-27.

Example 21-27. Caller Login Script Is Executed for a Forwarded Call

cue#show trace buffer tail
2702 10/10 12:31:10.389 ACCN VBRW 0 Task:18000000082 VoiceDomTraverser:
 handleElementBlock(): is called
2702 10/10 12:31:10.390 ACCN VBRW 0 Task:18000000082  destination: 
 [URI=http://localhost/voicemail/vxmlscripts/caller_login.vxml fragment=null] 
2702 10/10 12:31:10.391 ACCN VBRW 0 Task:18000000082 Got document:
 http://localhost/voicemail/vxmlscripts/caller_login.vxml from cache.
2702 10/10 12:31:10.391 ACCN VBRW 0 Task:18000000082 exitScope: anonymous
2702 10/10 12:31:10.391 ACCN VBRW 0 Task:18000000082 exitLevel: FIELD_LEVEL
2702 10/10 12:31:10.391 ACCN VBRW 0 Task:18000000082 exitLevel: DIALOG_LEVEL
2702 10/10 12:31:10.391 ACCN VBRW 0 Task:18000000082 Form context:
 check_pin_status=not defined
 _block1001="_defined"
 validate_id=not defined
 _block1000="_defined"

Because this is a forwarded call originally directed to extension 5010, the voice mail application must ensure that extension 5010 has a mailbox in this system. It verifies this by executing extValidation.jsp, as shown in Example 21-28.

Example 21-28. Voice Browser Executes JSP to Validate the Extension

cue#show trace buffer tail
2702 10/10 12:31:10.401 ACCN VBRW 0 Task:18000000082 Invoke subdialog[mbox_check]
 [URI=http://localhost/voicemail/vxmlscripts/extValidation.jsp fragment=null]
 Params: null
2702 10/10 12:31:10.401 ACCN VBRW 0 Task:18000000082 VBContext.pushContext level:1
2702 10/10 12:31:10.401 ACCN VBRW 0 Task:18000000082
 VoiceBrowser.invokeApplication(level:1): 
 [URI=http://localhost/voicemail/vxmlscripts/extValidation.jsp fragment=null] 
2702 10/10 12:31:10.402 ACCN VBRW 0 Task:18000000082 enterScope: application
2702 10/10 12:31:10.402 ACCN VBRW 0 Task:18000000082 enterLevel: APPLICATION_LEVEL
2702 10/10 12:31:10.420 ACCN VBRW 0 Task:18000000082 Fetch: HTTP 200 OK
2702 10/10 12:31:10.421 ACCN VBRW 0 Task:18000000082 Successfully fetched bytes:
 815, duration(s): 0.019, URI: http://localhost/voicemail/vxmlscripts/
 extValidation.jsp
2702 10/10 12:31:10.423 ACCN VBRW 0 Task:18000000082 exitLevel: APPLICATION_LEVEL
2702 10/10 12:31:10.424 ACCN VBRW 0 Task:18000000082 exitScope: application
2702 10/10 12:31:10.424 ACCN VBRW 0 Task:18000000082 enterScope: application
2702 10/10 12:31:10.424 ACCN VBRW 0 Task:18000000082 enterLevel: APPLICATION_LEVEL
2702 10/10 12:31:10.424 ACCN VBRW 0 Task:18000000082 enterScope: document
2702 10/10 12:31:10.425 ACCN VBRW 0 Task:18000000082 enterLevel: DOCUMENT_LEVEL
2702 10/10 12:31:10.425 ACCN VBRW 0 Task:18000000082 traverseDocument:
 http://localhost/voicemail/vxmlscripts/extValidation.jsp
 base=http://localhost/voicemail/vxmlscripts/extValidation.jsp
2702 10/10 12:31:10.425 ACCN VBRW 0 Task:18000000082
 VoiceDomParser:handleMetaElement(): - NodeName=meta:NodeValue=null:LocalName=

As you can see from this trace, the voice mail system continues to execute the appropriate JSP, which, in turn, access data from the LDAP and SQL databases to build dynamic VXML scripts and deliver these to the voice browser to execute.

The previous set of trace examples demonstrate the voice browser's operation. Sometimes it is necessary to troubleshoot TUI sessions for some calls. An example is when a caller hears unexpected prompts. You may need to see the DTMF digits the user is pressing and the prompts the voice mail system plays in response.

The following trace examples demonstrate TUI troubleshooting. In the voicemail vxml trace output, you can see a hexadecimal number (0x0000000430e2344f in the trace output). This is the unique call identification (or call ID) from the voice mail system's point of view. It is used to differentiate between multiple simultaneous calls.

This section discusses TUI operation with a sample TUI session where a subscriber logs in and addresses a message to another subscriber. As soon as you understand this example, it is very easy to troubleshoot any other TUI-related situations that might crop up. Use the following commands to troubleshoot these types of issues:

• trace ccn vbrowseroutput dbug
• trace voicemail vxml all
• show trace buffer tail

One tip for using these commands is to clear the trace buffer before troubleshooting (clear trace) and turn off all other traces (no trace all). Then turn on the trace ccn vbrowseroutput dbug and trace voicemail vxml all commands and make the test call. Use the show trace buffer long command to see the trace buffer contents, because this command shows detailed messages about prompts, including the text that is the content of the voice mail prompt. The long format of traces helps you understand the TUI interaction much better. One thing to note while looking at these traces is that voicemail vxml trace output is coming from the voicemail back end running as part of the Tomcat web server, and the trace lines containing VBRO are from the voice browser (client).

When the voice mail system answers a direct (not forwarded) incoming call, the voice browser takes the following actions:

• It starts accessing VXML scripts.
• It checks the default system language (which is only English until Cisco UE release 2.0).
• It validates the extension.
• It asks the user to enter a PIN.

The trace in Example 21-29 shows the output from the voice browser and voice mail VXML scripts. Note that traces come from modules ACCN and voicemail and entities VBRO and VXML, respectively.

Example 21-29. Voice Browser Logs in a Subscriber

cue#show trace buffer tail
2699 10/10 12:23:30.115 ACCN VBRO 0 Task:18000000079 Invoke:
 http://localhost/voicemail/vxmlscripts/login.vxml 
2699 10/10 12:23:30.118 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/systemLangID.jsp
2699 10/10 12:23:30.141 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/extValidation.jsp 
2699 10/10 12:23:30.165 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/checkPinStatus.jsp 

At this point, the voice mail application requests that the prompt AvSubSignInENU002.wav (which contains the phrase "Please enter your password") be played. This is shown in the voicemail vxml trace in Example 21-30.

Example 21-30. VXML Script Requesting That a Prompt Be Played

cue#show trace buffer tail
2699 10/10 12:23:30.234 voicemail vxml "Please enter your password.<1.5 sec 
 silence>" 0x0000000430e2344f AvSubSignInENU002.wav 
2699 10/10 12:23:30.235 ACCN VBRO 0 Task:18000000079 Play: 
 ../prompts/ENU/AvSubSignIn/AvSubSignInENU002.wav 

The DTMF digits pressed by the user are received by the voice browser, as shown in Example 21-31. These digits are delivered by the SIP stack (as discussed earlier, in the section "Troubleshooting DTMFNo Response for Digit Presses from Cisco UE") and CRS infrastructure components to the voice browser. This is another place where you should look for correct processing of digits in a case where voice mail is not responding as expected to digits pressed by a caller. This is to ensure that the digits are indeed reaching the voice browser application component.

Example 21-31. Digits Pressed by the User Are Received by the Voice Browser

cue#show trace buffer tail
2699 10/10 12:23:30.238 ACCN VBRO 0 Task:18000000079 Listen:
2699 10/10 12:23:34.332 ACCN VBRO 0 Task:18000000079 Heard: 'dtmf-2 dtmf-2 
 dtmf-2 dtmf-#' 

At this point, the voice mail system must execute a JSP to validate the caller's password. The interaction between the user and voice mail system continues in this manner until the end of the TUI session. If you are facing any issues with the voice mail TUI (including TUI performance), the traces discussed in this section are the best way to understand which component is not working as expected and why.

Example 21-32 shows the continuation of the direct call. This example shows that the voice mail system has successfully logged in the subscriber.

Example 21-32. Voice Mail System Logs in the User

cue#show trace buffer tail
2699 10/10 12:23:34.337 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/validate_password.jsp 
2699 10/10 12:23:34.416 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/setSubSession.jsp
2699 10/10 12:23:34.430 ACCN VBRO 0 Task:18000000079 Fetch: 
 http://localhost/voicemail/vxmlscripts/playSpokenName.jsp 
2699 10/10 12:23:34.453 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/root.jsp
2699 10/10 12:23:34.617 voicemail vxml "hello." 0x0000000430e2344f
 AvSubMsgCountENU128.wav
2699 10/10 12:23:34.618 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvSubMsgCount/AvSubMsgCountENU128.wav
2699 10/10 12:23:35.023 voicemail vxml "You have no new messages."
 0x0000000430e2344f AvSubMsgCountENU001.wav
2699 10/10 12:23:35.023 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvSubMsgCount/AvSubMsgCountENU001.wav

At this point, the user presses 2 to choose to send a message, as shown in Example 21-33.

Example 21-33. User Chooses to Send a Message

cue#show trace buffer tail
2699 10/10 12:23:35.029 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvSubMenu/AvSubMenuENU006.wav
2699 10/10 12:23:35.030 ACCN VBRO 0 Task:18000000079 Listen:
2699 10/10 12:23:42.340 ACCN VBRO 0 Task:18000000079 Heard: 'dtmf-2' 
2699 10/10 12:23:42.353 voicemail vxml "Spell the name of the person or group."
 0x0000000430e2344f AvAesopCustomENU002.wav
2699 10/10 12:23:42.354 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAesopCustom/AvAesopCustomENU002.wav
2699 10/10 12:23:42.354 voicemail vxml "Spell the last and first name"
 0x0000000430e2344f AvAddrSearchENU005.wav
2699 10/10 12:23:42.355 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAddrSearch/AvAddrSearchENU005.wav
2699 10/10 12:23:42.355 voicemail vxml "For Q, press 7. For Z, press 9."
 0x0000000430e2344f AvAddrSearchENU030.wav
2699 10/10 12:23:42.356 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAddrSearch/AvAddrSearchENU030.wav
2699 10/10 12:23:42.357 voicemail vxml "To switch between spelling and number
 entry, press ##." 0x0000000430e2344f AvAddrSearchENU075.wav
2699 10/10 12:23:42.357 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAddrSearch/AvAddrSearchENU075.wav

The user presses ## to select addressing by extension number, as shown in Example 21-34.

Example 21-34. User Chooses to Dial-by-Extension

cue#show trace buffer tail
2699 10/10 12:23:42.358 ACCN VBRO 0 Task:18000000079 Listen:
2699 10/10 12:23:45.990 ACCN VBRO 0 Task:18000000079 Heard: 'dtmf-#' 
2699 10/10 12:23:45.994 ACCN VBRO 0 Task:18000000079 Listen: 
2699 10/10 12:23:46.251 ACCN VBRO 0 Task:18000000079 Heard: 'dtmf-#' 
2699 10/10 12:23:46.292 ACCN VBRO 0 Task:18000000079 Fetch: 
 http://localhost/voicemail/vxmlscripts/setAddressingMode.jsp 
2699 10/10 12:23:46.305 voicemail vxml "Enter the extension." 0x0000000430e2344f 
 AvAddrSearchENU037.wav 
2699 10/10 12:23:46.305 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAddrSearch/AvAddrSearchENU037.wav
2699 10/10 12:23:46.306 voicemail vxml "To switch between spelling and number
 entry, press ##." 0x0000000430e2344f AvAddrSearchENU075.wav
2699 10/10 12:23:46.306 ACCN VBRO 0 Task:18000000079 Play:
 ../prompts/ENU/AvAddrSearch/AvAddrSearchENU075.wav
2699 10/10 12:23:46.307 ACCN VBRO 0 Task:18000000079 Listen:

The user enters the extension of the recipient mailbox, as shown in Example 21-35.

Example 21-35. User Addresses the Message to an Extension

cue#show trace buffer tail
2699 10/10 12:23:52.081 ACCN VBRO 0 Task:18000000079 Heard: 'dtmf-6 dtmf-0
 dtmf-0 dtmf-1 dtmf-#' 
2699 10/10 12:23:52.111 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/extValidation.jsp 
2699 10/10 12:23:52.136 ACCN VBRO 0 Task:18000000079 Fetch:
 http://localhost/voicemail/vxmlscripts/getAddrParts.jsp 

The user's interaction with the voice mail system continues like this until the end of the call.

Troubleshooting the Database, LDAP, and Mailbox Activities