Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
Community Member

Any FXO Outgoing call

Hi Guys,

From my findings on my debug voip ccapi trace, I do not see any outgoing call from POTS dialpeer to VOIP dialpeer. Can I confirm if my conclusion is correct?

Currently there are 4 FXO ports with 2 ports shutdown. Incoming call from VOIP to POTS is ok. User complaint they cannot make outgoing VOIP calls.

Any advise will be appreciated.

Thanks in advance,

TA                 

-----------------------------------------

Router-2821#
Router-2821#sh voice port sum
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    dorm idle     on-hook  y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y

PWR FAILOVER PORT        PSTN FAILOVER PORT
=================        ==================

Router-2821#sh voice port sum
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type SETUPIND_CHOSEN
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/H323/setup_ind: Entry
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind: callingNumber[35] calledNumber[8239890]
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind: ---- calling IE present
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind: ====== PI = 3
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind: Receive: infoXCap 16
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind: Receive: infoXCap ccb 16
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/setup_ind:
setup_ind: is_overlap = 0, info_complete = 0

.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/cch323_h225_receiver: SETUPIND_CHOSEN: src address = 183.81.252.18; dest address = 192.168.160.241
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_FS_SETUP_IND while at state H225_IDLE
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/idle_fsSetupInd_hdlr: Setup ccb 0x47B06CE8
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpAssociateIncomingPeerCore:
   Calling Number=35, Called Number=8239890, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/act_fastStartSetupInd: full match is found
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H32
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    up   idle     off-hook y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y

PWR FAILOVER PORT        PSTN FAILOVER PORT
=================        ==================

Router-2821#3/act_fastStartSetupInd: codec match = 1
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpAssociateIncomingPeerCore:
   Calling Number=35, Called Number=8239890, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/cch323_create_incoming_callinfo_block: peer 4701834C, voice_peer_tag 8357, ccb: 47B06CE8
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/cch323_h225_handle_deferred_ind: UnBuffering deferred indications
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=2
     2: Dial-peer Tag=1
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=8239890, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8239890, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8239890, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:32 SPORE: //-1/98F39104B269/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb: 
   CDB=0x4AA6E998
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
.Aug 21 09:37:32 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event: 
   [state:INVALID STATE MACHINE, event:E_CC_SETUP_REQ]
.Aug 21 09:37:32 SPORE: htsp_timer_stop3
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_og_call_req: 
   Echo Cancel=TRUE, Gain Control=0
   Auto Gain Control=FALSE, Dual Tone Detect Mask=0x0, Seq Tone Detect=FALSE
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_req:
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_req_pend_succ:
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_request_call: 
   Mode=0, Peer=1
.Aug 21 09:37:32 SPORE: digit_strip:1, pcn:8239890, poa:82.....
.Aug 21 09:37:32 SPORE: pcn:39890, poa:.....
.Aug 21 09:37:32 SPORE: Final pcn:39890, poa:....., dial_string:39890
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req: 
   Target Carrier ID=
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req: 
   Source Carrier ID=htsp_setup_req
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_request_call: 
   Progress Indication=3, Info Trans Capability=16
   Calling Number=35, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
   Called Number=8239890, TON=Unknown, NPI=Unknown
.Aug 21 09:37:32 SPORE: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
.Aug 21 09:37:32 SPORE: [0/1/0] set signal state = 0xC timestamp = 0
.Aug 21 09:37:32 SPORE: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0
.Aug 21 09:37:32 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:37:32 SPORE: htsp_timer - 1300 msec
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_timer: 
   Timer Start Time=5338326, Timer Value=25000(ms)
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding: 
   Peer=1, Progress Indication=0, Return Code=2
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_req_wait_pend_success: 
   Event=73
.Aug 21 09:37:32 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5338326
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_CALLPROC while at state H225_REQ_FS_SETUP
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_ACC_FS_CALLPROC state
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/generic_send_callproc: ====== PI = 0
.Aug 21 09:37:32 SPORE: //49/98F39104B269/H323/fastStartIdle: ccb->status_1 = 0x1
.Aug 21 09:37:33 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer  htsp_dial
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_DIAL]
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_dial: 
   Digits=39890, Tone Mode=0
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dial:
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/ds_do_dial: 
   Digits To Dial=39890
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb: 
   Begin Digit=9
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb: 
   Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=FALSE
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5338491
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb: 
   End Digit=9
.Aug 21 09:37:33 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb: 
   Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=FALSE
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_dial_done_cb:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_DS_DIALING, event:E_VTSP_DSM_DIALING_COMPLETE]
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/ds_dialing:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/ds_do_dial: 
   Digits To Dial=
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_digit_pop:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_dial_comp:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/ds_do_dial:exit@571
.Aug 21 09:37:34 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
.Aug 21 09:37:34 SPORE: htsp_timer - 350 msec
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_PROGRESS]
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_progress: 
   Progress Indication=8, Signal Indication=2, cdb->answer_supervision=0
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_start: 
   Timer Start Time=5338561, No Answer Timer Value=180000(ms)
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:
.Aug 21 09:37:34 SPORE: htsp_call_bridged invoked
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:exit@1360
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/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=8357
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config: 
   Save TTY configuration
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param: 
   Set TTY feat parameters
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_CC_DO_CAPS_IND]
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb: 
   Event=E_DSM_CC_CAPS_ACK
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_PROGRESS while at state H225_ACC_FS_CALLPROC
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_CALLPROC state to H225_ACC_FS_PROGRESS state
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_generic_progress: ====== PI = 8, cause = 0
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_CC_CAPS_IND]
.Aug 21 09:37:34 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:37:34 SPORE: flex_dsprm_forking_mixing_support:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb: 
   Event=E_DSM_CC_CALL_MODIFY
.Aug 21 09:37:34 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:37:34 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_feature_notify_cb: 
   Feature ID=0, Feature Status=1
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:exit@1152
.Aug 21 09:37:34 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
.Aug 21 09:37:34 SPORE: htsp_timer_stop
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_CONNECT]
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_setup_pend_connect: 
   Progress Indication=2
.Aug 21 09:37:34 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop: 
   Timer Stop Time=5338562
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=35, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=35
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=8357
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_post_call_service_msg: callID=49, notify data mask=0x00000007
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_NOTIFY while at state H225_ACC_FS_PROGRESS
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Notify data found, mask=0x00000007
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Display Info IE =
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Notification Indicator IE = 113
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Connected Number as ASN non-std
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: [cnum]/[oct]/[oct3a] = [8239890]/[0x00]/[0x00]
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=35, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=35
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=8357
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=2
     2: Dial-peer Tag=1
.Aug 21 09:37:34 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_post_call_service_msg: callID=49, notify data mask=0x00000007
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_SETUP_CFM while at state H225_ACC_FS_PROGRESS
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/generic_send_setup_cfm: ====== PI = 2
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/generic_send_setup_cfm: Sending CONNECT Display Info IE =
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/copy_token_from_ccb: copy_token_from_ccb: Entered
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_PROGRESS state to H225_FS_ACTIVE state
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_NOTIFY while at state H225_FS_ACTIVE
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Notify data found, mask=0x00000007
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Display Info IE =
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Notification Indicator IE = 113
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: Sending NOTIFY Connected Number as ASN non-std
.Aug 21 09:37:34 SPORE: //49/98F39104B269/H323/send_notify_msg: [cnum]/[oct]/[oct3a] = [8239890]/[0x00]/[0x00]
.Aug 21 09:37:57 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN
.Aug 21 09:37:57 SPORE: //49/98F39104B269/H323/release_ind: Disconnect cause 16 location code 1
.Aug 21 09:37:57 SPORE: //49/98F39104B269/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 183.81.252.18; dest address = 192.168.160.241
.Aug 21 09:37:57 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_FS_ACTIVE
.Aug 21 09:37:57 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
.Aug 21 09:37:57 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_CONNECT, event:E_CC_DISCONNECT]
.Aug 21 09:37:57 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_disconnect: 
   Cause Value=16
.Aug 21 09:37:57 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop: 
   Timer Stop Time=5340923
.Aug 21 09:37:57 SPORE: htsp_timer_stop3
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
.Aug 21 09:37:58 SPORE: //49/98F39104B269/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_FS_ACTIVE
.Aug 21 09:37:58 SPORE: //49/98F39104B269/H323/cch323_h225_send_release: Cause = 16; Location = 1
.Aug 21 09:37:58 SPORE: //49/98F39104B269/H323/cch323_h225_send_release: h225TerminateRequest: src address = -1219363822; dest address = 192.168.160.241
.Aug 21 09:37:58 SPORE: //49/98F39104B269/H323/cch323_h225_set_new_state: Changing from H225_FS_ACTIVE state to H225_IDLE state
.Aug 21 09:37:58 SPORE: //-1/xxxxxxxxxxxx/DP
Router-2821#M/dpAssociateIncomingPeerCore:
   Calling Number=35T, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:58 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_dsm_dsp_stats_complete: htsp_release_req: cause 16, no_onhook 0
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_timer: 
   Timer Start Time=5340925, Timer Value=60000(ms)
.Aug 21 09:37:58 SPORE: htsp_process_event: [0/1/0, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
.Aug 21 09:37:58 SPORE: htsp_timer_stop
.Aug 21 09:37:58 SPORE: htsp_timer_stop2
.Aug 21 09:37:58 SPORE: htsp_timer_stop3
.Aug 21 09:37:58 SPORE: [0/1/0] set signal state = 0x4 timestamp = 0
.Aug 21 09:37:58 SPORE: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
.Aug 21 09:37:58 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:37:58 SPORE: htsp_timer - 2000 msec
.Aug 21 09:37:58 SPORE: TGRM: reg_invoke_tgrm_channel_service_update(0, 1, 0, 65535, 1)
.Aug 21 09:37:58 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop: 
   Timer Stop Time=5340925
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5340925
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
.Aug 21 09:37
Router-2821#
Router-2821#sh voice port sum
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    dorm idle     on-hook  y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y

PWR FAILOVER PORT        PSTN FAILOVER PORT
=================        ==================

Router-2821#:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history: 
   Coder Rate=16
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle: 
   DMGR=0x49F6D514, VTSP CDB=0x4AA6E998
.Aug 21 09:37:58 SPORE: flex_dsprm_close_cleanup
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event: 
   [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/act_terminate:
.Aug 21 09:37:58 SPORE: //50/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop: 
   Timer Stop Time=5340926
.Aug 21 09:37:58 SPORE: //-1/98F39104B269/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb: 
   CDB=0x4AA6E998
.Aug 21 09:37:58 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=82....., Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:37:58 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:38:00 SPORE: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
.Aug 21 09:38:00 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:38:00 SPORE: dsp_req_sig_state: [0/1/0] packet_len=8 channel_id=128 packet_id=40
.Aug 21 09:38:00 SPORE: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]sh voice port sum
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    dorm idle     on-hook  y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y
Router-2821#
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type SETUPIND_CHOSEN
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/H323/setup_ind: Entry
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind: callingNumber[35] calledNumber[8239890]
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind: ---- calling IE present
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind: ====== PI = 3
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind: Receive: infoXCap 16
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind: Receive: infoXCap ccb 16
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/setup_ind:
setup_ind: is_overlap = 0, info_complete = 0

.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/cch323_h225_receiver: SETUPIND_CHOSEN: src address = 183.81.252.18; dest address = 192.168.160.241
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_FS_SETUP_IND while at state H225_IDLE
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/idle_fsSetupInd_hdlr: Setup ccb 0x47B06CE8
.Aug 21 09:
Router-2821#
Router-2821#
Router-2821#38:49 SPORE: //-1/C75CC8EFB275/DPM/dpAssociateIncomingPeerCore:
   Calling Number=35, Called Number=8239890, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/act_fastStartSetupInd: full match is found
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/act_fastStartSetupInd: codec match = 1
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpAssociateIncomingPeerCore:
   Calling Number=35, Called Number=8239890, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/cch323_create_incoming_callinfo_block: peer 4701834C, voice_peer_tag 8357, ccb: 47B06CE8
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/cch323_h225_handle_deferred_ind: UnBuffering deferred indications
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Matc
Router-2821#h Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=2
     2: Dial-peer Tag=1
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=8239890, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=2
     2: Dial-peer Tag=1
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8239890, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8239890, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:49 SPORE: //-1/C75CC8EFB275/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb: 
   CDB=0x4AA6E6D0
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
.Aug 21 09:38:49 SPORE: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event: 
   [state:INVALID STATE MACHINE, event:E_CC_SETUP_REQ]
.Aug 21 09:38:49 SPORE: htsp_timer_stop3
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/sh voice port sum1/0):-1:-1:-1/vtsp_og_call_req: 
   Echo Cancel=TRUE, Gain Control=0
   Auto Gain Control=FALSE, Dual Tone Detect Mask=0x0, Seq Tone Detect=FALSE
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_req:
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_req_pend_succ:
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_request_call: 
   Mode=0, Peer=1
.Aug 21 09:38:49 SPORE: digit_strip:1, pcn:8239890, poa:82.....
.Aug 21 09:38:49 SPORE: pcn:39890, poa:.....
.Aug 21 09:38:49 SPORE: Final pcn:39890, poa:....., dial_string:39890
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req: 
   Target Carrier ID=
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req: 
   Source Carrier ID=htsp_setup_req
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_request_call: 
   Progress Indication=3, Info Trans Capability=16
   Calling Number=35, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
   Called Number=8239890, TON=Unknown, NPI=Unknown
.Aug 21 09:38:49 SPORE: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
.Aug 21 09:38:49 SPORE: [0/1/0] set signal state = 0xC timestamp = 0
.Aug 21 09:38:49 SPORE: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0
.Aug 21 09:38:49 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:38:49 SPORE: htsp_timer - 1300 msec
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_timer: 
   Timer Start Time=5346071, Timer Value=25000(ms)
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding: 
   Peer=1, Progress Indication=0, Return Code=2
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_req_wait_pend_success: 
   Event=73
.Aug 21 09:38:49 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5346071
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_CALLPROC while at state H225_REQ_FS_SETUP
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_ACC_FS_CALLPROC state
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/generic_send_callproc: ====== PI = 0
.Aug 21 09:38:49 SPORE: //51/C75CC8EFB275/H323/fastStartIdle: c
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    up   idle     off-hook y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y

PWR FAILOVER PORT        PSTN FAILOVER PORT
=================        ==================

Router-2821#cb->status_1 = 0x1
.Aug 21 09:38:50 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer  htsp_dial
.Aug 21 09:38:50 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_DIAL]
.Aug 21 09:38:50 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_dial: 
   Digits=39890, Tone Mode=0
.Aug 21 09:38:50 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dial:
.Aug 21 09:38:50 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/ds_do_dial: 
   Digits To Dial=39890
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb: 
   Begin Digit=9
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_begin_cb: 
   Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=FALSE
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5346239
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb: 
   End Digit=9
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_digit_end_cb: 
   Digit Reporting=FALSE, Digit Consume=FALSE, Digit Relay=FALSE
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_dial_done_cb:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_DS_DIALING, event:E_VTSP_DSM_DIALING_COMPLETE]
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/ds_dialing:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/ds_do_dial: 
   Digits To Dial=
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_digit_pop:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_dial_comp:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/ds_do_dial:exit@571
.Aug 21 09:38:51 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
.Aug 21 09:38:51 SPORE: htsp_timer - 350 msec
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_PROGRESS]
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_progress: 
   Progress Indication=8, Signal Indication=2, cdb->answer_supervision=0
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_start: 
   Timer Start Time=5346306, No Answer Timer Value=180000(ms)
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:
.Aug 21 09:38:51 SPORE: htsp_call_bridged invoked
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:exit@1360
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/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=8357
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config: 
   Save TTY configuration
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param: 
   Set TTY feat parameters
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_CC_DO_CAPS_IND]
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb: 
   Event=E_DSM_CC_CAPS_ACK
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_PROGRESS while at state H225_ACC_FS_CALLPROC
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_CALLPROC state to H225_ACC_FS_PROGRESS state
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_generic_progress: ====== PI = 8, cause = 0
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_CC_CAPS_IND]
.Aug 21 09:38:51 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:38:51 SPORE: flex_dsprm_forking_mixing_support:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb: 
   Event=E_DSM_CC_CALL_MODIFY
.Aug 21 09:38:51 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:38:51 SPORE: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_feature_notify_cb: 
   Feature ID=0, Feature Status=1
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:exit@1152
.Aug 21 09:38:51 SPORE: htsp_process_event: [0/1/0, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
.Aug 21 09:38:51 SPORE: htsp_timer_stop
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_SETUP_REQ_PROC, event:E_TSP_CONNECT]
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_setup_pend_connect: 
   Progress Indication=2
.Aug 21 09:38:51 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop: 
   Timer Stop Time=5346307
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=35, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=35
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=8357
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=2
     2: Dial-peer Tag=1
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_post_call_service_msg: callID=51, notify data mask=0x00000007
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_NOTIFY while at state H225_ACC_FS_PROGRESS
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Notify data found, mask=0x00000007
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Display Info IE =
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Notification Indicator IE = 113
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Connected Number as ASN non-std
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: [cnum]/[oct]/[oct3a] = [8239890]/[0x00]/[0x00]
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=35, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=35
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=8357
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8239890, Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8239890
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1
     2: Dial-peer Tag=2
.Aug 21 09:38:51 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_post_call_service_msg: callID=51, notify data mask=0x00000007
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_SETUP_CFM while at state H225_ACC_FS_PROGRESS
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/generic_send_setup_cfm: ====== PI = 2
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/generic_send_setup_cfm: Sending CONNECT Display Info IE =
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/copy_token_from_ccb: copy_token_from_ccb: Entered
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_PROGRESS state to H225_FS_ACTIVE state
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_NOTIFY while at state H225_FS_ACTIVE
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Notify data found, mask=0x00000007
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Display Info IE =
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Notification Indicator IE = 113
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: Sending NOTIFY Connected Number as ASN non-std
.Aug 21 09:38:51 SPORE: //51/C75CC8EFB275/H323/send_notify_msg: [cnum]/[oct]/[oct3a] = [8239890]/[0x00]/[0x00]
.Aug 21 09:39:05 SPORE: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/release_ind: Disconnect cause 16 location code 1
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 183.81.252.18; dest address = 192.168.160.241
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_FS_ACTIVE
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_CONNECT, event:E_CC_DISCONNECT]
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_disconnect: 
   Cause Value=16
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop: 
   Timer Stop Time=5347694
.Aug 21 09:39:05 SPORE: htsp_timer_stop3
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_FS_ACTIVE
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/cch323_h225_send_release: Cause = 16; Location = 1
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/cch323_h225_send_release: h225TerminateRequest: src address = -1219363822; dest address = 192.168.160.241
.Aug 21 09:39:05 SPORE: //51/C75CC8EFB275/H323/cch323_h225_set_new_state: Changing from H225_FS_ACTIVE state to H225_IDLE state
.Aug 21 09:39:05 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=35T, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:39:05 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=8357
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_dsm_dsp_stats_complete: htsp_release_req: cause 16, no_onhook 0
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_timer: 
   Timer Start Time=5347695, Timer Value=60000(ms)
.Aug 21 09:39:05 SPORE: htsp_process_event: [0/1/0, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
.Aug 21 09:39:05 SPORE: htsp_timer_stop
.Aug 21 09:39:05 SPORE: htsp_timer_stop2
.Aug 21 09:39:05 SPORE: htsp_timer_stop3
.Aug 21 09:39:05 SPORE: [0/1/0] set signal state = 0x4 timestamp = 0
.Aug 21 09:39:05 SPORE: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
.Aug 21 09:39:05 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:39:05 SPORE: htsp_timer - 2000 msec
.Aug 21 09:39:05 SPORE: TGRM: reg_invoke_tgrm_channel_service_update(0, 1, 0, 65535, 1)
.Aug 21 09:39:05 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_process_event: 
   [state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop: 
   Timer Stop Time=5347695
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop: 
   Timer Stop Time=5347695
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history: 
   Coder Rate=16
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle: 
   DMGR=0x49F6D514, VTSP CDB=0x4AA6E6D0
.Aug 21 09:39:05 SPORE: flex_dsprm_close_cleanup
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event: 
   [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/act_terminate:
.Aug 21 09:39:05 SPORE: //52/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop: 
   Timer Stop Time=5347696
.Aug 21 09:39:05 SPORE: //-1/C75CC8EFB275/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb: 
   CDB=0x4AA6E6D0
.Aug 21 09:39:05 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=82....., Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
.Aug 21 09:39:05 SPORE: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
.Aug 21 09:39:07 SPORE: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
.Aug 21 09:39:07 SPORE: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
.Aug 21 09:39:07 SPORE: dsp_req_sig_state: [0/1/0] packet_len=8 channel_id=128 packet_id=40
.Aug 21 09:39:07 SPORE: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]sh voice port sum
                                           IN       OUT
PORT            CH   SIG-TYPE   ADMIN OPER STATUS   STATUS   EC
=============== == ============ ===== ==== ======== ======== ==
0/1/0           --  fxo-ls      up    dorm idle     on-hook  y
0/1/1           --  fxo-ls      up    dorm idle     on-hook  y
0/2/0           --  fxo-ls      down  down idle     on-hook  y
0/2/1           --  fxo-ls      down  down idle     on-hook  y

PWR FAILOVER PORT        PSTN FAILOVER PORT
=================        ==================

Router-2821#
Router-2821#
Router-2821#

1 REPLY
VIP Super Bronze

Any FXO Outgoing call

Its difficult to tell accurately whats's going on without understanding your setup. From the logs.

Calling Number=35, Called Number=8239890,

The logs showed that there was no outgoing dial-peer matched for the called number.

Can you send a sh run of your gateway.

Please rate all useful posts

"'Nature is too thin a screen, the glory of the omnipresent God bursts through it everywhere"-Ralph Waldo Emerson

Please rate all useful posts "The essence of christianity is not the enthronement but the obliteration of self --William Barclay"
345
Views
0
Helpful
1
Replies
CreatePlease to create content