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
399
Views
0
Helpful
1
Replies

FXO Calls Dropping If Answered Before Second Ring

R M
Level 1
Level 1

‎02-03-2016 06:30 AM - edited ‎03-17-2019 05:44 AM

Good morning! I've got a problem that's been stumping me for some time. I've got a site that has a Cisco 2921 Router with a VIC2-4FXO card. This is configured as a voice gateway in CUCM 7.1. When calls ring into the FXO card, if they are answered before the second ring (on the device), the call is dropped. It's not every single time, but very frequently. It seems like the drop occurs if the call is answered right at 6 seconds of ringing.

The telco sent a technician to inspect all the lines to the router, finding no faults.

Below is the debug from a call that actually dropped:


*Feb 3 01:37:47.851: htsp_process_event: [0/0/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Feb 3 01:37:47.851: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
*Feb 3 01:37:47.851: htsp_timer - 125 msec
*Feb 3 01:37:47.979: htsp_process_event: [0/0/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Feb 3 01:37:47.979: htsp_timer - 10000 msec
*Feb 3 01:37:47.979: htsp_timer3 - 5600 msec
*Feb 3 01:37:47.979: [0/0/0] htsp_start_caller_id_rx:BELLCORE
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_create: .
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/set_echo_canceller_data: echo_cancel: 0
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/set_echo_canceller_data: echo_flags: 38, echo_len: 1024
*Feb 3 01:37:47.979: htsp_start_caller_id_rx create dsp_stream_manager
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_set_dsp_allocated: .
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_implement_feature:
*Feb 3 01:37:47.979: dsp_stream_mgr_implement_feature: feature id = 7
*Feb 3 01:37:47.979: //-1/313233343930/DSM:(0/0/0):-1/dsmp_dsmapi_reserve_resource_cb: .
Cisco-Rtr-2921#
*Feb 3 01:37:47.979: [0/0/0] htsp_dsm_create_success returns 1
*Feb 3 01:37:47.979: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
Cisco-Rtr-2921#
*Feb 3 01:37:49.927: htsp_process_event: [0/0/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Feb 3 01:37:49.927: fxols_ringing_not
*Feb 3 01:37:49.927: htsp_timer_stop
*Feb 3 01:37:49.927: htsp_timer - 10000 msec
*Feb 3 01:37:51.243: //-1/313233343930/DSM:(0/0/0):-1/dsmp_dsmapi_detection_cb: .
*Feb 3 01:37:51.243: [0/0/0] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
*Feb 3 01:37:51.243: htsp_process_event: [0/0/0, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
*Feb 3 01:37:51.243: htsp_timer_stop
*Feb 3 01:37:51.243: htsp_timer_stop3
*Feb 3 01:37:51.243: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_destroy: .
*Feb 3 01:37:51.243: //-1/313233343930/DSM:(0/0/0):-1/dsm_delete_all_streams: .
*Feb 3 01:37:51.243: //-1/313233343930/DSM:(0/0/0):-1/dsmapi_accept_modem_passthrough_session: : dmgr: 31591AB4, active sessions 0, max sessions: 16 rejected sessions till now: 0
*Feb 3 01:37:51.243: [0/0/0] htsp_stop_caller_id_rx. message length 46htsp_setup_ind
*Feb 3 01:37:51.243: [0/0/0] get_fxo_caller_id:Caller ID received. Message type=128 length=42 checksum=73
*Feb 3 01:37:51.243: [0/0/0] Caller ID String 80 27 01 08 40 32 20 32 32 30 33 36 02 0A 33 30 34 30 34 38 33 33 30 34 07 0F 4D 55 4C 4C 49 4E 20 50 41 59 4D 4F 4E 44 20 73
*Feb 3 01:37:51.243: [0/0/0] get_fxo_caller_id calling num=8002420100 calling name=Morning Radio calling time=02/02 20:36
*Feb 3 01:37:51.243: TGRM: reg_invoke_tgrm_accept_call(1, TGRM_CALL_VOICE, TGRM_DIRECTION_IN, 0, 0, 0, 65535)
*Feb 3 01:37:51.243: TGRM: Calling vtsp_tsp_call_setup_ind().
*Feb 3 01:37:51.243: fxols_callerid_done: call being answered
*Feb 3 01:37:51.243: flex_dsprm_close_cleanup
*Feb 3 01:37:51.243: //-1/313233343930/DSM:(0/0/0):-1/dsmp_dsmapi_reserve_resource_cb: .
*Feb 3 01:37:51.243: [0/0/0] htsp_dsm_close_done
*Feb 3 01:37:51.243: htsp_process_event: [0/0/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Feb 3 01:37:51.243: fxols_wait_setup_ack:
*Feb 3 01:37:51.243: htsp_timer - 6000 msec
Cisco-Rtr-2921#
*Feb 3 01:37:51.247: htsp_process_event: [0/0/0, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
*Feb 3 01:37:51.295: htsp_process_event: [0/0/0, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alert
*Feb 3 01:37:51.295: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:51.319: htsp_process_event: [0/0/0, FXOLS_PROCEEDING, E_DSP_SIG_0110]fxols_rvs_battery
*Feb 3 01:37:51.319: htsp_timer_stop2
*Feb 3 01:37:51.319: htsp_timer_stop2 htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Cisco-Rtr-2921#
*Feb 3 01:37:53.851: htsp_process_event: [0/0/0, FXOLS_PROCEED_RVS_BT, E_DSP_SIG_0000]
Cisco-Rtr-2921#
*Feb 3 01:37:55.723: htsp_call_bridged invokedhtsp_connect: no_offhook 0 call_connected 0
*Feb 3 01:37:55.727: htsp_process_event: [0/0/0, FXOLS_PROCEED_RVS_BT, E_HTSP_CONNECT]fxols_offhook_connect
*Feb 3 01:37:55.727: [0/0/0] set signal state = 0xC timestamp = 0
*Feb 3 01:37:55.727: dsp_set_sig_state: [0/0/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0
*Feb 3 01:37:55.727: htsp_timer_stop
*Feb 3 01:37:55.727: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:55.727: flex_dsprm_forking_mixing_support: htsp_call_service_msghtsp_call_service_msg not EFXS (2)
*Feb 3 01:37:55.727: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:55.727: htsp_process_event: [0/0/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Feb 3 01:37:55.755: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:55.755: flex_dsprm_forking_mixing_support:
*Feb 3 01:37:55.755: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:55.755: flex_dsprm_forking_mixing_support:
*Feb 3 01:37:55.755: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Feb 3 01:37:55.755: htsp_process_event: [0/0/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Feb 3 01:37:55.755: htsp_process_event: [0/0/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Feb 3 01:37:55.927: htsp_process_event: [0/0/0, FXOLS_CONNECT, E_DSP_SIG_0100]fxols_normal_battery
*Feb 3 01:37:55.927: htsp_timer_stop2 fxols_disc_confirm
*Feb 3 01:37:55.927: htsp_timer_stop
*Feb 3 01:37:55.927: htsp_timer_stop2
*Feb 3 01:37:55.927: htsp_timer_stop3
*Feb 3 01:37:55.931: htsp_timer_stop3 htsp_release_req: cause 16, no_onhook 0
*Feb 3 01:37:55.947: htsp_process_event: [0/0/0, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Feb 3 01:37:55.947: htsp_timer_stop
*Feb 3 01:37:55.947: htsp_timer_stop2
*Feb 3 01:37:55.947: htsp_timer_stop3
*Feb 3 01:37:55.947: [0/0/0] set signal state = 0x4 timestamp = 0
*Feb 3 01:37:55.947: dsp_set_sig_state: [0/0/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
*Feb 3 01:37:55.947: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
*Feb 3 01:37:55.947: htsp_timer - 2000 msec
*Feb 3 01:37:55.947: TGRM: reg_invoke_tgrm_channel_service_update(0, 0, 0, 65535, 1)
*Feb 3 01:37:55.947: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
*Feb 3 01:37:55.947: flex_dsprm_close_cleanup
*Feb 3 01:37:56.003: htsp_process_event: [0/0/0, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
*Feb 3 01:37:56.219: htsp_process_event: [0/0/0, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
*Feb 3 01:37:56.311: htsp_process_event: [0/0/0, FXOLS_GUARD_OUT, E_DSP_SIG_0000]fxols_guard_out_ringing
*Feb 3 01:37:56.311: htsp_timer_stop
*Feb 3 01:37:56.311: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)fxols_onhook_ringing
*Feb 3 01:37:56.311: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
*Feb 3 01:37:56.311: htsp_timer - 125 msec
*Feb 3 01:37:56.439: htsp_process_event: [0/0/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Feb 3 01:37:56.439: htsp_timer - 10000 msec
*Feb 3 01:37:56.439: htsp_timer3 - 5600 msec
*Feb 3 01:37:56.439: [0/0/0] htsp_start_caller_id_rx:BELLCORE
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_create: .
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/set_echo_canceller_data: echo_cancel: 0
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/set_echo_canceller_data: echo_flags: 38, echo_len: 1024
*Feb 3 01:37:56.439: htsp_start_caller_id_rx create dsp_stream_manager
Cisco-Rtr-2921#
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_set_dsp_allocated: .
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_implement_feature:
*Feb 3 01:37:56.439: dsp_stream_mgr_implement_feature: feature id = 7
*Feb 3 01:37:56.439: //-1/313233343930/DSM:(0/0/0):-1/dsmp_dsmapi_reserve_resource_cb: .
*Feb 3 01:37:56.439: [0/0/0] htsp_dsm_create_success returns 1
*Feb 3 01:37:56.439: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
Cisco-Rtr-2921#
*Feb 3 01:38:02.039: htsp_process_event: [0/0/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
*Feb 3 01:38:02.039: htsp_timer_stop3
Cisco-Rtr-2921#
*Feb 3 01:38:06.439: htsp_process_event: [0/0/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER]fxols_ringing_disc
*Feb 3 01:38:06.439: htsp_timer_stop3
*Feb 3 01:38:06.439: htsp_timer_stop
*Feb 3 01:38:06.439: //-1/313233343930/DSM:(0/0/0):-1/dsp_stream_mgr_destroy: .
*Feb 3 01:38:06.439: //-1/313233343930/DSM:(0/0/0):-1/dsm_delete_all_streams: .
*Feb 3 01:38:06.439: //-1/313233343930/DSM:(0/0/0):-1/dsmapi_accept_modem_passthrough_session: : dmgr: 30EA3FE0, active sessions 0, max sessions: 16 rejected sessions till now: 0
*Feb 3 01:38:06.439: [0/0/0] htsp_stop_caller_id_rx. message length 0
Cisco-Rtr-2921#
*Feb 3 01:38:06.439: TGRM: reg_invoke_tgrm_call_update(0, 0, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
*Feb 3 01:38:06.439: flex_dsprm_close_cleanup
*Feb 3 01:38:06.439: //-1/313233343930/DSM:(0/0/0):-1/dsmp_dsmapi_reserve_resource_cb: .
*Feb 3 01:38:06.439: [0/0/0] htsp_dsm_close_done
Cisco-Rtr-2921#

Here's one of the port configs:

Cisco-Rtr-2921#sh voice port 0/0/0

Foreign Exchange Office 0/0/0 Slot is 0, Sub-unit is 0, Port is 0
 Type of VoicePort is FXO
 Operation State is DORMANT
 Administrative State is UP
 The Last Interface Down Failure Cause is Administrative Shutdown
 Description is -----------Main-Line
 Noise Regeneration is disabled
 Non Linear Processing is enabled
 Non Linear Mute is disabled
 Non Linear Threshold is -21 dB
 Music On Hold Threshold is Set to -38 dBm
 In Gain is Set to 0 dB
 Out Attenuation is Set to 3 dB
 Echo Cancellation is enabled
 Echo Cancellation NLP mute is disabled
 Echo Cancellation NLP threshold is -21 dB
 Echo Cancel Coverage is set to 128 ms
 Echo Cancel worst case ERL is set to 6 dB
 Playout-delay Mode is set to adaptive
 Playout-delay Nominal is set to 60 ms
 Playout-delay Maximum is set to 1000 ms
 Playout-delay Minimum mode is set to default, value 40 ms
 Playout-delay Fax is set to 300 ms
 Connection Mode is plar opx
 Connection Number is 10246
 Initial Time Out is set to 15 s
 Interdigit Time Out is set to 10 s
 Call Disconnect Time Out is set to 60 s
 Power Denial Disconnect Time Out is set to 1000 ms
 Ringing Time Out is set to 180 s
 Wait Release Time Out is set to 30 s
 Companding Type is u-law
 Region Tone is set for US

 Analog Info Follows:
 Currently processing none
 Maintenance Mode Set to None (not in mtc mode)
 Number of signaling protocol errors are 0
 Impedance is set to 600r Ohm
 Station name None, Station number None

 Caller ID Info Follows:
 Standard BELLCORE
 Caller ID is received after 1 ring(s)
 Translation profile (Incoming):
 Translation profile (Outgoing):
 lpcor (Incoming):
 lpcor (Outgoing):

 Voice card specific Info Follows:
 Signal Type is loopStart
 Battery-Reversal is enabled
 Number Of Rings is set to 1
 Supervisory Disconnect is signal
 Answer Supervision is inactive
 Hook Status is On Hook
 Ring Detect Status is inactive
 Ring Ground Status is inactive
 Tip Ground Status is inactive
 Dial Out Type is dtmf
 Digit Duration Timing is set to 100 ms
 InterDigit Duration Timing is set to 100 ms
 Pulse Rate Timing is set to 10 pulses/second
 InterDigit Pulse Duration Timing is set to 750 ms
 Percent Break of Pulse is 60 percent
 GuardOut timer is 2000 ms
 Minimum ring duration timer is 125 ms
 Hookflash-in Timing is set to 600 ms
 Hookflash-out Timing is set to 500 ms
 Supervisory Disconnect Timing (loopStart only) is set to 350 ms
 OPX Ring Wait Timing is set to 6000 ms

And suggestion that would point me in the right direction is appreciated!

Labels:
0 Helpful
1 Reply 1

R M
Level 1
Level 1

‎02-08-2016 07:56 AM

I ran debug voip ccapi and noticed something interesting on the dropped calls. "Transfer Number Is Null" appears on the dropped calls. I'm not sure what this could point to, but I think it's a vital clue. Has anyone seen this before?

Here's the output:

Cisco-Rtr-2921#
*Feb  6 03:08:22.424: //-1/B6FCCDB49662/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=5558675309
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=64201
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   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

*Feb  6 03:08:22.424: //-1/B6FCCDB49662/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x30C5C7A8, Call Info(
   Calling Number=5558675309,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=64201(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=TRUE,
   Source Trkgrp Route Label=FXO, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424: :cc_get_feature_vsa malloc success
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424:  cc_get_feature_vsa count is 1
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424: :FEATURE_VSA attributes are: feature_name:0,feature_time:805605016,feature_id:2443
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=5558675309(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=64201(TON=Unknown, NPI=Unknown))
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/cc_process_call_setup_ind:
   Event=0x307DB3F0
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 64201
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCallSetContext:
   Context=0x3005DD94
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 2448 with tag 0 to app "_ManagedAppProcess_Default"
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=100, Params=0x300618DC, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCheckClipClir:
   In: Calling Number=5558675309(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCheckClipClir:
   Out: Calling Number=5558675309(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCallSetupRequest:
   Destination Pattern=.....$, Called Number=64201, Digit Strip=FALSE
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccCallSetupRequest:
   Calling Number=5558675309(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=64201(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=Billy Kidd
   Account Number=, Final Destination Flag=TRUE,
   Guid=B6FCCDB4-CBB5-11E5-9662-CFB793497ABD, Outgoing Dial-peer=100
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=5558675309
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=64201
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   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

*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x29BB90B0, Interface Type=1, Destination=, Mode=0x0,
   Call Params(Calling Number=5558675309,(Calling Name=Billy Kidd )(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=64201(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=100, Call Count On=FALSE,
   Source Trkgrp Route Label=FXO, Target Trkgrp Route Label=, tg_label_flag=1, Application Call Id=)
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424: :cc_get_feature_vsa malloc success
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424:  cc_get_feature_vsa count is 2
*Feb  6 03:08:22.424: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb  6 03:08:22.424: :FEATURE_VSA attributes are: feature_name:0,feature_time:805605240,feature_id:2444
*Feb  6 03:08:22.424: //2449/B6FCCDB49662/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
*Feb  6 03:08:22.424: //2449/B6FCCDB49662/CCAPI/ccCallSetContext:
   Context=0x3006188C
*Feb  6 03:08:22.424: //2448/B6FCCDB49662/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=100
*Feb  6 03:08:22.452: //2449/B6FCCDB49662/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
*Feb  6 03:08:22.452: //2449/B6FCCDB49662/CCAPI/cc_api_call_proceeding:
   Interface=0x29BB90B0, Progress Indication=NULL(0)
*Feb  6 03:08:22.472: //2449/B6FCCDB49662/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
*Feb  6 03:08:22.472: //2449/B6FCCDB49662/CCAPI/cc_api_set_delay_xport:
   CallInfo(delay xport=TRUE)
*Feb  6 03:08:22.472: //2449/B6FCCDB49662/CCAPI/cc_api_call_alert:
   Interface=0x29BB90B0, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb  6 03:08:22.472: //2449/B6FCCDB49662/CCAPI/cc_api_call_alert:
   Call Entry(Retry Count=0, Responsed=TRUE)
*Feb  6 03:08:22.472: //2448/B6FCCDB49662/CCAPI/ccCallAlert:
   Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb  6 03:08:22.472: //2448/B6FCCDB49662/CCAPI/ccCallAlert:
   Call Entry(Responsed=TRUE, Alert Sent=TRUE)
*Feb  6 03:08:22.652: //2449/B6FCCDB49662/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
*Feb  6 03:08:22.652: //2449/B6FCCDB49662/CCAPI/cc_api_call_notify:
   Data Bitmask=0x5, Interface=0x29BB90B0, Call Id=2449
Cisco-Rtr-2921#
*Feb  6 03:08:22.652: //2449/B6FCCDB49662/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
   CallInfo(ssCTreRoutingNotSupported=FALSE)
*Feb  6 03:08:22.652: //2449/B6FCCDB49662/CCAPI/cc_api_get_ccm_detected:
   CallInfo(ccm detected=TRUE)
*Feb  6 03:08:22.652: //2448/B6FCCDB49662/CCAPI/ccCallNotify:
   Data Bitmask=0x5, Call Id=2448
Cisco-Rtr-2921#
*Feb  6 03:08:25.160: //2449/B6FCCDB49662/CCAPI/ccIsInfoRingback:
   Returning dpRingBack=0
*Feb  6 03:08:25.160: //2449/B6FCCDB49662/CCAPI/cc_api_call_connected:
   Interface=0x29BB90B0, Data Bitmask=0x0, Progress Indication=NULL(0),
   Connection Handle=0
*Feb  6 03:08:25.160: //2449/B6FCCDB49662/CCAPI/cc_api_call_connected:
   Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/ccGenerateToneInfo:
   Stop Tone On Digit=FALSE, Tone=Null,
   Tone Direction=Network, Params=0x0, Call Id=2448
*Feb  6 03:08:25.160: //2448/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
   (confID=0x30072E68, callID1=0x990, callID2=0x991, tag=0x0)
*Feb  6 03:08:25.160: //2448/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
   (confID=0x30072E68, callID1=0x990, gcid=B6FCCDB4-CBB511E5-9662CFB7-93497ABD, tag=0x0)
*Feb  6 03:08:25.160: //2449/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
   (confID=0x30072E68, callID2=0x991, gcid=B6FCCDB4-CBB511E5-9662CFB7-93497ABD, tag=0x0)
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/ccConferenceCreate:
   Conference Id=0x30072E68, Call Id1=2448, Call Id2=2449, Tag=0x0
*Feb  6 03:08:25.160: //2448/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
   Conference Id=0x352, Source Interface=0x30C5C7A8, Source Call Id=2448,
   Destination Call Id=2449, Disposition=0x0, Tag=0xFFFFFFFF
*Feb  6 03:08:25.160: //2449/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Feb  6 03:08:25.160: cc_api_get_xcode_stream : 4548
*Feb  6 03:08:25.160: //2449/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
   Conference Id=0x352, Source Interface=0x29BB90B0, Source Call Id=2449,
   Destination Call Id=2448, Disposition=0x0, Tag=0x0
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/cc_generic_bridge_done:
   Conference Id=0x352, Source Interface=0x29BB90B0, Source Call Id=2449,
   Destination Call Id=2448, Disposition=0x0, Tag=0x0
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/ccConferenceCreate:
   Call Entry(Conference Id=0x352, Destination Call Id=2449)
*Feb  6 03:08:25.160: //2449/B6FCCDB49662/CCAPI/ccConferenceCreate:
   Call Entry(Conference Id=0x352, Destination Call Id=2448)
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/cc_api_caps_ind:
   Destination Interface=0x29BB90B0, Destination Call Id=2449, Source Call Id=2448,
   Caps(Codec=0x1, Fax Rate=0x1, Fax Version:=0, Vad=0x1,
   Modem=0x2, Codec Bytes=20, Signal Type=3)
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/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))
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/ccCallConnect:
   Progress Indication=NULL(0), Data Bitmask=0x1
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/ccCallConnect:
   Call Entry(Connected=TRUE, Responsed=TRUE)
*Feb  6 03:08:25.160: //2448/B6FCCDB49662/CCAPI/cc_process_notify_bridge_done:
   Conference Id=0x352, Call Id1=2448, Call Id2=2449
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ind:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=0x1, Fax Rate=0x2, Fax Version:=0, Vad=0x1,
   Modem=0x0, Codec Bytes=160, Signal Type=2)
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/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))
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.164: //2448/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x29BB90B0, Destination Call Id=2449, Source Call Id=2448,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_call_notify:
   Data Bitmask=0x5, Interface=0x29BB90B0, Call Id=2449
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
   CallInfo(ssCTreRoutingNotSupported=FALSE)
*Feb  6 03:08:25.164: //2449/B6FCCDB49662/CCAPI/cc_api_get_ccm_detected:
   CallInfo(ccm detected=TRUE)
*Feb  6 03:08:25.164: //2448/B6FCCDB49662/CCAPI/ccCallNotify:
   Data Bitmask=0x5, Call Id=2448
*Feb  6 03:08:25.164: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Id=2448
*Feb  6 03:08:25.164: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Entry(Context=0x3005DD94)
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ind:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=0x1, Fax Rate=0x2, Fax Version:=0, Vad=0x1,
   Modem=0x0, Codec Bytes=160, Signal Type=2)
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/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))
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ind:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=0x1, Fax Rate=0x2, Fax Version:=0, Vad=0x1,
   Modem=0x0, Codec Bytes=160, Signal Type=2)
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/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))
*Feb  6 03:08:25.192: //2449/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x30C5C7A8, Destination Call Id=2448, Source Call Id=2449,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x29BB90B0, Destination Call Id=2449, Source Call Id=2448,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_caps_ack:
   Destination Interface=0x29BB90B0, Destination Call Id=2449, Source Call Id=2448,
   Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Fax Version:=0, Vad=OFF(0x1),
   Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=8408)
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Id=2448
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Entry(Context=0x3005DD94)
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Id=2448
*Feb  6 03:08:25.192: //2448/B6FCCDB49662/CCAPI/cc_api_voice_mode_event:
   Call Entry(Context=0x3005DD94)
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/cc_api_call_disconnected:
   Cause Value=16, Interface=0x30C5C7A8, Call Id=2448
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/ccConferenceDestroy:
   Conference Id=0x352, Tag=0x0
*Feb  6 03:08:25.364: //2448/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x352, Source Interface=0x30C5C7A8, Source Call Id=2448,
   Destination Call Id=2449, Disposition=0x0, Tag=0x0
*Feb  6 03:08:25.364: //2449/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x352, Source Interface=0x29BB90B0, Source Call Id=2449,
   Destination Call Id=2448, Disposition=0x0, Tag=0x0
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/cc_generic_bridge_done:
   Conference Id=0x352, Source Interface=0x29BB90B0, Source Call Id=2449,
   Destination Call Id=2448, Disposition=0x0, Tag=0x0
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Feb  6 03:08:25.364: //2448/B6FCCDB49662/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
*Feb  6 03:08:25.364: //2449/B6FCCDB49662/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Feb  6 03:08:25.364: //2449/B6FCCDB49662/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Feb  6 03:08:25.364: //2449/B6FCCDB49662/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
*Feb  6 03:08:25.376: //2449/B6FCCDB49662/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
*Feb  6 03:08:25.376: //2449/B6FCCDB49662/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x29BB90B0, Tag=0x0, Call Id=2449,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Feb  6 03:08:25.376: //2449/B6FCCDB49662/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
*Feb  6 03:08:25.376: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb  6 03:08:25.376: :cc_free_feature_vsa freeing 30048F70
*Feb  6 03:08:25.376: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb  6 03:08:25.376:  vsacount in free is 1
*Feb  6 03:08:25.388: //2448/B6FCCDB49662/CCAPI/cc_api_call_disconnect_done:

Cisco-Rtr-2921#Disposition=0, Interface=0x30C5C7A8, Tag=0x0, Call Id=2448,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Feb  6 03:08:25.388: //2448/B6FCCDB49662/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
*Feb  6 03:08:25.388: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb  6 03:08:25.388: :cc_free_feature_vsa freeing 30048E90
*Feb  6 03:08:25.388: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb  6 03:08:25.388:  vsacount in free is 0
Cisco-Rtr-2921#
Cisco-Rtr-2921#
Cisco-Rtr-2921#

0 Helpful
Customers Also Viewed These Support Documents