Dial Peer Issues

[ndegwajim]

Hey folks,

I'm having an issue sending out calls from the CCME router. I can't receive calls either though i can hear the line ring when i call it. All phones re registered and have directory numbers assigned

FXO configs

voice-port 0/1/0
connection plar 5300
caller-id enable
!
voice-port 0/1/1
connection plar 5301
caller-id enable

Dial- Peer configs

dial-peer voice 1 pots
destination-pattern ...............
port 0/1/0
prefix 9,
!
dial-peer voice 2 pots
destination-pattern 9...............
port 0/1/1
prefix 9,
!
dial-peer voice 3 voip
destination-pattern 5330
session protocol sipv2
session target ipv4:192.168.200.4
dtmf-relay sip-notify
codec g711ulaw
no vad
!
!
!
!
telephony-service
no auto-reg-ephone
load 7960-7940 P00307020400
load 7975 SCCP75.8-5-4S
load 7936 cmterm_7936.3-3-9-0
max-ephones 30
max-dn 50
ip source-address 192.168.200.1 port 2000
voicemail 5330
max-conferences 4 gain -6
transfer-system full-consult
secondary-dialtone 9
create cnf-files version-stamp Jan 01 2002 00:00:00
!
!
ephone-dn  1  dual-line
number 5300
name RECEPTION
call-forward busy 5330
call-forward noan 5330 timeout 10
!
!
ephone-dn  2  dual-line
number 5301
name RECEPTION
call-forward busy 5330
call-forward noan 5330 timeout 10

[david-lima]

Hi friend, try changing the

dial-peer voice 2 pots
destination-pattern 9...............
port  0/1/1
prefix 9,

with this one

dial-peer voice 2 pots
destination-pattern 9T
port  0/1/1

hth

David

[ndegwajim]

Thanks. I'll test and advice tomorrow

[paolo bevilacqua]

I'm having an issue sending out calls from the CCME router. I can't receive calls either though

Test these lines with a regular telephone.

[ndegwajim]

i tested the line with an analog handset and line works fine

[Volodymyr Morskyy]

1 Is your phone ringing when you run "csim start 5300"?

2 Try to use "plar opx" instead of "plar".

Can you post "sh voice port *" output?

[paolo bevilacqua]

Router may be getting a battery reversal. To confirm, enable "debug vpm signal" with "term mon" when receiving or making a call.

Do not enable any other debug and do not use attachment when reporting results.

[ndegwajim]

output from the debug command. Please note that i'm getting a single ring followed by a busy signal. Thanks in advance

CCME#debug vpm signal
Voice Port Module signaling debugging is enabled
CCME#term mon
CCME#
*Mar  3 11:11:48.922: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Mar  3 11:11:48.922: htsp_timer - 125 msec
*Mar  3 11:11:49.050: htsp_process_event: [0/3/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar  3 11:11:49.050: htsp_timer - 10000 msec
*Mar  3 11:11:49.970: htsp_process_event: [0/3/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar  3 11:11:49.970: fxols_ringing_not
*Mar  3 11:11:49.970: htsp_timer_stop
*Mar  3 11:11:49.970: htsp_timer_stop3 htsp_setup_ind
*Mar  3 11:11:49.970: [0/3/0] get_local_station_id calling num= calling name= calling time=03/03 11:11  orig called=
*Mar  3 11:11:49.970: //-1/xxxxxxxxxxxx/VTSP:(0/3/0):-1:-1:-1/vtsp_allocate_cdb:
   CDB=0x67B2D700
*Mar  3 11:11:49.970: //-1/xxxxxxxxxxxx/VTSP:(0/3/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
*Mar  3 11:11:49.970: //-1/661729658250/VTSP:(0/3/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:-1:-1/vtsp_timer:
   Timer Start Time=19112499, Timer Value=180000(ms)
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
   IC State Machine (ICSM) Added
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:-1:-1/vtsp_insert_cdb:
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_dsm_opened_cb:
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_process_event:
   [state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:1:1/act_setup_ind_pend_success:
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_realloc_cdb:
   CDB=0x67B2D700
*Mar  3 11:11:49.974: //-1/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_indicate_call:
*Mar  3 11:11:49.974: //-1/661729658250/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=
   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

*Mar  3 11:11:49.974: //-1/661729658250/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x672AE66C, Call Info(
   Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE,
   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
*Mar  3 11:11:49.978: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar  3 11:11:49.978: :cc_get_feature_vsa malloc success
*Mar  3 11:11:49.978: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar  3 11:11:49.978:  cc_get_feature_vsa count is 1
*Mar  3 11:11:49.978: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Mar  3 11:11:49.978: :FEATURE_VSA attributes are: feature_name:0,feature_time:1730644512,feature_id:166
*Mar  3 11:11:49.978: //166/661729658250/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=(TON=Unknown, NPI=Unknown))
*Mar  3 11:11:49.978: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_insert_cdb:
*Mar  3 11:11:49.978: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_timer:
   Timer Start Time=19112499, Timer Value=180000(ms)
*Mar  3 11:11:49.978: //166/661729658250/CCAPI/cc_process_call_setup_ind:
   Event=0x67286D38
*Mar  3 11:11:49.982: //166/661729658250/CCAPI/ccCallSetContext:
   Context=0x686DC218
*Mar  3 11:11:49.982: //166/661729658250/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 166 with tag 0 to app "_ManagedAppProcess_Default"
*Mar  3 11:11:49.982: //166/661729658250/CCAPI/ccCallSetupAck:
   Call Id=166
*Mar  3 11:11:49.982: //166/661729658250/CCAPI/cc_api_set_transfer_info:
   Transfer Number=, Transfer Reason=0x0
*Mar  3 11:11:49.982: //166/661729658250/CCAPI/ccGenerateToneInfo:
   Stop Tone On Digit=TRUE, Tone=Dial Tone,
   Tone Direction=Network, Params=0x0, Call Id=166
*Mar  3 11:11:49.986: //166/661729658250/CCAPI/ccSetDigitTimeouts:
   Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)
*Mar  3 11:11:49.986: //166/661729658250/CCAPI/ccSetDigitTimeouts:
   Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))
*Mar  3 11:11:49.986: //166/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:
   (callID=0xA6, digit_event=0x1, enable=TRUE, consume=FALSE)
*Mar  3 11:11:49.986: //166/661729658250/CCAPI/ccCallReportDigits:
   Enabled=TRUE, Call Id=166
*Mar  3 11:11:49.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
*Mar  3 11:11:49.986: //166/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:
   (vdbPtr=0x672AE66C, callID=0xA6, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
*Mar  3 11:11:49.986: //166/661729658250/CCAPI/cc_api_call_report_digits_done:
   Enabled=TRUE, Disposition=0x0, Interface=0x672AE66C, Call Id=166
*Mar  3 11:11:49.986: //166/661729658250/CCAPI/cc_api_call_report_digits_done:
   Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))
*Mar  3 11:11:49.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
   Digit Reporting=TRUE
*Mar  3 11:11:49.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_process_event:
   [state:S_SETUP_INDICATED, event:E_CC_SETUP_ACK]
*Mar  3 11:11:49.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/act_setup_ind_ack:
   Fax Relay=TRUE, Dial Tone=TRUE, Digit Collect=TRUE, Overlap=FALSE, DID=FALSE
*Mar  3 11:11:49.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19112500
*Mar  3 11:11:49.990: htsp_process_event: [0/3/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar  3 11:11:49.990: fxols_wait_setup_ack:
*Mar  3 11:11:49.990: [0/3/0] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar  3 11:11:50.262: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_DSP_SIG_0110]fxols_rvs_battery
*Mar  3 11:11:50.262: htsp_timer_stop2
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/cc_handle_inter_digit_timer:
   Generate inter-digit timeout CC_EV_CALL_DIGIT_END event
*Mar  3 11:11:59.986: //166/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:
   (callID=0xA6, digit_event=0x0, enable=FALSE, consume=FALSE)
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/ccCallReportDigits:
   Enabled=TRUE, Call Id=166
*Mar  3 11:11:59.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
*Mar  3 11:11:59.986: //166/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:
   (vdbPtr=0x672AE66C, callID=0xA6, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/cc_api_call_report_digits_done:
   Enabled=TRUE, Disposition=0x0, Interface=0x672AE66C, Call Id=166
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/cc_api_call_report_digits_done:
   Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))
*Mar  3 11:11:59.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
   Digit Reporting=FALSE
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/ccCallDisconnect:
   Cause Value=28, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/ccCallDisconnect:
   Cause Value=28, Call Entry(Responsed=TRUE, Cause Value=28)
*Mar  3 11:11:59.986: //166/661729658250/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
*Mar  3 11:11:59.986: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_process_event:
   [state:S_DIGIT_COLLECT, event:E_CC_DISCONNECT]
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   Cause Value=28, Hairpin=FALSE
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19113500
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_ring_noan_timer_stop:
   Timer Stop Time=19113500
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   [Number Unobtainable]-Tone Played In Direction [Network]
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19113500
*Mar  3 11:11:59.990: //166/661729658250/CCAPI/cc_api_call_disc_cause_update:
   Cause Value=16
*Mar  3 11:11:59.990: //166/661729658250/CCAPI/cc_api_call_disc_cause_update:
   Call Entry(Disconnect Cause=16)
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/vtsp_play_busy_timer_start:
   Timer Start Time=19113500, Busy Timer Value=30(ms)
*Mar  3 11:11:59.990: //166/661729658250/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   Tone=Number Unobtainable, Tone Timeout=30(s), Progress Indication Sent=0

[paolo bevilacqua]

Configure "no battery-reversal" under voice-port.

[ndegwajim]

Done but we still have the same issue. Whn making inbound calls, i hear a single ring then line goes busy

!
voice-port 0/1/0
no battery-reversal
connection plar opx 5300
caller-id enable
!
voice-port 0/1/1
no battery-reversal
connection plar opx 5301
caller-id enable
!

CCME#debug vpm signal
Voice Port Module signaling debugging is enabled
CCME#term mon
CCME#
*Mar  3 12:14:51.014: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0000]f                                                                              xols_onhook_ringing
*Mar  3 12:14:51.014: htsp_timer - 125 msec
*Mar  3 12:14:51.142: htsp_process_event: [0/3/0, FXOLS_WAIT_RING_MIN, E_HTSP_EV                                                                              ENT_TIMER]fxols_wait_ring_min_timer
*Mar  3 12:14:51.142: htsp_timer - 10000 msec
*Mar  3 12:14:52.066: htsp_process_event: [0/3/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar  3 12:14:52.066: fxols_ringing_not
*Mar  3 12:14:52.066: htsp_timer_stop
*Mar  3 12:14:52.066: htsp_timer_stop3 htsp_setup_ind
*Mar  3 12:14:52.066: [0/3/0] get_local_station_id calling num= calling name= ca                                                                              lling time=03/03 12:14  orig called=
*Mar  3 12:14:52.066: //-1/xxxxxxxxxxxx/VTSP:(0/3/0):-1:-1:-1/vtsp_allocate_cdb:                                                                             
   CDB=0x67B2D700
*Mar  3 12:14:52.066: //-1/xxxxxxxxxxxx/VTSP:(0/3/0):-1:-1:-1/vtsp_do_call_setup                                                                              _ind:
   Event=E_TSP_SETUP_IND
   Progress Indication=3, CarrierIDCode=, Info Trans Capability=144, Source Carr                                                                              ier ID=, tg_label_flag=0
*Mar  3 12:14:52.066: //-1/34652DD18290/VTSP:(0/3/0):-1:-1:-1/vtsp_do_normal_cal                                                                              l_setup_ind:
*Mar  3 12:14:52.066: //-1/34652DD18290/VTSP:(0/3/0):-1:-1:-1/vtsp_timer:
   Timer Start Time=19490708, Timer Value=180000(ms)
*Mar  3 12:14:52.066: //-1/34652DD18290/VTSP:(0/3/0):-1:-1:-1/vtsp_do_normal_cal                                                                              l_setup_ind:
   IC State Machine (ICSM) Added
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:-1:-1/vtsp_insert_cdb:
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_dsm_opened_cb:
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_process_event:                                                                              
   [state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:1:1/act_setup_ind_pend_s                                                                              uccess:
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_realloc_cdb:
   CDB=0x67B2D700
*Mar  3 12:14:52.070: //-1/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_indicate_call:
*Mar  3 12:14:52.070: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_insert_cdb:
*Mar  3 12:14:52.070: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_timer:
   Timer Start Time=19490708, Timer Value=180000(ms)
*Mar  3 12:14:52.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_c                                                                              ontrol:
*Mar  3 12:14:52.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_c                                                                              ontrol:
   Digit Reporting=TRUE
*Mar  3 12:14:52.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_process_event:                                                                             
   [state:S_SETUP_INDICATED, event:E_CC_SETUP_ACK]
*Mar  3 12:14:52.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/act_setup_ind_ack:                                                                              
   Fax Relay=TRUE, Dial Tone=TRUE, Digit Collect=TRUE, Overlap=FALSE, DID=FALSE
*Mar  3 12:14:52.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19490709
*Mar  3 12:14:52.078: htsp_process_event: [0/3/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_S                                                                              ETUP_ACK]
*Mar  3 12:14:52.078: fxols_wait_setup_ack:
*Mar  3 12:14:52.078: [0/3/0] set signal state = 0xC timestamp = 0fxols_check_au                                                                              to_call
*Mar  3 12:14:52.350: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_DSP_SIG_01                                                                              10]fxols_rvs_battery
*Mar  3 12:14:52.350: htsp_timer_stop2
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_report_digit_control:
   Digit Reporting=FALSE
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_process_event:
   [state:S_DIGIT_COLLECT, event:E_CC_DISCONNECT]
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   Cause Value=28, Hairpin=FALSE
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19491709
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_ring_noan_timer_stop:
   Timer Stop Time=19491709
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   [Number Unobtainable]-Tone Played In Direction [Network]
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19491709
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/vtsp_play_busy_timer_start:
   Timer Start Time=19491709, Busy Timer Value=30(ms)
*Mar  3 12:15:02.074: //191/34652DD18290/VTSP:(0/3/0):-1:1:1/act_pre_con_disconnect:
   Tone=Number Unobtainable, Tone Timeout=30(s), Progress Indication Sent=0

[ndegwajim]

Below is the output in the OUTBOUND direction. The line in red looks interesting

*Mar  3 12:21:51.322: digit_strip:1, pcn:90721432454, poa:9T
*Mar  3 12:21:51.322: pcn:0721432454, poa:T
*Mar  3 12:21:51.322: Final pcn:0721432454, poa:T, dial_string:9,0721432454
*Mar  3 12:21:51.322: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_create_call_active_on_setup_req:
   Target Carrier ID=
*Mar  3 12:21:51.326: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_create_call_active_on_setup_req:
   Source Carrier ID=htsp_setup_req
*Mar  3 12:21:51.326: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_request_call:
   Progress Indication=3, Info Trans Capability=0
   Calling Number=5324, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
   Called Number=90721432454, TON=Unknown, NPI=Unknown
*Mar  3 12:21:51.326: htsp_process_event: [0/1/1, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
*Mar  3 12:21:51.326: [0/1/1] set signal state = 0xC timestamp = 0
*Mar  3 12:21:51.326: htsp_timer - 1300 msec
*Mar  3 12:21:51.326: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_process_event:
   [state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
*Mar  3 12:21:51.326: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/act_setup_pend_proceeding:
*Mar  3 12:21:51.326: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_timer:
   Timer Start Time=19532634, Timer Value=10000(ms)
*Mar  3 12:21:51.330: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/act_setup_pend_proceeding:
   Peer=2, Progress Indication=0, Return Code=2
*Mar  3 12:21:51.334: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_dsm_opened_cb:
*Mar  3 12:21:51.334: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_process_event:
   [state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
*Mar  3 12:21:51.334: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/act_setup_req_wait_pend_success:
   Event=72
*Mar  3 12:21:51.334: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=19532635
*Mar  3 12:21:51.578: htsp_process_event: [0/1/1, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_1100]fxols_power_denial_proc
*Mar  3 12:21:51.578: htsp_timer2 - 1000 msec
*Mar  3 12:21:51.578: htsp_timer_stop
*Mar  3 12:21:52.578: htsp_process_event: [0/1/1, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER2]fxols_timer2_proc
*Mar  3 12:21:52.578: htsp_timer_stop
*Mar  3 12:21:52.578: htsp_timer_stop2
*Mar  3 12:21:52.578: [0/1/1] set signal state = 0x4 timestamp = 0
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_process_event:
   [state:S_SETUP_REQ_PROC, event:E_TSP_DISCONNECT_IND]
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/act_setup_pend_release_ind:
   Cause Value=34
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_ring_noan_timer_stop:
   Timer Stop Time=19532759
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_cc_call_disconnected:
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_cc_call_disconnected:
   Cause Value=34
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_set_release_source:
   Release Direction=PSTN, Release Source=Called Party-PSTN
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/act_setup_pend_release_ind:
   Peer=2
*Mar  3 12:21:52.578: //196/2BD2D909829A/VTSP:(0/1/1):-1:1:1/vtsp_call_disconnect:
   [Out Of Service]-Tone Played In Direction [Both]

[paolo bevilacqua]

Which country is this?

Also set "no supervisory disconnect signal"

[Volodymyr Morskyy]

Probably it's not a professional answer but sometimes some bugs are solved by rebooting.

Multiservice Voice Debug Lookup page suggests also:

Show voice trace

Basic Debugs
------------
debug voip ccapi inout
debug vpm signal
debug voip vtsp default
debug voip vtsp session

Advanced Debugs
----------------
debug voip dspapi all
debug voip hpi all
debug voip vtsp all
debug dsprm all