Buy or Renew
Buy or Renew
Cisco + Splunk: It’s a new day for your data. Learn more.
 
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
1027
Views
0
Helpful
2
Replies

CUCM and Gateway to PSTN

karlschilv
Level 1
Level 1

‎10-26-2018 09:08 AM

Hello everyone,

 

We are trying to configure a Cisco gateway 15.1(4)M10 with a FXO port and PSTN line to send calls to CUCM.

We have configured the following on the router side:

!

!

voice service voip
ip address trusted list
ipv4 10.60.90.102 255.255.255.255  <----- CUCM IP
allow-connections h323 to sip
allow-connections sip to h323
h323

!

!

interface Fa0/0 ####### LAN interface

    ip address 10.60.90.253 255.255.254.0

    h323-gateway voip bind srcaddr 10.60.90.253

!

!

voice-port 0/1/0
connection plar opx 100

!

!

dial-peer voice 10 voip
destination-pattern 100
session target ipv4:10.60.90.102 <----- CUCM IP
dtmf-relay h245-alphanumeric h245-signal

!

!

telephony-service
max-conferences 4 gain -6
transfer-system full-consult

!

!

@ CUCM

 

Gateway Information on CUCM

Product H.323 Gateway

Device Protocol H.225

Device Name: 10.60.90.253

 

PSTN Access [Checked]

Enable Inbound FastStart [Checked]

 

 

IP Phone 7961 configured with Extension 100 on CUCM

 

############### DEBUG on Router ############################

On Router - Gateway

#debug voip dialpeer all

##### External call to the line connected to the FXO port:

Calling Number hears ringing but called number never answers.

 

Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Calling Number=, Called Number=, Voice-Interface=0x89C354A4,
Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
Peer Info Type=DIALPEER_INFO_SPEECH
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_PORT;
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Result=NO_MATCH(-1) After All Match Rules Attempt
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerSPI:exit@6564
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Calling Number=, Called Number=100, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Match Rule=DP_MATCH_DEST; Called Number=100
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=100, Expanded String=100, Calling Number=
Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
Result=Success(0); Outgoing Dial-peer=10 Is Matched
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Result=Success(0) after DP_MATCH_DEST
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=100, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 26 16:02:17.979: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
Result=SUCCESS(0)
List of Matched Outgoing Dial-peer(s):
1: Dial-peer Tag=10
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchPeersCore:
Calling Number=, Called Number=100, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchPeersCore:
Match Rule=DP_MATCH_DEST; Called Number=100
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchCore:
Dial String=100, Expanded String=100, Calling Number=
Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/MatchNextPeer:
Result=Success(0); Outgoing Dial-peer=10 Is Matched
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchPeersCore:
Result=Success(0) after DP_MATCH_DEST
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchSafModulePlugin:
dialstring=100, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 26 16:02:17.983: //-1/58EE8A73B7FB/DPM/dpMatchPeersMoreArg:
Result=SUCCESS(0)
List of Matched Outgoing Dial-peer(s):
1: Dial-peer Tag=10

 


topology.png

Labels:
0 Helpful
2 Replies 2

R0g22
Cisco Employee
Cisco Employee

‎10-26-2018 11:19 AM

First thing, there is no requirement for trust list in your scenario since you already have a dial-peer with that IP address. It get's automatically added to the IOS trust list.
Can you add "deb voip vtsp all" , "debug vpm signal" and "debug voice cc inout" and make a test call ?

0 Helpful

karlschilv
Level 1
Level 1
In response to R0g22

‎10-26-2018 11:36 AM

Hi Nipun,

 

First of all, thank you for your reply.

 

Do you recommend we disable the trust list applying the following command?

voice service voip
 no ip address trusted authenticate

 Debug results:

#debug voip vtsp all

Oct 26 18:26:14.578: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb:
CDB=0x8B00F6C0
Oct 26 18:26:14.578: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_ind:
Event=E_TSP_SETUP_IND
Progress Indication=3, CarrierIDCode=, Info Trans Capability=144, Source Carrier ID=, tg_label_flag=0
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_timer:
Timer Start Time=1175935316, Timer Value=180000(ms)
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
IC State Machine (ICSM) Added
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_setup_ind_pend_success:
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_realloc_cdb:
CDB=0x8B00F6C0
Oct 26 18:26:14.578: //-1/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_indicate_call:
Oct 26 18:26:14.578: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_insert_cdb:
Oct 26 18:26:14.578: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer:
Timer Start Time=1175935316, Timer Value=180000(ms)
Oct 26 18:26:14.586: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_spi_event_handler:
Event Category=1, Event=176
Oct 26 18:26:14.586: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_INDICATED, event:E_CC_PROCEEDING]
Oct 26 18:26:14.586: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_proceeding:
Progress Indication=0
Oct 26 18:26:14.586: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175935317
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:exit@1477
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=CISCO_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=Dialpeer, Peer=10
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
Save TTY configuration
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
Set TTY feat parameters
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_PROCEEDING, event:E_CC_ALERT]
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_alert:
Progress Indication=8, Signal Indication=1, Setup Progress Indication=3
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175935320
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_open_packet_path:
Progress Indication=8
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_open_packet_path: Setting pak_suppress to DSP_PAK_SUPPRESS_DISABLE
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_alert:
Progress Indication=8
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_ALERTING, event:E_CC_DO_CAPS_IND]
Oct 26 18:26:14.618: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_IND
Oct 26 18:26:14.630: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_ALERTING, event:E_CC_CAPS_IND]
Oct 26 18:26:14.630: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_ACK
Oct 26 18:26:14.630: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_feature_notify_cb:
Feature ID=0, Feature Status=1
Oct 26 18:26:14.630: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:
Oct 26 18:26:14.630: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:exit@1268
Oct 26 18:26:14.962: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Oct 26 18:26:14.962: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=1
Oct 26 18:26:14.962: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:14.990: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Oct 26 18:26:14.990: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175935357
Oct 26 18:26:14.990: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=1
Oct 26 18:26:14.990: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:15.242: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Oct 26 18:26:15.242: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=5
Oct 26 18:26:15.242: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:15.270: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Oct 26 18:26:15.270: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175935385
Oct 26 18:26:15.270: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=5
Oct 26 18:26:15.270: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:15.970: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Oct 26 18:26:15.970: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=1
Oct 26 18:26:15.970: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:16.002: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Oct 26 18:26:16.002: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175935458
Oct 26 18:26:16.002: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=1
Oct 26 18:26:16.002: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=TRUE
Oct 26 18:26:23.946: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_ALERTING, event:E_CC_DISCONNECT]
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_pre_con_disconnect:
Cause Value=1, Hairpin=FALSE
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175936254
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=1175936254
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_pre_con_disconnect:
[Fast Busy]-Tone Played In Direction [Network]
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer:
Timer Start Time=1175936254, Timer Value=30000(ms)
Oct 26 18:26:23.954: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_pre_con_disconnect:
Tone=Fast Busy, Tone Timeout=30(s)
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE_NC, event:E_TSP_DISCONNECT_IND]
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_pre_con_disc_rel:
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_pre_con_disc_rel:
Cause Value=1
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE_RESP, event:E_TSP_DISCONNECT_CONF]
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop:
Timer Stop Time=1175936622
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=1175936622
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
Coder Rate=16
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle:
DMGR=0x8A616184, VTSP CDB=0x8B00F6C0
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
Oct 26 18:26:27.638: //95/74BEE9F3B800/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:
[state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]

 

#debug vpm signal

Oct 26 18:30:47.483: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=3028 systime=1175962606
Oct 26 18:30:47.483: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Oct 26 18:30:47.483: htsp_timer - 125 msec
Oct 26 18:30:47.611: htsp_process_event: [0/1/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Oct 26 18:30:47.611: htsp_timer - 10000 msec
Oct 26 18:30:48.519: htsp_dsp_message: SEND_SIG_STATUS: state=0x6 timestamp=4063 systime=1175962709
Oct 26 18:30:48.519: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0110]
Oct 26 18:30:48.707: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=4249 systime=1175962728
Oct 26 18:30:48.707: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
Oct 26 18:30:48.707: fxols_ringing_not
Oct 26 18:30:48.707: htsp_timer_stop
Oct 26 18:30:48.707: htsp_timer_stop3 htsp_setup_ind
Oct 26 18:30:48.707: [0/1/0] get_local_station_id calling num= calling name= calling time=10/26 18:30 orig called=
Oct 26 18:30:48.707: htsp_process_event: [0/1/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Oct 26 18:30:48.707: fxols_wait_setup_ack:
Oct 26 18:30:48.707: htsp_timer - 6000 msec
Oct 26 18:30:48.715: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
Oct 26 18:30:48.731: htsp_call_bridged invokedhtsp_alert_notify
Oct 26 18:30:48.731: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alert
Oct 26 18:30:48.747: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_VOICE_CUT_THROUGH]fxols_proc_voice
Oct 26 18:30:54.655: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=10197 systime=1175963323
Oct 26 18:30:54.655: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Oct 26 18:30:54.655: htsp_timer_stop
Oct 26 18:30:54.655: htsp_timer_stop2
Oct 26 18:30:55.771: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=11315 systime=1175963434
Oct 26 18:30:55.771: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Oct 26 18:30:55.771: htsp_timer_stop2
Oct 26 18:30:55.771: htsp_timer - 6000 msec
Oct 26 18:30:58.071: htsp_pre_connect_disconnect, cdb = 8B00F6C0 cause = 1

Oct 26 18:30:58.071: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_PRE_CONN_DISC]
Oct 26 18:30:59.668: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=15212 systime=1175963824
Oct 26 18:30:59.668: htsp_process_event: [0/1/0, FXOLS_OFFHOOK, E_DSP_SIG_0000]
Oct 26 18:31:00.792: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=16334 systime=1175963936
Oct 26 18:31:00.792: htsp_process_event: [0/1/0, FXOLS_OFFHOOK, E_DSP_SIG_0100]fxols_offhook_clear
Oct 26 18:31:00.792: htsp_timer_stop2
Oct 26 18:31:01.772: htsp_process_event: [0/1/0, FXOLS_OFFHOOK, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Oct 26 18:31:01.772: htsp_timer_stop
Oct 26 18:31:01.772: htsp_timer_stop2
Oct 26 18:31:01.772: htsp_timer_stop3
Oct 26 18:31:01.772: htsp_process_event: [0/1/0, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
Oct 26 18:31:01.772: htsp_timer_stop
Oct 26 18:31:01.772: htsp_timer_stop2
Oct 26 18:31:01.772: htsp_timer_stop3
Oct 26 18:31:01.772: [0/1/0] set signal state = 0x4 timestamp = 0
Oct 26 18:31:01.772: htsp_timer - 2000 msec
Oct 26 18:31:03.772: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Oct 26 18:31:03.772: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=16334 systime=1175964234
Oct 26 18:31:03.772: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]

 

#debug voice cc inout

Oct 26 18:33:05.932: //-1/69EE8ECDB80A/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=100
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

Oct 26 18:33:05.932: //-1/69EE8ECDB80A/CCAPI/cc_api_call_setup_ind_common:
Interface=0x89C354A4, Call Info(
Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=100(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,
Incoming Dial-peer=0, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Oct 26 18:33:05.932: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.932: :cc_get_feature_vsa malloc success
Oct 26 18:33:05.932: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.932: cc_get_feature_vsa count is 1
Oct 26 18:33:05.932: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.932: :FEATURE_VSA attributes are: feature_name:0,feature_time:2354756560,feature_id:52
Oct 26 18:33:05.932: //99/69EE8ECDB80A/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=100(TON=Unknown, NPI=Unknown))
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/cc_process_call_setup_ind:
Event=0x89BD9AB8
Oct 26 18:33:05.936: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 100
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCallSetContext:
Context=0x8ADD2808
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 99 with tag 0 to app "_ManagedAppProcess_Default"
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=FALSE, Mode=0,
Outgoing Dial-peer=10, Params=0x8ADD3D18, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCheckClipClir:
In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCheckClipClir:
Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCallSetupRequest:
Destination Pattern=100, Called Number=100, Digit Strip=FALSE
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/ccCallSetupRequest:
Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=100(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=TRUE,
Guid=69EE8ECD-D884-11E8-B80A-8CC2BBA72503, Outgoing Dial-peer=10
Oct 26 18:33:05.936: //99/69EE8ECDB80A/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=100
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

Oct 26 18:33:05.940: //99/69EE8ECDB80A/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x8941EF14, Interface Type=1, Destination=, Mode=0x0,
Call Params(Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=100(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=10, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 26 18:33:05.940: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.940: :cc_get_feature_vsa malloc success
Oct 26 18:33:05.940: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.940: cc_get_feature_vsa count is 2
Oct 26 18:33:05.940: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 26 18:33:05.940: :FEATURE_VSA attributes are: feature_name:0,feature_time:2354756336,feature_id:53
Oct 26 18:33:05.940: //100/69EE8ECDB80A/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
Oct 26 18:33:05.940: //100/69EE8ECDB80A/CCAPI/ccCallSetContext:
Context=0x8ADD3CC8
Oct 26 18:33:05.940: //99/69EE8ECDB80A/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=10
Oct 26 18:33:05.952: //100/69EE8ECDB80A/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
Oct 26 18:33:05.952: //100/69EE8ECDB80A/CCAPI/cc_api_call_proceeding:
Interface=0x8941EF14, Progress Indication=NULL(0)
Oct 26 18:33:05.952: //100/69EE8ECDB80A/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
Oct 26 18:33:05.952: //100/69EE8ECDB80A/CCAPI/cc_api_call_cut_progress:
Interface=0x8941EF14, Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1),
Cause Value=1
Oct 26 18:33:05.952: //100/69EE8ECDB80A/CCAPI/cc_api_call_cut_progress:
Call Entry(Responsed=TRUE)
Oct 26 18:33:05.956: //99/69EE8ECDB80A/CCAPI/ccCallCutProgress:
Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1), Cause Value=1
Voice Call Send Alert=TRUE, Call Entry(Alert Sent=FALSE)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccCallCutProgress:
Call CallAlert;
Call Entry(Responsed=TRUE)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccCallAlert:
Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=99
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccConferenceCreate:
(confID=0x8AC582E8, callID1=0x63, gcid=69EE8ECD-D88411E8-B80A8CC2-BBA72503, tag=0x0)
Oct 26 18:33:05.960: //100/69EE8ECDB80A/CCAPI/ccConferenceCreate:
(confID=0x8AC582E8, callID2=0x64, gcid=69EE8ECD-D88411E8-B80A8CC2-BBA72503, tag=0x0)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccConferenceCreate:
Conference Id=0x8AC582E8, Call Id1=99, Call Id2=100, Tag=0x0
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/cc_api_bridge_done:
Conference Id=0x19, Source Interface=0x89C354A4, Source Call Id=99,
Destination Call Id=100, Disposition=0x0, Tag=0xFFFFFFFF
Oct 26 18:33:05.960: //100/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

Oct 26 18:33:05.960: cc_api_get_xcode_stream : 4702
Oct 26 18:33:05.960: //100/69EE8ECDB80A/CCAPI/cc_api_bridge_done:
Conference Id=0x19, Source Interface=0x8941EF14, Source Call Id=100,
Destination Call Id=99, Disposition=0x0, Tag=0x0
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/cc_generic_bridge_done:
Conference Id=0x19, Source Interface=0x8941EF14, Source Call Id=100,
Destination Call Id=99, Disposition=0x0, Tag=0x0
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x19, Destination Call Id=100)
Oct 26 18:33:05.960: //100/69EE8ECDB80A/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x19, Destination Call Id=99)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/cc_api_caps_ind:
Destination Interface=0x8941EF14, Destination Call Id=100, Source Call Id=99,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
Oct 26 18:33:05.960: //99/69EE8ECDB80A/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
Oct 26 18:33:05.964: //99/69EE8ECDB80A/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x19, Call Id1=99, Call Id2=100
Oct 26 18:33:05.968: //100/69EE8ECDB80A/CCAPI/cc_api_caps_ind:
Destination Interface=0x89C354A4, Destination Call Id=99, Source Call Id=100,
Caps(Codec=0x4, Fax Rate=0x2, Vad=0x2,
Modem=0x0, Codec Bytes=20, Signal Type=2)
Oct 26 18:33:05.972: //100/69EE8ECDB80A/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
Oct 26 18:33:05.972: //100/69EE8ECDB80A/CCAPI/cc_api_caps_ack:
Destination Interface=0x89C354A4, Destination Call Id=99, Source Call Id=100,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=5600)
Oct 26 18:33:05.972: //99/69EE8ECDB80A/CCAPI/cc_api_caps_ack:
Destination Interface=0x8941EF14, Destination Call Id=100, Source Call Id=99,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=5600)
Oct 26 18:33:05.972: //99/69EE8ECDB80A/CCAPI/cc_api_voice_mode_event:
Call Id=99
Oct 26 18:33:05.972: //99/69EE8ECDB80A/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x8ADD2808)
Oct 26 18:33:06.032: //99/69EE8ECDB80A/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 1 to dstCallId 0x64
Oct 26 18:33:06.032: //99/69EE8ECDB80A/CCAPI/cc_relay_digit_begin_for_3way_conference:
Check DTMF relay digit begin for 3way conf
Oct 26 18:33:06.052: //99/69EE8ECDB80A/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 1 to dstCallId 0x64
Oct 26 18:33:06.052: //99/69EE8ECDB80A/CCAPI/cc_relay_digit_end_for_3way_conference:
Check DTMF relay digit end for 3way conf
Oct 26 18:33:07.324: //99/69EE8ECDB80A/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 1 to dstCallId 0x64
Oct 26 18:33:07.324: //99/69EE8ECDB80A/CCAPI/cc_relay_digit_begin_for_3way_conference:
Check DTMF relay digit begin for 3way conf
Oct 26 18:33:07.352: //99/69EE8ECDB80A/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 1 to dstCallId 0x64
Oct 26 18:33:07.352: //99/69EE8ECDB80A/CCAPI/cc_relay_digit_end_for_3way_conference:
Check DTMF relay digit end for 3way conf
Oct 26 18:33:15.280: //100/69EE8ECDB80A/CCAPI/cc_api_call_disconnected:
Cause Value=1, Interface=0x8941EF14, Call Id=100
Oct 26 18:33:15.280: //100/69EE8ECDB80A/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
Oct 26 18:33:15.280: //99/69EE8ECDB80A/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
Oct 26 18:33:15.280: //100/69EE8ECDB80A/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=100
Oct 26 18:33:15.280: //99/69EE8ECDB80A/CCAPI/ccConferenceDestroy:
Conference Id=0x19, Tag=0x0
Oct 26 18:33:15.280: //99/69EE8ECDB80A/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x19, Source Interface=0x89C354A4, Source Call Id=99,
Destination Call Id=100, Disposition=0x0, Tag=0x0
Oct 26 18:33:15.284: //100/69EE8ECDB80A/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x19, Source Interface=0x8941EF14, Source Call Id=100,
Destination Call Id=99, Disposition=0x0, Tag=0x0
Oct 26 18:33:15.284: //99/69EE8ECDB80A/CCAPI/cc_generic_bridge_done:
Conference Id=0x19, Source Interface=0x8941EF14, Source Call Id=100,
Destination Call Id=99, Disposition=0x0, Tag=0x0
Oct 26 18:33:15.284: //100/69EE8ECDB80A/CCAPI/ccCallDisconnect:
Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1)
Oct 26 18:33:15.284: //100/69EE8ECDB80A/CCAPI/ccCallDisconnect:
Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 26 18:33:15.284: //100/69EE8ECDB80A/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
Oct 26 18:33:15.292: //100/69EE8ECDB80A/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
Oct 26 18:33:15.296: //100/69EE8ECDB80A/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x8941EF14, Tag=0x0, Call Id=100,
Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 26 18:33:15.296: //100/69EE8ECDB80A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
Oct 26 18:33:15.296: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 26 18:33:15.296: :cc_free_feature_vsa freeing 8C5ABAE8
Oct 26 18:33:15.296: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 26 18:33:15.296: vsacount in free is 1
Oct 26 18:33:15.296: //99/69EE8ECDB80A/CCAPI/ccCallDisconnect:
Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Oct 26 18:33:15.300: //99/69EE8ECDB80A/CCAPI/ccCallDisconnect:
Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 26 18:33:15.300: //99/69EE8ECDB80A/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
Oct 26 18:33:18.992: //99/69EE8ECDB80A/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x89C354A4, Tag=0x0, Call Id=99,
Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 26 18:33:18.992: //99/69EE8ECDB80A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
Oct 26 18:33:18.992: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 26 18:33:18.992: :cc_free_feature_vsa freeing 8C5ABBC8
Oct 26 18:33:18.992: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 26 18:33:18.992: vsacount in free is 0

0 Helpful
Customers Also Viewed These Support Documents