<div>Per Barbie's suggestion, I created a specific inbound dialpeer:</div>
<div>dial-peer voice 8522 pots<br> incoming called-number 8522<br> port 0/0/0:1</div>
<div>which appears to be matched when the IVR goes off hook. We currently have the IVR repeatedly trying to place a call. For each debug I attach, one call cycle is included.</div>
<div> </div>
<div>Here are the debug results:</div>
<div>debug vpm sig</div>
<div>*Dec 12 12:12:04.355: htsp_process_event: [0/0/0:1(13), FXSLS_ONHOOK, E_DSP_SIG_<br>1100]fxsls_onhook_offhook htsp_setup_ind<br>*Dec 12 12:12:04.355: [0/0/0:1(13)] get_local_station_id calling num= calling na<br>me= calling time=12/12 12:12 orig called=
<br>*Dec 12 12:12:04.359: htsp_process_event: [0/0/0:1(13), FXSLS_WAIT_SETUP_ACK, E_<br>HTSP_SETUP_ACK]fxsls_check_auto_call <br>*Dec 12 12:12:06.483: htsp_process_event: [0/0/0:1(13), FXSLS_OFFHOOK, E_DSP_SIG<br>_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
<br>*Dec 12 12:12:06.483: htsp_timer - 1000 msec<br>*Dec 12 12:12:07.483: htsp_process_event: [0/0/0:1(13), FXSLS_OFFHOOK, E_HTSP_EV<br>ENT_TIMER]fxsls_offhook_timer<br>*Dec 12 12:12:07.491: htsp_process_event: [0/0/0:1(13), FXSLS_ONHOOK, E_HTSP_REL
<br>EASE_REQ]fxsls_onhook_release<br>*Dec 12 12:12:07.491: htsp_timer_stop</div>
<div> </div>
<div>debug voip dialpeer</div>
<div>*Dec 12 12:09:53.563: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:<br> Calling Number=, Called Number=, Voice-Interface=0x44CF465C,<br> Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
<br> Peer Info Type=DIALPEER_INFO_SPEECH<br>*Dec 12 12:09:53.563: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:<br> Match Rule=DP_MATCH_PORT;<br>*Dec 12 12:09:53.563: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
<br> Result=Success(0) after DP_MATCH_PORT; Incoming Dial-peer=8522<br>*Dec 12 12:09:53.563: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerSPI:exit@5931</div>
<div> </div>
<div>debug voip vtsp all</div>
<div>*Dec 12 12:04:51.347: //-1/CBDF20C08237/VTSP:(0/0/0:1):-1:-1:-1/vtsp_free_cdb: <br> CDB=0x457EC080<br>*Dec 12 12:04:52.347: //-1/xxxxxxxxxxxx/VTSP:(0/0/0:1):-1:-1:-1/vtsp_allocate_cd<br>b: <br> CDB=0x457EBDD8<br>
*Dec 12 12:04:52.347: //-1/xxxxxxxxxxxx/VTSP:(0/0/0:1):-1:-1:-1/vtsp_do_call_set<br>up_ind: <br> Event=E_TSP_SETUP_IND<br> Progress Indication=3, CarrierIDCode=, Info Trans Capability=144, Source Carr<br>ier ID=, tg_label_flag=0
<br>*Dec 12 12:04:52.347: //-1/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/vtsp_do_normal_c<br>all_setup_ind: <br>*Dec 12 12:04:52.347: //-1/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/vtsp_timer: <br> Timer Start Time=6612339, Timer Value=180000(ms)
<br>*Dec 12 12:04:52.347: //-1/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/vtsp_do_normal_c<br>all_setup_ind: <br> IC State Machine (ICSM) Added<br>*Dec 12 12:04:52.351: //-1/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_indicate_call
<br>: <br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_insert_cdb: <br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_report_digit<br>_control: <br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_report_digit
<br>_control: <br> Digit Reporting=TRUE<br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even<br>t: <br> [state:S_SETUP_INDICATED, event:E_CC_SETUP_ACK]<br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_setup_ind_ack
<br>: <br> Fax Relay=TRUE, Dial Tone=TRUE, Digit Collect=TRUE, Overlap=FALSE, DID=FALSE<br>*Dec 12 12:04:52.351: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_timer_stop: <br> <br> Timer Stop Time=6612340<br>*Dec 12 12:04:
55.451: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even<br>t: <br> [state:S_DIGIT_COLLECT, event:E_TSP_CALL_FEATURE_IND]<br>*Dec 12 12:04:55.451: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_call_feature_<br>
ind: <br> Feature Type=5<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even<br>t: <br> [state:S_DIGIT_COLLECT, event:E_TSP_DISCONNECT_IND]<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_generate_disc
<br>: <br> Cause Value=16<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_timer_stop: <br> <br> Timer Stop Time=6612777<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_ring_noan_ti
<br>mer_stop: <br> Timer Stop Time=6612777<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_set_release_<br>source: <br> Release Direction=PSTN, Release Source=Calling Party-PSTN<br>*Dec 12 12:04:
56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_cc_call_disc<br>onnected: <br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_cc_call_disc<br>onnected: <br> Cause Value=16<br>*Dec 12 12:04:56.727
: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_timer: <br> Timer Start Time=6612777, Timer Value=15000(ms)<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_generate_disc<br>: <br> Return Code=0
<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even<br>t: <br> [state:S_WAIT_HOST_DISC, event:E_CC_DISCONNECT]<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_host_disc_cle
<br>anup: <br> dsm_indicate_error=0, short_cleardown_timeout=1, Mode=0<br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_dsm_save_fax<br>_config: <br>*Dec 12 12:04:56.727: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_dsm_save_fax
<br>_config: <br> Call Entry=NULL, Call Id=-1<br>*Dec 12 12:04:56.731: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_host_disc_cle<br>anup: <br> Exit State=16<br>*Dec 12 12:04:56.731: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even
<br>t: <br> [state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]<br>*Dec 12 12:04:56.731: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_dsm_dsp_stats<br>_complete: <br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_timer:
<br> Timer Start Time=6612778, Timer Value=60000(ms)<br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_process_even<br>t: <br> [state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]<br>*Dec 12 12:04:
56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/act_wrelease_rele<br>ase: <br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_play_busy_ti<br>mer_stop: <br> Timer Stop Time=6612778<br>*Dec 12 12:04:
56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_timer_stop: <br> <br> Timer Stop Time=6612778<br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_do_call_hist<br>ory: <br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_do_call_hist
<br>ory: <br> Coder Rate=-1<br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:3:1/vtsp_dsm_closed_c<br>b: <br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/vtsp_process_ev<br>ent: <br> [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
<br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/act_terminate: <br>*Dec 12 12:04:56.735: //275/CEBB8D46823A/VTSP:(0/0/0:1):-1:-1:-1/vtsp_timer_stop<br>: <br> Timer Stop Time=6612778</div>
<div> </div>
<div>debug voip ccapi inout</div>
<div>*Dec 12 12:03:19.847: //-1/97988EDC81FE/CCAPI/cc_api_display_ie_subfields:<br> cc_api_call_setup_ind_common:<br> cisco-username=<br> ----- ccCallInfo IE subfields -----<br> cisco-ani=<br> cisco-anitype=0<br>
cisco-aniplan=0<br> cisco-anipi=0<br> cisco-anisi=0<br> dest=<br> cisco-desttype=0<br> cisco-destplan=0<br> cisco-rdn=<br> cisco-rdntype=0<br> cisco-rdnplan=0<br> cisco-rdnpi=0<br> cisco-rdnsi=0<br>
cisco-redirectreason=0<br>*Dec 12 12:03:19.847: //-1/97988EDC81FE/CCAPI/cc_api_call_setup_ind_common:<br> Interface=0x44CF465C, Call Info(<br> Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentatio
<br>n=Allowed),<br> Called Number=(TON=Unknown, NPI=Unknown),<br> Calling Translated=FALSE, Subsriber Type Str=RegularLine, FinalDestinationFla<br>g=FALSE,<br> Incoming Dial-peer=8522, Progress Indication=ORIGINATING SIDE IS NON ISDN(3),
<br> Calling IE Present=FALSE,<br> Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALS<br>E), Call Id=-1<br>*Dec 12 12:03:19.847: //-1/97988EDC81FE/CCAPI/ccCheckClipClir:<br> In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Present
<br>ation=Allowed)<br>*Dec 12 12:03:19.847: //-1/97988EDC81FE/CCAPI/ccCheckClipClir:<br> Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presen<br>tation=Allowed)<br>*Dec 12 12:03:19.847: //255/97988EDC81FE/CCAPI/cc_api_call_setup_ind_common:
<br> Set Up Event Sent;<br> Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, P<br>resentation=Allowed),<br> Called Number=(TON=Unknown, NPI=Unknown))<br>*Dec 12 12:03:19.847: //255/97988EDC81FE/CCAPI/cc_process_call_setup_ind:
<br> Event=0x45328288<br>*Dec 12 12:03:19.847: //255/97988EDC81FE/CCAPI/ccCallSetContext:<br> Context=0x457F4064<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/cc_process_call_setup_ind:<br> >>>>CCAPI handed cid 255 with tag 8522 to app "Default"
<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/ccCallSetupAck:<br> Call Id=255<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/cc_api_set_transfer_info:<br> Transfer Number=, Transfer Reason=0x0<br>*Dec 12 12:03:
19.851: //255/97988EDC81FE/CCAPI/ccGenerateToneInfo:<br> Stop Tone On Digit=TRUE, Tone=Dial Tone,<br> Tone Direction=Network, Params=0x0, Call Id=255<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/ccSetDigitTimeouts:
<br> Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/ccSetDigitTimeouts:<br> Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))<br>
*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/ccCallReportDigits:<br> Enabled=TRUE, Call Id=255<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/cc_api_call_report_digits_done:<br> Enabled=TRUE, Disposition=0x0, Interface=0x44CF465C, Call Id=255
<br>*Dec 12 12:03:19.851: //255/97988EDC81FE/CCAPI/cc_api_call_report_digits_done:<br> Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))<br>*Dec 12 12:03:22.359: //255/97988EDC81FE/CCAPI/cc_api_call_feature:
<br> Feature Type=5, Interface=0x44CF465C, Call Id=255<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/cc_api_call_disconnected:<br> Cause Value=16, Interface=0x44CF465C, Call Id=255<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/cc_api_call_disconnected:
<br> Call Entry(Responsed=FALSE, Cause Value=16, Retry Count=0)<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/ccRestartDigitTimeoutMsec:<br> Digit Timeout=0, Call Id=255<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/ccCallDisconnect:
<br> Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect C<br>ause=16)<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/ccCallDisconnect:<br> Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
<br>*Dec 12 12:03:23.599: //255/97988EDC81FE/CCAPI/cc_api_get_transfer_info:<br> Transfer Number Is Null<br>*Dec 12 12:03:23.603: //255/97988EDC81FE/CCAPI/cc_api_call_disconnect_done:<br> Disposition=0, Interface=0x44CF465C, Tag=0x0, Call Id=255,
<br> Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)<br>*Dec 12 12:03:23.603: //255/97988EDC81FE/CCAPI/cc_api_call_disconnect_done:<br> Call Disconnect Event Sent</div>
<div> </div>
<div>Any h.245 and h.225 debugs produce no result.</div>
<div> </div>
<div>Any additional help is greatly appreciated.<br><br>-- <br>Dave Wolgast<br>Livonia, NY </div>