cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
972
Views
0
Helpful
5
Replies

Emergency phone immediately disconnects after dialing. (VG204xm to CUCM 11.5)

Wayne Ficklin
Level 1
Level 1

The emergency telephone (Ramtel RR733, or maybe R733) will dial 911 and hang up.  An older model seems to work fine.  We thought it might be a distance issue, but the behavior is the same when connected directly to the gateway in the closet.

 

Where would you start looking to troubleshoot this?

 

(We're about to lab this up so I can test it without calls to 911 dispatching an officer each time.  I ought to be able to get better information soon.)

VG204xm running 15.7(3)M.

5 Replies 5

R0g22
Cisco Employee
Cisco Employee
How is this VG-204 setup on CUCM ? Protocol ? Do you hear a ring back and call drops on answer or call drops as soon as you complete dialing the number ?

I believe the gateway is setup as SCCP.  Its reported to me that it it drops immediately after dialing the number.

Please collect the following for a test call -

debug voip application stcapp port x/y/z >>> port in question
debug vpm signal
debug sccp event
debug voip vtsp all
debug voip ccapi inout

 

I'll include the output below.  2 interesting things to note: When the device is plugged into a PoTS line, it rings my phone as expected (I've reprogrammed it from 911 to my 7 digit DID).  Also, when connected to our analog gateway, a coworker held a dtmf decoder to the speaker and it was able to determine all 7 digits.

 

In the output below, you'll see that 6 digits were received.  The first 5 and the last 1.  The 6th digit didn't go through.  I tried it 3 times and each time gave the same output.  (Search "Digit received is".)

 

It looks like the timing between digits is between 120-130 milliseconds according to the timestamp.

 

 

*May 27 00:01:47.214: htsp_dsp_message: SEND_SIG_STATUS: state=0xC timestamp=11232 systime=728023238
*May 27 00:01:47.214: htsp_process_event: [0/0, FXSLS_ONHOOK, E_DSP_SIG_1100]fxsls_onhook_offhook htsp_setup_ind
*May 27 00:01:47.214: [0/0] get_local_station_id calling num= calling name= calling time=05/27 00:01 orig called=
*May 27 00:01:47.214: //-1/xxxxxxxxxxxx/VTSP:(0/0):-1:-1:-1/vtsp_allocate_cdb:
CDB=0x86711EF0
*May 27 00:01:47.214: //-1/xxxxxxxxxxxx/VTSP:(0/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
*May 27 00:01:47.218: //-1/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
*May 27 00:01:47.218: //-1/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_timer:
Timer Start Time=728023238, Timer Value=180000(ms)
*May 27 00:01:47.218: //-1/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
IC State Machine (ICSM) Added
*May 27 00:01:47.218: //-1/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_insert_cdb:
*May 27 00:01:47.218: //-1/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_opened_cb:
*May 27 00:01:47.222: //-1/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
*May 27 00:01:47.222: //-1/C57534E88220/VTSP:(0/0):-1:1:1/act_setup_ind_pend_success:
*May 27 00:01:47.222: //-1/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_realloc_cdb:
CDB=0x86711EF0
*May 27 00:01:47.222: //-1/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_indicate_call:
*May 27 00:01:47.222: //-1/C57534E88220/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

*May 27 00:01:47.222: //-1/C57534E88220/CCAPI/cc_api_call_setup_ind_common:
Interface=0x88B03B60, 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=999000, 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
*May 27 00:01:47.222: //-1/C57534E88220/CCAPI/ccCheckClipClir:
In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*May 27 00:01:47.222: //-1/C57534E88220/CCAPI/ccCheckClipClir:
Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*May 27 00:01:47.226: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:47.226: :cc_get_feature_vsa malloc success
*May 27 00:01:47.226: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:47.226: cc_get_feature_vsa count is 1
*May 27 00:01:47.226: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:47.226: :FEATURE_VSA attributes are: feature_name:0,feature_time:2305541344,feature_id:239
*May 27 00:01:47.226: //239/C57534E88220/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))
*May 27 00:01:47.226: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_insert_cdb:
*May 27 00:01:47.226: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer:
Timer Start Time=728023239, Timer Value=180000(ms)
*May 27 00:01:47.226: //239/C57534E88220/CCAPI/cc_process_call_setup_ind:
Event=0x88AB2B68
*May 27 00:01:47.226: //239/C57534E88220/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 239 with tag 999000 to app "stcapp"
*May 27 00:01:47.226: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_SETUP_IND for CallId: 239
*May 27 00:01:47.226: 0/0 : Call State:IDLE
*May 27 00:01:47.226: 0/0 : stcapp_setup_ind_eh
*May 27 00:01:47.226: 0/0 : Set the line mode to CALL_BASIC!
*May 27 00:01:47.226: 0/0 : stcapp_get_ccb
*May 27 00:01:47.226: 0/0 : dcb->lcb[line_inst - 1].num_ccbs=0
*May 27 00:01:47.230: 0/0 : Acquired CCB 0x86B6E1D4 for device id:4
*May 27 00:01:47.230: 0/0 : num_ccbs++, num_ccbs=1
*May 27 00:01:47.230: 0/0 : stcapp_conn_db_insert_ccb
*May 27 00:01:47.230: 0/0 : ccb=0x86B6E1D4
*May 27 00:01:47.230: 0/0 : Voice Setup: callID:239, vdb_ptr:88B03B60
*May 27 00:01:47.230: 0/0 : Sending StationOffHook to CallManager
*May 27 00:01:47.230: sccp_spi_dev_off_hook: enqueue spi evt SCCP_SPI_DEV_OFF_HOOK, reg_name=ANA5C5D439A8000
*May 27 00:01:47.230: 0/0 : Sending ccCallSetupAck to Symphony for voice call id:239
*May 27 00:01:47.230: //239/C57534E88220/CCAPI/ccCallSetupAck:
Call Id=239
*May 27 00:01:47.230: //239/C57534E88220/CCAPI/cc_api_set_transfer_info:
Transfer Number=, Transfer Reason=0x0
*May 27 00:01:47.230: 0/0 : New State = OFFHOOK
*May 27 00:01:47.230: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_INDICATED, event:E_CC_SETUP_ACK]
*May 27 00:01:47.230: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_setup_ind_ack:
Fax Relay=TRUE, Dial Tone=TRUE, Digit Collect=TRUE, Overlap=FALSE, DID=FALSE
*May 27 00:01:47.230: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023239
*May 27 00:01:47.230: sccp_send_offhook_v1
*May 27 00:01:47.234: htsp_process_event: [0/0, FXSLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]fxsls_check_auto_call
*May 27 00:01:47.234: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_get_plc_by_dsp_pltf_intf: vtsp_get_plc_by_dsp_pltf_intf: callID 239, dialpeer tag 999000, plc 1
*May 27 00:01:47.242: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_SET_RINGER
*May 27 00:01:47.242: 0/0 : Call State:OFFHOOK
*May 27 00:01:47.242: 0/0 : Uninteresting event
*May 27 00:01:47.246: 0/0 : stcapp_get_dcb_and_lcb
*May 27 00:01:47.246: 0/0 : stcapp_screen_api_event
*May 27 00:01:47.246: 0/0 : event:STCAPP_DC_EV_DEVICE_CALL_STATE_OFFHOOK received.
*May 27 00:01:47.246: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_CALL_STATE_OFFHOOK
*May 27 00:01:47.246: 0/0 : Call State:OFFHOOK
*May 27 00:01:47.246: 0/0 : stcapp_cs_offhook_eh
*May 27 00:01:47.246: 0/0 : call_ref=116375025
*May 27 00:01:47.246: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:47.246: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:47.246: 0/0 : Using call_ref 0 to get ccb=0x86B6E1D4
*May 27 00:01:47.246: 0/0 : No state change
*May 27 00:01:47.246: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_DISPLAY_PROMPT_STATUS
*May 27 00:01:47.246: 0/0 : Device State:IS
*May 27 00:01:47.246: 0/0 : stcapp_display_prompt_status_eh
*May 27 00:01:47.246: 0/0 : lineNumber: 1
*May 27 00:01:47.246: 0/0 : call reference: 116375025
*May 27 00:01:47.246: 0/0 : promptStatus: 'Enter Number'
*May 27 00:01:47.246: 0/0 : device control type: CCM
*May 27 00:01:47.246: 0/0 : No state change
*May 27 00:01:47.250: xapp_xlate_cm_tone_to_sym_tone:InsideDialTone -
*May 27 00:01:47.250: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_START_TONE
*May 27 00:01:47.250: 0/0 : Call State:OFFHOOK
*May 27 00:01:47.250: 0/0 : stcapp_start_tone_eh
*May 27 00:01:47.250: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:47.250: 0/0 : call_ref=116375025, ccb=0x86B6E1D4, tone=9(0x9), dir=1
*May 27 00:01:47.250: 0/0 : plar enable (0), hookflash (0)
*May 27 00:01:47.250: 0/0 : plar enable (0), tone (0x9), hookflash (0)
*May 27 00:01:47.250: 0/0 : Sending ccGenerateTone(9(0x9))
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Internal Dial Tone,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:47.250: 0/0 : Sending ccCallReportDigits
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/ccCallReportDigits:
(callID=0xEF, digit_event=0x1, enable=TRUE, consume=FALSE)
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=239
*May 27 00:01:47.250: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_report_digit_control:
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x88B03B60, callID=0xEF, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x88B03B60, Call Id=239
*May 27 00:01:47.250: //239/C57534E88220/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=60000(ms), Inter Digit Timeout=60000(ms))
*May 27 00:01:47.250: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_report_digit_control:
Digit Reporting=TRUE
*May 27 00:01:47.254: 0/0 : No state change
*May 27 00:01:47.254: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_REPORT_DIGITS_DONE for CallId: 239
*May 27 00:01:47.254: 0/0 : Call State:OFFHOOK
*May 27 00:01:47.254: 0/0 : stcapp_report_digits_done_eh
*May 27 00:01:47.254: 0/0 : No state change
*May 27 00:01:47.494: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=11512 systime=728023266
*May 27 00:01:47.494: htsp_process_event: [0/0, FXSLS_OFFHOOK, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
*May 27 00:01:47.494: htsp_timer - 1000 msec
*May 27 00:01:47.550: htsp_dsp_message: SEND_SIG_STATUS: state=0xC timestamp=11566 systime=728023271
*May 27 00:01:47.550: htsp_process_event: [0/0, FXSLS_OFFHOOK, E_DSP_SIG_1100]fxsls_offhook_offhook
*May 27 00:01:47.550: htsp_timer_stop
*May 27 00:01:50.826: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:50.826: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=6
*May 27 00:01:50.826: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:50.826: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054BF68, Rtp Expiration=0x0
*May 27 00:01:50.826: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:50.826: 0/0 : Call State:OFFHOOK
*May 27 00:01:50.826: 0/0 : Uninteresting event
*May 27 00:01:50.866: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:50.866: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023603
*May 27 00:01:50.866: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=6
*May 27 00:01:50.866: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:50.866: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, Duration=77,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:50.866: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:50.866: htsp_digit_ready(0/0): digit = 6
*May 27 00:01:50.866: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:50.866: 0/0 : Call State:OFFHOOK
*May 27 00:01:50.866: 0/0 : stcapp_digit_end_eh
*May 27 00:01:50.866: 0/0 : Digit received is (6)
*May 27 00:01:50.866: 0/0 : First digit received, stopping the dial tone!
*May 27 00:01:50.866: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:50.866: 0/0 : stcapp_send_keypad_button
*May 27 00:01:50.866: 0/0 : Sending StationKeypadButton(6) to CallManager
*May 27 00:01:50.866: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:50.870: 0/0 : No state change
*May 27 00:01:50.874: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_STOP_TONE
*May 27 00:01:50.874: 0/0 : Call State:OFFHOOK
*May 27 00:01:50.874: 0/0 : stcapp_stop_tone_eh
*May 27 00:01:50.874: 0/0 : call_ref=116375025
*May 27 00:01:50.874: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:50.874: 0/0 : Sending ccGenerateTone(NULL)
*May 27 00:01:50.874: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:50.874: 0/0 : No state change
*May 27 00:01:50.946: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:50.946: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=5
*May 27 00:01:50.946: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:50.946: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=5, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054C32D, Rtp Expiration=0x0
*May 27 00:01:50.946: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:50.946: 0/0 : Call State:OFFHOOK
*May 27 00:01:50.946: 0/0 : Uninteresting event
*May 27 00:01:50.986: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:50.986: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023615
*May 27 00:01:50.986: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=5
*May 27 00:01:50.986: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:50.986: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=5, Duration=72,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:50.986: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:50.986: htsp_digit_ready(0/0): digit = 5
*May 27 00:01:50.986: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:50.986: 0/0 : Call State:OFFHOOK
*May 27 00:01:50.986: 0/0 : stcapp_digit_end_eh
*May 27 00:01:50.986: 0/0 : Digit received is (5)
*May 27 00:01:50.986: 0/0 : stcapp_send_keypad_button
*May 27 00:01:50.986: 0/0 : Sending StationKeypadButton(5) to CallManager
*May 27 00:01:50.986: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:50.986: 0/0 : No state change
*May 27 00:01:51.074: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:51.074: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=6
*May 27 00:01:51.074: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.074: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054C738, Rtp Expiration=0x0
*May 27 00:01:51.078: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:51.078: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.078: 0/0 : Uninteresting event
*May 27 00:01:51.114: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:51.114: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023628
*May 27 00:01:51.114: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=6
*May 27 00:01:51.114: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.114: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, Duration=77,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:51.114: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:51.118: htsp_digit_ready(0/0): digit = 6
*May 27 00:01:51.118: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:51.118: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.118: 0/0 : stcapp_digit_end_eh
*May 27 00:01:51.118: 0/0 : Digit received is (6)
*May 27 00:01:51.118: 0/0 : stcapp_send_keypad_button
*May 27 00:01:51.118: 0/0 : Sending StationKeypadButton(6) to CallManager
*May 27 00:01:51.118: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:51.118: 0/0 : No state change
*May 27 00:01:51.194: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:51.194: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=6
*May 27 00:01:51.194: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.194: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054CAFD, Rtp Expiration=0x0
*May 27 00:01:51.198: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:51.198: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.198: 0/0 : Uninteresting event
*May 27 00:01:51.234: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:51.234: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023640
*May 27 00:01:51.234: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=6
*May 27 00:01:51.234: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.234: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=6, Duration=72,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:51.234: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:51.238: htsp_digit_ready(0/0): digit = 6
*May 27 00:01:51.238: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:51.238: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.238: 0/0 : stcapp_digit_end_eh
*May 27 00:01:51.238: 0/0 : Digit received is (6)
*May 27 00:01:51.238: 0/0 : stcapp_send_keypad_button
*May 27 00:01:51.238: 0/0 : Sending StationKeypadButton(6) to CallManager
*May 27 00:01:51.238: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:51.238: 0/0 : No state change
*May 27 00:01:51.326: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:51.326: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=1
*May 27 00:01:51.326: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.326: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=1, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054CF08, Rtp Expiration=0x0
*May 27 00:01:51.326: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:51.326: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.326: 0/0 : Uninteresting event
*May 27 00:01:51.366: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:51.366: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023653
*May 27 00:01:51.366: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=1
*May 27 00:01:51.366: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.366: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=1, Duration=77,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:51.366: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:51.366: htsp_digit_ready(0/0): digit = 1
*May 27 00:01:51.366: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:51.366: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.366: 0/0 : stcapp_digit_end_eh
*May 27 00:01:51.366: 0/0 : Digit received is (1)
*May 27 00:01:51.366: 0/0 : stcapp_send_keypad_button
*May 27 00:01:51.366: 0/0 : Sending StationKeypadButton(1) to CallManager
*May 27 00:01:51.366: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:51.366: 0/0 : No state change
*May 27 00:01:51.574: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
*May 27 00:01:51.574: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Begin Digit=0
*May 27 00:01:51.574: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_begin_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.574: //239/C57534E88220/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=0, DigitBeginFlags=0x1,
Rtp Timestamp=0x9054D6D8, Rtp Expiration=0x0
*May 27 00:01:51.578: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_BEGIN for CallId: 239
*May 27 00:01:51.578: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.578: 0/0 : Uninteresting event
*May 27 00:01:51.614: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
*May 27 00:01:51.614: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728023678
*May 27 00:01:51.614: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
End Digit=0
*May 27 00:01:51.614: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_digit_end_cb:
Digit Reporting=TRUE, Digit Consume=FALSE, Digit Relay=FALSE
*May 27 00:01:51.614: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x1, Destination Call Id=-1,
Source Call Id=239, Digit=0, Duration=77,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
*May 27 00:01:51.614: //239/C57534E88220/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
*May 27 00:01:51.618: htsp_digit_ready(0/0): digit = 0
*May 27 00:01:51.618: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DIGIT_END for CallId: 239
*May 27 00:01:51.618: 0/0 : Call State:OFFHOOK
*May 27 00:01:51.618: 0/0 : stcapp_digit_end_eh
*May 27 00:01:51.618: 0/0 : Digit received is (0)
*May 27 00:01:51.618: 0/0 : stcapp_send_keypad_button
*May 27 00:01:51.618: 0/0 : Sending StationKeypadButton(0) to CallManager
*May 27 00:01:51.618: sccp_spi_dev_keypad_button: enqueue spi evt SCCP_SPI_DEV_KEYPAD_BUTTON, reg_name=ANA5C5D439A8000
*May 27 00:01:51.618: 0/0 : No state change
*May 27 00:01:56.634: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_STOP_TONE
*May 27 00:01:56.634: 0/0 : Call State:OFFHOOK
*May 27 00:01:56.634: 0/0 : stcapp_stop_tone_eh
*May 27 00:01:56.634: 0/0 : call_ref=116375025
*May 27 00:01:56.634: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:56.634: 0/0 : Sending ccGenerateTone(NULL)
*May 27 00:01:56.634: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:56.634: 0/0 : No state change
*May 27 00:01:56.638: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_STOP_TONE
*May 27 00:01:56.638: 0/0 : Call State:OFFHOOK
*May 27 00:01:56.638: 0/0 : stcapp_stop_tone_eh
*May 27 00:01:56.638: 0/0 : call_ref=116375025
*May 27 00:01:56.638: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:56.638: 0/0 : Sending ccGenerateTone(NULL)
*May 27 00:01:56.638: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:56.638: 0/0 : No state change
*May 27 00:01:56.638: sccp_dcapi_extract_and_validate_srtp_context
*May 27 00:01:56.638: 0/0 : stcapp_get_dcb_and_lcb
*May 27 00:01:56.638: 0/0 : stcapp_screen_api_event
*May 27 00:01:56.642: 0/0 : event:STCAPP_DC_EV_MEDIA_OPEN_RCV_CHNL received.
*May 27 00:01:56.642: 0/0 : stcapp_screen_open_rcv_chnl
*May 27 00:01:56.642: 0/0 : active_ccb=0x86B6E1D4, media_state is NO_MEDIA
*May 27 00:01:56.642: 0/0 : ==> Received event:STCAPP_DC_EV_MEDIA_OPEN_RCV_CHNL
*May 27 00:01:56.642: 0/0 : Call State:OFFHOOK
*May 27 00:01:56.642: 0/0 : stcapp_open_rcv_chnl_eh
*May 27 00:01:56.642: 0/0 : call_ref=116375025
*May 27 00:01:56.642: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:56.642: 0/0 : In stcapp_open_rcv_chnl_eh, after v150 copy, nse 0, rfc2833 0, sse 0
*May 27 00:01:56.642: 0/0 : In stcapp_open_rcv_chnl_eh, after v150 copy, v150_sprt 0, noaudio 0
*May 27 00:01:56.642: 0/0 : In stcapp_open_rcv_chnl_eh, voice codec is 5
*May 27 00:01:56.642: 0/0 : received ORC: rcv payload=0
*May 27 00:01:56.642: sccp_get_local_address_by_idb: get_physical_ip:1, use IP addr 172.19.4.199
*May 27 00:01:56.642: 0/0 : stcapp_set_up_voip_leg
*May 27 00:01:56.642: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:56.642: 0/0 : In stcapp_set_up_voip_leg, local port allocated 16610
*May 27 00:01:56.642: 0/0 : stcapp_set_up_modem_parms
*May 27 00:01:56.642: STCAPP:Codec: 5 ptime :20, codecbytes: 160
*May 27 00:01:56.642: 0/0 : No modem passthrough codec configured - modem passthrough disabled
*May 27 00:01:56.642: 0/0 : Info provided to RTPSPI - sess_mode:2, desired_qos 0, codec 5, pkt_period 20,
*May 27 00:01:56.642: 0/0 : rem_port 4000, lr_port 16610, dtmf_mode 8, rcv_nte 0 nte 0
*May 27 00:01:56.642: 0/0 : Sending ccIFCallSetupRequest for voip leg
*May 27 00:01:56.642: //-1/xxxxxxxxxxxx/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x8858156C, Interface Type=9, Destination=0.0.0.0, Mode=0x0,
Call Params(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=, FinalDestinationFlag=FALSE, Outgoing Dial-peer=0, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*May 27 00:01:56.642: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:56.642: :cc_get_feature_vsa malloc success
*May 27 00:01:56.642: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:56.642: cc_get_feature_vsa count is 2
*May 27 00:01:56.646: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 27 00:01:56.646: :FEATURE_VSA attributes are: feature_name:0,feature_time:2305541120,feature_id:240
*May 27 00:01:56.646: //240/xxxxxxxxxxxx/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=9, FlowMode=1
*May 27 00:01:56.646: 0/0 : ccIFCallSetRequest returned voip call id:240
*May 27 00:01:56.646: 0/0 : MER modem relay configuration passed down ? call id:240 MR proto = 0
*May 27 00:01:56.646: STCAPP:stcapp_find_ccb_by_call_id:ERROR:Invalid Call ID
*May 27 00:01:56.646: 0/0 : stcapp_conn_db_insert_ccb
*May 27 00:01:56.646: 0/0 : ccb=0x86B6E1D4
*May 27 00:01:56.646: 0/0 : call ccCallConnect for voice call_id 239
*May 27 00:01:56.646: //239/C57534E88220/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x0
*May 27 00:01:56.646: //239/C57534E88220/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*May 27 00:01:56.646: 0/0 : Media state is set to RECV_ONLY
*May 27 00:01:56.646: 0/0 : Sending dcDeviceOpenReceiveChannelAck
*May 27 00:01:56.646: 0/0 : ORChnlAck Info: codec:5, loc_ipaddr: 172.19.4.199, loc_port:16610, chnl_id:100864260
*May 27 00:01:56.646: sccp_spi_orc_ack: enqueue spi evt SCCP_SPI_MEDIA_ORC_ACK, reg_name=ANA5C5D439A8000
*May 27 00:01:56.646: 0/0 : New State = CONNECTING
*May 27 00:01:56.646: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_DIGIT_COLLECT, event:E_CC_CONNECT]
*May 27 00:01:56.646: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_connect:
Progress Indication=0
*May 27 00:01:56.646: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728024181
*May 27 00:01:56.646: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=728024181
*May 27 00:01:56.650: htsp_process_event: [0/0, FXSLS_OFFHOOK, E_HTSP_CONNECT]fxsls_offhook_connect
*May 27 00:01:56.650: [0/0] set signal state = 0x6 timestamp = 0
*May 27 00:01:56.650: //240/xxxxxxxxxxxx/CCAPI/cc_api_call_connected:
Interface=0x8858156C, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*May 27 00:01:56.650: //240/xxxxxxxxxxxx/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*May 27 00:01:56.650: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_CONNECTED for CallId: 240
*May 27 00:01:56.650: 0/0 : Call State:CONNECTING
*May 27 00:01:56.650: 0/0 : stcapp_call_connected_eh
*May 27 00:01:56.650: 0/0 : stcapp_create_conference
*May 27 00:01:56.650: 0/0 : Sending ccConferenceCreate to Symphony
*May 27 00:01:56.650: //239/C57534E88220/CCAPI/ccConferenceCreate:
(confID=0xFFFFFFFF, callID1=0xEF, gcid=C57534E8-703B11D6-8220E4C5-AD12165E, tag=0x0)
*May 27 00:01:56.650: //240/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0xFFFFFFFF, callID2=0xF0, gcid=0-0-0-0, tag=0x0)
*May 27 00:01:56.654: //239/C57534E88220/CCAPI/ccConferenceCreate:
Conference Id=0xFFFFFFFF, Call Id1=239, Call Id2=240, Tag=0x0
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_bridge_check_cb:
*May 27 00:01:56.654: htsp_call_bridged invoked
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_bridge_check_cb:exit@1500
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_bridge_status_cb:
*May 27 00:01:56.654: //239/C57534E88220/CCAPI/cc_api_bridge_done:
Conference Id=0x72, Source Interface=0x88B03B60, Source Call Id=239,
Destination Call Id=240, Disposition=0x0, Tag=0xFFFFFFFF
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=CISCO_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=SCCP Call Type
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_tty_config:
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_tty_config:
Save TTY configuration
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
*May 27 00:01:56.654: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
Set TTY feat parameters
*May 27 00:01:56.654: //240/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*May 27 00:01:56.654: cc_api_get_xcode_stream : 4977
*May 27 00:01:56.654: //240/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*May 27 00:01:56.654: call_info mainst_callID:0xF0, peer_callID:0xEF, confID:0x72, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*May 27 00:01:56.654: //240/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*May 27 00:01:56.654: stream[0]: callid:0xF0, media_passthrough:0
*May 27 00:01:56.654: //240/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x72, Source Interface=0x8858156C, Source Call Id=240,
Destination Call Id=239, Disposition=0x0, Tag=0x0
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/cc_generic_bridge_done:
Conference Id=0x72, Source Interface=0x8858156C, Source Call Id=240,
Destination Call Id=239, Disposition=0x0, Tag=0x0
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x72, Destination Call Id=240)
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x72, Destination Call Id=239)
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/ccConferenceCreate:

*May 27 00:01:56.658: confID:0x72; callEntry1 callID1:0xEF, type:6; callEntry2 callID2:0xF0, type:9

*May 27 00:01:56.658: 0/0 : Conference created. voice call id:239, voip call id:240
*May 27 00:01:56.658: 0/0 : No state change
*May 27 00:01:56.658: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_DO_CAPS_IND]
*May 27 00:01:56.658: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_IND
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/cc_api_caps_ind:

*May 27 00:01:56.658: voice_rtp_nse_payload 0, voice_rtp_sse_payload 118 voice_sprt_payload 120
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/cc_api_caps_ind:

*May 27 00:01:56.658: sprt_latency 200, sprt_retries 12
*May 27 00:01:56.658: //239/C57534E88220/CCAPI/cc_api_caps_ind:
Destination Interface=0x8858156C, Destination Call Id=240, Source Call Id=239,
Caps(Codec=0x1, Fax Rate=0x1, Fax Version:=0, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*May 27 00:01:56.658: //239/C57534E88220/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))
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*May 27 00:01:56.658: cc_api_get_xcode_stream : 4977
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:

*May 27 00:01:56.658: voice_rtp_nse_payload 100, voice_rtp_sse_payload 0 voice_sprt_payload 0
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:

*May 27 00:01:56.658: sprt_latency 0, sprt_retries 0
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Destination Interface=0x88B03B60, Destination Call Id=239, Source Call Id=240,
Caps(Codec=0x1, Fax Rate=0x2, Fax Version:=0, Vad=0x1,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/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))
*May 27 00:01:56.658: //240/xxxxxxxxxxxx/CCAPI/cc_api_caps_ack:
Destination Interface=0x88B03B60, Destination Call Id=239, Source Call Id=240,
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=441)
*May 27 00:01:56.658: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_CAPS_IND]
*May 27 00:01:56.662: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_ACK
*May 27 00:01:56.662: //239/C57534E88220/CCAPI/cc_api_caps_ack:
Destination Interface=0x8858156C, Destination Call Id=240, Source Call Id=239,
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=441)
*May 27 00:01:56.662: //239/C57534E88220/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x72, Call Id1=239, Call Id2=240
*May 27 00:01:56.662: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_get_plc_by_dsp_pltf_intf: vtsp_get_plc_by_dsp_pltf_intf: callID 239, dialpeer tag 999000, plc 1
*May 27 00:01:56.662: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_feature_notify_cb:
Feature ID=0, Feature Status=1
*May 27 00:01:56.666: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_reactivate_ringback:
*May 27 00:01:56.666: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_reactivate_ringback:exit@1291
*May 27 00:01:56.666: //239/C57534E88220/CCAPI/cc_api_voice_mode_event:
Call Id=239
*May 27 00:01:56.666: //239/C57534E88220/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x0)
*May 27 00:01:56.666: htsp_process_event: [0/0, FXSLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxsls_voice_cut_thru
*May 27 00:01:56.670: 0/0 : ==> Received event:STCAPP_CC_EV_CONF_CREATE_DONE for CallId: 239
*May 27 00:01:56.670: 0/0 : Call State:CONNECTING
*May 27 00:01:56.670: 0/0 : stcapp_default_eh
*May 27 00:01:56.670: 0/0 : call_ref=114, call_state=0
*May 27 00:01:56.670: 0/0 : New State = ACTIVE_PENDING
*May 27 00:01:56.670: 0/0 : ==> Received event:STCAPP_CC_EV_VOICE_MODE_DONE for CallId: 239
*May 27 00:01:56.670: 0/0 : Call State:ACTIVE_PENDING
*May 27 00:01:56.670: 0/0 : Uninteresting event
*May 27 00:01:56.674: 0/0 : ==> Received event:STCAPP_CC_EV_UNINTERESTED for CallId: 239
*May 27 00:01:56.674: 0/0 : Call State:ACTIVE_PENDING
*May 27 00:01:56.674: 0/0 : Uninteresting event
*May 27 00:01:56.674: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_CALL_INFO
*May 27 00:01:56.674: 0/0 : Call State:ACTIVE_PENDING
*May 27 00:01:56.674: 0/0 : stcapp_call_info_eh
*May 27 00:01:56.674: 0/0 : call_ref=116375025
*May 27 00:01:56.674: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:56.674: 0/0 : Message call_info received when hook state is offhook, voice leg setup bypassed!
*May 27 00:01:56.674: 0/0 : No state change
*May 27 00:01:56.806: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=20822 systime=728024197
*May 27 00:01:56.806: htsp_process_event: [0/0, FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
*May 27 00:01:56.806: htsp_timer - 1000 msec
*May 27 00:01:57.806: htsp_process_event: [0/0, FXSLS_CONNECT, E_HTSP_EVENT_TIMER]fxsls_connect_wait_release_req
*May 27 00:01:57.806: htsp_timer_stop
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_TSP_DISCONNECT_IND]
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_generate_disc:
Cause Value=16
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728024297
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=728024297
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_set_release_source:
Release Direction=PSTN, Release Source=Calling Party-PSTN
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_cc_call_disconnected:
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_cc_call_disconnected:
Cause Value=16
*May 27 00:01:57.806: //239/C57534E88220/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x88B03B60, Call Id=239
*May 27 00:01:57.806: //239/C57534E88220/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer:
Timer Start Time=728024297, Timer Value=15000(ms)
*May 27 00:01:57.806: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_generate_disc:
Return Code=0
*May 27 00:01:57.806: 0/0 : stcapp_screen_api_event
*May 27 00:01:57.806: 0/0 : event:STCAPP_CC_EV_CALL_DISCONNECTED received.
*May 27 00:01:57.806: 0/0 : stcapp_screen_call_disconnected
*May 27 00:01:57.806: STCAPP:Receive CC event:: call_id=239, ccb=0x86B6E1D4
*May 27 00:01:57.810: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DISCONNECTED for CallId: 239
*May 27 00:01:57.810: 0/0 : Call State:ACTIVE_PENDING
*May 27 00:01:57.810: 0/0 : stcapp_loc_onhook_eh
*May 27 00:01:57.810: 0/0 : stcapp_reset_voice_call_attr
*May 27 00:01:57.810: 0/0 : Reset device attributes used by dialtone generation after remote onhook feature
*May 27 00:01:57.810: //239/C57534E88220/CCAPI/ccRestartDigitTimeoutMsec:
Digit Timeout=0, Call Id=239
*May 27 00:01:57.810: 0/0 : lcb->num_ccbs=1
*May 27 00:01:57.810: 0/0 : Sending ccGenerateTone(NULL)
*May 27 00:01:57.810: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:57.810: 0/0 : Sending StationOnHook to CallManager, call_ref is 116375025
*May 27 00:01:57.810: sccp_spi_dev_on_hook: enqueue spi evt SCCP_SPI_DEV_ON_HOOK, reg_name=ANA5C5D439A8000
*May 27 00:01:57.810: //239/C57534E88220/CCAPI/ccRestartDigitTimeoutMsec:
Digit Timeout=0, Call Id=239
*May 27 00:01:57.810: 0/0 : New State = ONHOOK_DISCONNECT
*May 27 00:01:57.810: sccp_send_onhook_v1
*May 27 00:01:57.818: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_STOP_TONE
*May 27 00:01:57.818: 0/0 : Call State:ONHOOK_DISCONNECT
*May 27 00:01:57.818: 0/0 : stcapp_stop_tone_eh
*May 27 00:01:57.818: 0/0 : call_ref=116375025
*May 27 00:01:57.818: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:57.818: 0/0 : Sending ccGenerateTone(NULL)
*May 27 00:01:57.818: //239/C57534E88220/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=239
*May 27 00:01:57.818: 0/0 : No state change
*May 27 00:01:57.822: 0/0 : stcapp_get_dcb_and_lcb
*May 27 00:01:57.822: 0/0 : stcapp_screen_api_event
*May 27 00:01:57.822: 0/0 : event:STCAPP_DC_EV_MEDIA_CLOSE_RCV_CHNL received.
*May 27 00:01:57.822: 0/0 : stcapp_screen_close_rcv_chnl
*May 27 00:01:57.822: 0/0 : ==> Received event:STCAPP_DC_EV_MEDIA_CLOSE_RCV_CHNL
*May 27 00:01:57.822: 0/0 : Call State:ONHOOK_DISCONNECT
*May 27 00:01:57.822: 0/0 : stcapp_close_rcv_chnl_eh
*May 27 00:01:57.822: 0/0 : call_ref=116375025
*May 27 00:01:57.822: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:57.822: 0/0 : call_ref=116375025, lcb->mode=0, lcb->conf_status=0
*May 27 00:01:57.822: 0/0 : Current Media state is RECV_ONLY
*May 27 00:01:57.822: 0/0 : Sending ccConferenceDestroy
*May 27 00:01:57.822: //239/C57534E88220/CCAPI/ccConferenceDestroy:
Conference Id=0x72, Tag=0x0
*May 27 00:01:57.822: //239/C57534E88220/CCAPI/ccConferenceDestroy:

*May 27 00:01:57.822: confID:0x72; callEntry1 callID1:0xEF, type:6; callEntry2 callID2:0xF0, type:9

*May 27 00:01:57.822: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_bridge_status_cb:
*May 27 00:01:57.822: //239/C57534E88220/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x72, Source Interface=0x88B03B60, Source Call Id=239,
Destination Call Id=240, Disposition=0x0, Tag=0x0
*May 27 00:01:57.822: //240/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*May 27 00:01:57.822: cc_api_get_xcode_stream : 4977
*May 27 00:01:57.822: //240/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x72, Source Interface=0x8858156C, Source Call Id=240,
Destination Call Id=239, Disposition=0x0, Tag=0x0
*May 27 00:01:57.822: //239/C57534E88220/CCAPI/cc_generic_bridge_done:
Conference Id=0x72, Source Interface=0x8858156C, Source Call Id=240,
Destination Call Id=239, Disposition=0x0, Tag=0x0
*May 27 00:01:57.826: 0/0 : Sending ccCallDisconnect for voip call id:240
*May 27 00:01:57.826: 0/0 : stcapp_disconnect_call_leg
*May 27 00:01:57.826: 0/0 : Sending ccCallDisconnect for VoIP_LEG with call id:240
*May 27 00:01:57.826: //240/xxxxxxxxxxxx/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*May 27 00:01:57.826: //240/xxxxxxxxxxxx/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*May 27 00:01:57.826: 0/0 : Media state is set to NO_MEDIA
*May 27 00:01:57.826: 0/0 : Media state is set to NO_MEDIA
*May 27 00:01:57.826: 0/0 : No state change
*May 27 00:01:57.826: 0/0 : Conference already destroyed for callid:239, event:STCAPP_CC_EV_CONF_DESTROY_DONE
*May 27 00:01:57.830: 0/0 : stcapp_get_dcb_and_lcb
*May 27 00:01:57.830: 0/0 : stcapp_screen_api_event
*May 27 00:01:57.830: 0/0 : event:STCAPP_DC_EV_DEVICE_CALL_STATE_ONHOOK received.
*May 27 00:01:57.830: 0/0 : stcapp_screen_dev_cs_onhook
*May 27 00:01:57.830: 0/0 : onhook 1, num_ccbs=1, dcb->mwi 0, dcb->vmwi_on 0, vmwi_reprocess 0, mwi_config 0
*May 27 00:01:57.830: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_CALL_STATE_ONHOOK
*May 27 00:01:57.830: 0/0 : Call State:ONHOOK_DISCONNECT
*May 27 00:01:57.830: 0/0 : stcapp_cs_onhook_onhook_eh
*May 27 00:01:57.830: 0/0 : call_ref=116375025
*May 27 00:01:57.830: 0/0 : stcapp_get_ccb_ptr
*May 27 00:01:57.830: 0/0 : stcapp_check_reset_shared_overlay
*May 27 00:01:57.830: 0/0 : Reset the overlay mode of this phone!
*May 27 00:01:57.830: 0/0 : stcapp_process_cs_onhook
*May 27 00:01:57.830: 0/0 : lcb->mode=CALL_BASIC (0)
*May 27 00:01:57.830: 0/0 : conn_cb=0x86B6E1D4, lcb->num_ccbs=1, role=1, media_state=NO_MEDIA , call_id=239
*May 27 00:01:57.830: 0/0 : stcapp_call_cleanup
*May 27 00:01:57.830: 0/0 : conf_id=-1
*May 27 00:01:57.830: 0/0 : voice 239, voip 240
*May 27 00:01:57.830: 0/0 : stcapp_set_ring_mode
*May 27 00:01:57.830: 0/0 : SCCP ring mode:1
*May 27 00:01:57.830: //239/C57534E88220/CCAPI/ccCallFeature:
Feature Type=34, Call Id=239
*May 27 00:01:57.830: 0/0 : Invoking Feature:34. Mode:0 for callid:239
*May 27 00:01:57.830: 0/0 : stcapp_disconnect_call_leg
*May 27 00:01:57.830: 0/0 : Sending ccCallDisconnect for VOICE_LEG with call id:239
*May 27 00:01:57.830: //239/C57534E88220/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*May 27 00:01:57.830: //239/C57534E88220/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*May 27 00:01:57.830: //239/C57534E88220/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
*May 27 00:01:57.834: 0/0 : Media state is set to NO_MEDIA
*May 27 00:01:57.834: 0/0 : CCB 0x86B6E1D4 unlinked
*May 27 00:01:57.834: 0/0 : !!!! conn_cb->lcb->num_ccbs-- !!!!!
*May 27 00:01:57.834: 0/0 : num_ccbs=0
*May 27 00:01:57.834: 0/0 : Reset the overlay mode of this phone!
*May 27 00:01:57.834: 0/0 : stcapp_call_idle_cleanup
*May 27 00:01:57.834: 0/0 : stcapp_reset_plar_info
*May 27 00:01:57.834: 0/0 : New State = IDLE
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_FEATURE]
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_call_feature:
Feature Type=34htsp_call_feature:feature 34

*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_DISCONNECT]
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_disconnect:
Cause Value=16, Previous Cause Value=16
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=728024300
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_pcm_cap_conf_tone_timer_stop:
Timer Stop Time=728024300
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=CISCO_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=SCCP Call Type
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*May 27 00:01:57.834: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*May 27 00:01:57.838: htsp_timer_stop3
*May 27 00:01:57.838: htsp_process_event: [0/0, FXSLS_WAIT_RELEASE_REQ, E_HTSP_STOP_RINGING]fxsls_stop_ringing
*May 27 00:01:57.838: [0/0] set signal state = 0x4 timestamp = 0
*May 27 00:01:57.842: //240/xxxxxxxxxxxx/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x8858156C, Tag=0x0, Call Id=240,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*May 27 00:01:57.842: //240/xxxxxxxxxxxx/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*May 27 00:01:57.842: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 27 00:01:57.842: :cc_free_feature_vsa freeing 896BC3F8
*May 27 00:01:57.842: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 27 00:01:57.842: vsacount in free is 1
*May 27 00:01:57.842: 0/0 : stcapp_screen_api_event
*May 27 00:01:57.842: 0/0 : event:STCAPP_CC_EV_CALL_DISCONNECT_DONE received.
*May 27 00:01:57.842: 0/0 : stcapp_screen_call_disconnect_done
*May 27 00:01:57.842: STCAPP:Receive CC event:: call_id=240, ccb=0x86B6E1D4
*May 27 00:01:57.842: 0/0 : Received event:CC_EV_CALL_DISCONNECT_DONE for CallId: 240
*May 27 00:01:57.842: 0/0 : stcapp_process_disconnect_done
*May 27 00:01:57.842: 0/0 : stcapp_reset_call_leg
*May 27 00:01:57.842: 0/0 : ccb(0x86B6E1D4): voice/voip call_id=239/240, reset call_id=240
*May 27 00:01:57.842: 0/0 : stcapp_conn_db_delete_ccb
*May 27 00:01:57.842: 0/0 : ccb=0x86B6E1D4
*May 27 00:01:57.842: 0/0 : Disconnect Done: CCB Count:1 Call Leg Count:1
*May 27 00:01:57.842: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DISCONNECT_DONE
*May 27 00:01:57.842: 0/0 : Call State:IDLE
*May 27 00:01:57.842: 0/0 : Uninteresting event
*May 27 00:01:57.846: 0/0 : ==> Received event:STCAPP_DC_EV_DEVICE_DEFINE_DATE_TIME_RES
*May 27 00:01:57.846: 0/0 : Device State:IS
*May 27 00:01:57.846: 0/0 : No state change
*May 27 00:01:57.846: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
*May 27 00:01:57.854: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
*May 27 00:01:57.854: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_dsm_dsp_stats_complete:
*May 27 00:01:57.854: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer:
Timer Start Time=728024302, Timer Value=60000(ms)
*May 27 00:01:57.854: htsp_process_event: [0/0, FXSLS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]fxsls_waitrls_req_rls
*May 27 00:01:57.858: [0/0] set signal state = 0x4 timestamp = 0
*May 27 00:01:57.858: [0/0] set signal state = 0x4 timestamp = 0
*May 27 00:01:57.858: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=236 systime=728024302
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/act_wrelease_release:
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_play_busy_timer_stop:
Timer Stop Time=728024302
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=728024302
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_do_call_history:
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_do_call_history:
Coder Rate=5
*May 27 00:01:57.858: //239/C57534E88220/VTSP:(0/0):-1:1:1/vtsp_is_valid_dsm_handle:
DMGR=0x896B53D4, VTSP CDB=0x86711EF0
*May 27 00:01:57.858: htsp_process_event: [0/0, FXSLS_ONHOOK, E_DSP_SIG_0100]fxsls_onhook_onhook
*May 27 00:01:57.862: //239/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_dsm_closed_cb:
*May 27 00:01:57.862: //239/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_process_event:
[state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
*May 27 00:01:57.866: //239/C57534E88220/VTSP:(0/0):-1:-1:-1/act_terminate:
*May 27 00:01:57.866: //239/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_timer_stop:
Timer Stop Time=728024303
*May 27 00:01:57.866: //239/C57534E88220/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x88B03B60, Tag=0x0, Call Id=239,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*May 27 00:01:57.866: //239/C57534E88220/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*May 27 00:01:57.866: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 27 00:01:57.866: :cc_free_feature_vsa freeing 896BC4D8
*May 27 00:01:57.866: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 27 00:01:57.866: vsacount in free is 0
*May 27 00:01:57.866: //-1/C57534E88220/VTSP:(0/0):-1:-1:-1/vtsp_free_cdb:
CDB=0x86711EF0
*May 27 00:01:57.866: 0/0 : stcapp_screen_api_event
*May 27 00:01:57.866: 0/0 : event:STCAPP_CC_EV_CALL_DISCONNECT_DONE received.
*May 27 00:01:57.866: 0/0 : stcapp_screen_call_disconnect_done
*May 27 00:01:57.866: 0/0 : onhook 1, num_ccbs=0, dcb->mwi 0, dcb->vmwi_on 0, vmwi_reprocess 0, mwi_config 0
*May 27 00:01:57.866: STCAPP:Receive CC event:: call_id=239, ccb=0x86B6E1D4
*May 27 00:01:57.866: 0/0 : Received event:CC_EV_CALL_DISCONNECT_DONE for CallId: 239
*May 27 00:01:57.866: 0/0 : stcapp_process_disconnect_done
*May 27 00:01:57.866: 0/0 : stcapp_reset_call_leg
*May 27 00:01:57.866: 0/0 : ccb(0x86B6E1D4): voice/voip call_id=239/-1, reset call_id=239
*May 27 00:01:57.866: 0/0 : stcapp_conn_db_delete_ccb
*May 27 00:01:57.866: 0/0 : ccb=0x86B6E1D4
*May 27 00:01:57.866: 0/0 : Set the hook status to ONHOOK to make sure SO/SB won't cause issues!
*May 27 00:01:57.866: 0/0 : stcapp_free_ccb
*May 27 00:01:57.870: 0/0 : ccb->dcb/ccb->lcb=0x8970E9D4/0x8970EC50
*May 27 00:01:57.870: 0/0 : Freed CCB 0x86B6E1D4
*May 27 00:01:57.870: 0/0 : After freeing this ccb, global ccb count becomes 0
*May 27 00:01:57.870: 0/0 : Disconnect Done: CCB Count:0 Call Leg Count:0
*May 27 00:01:57.870: 0/0 : ==> Received event:STCAPP_CC_EV_CALL_DISCONNECT_DONE
*May 27 00:01:57.870: 0/0 : Call State:IDLE
*May 27 00:01:57.870: 0/0 : Uninteresting event

We got a callback from the manufacturer and he pointed us to voltages.  We measured on-hook voltage @ 44.5vDC and off-hook @ ~9.05vDC.

 

Connected to PoTS on-hook is ~52vDC and ~11.5vDC off-hook.

 

 

The guy who called me back said that these devices need closer to 10vDC to work and low voltage would cause it to behave weirdly.

 

 

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: