Call gets disconnected after playing the menu from CVP

John Faust · ‎05-15-2013

Hello,

When I make a call, the call is going to the ICM and then it is coming to the Call server then to the VXML gateway and then it goes to the VXML server and plays the promt.

The problem i am facing is that once the menu audio is played the call gets disconnected. It doesnt let me choose any options. I feel it is not able to identify the my inputs

I have some debug outputs

Mar 1 01:09:03.095: //-1/C113522D805A/CCAPI/cc_api_display_ie_subfields:

cc_api_call_setup_ind_common:

cisco-username=1000

----- ccCallInfo IE subfields -----

cisco-ani=sip:1000@192.168.1.57:5060

cisco-anitype=0

cisco-aniplan=0

cisco-anipi=0

cisco-anisi=1

dest=sip:811123456725@192.168.1.253;transport=udp

cisco-desttype=0

cisco-destplan=0

cisco-rdie=FFFFFFFF

cisco-rdn=

cisco-rdntype=0

cisco-rdnplan=0

cisco-rdnpi=-1

cisco-rdnsi=-1

cisco-redirectreason=-1 fwd_final_type =0

final_redirectNumber =

hunt_group_timeout =0

*Mar 1 01:09:03.103: //-1/C113522D805A/CCAPI/cc_api_call_setup_ind_common:

Interface=0x67213130, Call Info(

Calling Number=sip:1000@192.168.1.57:5060,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

Called Number=sip:811123456725@192.168.1.253;transport=udp(TON=Unknown, NPI=Unknown),

Calling Translated=FALSE, Subscriber Type Str=Un

R1#known, FinalDestinationFlag=TRUE,

Incoming Dial-peer=811, Progress Indication=NULL(0), Calling IE Present=TRUE,

Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=65

*Mar 1 01:09:03.103: //-1/C113522D805A/CCAPI/ccCheckClipClir:

In: Calling Number=sip:1000@192.168.1.57:5060(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Mar 1 01:09:03.103: //-1/C113522D805A/CCAPI/ccCheckClipClir:

Out: Calling Number=sip:1000@192.168.1.57:5060(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Mar 1 01:09:03.103: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar 1 01:09:03.103: :cc_get_feature_vsa malloc success

*Mar 1 01:09:03.103: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar 1 01:09:03.103: cc_get_feature_vsa count is 1

*Mar 1 01:09:03.103: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar 1 01:09:03.103: :FEATURE_VSA attributes are: feature_name:0,feature_time:1732532552,feature_id:23

*Mar 1 01:09:03.103: //65/C113522D805A/CCAPI/cc_api_call_setup_ind_common:

Set Up Event Sent;

Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

Called Number=(TON=Unknown, NPI=Unknown))

*Mar 1 01:09:03.111: //65/C113522D805A/CCAPI/cc_process_call_setup_ind:

Event=0x67452800

*Mar 1 01:09:03.119: //65/C113522D805A/CCAPI/ccCallSetContext:

Context=0x65097114

*Mar 1 01:09:03.119: //65/C113522D805A/CCAPI/cc_process_call_setup_ind:

>>>>CCAPI handed cid 65 with tag 811 to app "_ManagedAppProcess_bootstrap"

*Mar 1 01:09:03.143: //65/C113522D805A/CCAPI/ccCallProceeding:

Progress Indication=NULL(0)

*Mar 1 01:09:03.147: //65/C113522D805A/CCAPI/ccCallConnect:

Progress Indication=NULL(0), Data Bitmask=0x0

*Mar 1 01:09:03.151: //65/C113522D805A/CCAPI/ccCallConnect:

Call Entry(Connected=TRUE, Responsed=TRUE)

*Mar 1 01:09:03.239: //65/C113522D805A/CCAPI/cc_api_event_indication:

Event=141, Call Id=65

*Mar 1 01:09:03.243: //65/C113522D805A/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Mar 1 01:09:03.243: //65/C113522D805A/CCAPI/cc_api_caps_ind:

Destination Interface=0x0, Destination Call Id=-1, Source Call Id=65,

Caps(Codec=0x0, Fax Rate=0x2, Vad=0x2,

Modem=0x0, Codec Bytes=20, Signal Type=2)

*Mar 1 01:09:03.243: //65/C113522D805A/CCAPI/cc_api_caps_ind:

Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),

Playout Max=250(ms), Fax Nom=300(ms))

*Mar 1 01:09:04.163: //65/C113522D805A/CCAPI/ccCallHandoff:

Silent=FALSE, Application=0x6773AB4C, Conference Id=0xFFFFFFFF

*Mar 1 01:09:04.295: //65/C113522D805A/CCAPI/ccSetDigitTimeouts:

Initial Digit Timeout=0(ms), Inter Digit Timeout=0(ms)

*Mar 1 01:09:04.295: //65/C113522D805A/CCAPI/ccSetDigitTimeouts:

Call Entry(Inter Digit Timeout=0(ms), Initial Digit Timeout=0(ms))

*Mar 1 01:09:04.295: //65/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:

(callID=0x41, digit_event=0x1, enable=TRUE, consume=FALSE)

*Mar 1 01:09:04.299: //65/C113522D805A/CCAPI/ccCallReportDigits:

Enabled=TRUE, Call Id=65

*Mar 1 01:09:04.303: //65/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:

(vdbPtr=0x67213130, callID=0x41, disp=-4, digit_event=0x1, enable=TRUE, consume=FALSE)

*Mar 1 01:09:04.307: //65/C113522D805A/CCAPI/cc_api_call_report_digits_done:

Enabled=TRUE, Disposition=0xFFFFFFFC, Interface=0x67213130, Call Id=65

*Mar 1 01:09:04.311: //65/C113522D805A/CCAPI/cc_api_call_report_digits_done:

Call Entry(Initial Digit Timeout=0(ms), Inter Digit Timeout=0(ms))

*Mar 1 01:09:05.291: //65/C113522D805A/CCAPI/ccAssociateStream:

Coder=5, DTMF Relay=4, Vad=0,

Record Function=0x0, Event Queue=0x66954714, Stream Context=678B0364,

Record Context=0x0, Stream Call Id=66, Call Id=65

*Mar 1 01:09:05.295: //65/C113522D805A/CCAPI/ccAssociateStream:

Call Entry(Stream Status=2, Digit Enable=TRUE)

*Mar 1 01:09:05.327: //65/C113522D805A/CCAPI/cc_api_call_associated:

Interface=0x0, CallId=65, Disposition=0

Play Function=0x62C2DFA8, Codec=0x5, Vad=0x0

Media Type=0x3, SPI Context=0x678D2480, Stream CallId=66

TX Dynamic Pt=0x0, RX Dynamic Pt=0x0

*Mar 1 01:09:05.531: //65/C113522D805A/CCAPI/ccSetDigitTimeouts:

Initial Digit Timeout=5000(ms), Inter Digit Timeout=10000(ms)

*Mar 1 01:09:05.535: //65/C113522D805A/CCAPI/ccSetDigitTimeouts:

Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=5000(ms))

*Mar 1 01:09:05.535: //65/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:

(callID=0x41, digit_event=0x1, enable=TRUE, consume=FALSE)

*Mar 1 01:09:05.535: //65/C113522D805A/CCAPI/ccCallReportDigits:

Enabled=TRUE, Call Id=65

*Mar 1 01:09:05.535: //65/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:

(vdbPtr=0x67213130, callID=0x41, disp=-4, digit_event=0x1, enable=TRUE, consume=FALSE)

*Mar 1 01:09:05.539: //65/C113522D805A/CCAPI/cc_api_call_report_digits_done:

Enabled=TRUE, Disposition=0xFFFFFFFC, Interface=0x67213130, Call Id=65

*Mar 1 01:09:05.543: //65/C113522D805A/CCAPI/cc_api_call_report_digits_done:

Call Entry(Initial Digit Timeout=5000(ms), Inter Digit Timeout=10000(ms))

*Mar 1 01:09:08.723: //65/C113522D805A/CCAPI/ccDisassociateStream:

Record Context=0x0, Stream Call Id=66, Call Id=65

*Mar 1 01:09:08.723: //65/C113522D805A/CCAPI/ccDisassociateStream:

Call Entry(Stream Status=1, Digit Enable=TRUE)

*Mar 1 01:09:08.735: //65/C113522D805A/CCAPI/ccAssociateStream:

Coder=5, DTMF Relay=4, Vad=0,

Record Function=0x0, Event Queue=0x66954714, Stream Context=678B0364,

Record Context=0x0, Stream Call Id=66, Call Id=65

*Mar 1 01:09:08.739: //65/C113522D805A/CCAPI/ccAssociateStream:

Call Entry(Stream Status=2, Digit Enable=TRUE)

*Mar 1 01:09:08.747: //65/C113522D805A/CCAPI/cc_api_call_associated:

Interface=0x0, CallId=65, Disposition=0

Play Function=0x62C2DFA8, Codec=0x5, Vad=0x0

Media Type=0x3, SPI Context=0x678D2480, Stream CallId=66

TX Dynamic Pt=0x0, RX Dynamic Pt=0x0

R1#

*Mar 1 01:09:16.143: //65/C113522D805A/CCAPI/ccDisassociateStream:

Record Context=0x0, Stream Call Id=66, Call Id=65

*Mar 1 01:09:16.143: //65/C113522D805A/CCAPI/ccDisassociateStream:

Call Entry(Stream Status=1, Digit Enable=TRUE)

*Mar 1 01:09:16.175: //65/C113522D805A/CCAPI/ccCallDisconnect:

Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)

*Mar 1 01:09:16.179: //65/C113522D805A/CCAPI/ccCallDisconnect:

Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)

*Mar 1 01:09:16.227: //65/C113522D805A/CCAPI/cc_api_call_disconnect_done:

R1#Disposition=0, Interface=0x67213130, Tag=0x0, Call Id=65,

Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)

*Mar 1 01:09:16.235: //65/C113522D805A/CCAPI/cc_api_call_disconnect_done:

Call Disconnect Event Sent

*Mar 1 01:09:16.235: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Mar 1 01:09:16.235: :cc_free_feature_vsa freeing 67445940

*Mar 1 01:09:16.235: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Mar 1 01:09:16.235: vsacount in free is 0

I have some basic VXML gateway configuration

R1#show run

Building configuration...

Current configuration : 2588 bytes

!

version 12.4

service timestamps debug datetime msec

service timestamps log datetime msec

no service password-encryption

!

hostname R1

!

boot-start-marker

boot-end-marker

!

no aaa new-model

memory-size iomem 5

ip cef

!

no ip domain lookup

ip domain name lab.local

ip auth-proxy max-nodata-conns 3

ip admission max-nodata-conns 3

!

multilink bundle-name authenticated

!

voice service voip

sip

header-passing

!

application

service cvperror flash:cvperror.tcl

paramspace english index 0

paramspace english language en

paramspace english location flash

paramspace english prefix en

!

service new-call flash:bootstrap.vxml

paramspace english index 0

paramspace english language en

paramspace english location flash

paramspace english prefix en

!

service ringtone flash:ringtone.tcl

paramspace english language en

paramspace english index 0

paramspace english location flash

paramspace english prefix en

!

service ringback flash:ringtone.tcl

!

service handoff flash:handoff.tcl

paramspace english index 0

paramspace english language en

paramspace english location flash

paramspace english prefix en

!

service bootstrap flash:bootstrap.tcl

paramspace english index 0

paramspace english language en

paramspace english location flash

paramspace english prefix en

!

archive

log config

hidekeys

!

interface FastEthernet0/0

ip address 192.168.1.253 255.255.255.0

duplex auto

speed auto

!

interface FastEthernet0/1

no ip address

shutdown

duplex auto

speed auto

!

ip forward-protocol nd

!

no ip http server

no ip http secure-server

!

control-plane

!

dial-peer voice 9191 voip

service ringtone

session protocol sipv2

incoming called-number 91919191

codec g711ulaw

no vad

!

dial-peer voice 9292 voip

service cvperror

session protocol sipv2

incoming called-number 92929292

codec g711ulaw

no vad

!

dial-peer voice 1503 voip

destination-pattern 1503

session protocol sipv2

session target ipv4:192.168.1.57

dtmf-relay rtp-nte h245-alphanumeric h245-signal

codec g711ulaw

ip qos dscp cs3 signaling

no vad

!

dial-peer voice 100 voip

destination-pattern 10..

session target ipv4:192.168.1.100

!

dial-peer voice 811 voip

service bootstrap

session protocol sipv2

session target sip-server

incoming called-number 81T

codec g711ulaw

no vad

!

line con 0

exec-timeout 0 0

privilege level 15

logging synchronous

line aux 0

exec-timeout 0 0

privilege level 15

logging synchronous

line vty 0 4

login

!

end

Please help me out how o fix this issue/

Senthil Kumar Sankar · ‎05-15-2013

Hi John,

This Log doesn't help much on finding the probelm.

What is the Microapp you use in the ICM Scripting for playing prompt ?

You need to look into the CVP logs and VXML Gateway Logs for the failure reason. Which would give us clue where the call is failing and concentrate on that.

Regards,

Senthil

John Faust · ‎05-15-2013

Thanks for the respose

The microapp what I use is user.microapp.ToExtVXML[]

This is the activity log in the CVP application. I dont see any error logs.

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,newcall,

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,ani,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,areacode,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,exchange,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,dnis,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,uui,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.109,,start,iidigits,NA

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.125,CVP Subdialog Start_01,enter,

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.593,CVP Subdialog Start_01,exit,done

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.593,Greetings,enter,

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.597,Greetings,interaction,audio_group,initial_audio_group

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.703,Greetings,exit,done

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.703,Menu,enter,

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.707,Menu,interaction,audio_group,initial_audio_group

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.875,Menu,exit,

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.875,,end,how,hangup

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.875,,end,result,normal

192.168.1.57.1368611401109.0.ImationIVR,05/15/2013 15:20:01.875,,end,duration,1

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,newcall,

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,ani,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,areacode,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,exchange,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,dnis,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,uui,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,,start,iidigits,NA

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.531,CVP Subdialog Start_01,enter,

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.921,CVP Subdialog Start_01,exit,done

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.921,Greetings,enter,

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:06.957,Greetings,interaction,audio_group,initial_audio_group

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:07.109,Greetings,exit,done

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:20:07.109,Menu,enter,

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:50:25.718,,end,how,app_session_complete

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:50:25.718,,end,result,timeout

192.168.1.57.1368611406531.1.ImationIVR,05/15/2013 15:50:25.718,,end,duration,1819

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,newcall,

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,ani,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,areacode,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,exchange,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,dnis,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,uui,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,,start,iidigits,NA

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.312,CVP Subdialog Start_01,enter,

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.750,CVP Subdialog Start_01,exit,done

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.750,Greetings,enter,

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.782,Greetings,interaction,audio_group,initial_audio_group

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.937,Greetings,exit,done

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:22:56.937,Menu,enter,

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:53:25.718,,end,how,app_session_complete

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:53:25.718,,end,result,timeout

192.168.1.57.1368611576312.2.ImationIVR,05/15/2013 15:53:25.718,,end,duration,1829

Thank you