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
1369
Views
5
Helpful
7
Replies

Incoming Calls via MGCP Gateway FXO port rings twice before getting connected

edson_guevara14
Level 1
Level 1

‎08-15-2018 12:51 PM - edited ‎03-17-2019 01:21 PM

Hello Everyone,

 

I have a problem were i have set up a MGCP Gateway With a FXO port for a customer, i have set it up so that when a call gets in, it gets delivered to an AA in unity connection, now the call gets connected fine but the issue i have is that it rings twice before it gets answered, this problem is only when the call gets in trough the FXO since i have dialed directly from a phone to the pilot and the AA works fine (no rings delay) i have observed the fxo port behavior and it gets ring detected (while i hear the ringing on my phone) and the it goes off-hook the moment i start hearing the audio so i believe its not going off-hook as soon as the call gets in.

 

Any help in this would be much appreciated here is the config from the FXO port:

 

voice-port 0/1/0

 no battery-reversal
 output attenuation 0
 no vad
 cptone PE
 timeouts interdigit 2
 timeouts call-disconnect 2
 timeouts wait-release 1
 timing hookflash-out 500
 bearer-cap Speech
 caller-id enable

 

Regards,

Edson

1 person had this problem
Labels:
0 Helpful
7 Replies 7

Sreekanth Narayanan
Cisco Employee
Cisco Employee

‎08-15-2018 10:30 PM

This could be due to the fact that you are using FXO for the incoming call. Generally there is a delay when the call comes in on the FXO and goes to the CUCM because of the way it is implemented (legacy circuits). You can take debugs on the gateway to see how long it takes for the call to go to the Unity Connection once it hits the FXO port. 

debug vpm signal

debug mgcp packet

 

These debugs will show you the delay between the time the call comes in on the fxo port and the call answered by the CUC. Based on that, we will be able to say where the extra ring is added.

0 Helpful

edson_guevara14
Level 1
Level 1
In response to Sreekanth Narayanan

‎08-20-2018 09:41 AM

Hello Sreekanth,

Here is the output for the 2 commands can you help me identify the problem? It took me some time to get back to customer site and get the logs sorry for the delay, you can see a 15 sec window that corresponds to the 2 ringtones that i hear before the Unity Audio


debug vpm signal

*Aug 20 16:36:16.783: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=21107 systime=283051230
*Aug 20 16:36:16.784: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Aug 20 16:36:16.784: htsp_timer - 125 msec
*Aug 20 16:36:16.909: htsp_process_event: [0/1/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Aug 20 16:36:16.910: htsp_timer - 10000 msec
*Aug 20 16:36:16.910: htsp_timer3 - 5600 msec
*Aug 20 16:36:16.910: [0/1/0] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
*Aug 20 16:36:16.910: htsp_start_caller_id_rx create dsp_stream_manager
*Aug 20 16:36:16.910: [0/1/0] htsp_dsm_create_success returns 1
*Aug 20 16:36:17.829: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=22149 systime=283051335
*Aug 20 16:36:17.829: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Aug 20 16:36:17.829: fxols_ringing_not
*Aug 20 16:36:17.829: htsp_timer_stop
*Aug 20 16:36:17.829: htsp_timer - 10000 msec
*Aug 20 16:36:22.444: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=26766 systime=283051796
*Aug 20 16:36:22.444: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0000]
*Aug 20 16:36:22.510: htsp_process_event: [0/1/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
*Aug 20 16:36:22.510: htsp_timer_stop3
*Aug 20 16:36:23.488: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=27808 systime=283051901
*Aug 20 16:36:23.489: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Aug 20 16:36:23.489: fxols_ringing_not
*Aug 20 16:36:23.489: htsp_timer_stop
*Aug 20 16:36:23.489: htsp_timer_stop3
*Aug 20 16:36:23.489: [0/1/0] htsp_stop_caller_id_rx. message length 0
*Aug 20 16:36:23.489: htsp_timer3 - 20 msec
*Aug 20 16:36:23.491: [0/1/0] htsp_dsm_close_done
*Aug 20 16:36:23.509: htsp_process_event: [0/1/0, FXOLS_STOP_CALLERID_DELAY, E_HTSP_EVENT_TIMER3]
*Aug 20 16:36:23.509: htsp_timer_stop
*Aug 20 16:36:23.509: htsp_timer_stop3 htsp_setup_ind
*Aug 20 16:36:23.509: [0/1/0] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
*Aug 20 16:36:23.509: [0/1/0] get_local_station_id calling num= calling name= calling time=08/20 16:36 orig called=
*Aug 20 16:36:23.509: fxols_callerid_done: call being answered
*Aug 20 16:36:23.510: htsp_process_event: [0/1/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Aug 20 16:36:23.510: fxols_wait_setup_ack:
*Aug 20 16:36:23.510: [0/1/0] nim_set_sig_state: ABCD=12, timestamp=0, sys_time=283051903
*Aug 20 16:36:23.510: [0/1/0] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Aug 20 16:36:23.511: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_SETUP_ACK]
*Aug 20 16:36:23.512: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Aug 20 16:36:23.512: htsp_timer_stop
*Aug 20 16:36:23.537: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Aug 20 16:36:23.537: htsp_call_bridged invoked
*Aug 20 16:36:23.539: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Aug 20 16:36:24.545: htsp_dsp_message: SEND_SIG_STATUS: state=0x6 timestamp=28861 systime=283052006
*Aug 20 16:36:24.545: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery
*Aug 20 16:36:24.545: htsp_timer_stop2
*Aug 20 16:36:40.716: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=45039 systime=283053623
*Aug 20 16:36:40.716: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0100]fxols_normal_battery
*Aug 20 16:36:40.716: htsp_timer_stop2

*Aug 20 16:38:22.989: htsp_timer_stop3
*Aug 20 16:38:23.048: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Aug 20 16:38:23.048: htsp_timer_stop
*Aug 20 16:38:23.048: htsp_timer_stop2
*Aug 20 16:38:23.048: htsp_timer_stop3
*Aug 20 16:38:23.048: [0/1/0] nim_set_sig_state: ABCD=4, timestamp=0, sys_time=283063857
*Aug 20 16:38:23.048: [0/1/0] set signal state = 0x4 timestamp = 0
*Aug 20 16:38:23.048: htsp_timer - 2000 msec
*Aug 20 16:38:25.048: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Aug 20 16:38:25.052: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=283064057
*Aug 20 16:38:25.052: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]






debug mgcp packet



*Aug 20 16:40:04.200: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668697 *@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
O:
<---

*Aug 20 16:40:04.214: MGCP Packet received from 10.13.1.100:2427--->
200 300668697
<---

*Aug 20 16:40:13.934: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668698 aaln/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
N: ca@10.13.1.100:2427
X: 0
O: L/hd
<---

*Aug 20 16:40:13.960: MGCP Packet received from 10.13.1.100:2427--->
200 300668698
<---

*Aug 20 16:40:13.960: MGCP Packet received from 10.13.1.100:2427--->
CRCX 270850 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152caa8000000F5
X: 0
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu
Q: process,loop
<---

*Aug 20 16:40:13.964: MGCP Packet sent to 10.13.1.100:2427--->
200 270850 OK
I: 6E

v=0
o=- 110 0 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8942 RTP/AVP 0 100
a=rtpmap:100 X-NSE/8000
a=fmtp:100 200-202
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 16:40:13.985: MGCP Packet received from 10.13.1.100:2427--->
RQNT 270851 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S: G/rt
Q: process,loop
<---

*Aug 20 16:40:13.986: MGCP Packet sent to 10.13.1.100:2427--->
200 270851 OK
<---

*Aug 20 16:40:14.011: MGCP Packet received from 10.13.1.100:2427--->
MDCX 270852 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152caa8000000F5
I: 6E
X: 0
L: p:20, a:G.729, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 16:40:14.014: MGCP Packet sent to 10.13.1.100:2427--->
200 270852 OK

v=0
o=- 110 1 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8942 RTP/AVP 18
a=rtpmap:18 G.729/8000
a=fmtp:18 annexb=no
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 16:40:14.035: MGCP Packet received from 10.13.1.100:2427--->
RQNT 270853 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 16:40:14.036: MGCP Packet sent to 10.13.1.100:2427--->
200 270853 OK
<---

*Aug 20 16:40:14.061: MGCP Packet received from 10.13.1.100:2427--->
MDCX 270854 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152caa8000000F5
I: 6E
X: 0
L: p:20, a:G.729, s:off, t:b8, fxr/fx:t38
M: sendrecv
R: L/hu, D/[0-9ABCD*#], FXR/t38
S:
Q: process,loop

v=0
o=- 110 0 IN EPN AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com
s=Cisco SDP 0
t=0 0
m=audio 18046 RTP/AVP 18
c=IN IP4 10.13.1.110
a=X-sqn:0
a=X-cap:1 image udptl t38
<---

*Aug 20 16:40:14.063: MGCP Packet sent to 10.13.1.100:2427--->
200 270854 OK
<---

*Aug 20 16:40:19.200: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668699 *@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
O:
<---

*Aug 20 16:40:19.282: MGCP Packet received from 10.13.1.100:2427--->
200 300668699
<---

*Aug 20 16:40:31.669: MGCP Packet received from 10.13.1.100:2427--->
MDCX 270858 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152caa8000000F5
I: 6E
X: 0
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 16:40:31.671: MGCP Packet sent to 10.13.1.100:2427--->
200 270858 OK

v=0
o=- 110 2 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8942 RTP/AVP 18
a=rtpmap:18 G.729/8000
a=fmtp:18 annexb=no
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 16:40:31.692: MGCP Packet received from 10.13.1.100:2427--->
MDCX 270859 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152caa8000000F5
I: 6E
X: 0
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 16:40:31.696: MGCP Packet sent to 10.13.1.100:2427--->
200 270859 OK

v=0
o=- 110 3 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8942 RTP/AVP 0
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 16:40:33.061: MGCP Packet received from 10.13.1.100:2427--->
RQNT 270860 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S: G/rt
Q: process,loop
<---

*Aug 20 16:40:33.062: MGCP Packet sent to 10.13.1.100:2427--->
200 270860 OK
<---

thannk you for any help i can get here
0 Helpful

R0g22
Cisco Employee
Cisco Employee
In response to edson_guevara14

‎08-20-2018 10:14 AM

Looks to be your Telco disconnecting -

## Battery reversal used by Telco for answer supervision -

*Aug 20 16:36:24.545: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery

## Polarity is reversed back to normal after 16 seconds or so -

*Aug 20 16:36:40.716: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0100]fxols_normal_battery

## Port is released by IOS -

*Aug 20 16:38:23.048: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release

Can you take another set please ? Enable all of the following at the same time and make a test call -

debug voip vtsp all
debug vpm signal
debug voice cc inout
debug mgcp packet

0 Helpful

edson_guevara14
Level 1
Level 1
In response to R0g22

‎08-20-2018 10:25 AM

Hello Nipun,

Here are the logs you requested, all enabled at the same time

*Aug 20 17:25:40.347: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668882 *@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
O:
<---

*Aug 20 17:25:40.360: MGCP Packet received from 10.13.1.100:2427--->
200 300668882
<---

pica-cer-gw-voz-pro#
pica-cer-gw-voz-pro#
pica-cer-gw-voz-pro#
*Aug 20 17:25:47.576: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=42783 systime=283348309
*Aug 20 17:25:47.577: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Aug 20 17:25:47.577: htsp_timer - 125 msec
*Aug 20 17:25:47.702: htsp_process_event: [0/1/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Aug 20 17:25:47.702: htsp_timer - 10000 msec
*Aug 20 17:25:47.702: htsp_timer3 - 5600 msec
*Aug 20 17:25:47.702: [0/1/0] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
*Aug 20 17:25:47.702: htsp_start_caller_id_rx create dsp_stream_manager
*Aug 20 17:25:47.702: [0/1/0] htsp_dsm_create_success returns 1
*Aug 20 17:25:48.619: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=43825 systime=283348414
*Aug 20 17:25:48.620: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Aug 20 17:25:48.620: fxols_ringing_not
*Aug 20 17:25:48.620: htsp_timer_stop
*Aug 20 17:25:48.620: htsp_timer - 10000 msec
*Aug 20 17:25:53.237: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=48438 systime=283348875
*Aug 20 17:25:53.238: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0000]
*Aug 20 17:25:53.302: htsp_process_event: [0/1/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
*Aug 20 17:25:53.302: htsp_timer_stop3
*Aug 20 17:25:54.273: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=49479 systime=283348979
*Aug 20 17:25:54.273: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Aug 20 17:25:54.273: fxols_ringing_not
*Aug 20 17:25:54.273: htsp_timer_stop
*Aug 20 17:25:54.273: htsp_timer_stop3
*Aug 20 17:25:54.273: [0/1/0] htsp_stop_caller_id_rx. message length 0
*Aug 20 17:25:54.273: htsp_timer3 - 20 msec
*Aug 20 17:25:54.275: [0/1/0] htsp_dsm_close_done
*Aug 20 17:25:54.293: htsp_process_event: [0/1/0, FXOLS_STOP_CALLERID_DELAY, E_HTSP_EVENT_TIMER3]
*Aug 20 17:25:54.293: htsp_timer_stop
*Aug 20 17:25:54.293: htsp_timer_stop3 htsp_setup_ind
*Aug 20 17:25:54.293: [0/1/0] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
*Aug 20 17:25:54.293: [0/1/0] get_local_station_id calling num= calling name= calling time=08/20 17:25 orig called=
*Aug 20 17:25:54.293: fxols_callerid_done: call being answered
*Aug 20 17:25:54.293: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb:
CDB=0x7FD054D1A710
*Aug 20 17:25:54.293: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_ind:
Event=E_TSP_SETUP_IND
Progress Indication=3, CarrierIDCode=, Info Trans Capability=128, Source Carrier ID=, tg_label_flag=0
*Aug 20 17:25:54.293: //-1/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_timer:
Timer Start Time=283348981, Timer Value=180000(ms)
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_do_normal_call_setup_ind:
XCC State Machine (XCCSM) Added
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_setup_ind_pend_success:
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_realloc_cdb:
CDB=0x7FD054D1A710
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_indicate_call:
*Aug 20 17:25:54.294: //-1/ED35F1B18582/VTSP:(0/1/0):-1:1:1/is_secondary_dialtone_disabled:
DID=TRUE
*Aug 20 17:25:54.294: //-1/ED35F1B18582/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=FFFFFFFFFFFFFFFF
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

*Aug 20 17:25:54.294: //-1/ED35F1B18582/CCAPI/cc_api_call_setup_ind_common:
Interface=0x7FD050F7DBD8, 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=TRUE,
Incoming Dial-peer=999010, 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
*Aug 20 17:25:54.294: //-1/ED35F1B18582/CCAPI/ccCheckClipClir:
In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Aug 20 17:25:54.294: //-1/ED35F1B18582/CCAPI/ccCheckClipClir:
Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Aug 20 17:25:54.294: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.294: :cc_get_feature_vsa malloc success
*Aug 20 17:25:54.294: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.295: cc_get_feature_vsa count is 1
*Aug 20 17:25:54.295: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.295: :FEATURE_VSA attributes are: feature_name:0,feature_time:140532631841100,feature_id:953
*Aug 20 17:25:54.295: //953/ED35F1B18582/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))
*Aug 20 17:25:54.295: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_insert_cdb:
*Aug 20 17:25:54.295: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_timer:
Timer Start Time=283348981, Timer Value=180000(ms)
*Aug 20 17:25:54.295: htsp_process_event: [0/1/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Aug 20 17:25:54.295: fxols_wait_setup_ack:
*Aug 20 17:25:54.295: [0/1/0] nim_set_sig_state: ABCD=12, timestamp=0, sys_time=283348981
*Aug 20 17:25:54.295: [0/1/0] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Aug 20 17:25:54.295: //953/ED35F1B18582/CCAPI/cc_process_call_setup_ind:
Event=0x7FD04D9BB748
*Aug 20 17:25:54.295: //953/ED35F1B18582/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 953 with tag 999010 to app "MGCPAPP"
*Aug 20 17:25:54.295: //953/ED35F1B18582/CCAPI/ccCallSetContext:
Context=0x7FD055410A80
*Aug 20 17:25:54.295: //953/ED35F1B18582/CCAPI/ccCallSetupAck:
Call Id=953
*Aug 20 17:25:54.295: //953/ED35F1B18582/CCAPI/cc_api_set_transfer_info:
Transfer Number=, Transfer Reason=0x0
*Aug 20 17:25:54.296: //953/ED35F1B18582/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x0
*Aug 20 17:25:54.296: //953/ED35F1B18582/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Aug 20 17:25:54.296: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668883 aaln/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
N: ca@10.13.1.100:2427
X: 0
O: L/hd
<---

*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_INDICATED, event:E_CC_SETUP_ACK]
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_setup_ind_ack:
Fax Relay=TRUE, Dial Tone=FALSE, Digit Collect=FALSE, Overlap=FALSE, DID=TRUE
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=283348981
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_setup_ind_ack:
Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=1000(ms), Fax Nom=300(ms)
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_DIGIT_COLLECT, event:E_CC_CONNECT]
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_connect:
Progress Indication=0
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=283348981
*Aug 20 17:25:54.296: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=283348981
*Aug 20 17:25:54.296: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_SETUP_ACK]
*Aug 20 17:25:54.297: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Aug 20 17:25:54.297: htsp_timer_stop
*Aug 20 17:25:54.311: MGCP Packet received from 10.13.1.100:2427--->
200 300668883
<---

*Aug 20 17:25:54.317: MGCP Packet received from 10.13.1.100:2427--->
CRCX 271282 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
X: 0
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu
Q: process,loop
<---

*Aug 20 17:25:54.318: //953/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x1, Params=0x7FD054FF0FCC, Call Id=953
*Aug 20 17:25:54.318: //-1/xxxxxxxxxxxx/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x7FD04C940768, Interface Type=9, Destination=0.0.0.0, Mode=0x9,
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=)
*Aug 20 17:25:54.318: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.318: :cc_get_feature_vsa malloc success
*Aug 20 17:25:54.318: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.318: cc_get_feature_vsa count is 2
*Aug 20 17:25:54.318: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Aug 20 17:25:54.318: :FEATURE_VSA attributes are: feature_name:0,feature_time:140532631840876,feature_id:954
*Aug 20 17:25:54.318: //954/ED35F1B18582/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=9, FlowMode=1
*Aug 20 17:25:54.318: //954/ED35F1B18582/CCAPI/ccCallSetContext:
Context=0x7FD055410760
*Aug 20 17:25:54.319: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:25:54.319: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.319: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.319: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Call Entry=NULL, Call Id=-1
*Aug 20 17:25:54.320: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/cc_api_call_connected:
Interface=0x7FD04C940768, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/ccConferenceCreate:
(confID=0xFFFFFFFFFFFFFFFF, callID1=0x3BA, gcid=0-0-0-0, tag=0x0)
*Aug 20 17:25:54.320: //953/ED35F1B18582/CCAPI/ccConferenceCreate:
(confID=0xFFFFFFFFFFFFFFFF, callID2=0x3B9, gcid=ED35F1B1-A3D411E8-85829CCB-561FA989, tag=0x0)
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/ccConferenceCreate:
Conference Id=0xFFFFFFFFFFFFFFFF, Call Id1=954, Call Id2=953, Tag=0x0
*Aug 20 17:25:54.320: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.320: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.320: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.320: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:25:54.320: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.320: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/cc_api_bridge_done:
Conference Id=0x150, Source Interface=0x7FD04C940768, Source Call Id=954,
Destination Call Id=953, Disposition=0x0, Tag=0x0
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:
*Aug 20 17:25:54.320: htsp_call_bridged invoked
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_check_cb:exit@1496
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
*Aug 20 17:25:54.320: //953/ED35F1B18582/CCAPI/cc_api_bridge_done:
Conference Id=0x150, Source Interface=0x7FD050F7DBD8, Source Call Id=953,
Destination Call Id=954, Disposition=0x0, Tag=0xFFFFFFFFFFFFFFFF
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/cc_generic_bridge_done:
Conference Id=0x150, Source Interface=0x7FD050F7DBD8, Source Call Id=953,
Destination Call Id=954, Disposition=0x0, Tag=0xFFFFFFFFFFFFFFFF
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=DISABLED - MGCP Application
Primary Fax Protocol=IGNORE_FAX_RELAY, Fallback Fax Protocol=IGNORE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_tty_config:
Save TTY configuration
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
*Aug 20 17:25:54.320: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_tty_feat_param:
Set TTY feat parameters
*Aug 20 17:25:54.320: //954/ED35F1B18582/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x150, Destination Call Id=953)
*Aug 20 17:25:54.321: //953/ED35F1B18582/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x150, Destination Call Id=954)
*Aug 20 17:25:54.321: //954/ED35F1B18582/CCAPI/ccConferenceCreate:

*Aug 20 17:25:54.321: confID:0x150; callEntry1 callID1:0x3BA, type:9; callEntry2 callID2:0x3B9, type:6

*Aug 20 17:25:54.321: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_DO_CAPS_IND]
*Aug 20 17:25:54.321: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_IND
*Aug 20 17:25:54.321: //953/ED35F1B18582/CCAPI/cc_api_caps_ind:
Destination Interface=0x7FD04C940768, Destination Call Id=954, Source Call Id=953,
Caps(Codec=0x1, Fax Rate=0x1, Fax Version:=0, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*Aug 20 17:25:54.321: //953/ED35F1B18582/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))
*Aug 20 17:25:54.321: //954/ED35F1B18582/CCAPI/cc_api_caps_ind:
Destination Interface=0x7FD050F7DBD8, Destination Call Id=953, Source Call Id=954,
Caps(Codec=0x1, Fax Rate=0x2, Fax Version:=0, Vad=0x1,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*Aug 20 17:25:54.321: //954/ED35F1B18582/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))
*Aug 20 17:25:54.321: //954/ED35F1B18582/CCAPI/cc_api_caps_ack:
Destination Interface=0x7FD050F7DBD8, Destination Call Id=953, Source Call Id=954,
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=3896)
*Aug 20 17:25:54.321: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_CAPS_IND]
*Aug 20 17:25:54.321: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_CAPS_ACK
*Aug 20 17:25:54.321: //953/ED35F1B18582/CCAPI/cc_api_caps_ack:
Destination Interface=0x7FD04C940768, Destination Call Id=954, Source Call Id=953,
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=3896)
*Aug 20 17:25:54.321: //954/ED35F1B18582/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x150, Call Id1=954, Call Id2=953
*Aug 20 17:25:54.322: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_feature_notify_cb:
Feature ID=0, Feature Status=1
*Aug 20 17:25:54.322: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:
*Aug 20 17:25:54.322: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_reactivate_ringback:exit@1287
*Aug 20 17:25:54.322: //953/ED35F1B18582/CCAPI/cc_api_voice_mode_event:
Call Id=953
*Aug 20 17:25:54.322: //953/ED35F1B18582/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x7FD055410A80)
*Aug 20 17:25:54.322: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Aug 20 17:25:54.322: MGCP Packet sent to 10.13.1.100:2427--->
200 271282 OK
I: 73

v=0
o=- 115 0 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8952 RTP/AVP 0 100
a=rtpmap:100 X-NSE/8000
a=fmtp:100 200-202
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 17:25:54.324: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_ENABLE_TDM_RTCP
*Aug 20 17:25:54.345: MGCP Packet received from 10.13.1.100:2427--->
RQNT 271283 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S: G/rt
Q: process,loop
<---

*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccSetDigitTimeouts:
Initial Digit Timeout=4000(ms), Inter Digit Timeout=4000(ms)
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccSetDigitTimeouts:
Call Entry(Inter Digit Timeout=4000(ms), Initial Digit Timeout=4000(ms))
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccRestartDigitTimeoutMsec:
Digit Timeout=0, Call Id=953
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccCallReportDigits:
(callID=0x3B9, digit_event=0x1, enable=TRUE, consume=FALSE)
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=953
*Aug 20 17:25:54.345: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_report_digit_control:
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x7FD050F7DBD8, callID=0x3B9, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=4000(ms), Inter Digit Timeout=4000(ms))
*Aug 20 17:25:54.345: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_report_digit_control:
Digit Reporting=TRUE
*Aug 20 17:25:54.345: //953/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x1000, Params=0x7FD054FF1168, Call Id=953
*Aug 20 17:25:54.346: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:25:54.346: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.346: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.346: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=DISABLED - MGCP Application
Primary Fax Protocol=IGNORE_FAX_RELAY, Fallback Fax Protocol=IGNORE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:25:54.346: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:25:54.346: //953/ED35F1B18582/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Ring Back,
Tone Direction=Network, Params=0x0, Call Id=953
*Aug 20 17:25:54.346: MGCP Packet sent to 10.13.1.100:2427--->
200 271283 OK
<---

*Aug 20 17:25:54.383: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271284 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
L: p:20, a:G.729, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 17:25:54.384: //953/ED35F1B18582/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=953
*Aug 20 17:25:54.384: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:25:54.384: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x80019830, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:25:54.385: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:25:54.385: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.385: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.385: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=DISABLED - MGCP Application
Primary Fax Protocol=IGNORE_FAX_RELAY, Fallback Fax Protocol=IGNORE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:25:54.385: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:25:54.385: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.385: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.385: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:25:54.385: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.385: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.385: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.385: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:25:54.385: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.385: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:25:54.386: MGCP Packet sent to 10.13.1.100:2427--->
200 271284 OK

v=0
o=- 115 1 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8952 RTP/AVP 18
a=rtpmap:18 G.729/8000
a=fmtp:18 annexb=no
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 17:25:54.401: MGCP Packet received from 10.13.1.100:2427--->
RQNT 271285 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 17:25:54.401: //953/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x1000, Params=0x7FD054FF1168, Call Id=953
*Aug 20 17:25:54.401: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:25:54.402: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.402: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.402: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=DISABLED - MGCP Application
Primary Fax Protocol=IGNORE_FAX_RELAY, Fallback Fax Protocol=IGNORE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:25:54.402: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:25:54.402: MGCP Packet sent to 10.13.1.100:2427--->
200 271285 OK
<---

*Aug 20 17:25:54.416: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271286 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
L: p:20, a:G.729, s:off, t:b8, fxr/fx:t38
M: sendrecv
R: L/hu, D/[0-9ABCD*#], FXR/t38
S:
Q: process,loop

v=0
o=- 115 0 IN EPN AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com
s=Cisco SDP 0
t=0 0
m=audio 20642 RTP/AVP 18
c=IN IP4 10.13.1.110
a=X-sqn:0
a=X-cap:1 image udptl t38
<---

*Aug 20 17:25:54.416: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:25:54.416: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x18E30, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:25:54.417: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:25:54.417: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:25:54.417: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.417: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.417: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.417: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.417: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:25:54.418: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.418: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.418: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:25:54.418: cc_api_get_xcode_stream : 4983
*Aug 20 17:25:54.418: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.418: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:25:54.418: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:25:54.418: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:25:54.418: MGCP Packet sent to 10.13.1.100:2427--->
200 271286 OK
<---

*Aug 20 17:25:54.420: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_ENABLE_TDM_RTCP
*Aug 20 17:25:55.415: htsp_dsp_message: SEND_SIG_STATUS: state=0x6 timestamp=50616 systime=283349093
*Aug 20 17:25:55.415: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery
*Aug 20 17:25:55.415: htsp_timer_stop2
*Aug 20 17:25:58.345: //953/ED35F1B18582/CCAPI/cc_handle_inter_digit_timer:
Generate inter-digit timeout CC_EV_CALL_DIGIT_END event
*Aug 20 17:25:58.345: //953/ED35F1B18582/CCAPI/cc_handle_inter_digit_timer:
Generate inter-digit timeout CC_EV_CALL_DIGIT_END event
*Aug 20 17:26:10.348: MGCP Packet sent to 10.13.1.100:2427--->
NTFY 300668884 *@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
O:
<---

*Aug 20 17:26:10.361: MGCP Packet received from 10.13.1.100:2427--->
200 300668884
<---

*Aug 20 17:26:12.026: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271294 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 17:26:12.026: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:26:12.026: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x80000800, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:12.027: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:12.027: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:12.027: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.028: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.028: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.028: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.028: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:26:12.028: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.028: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.028: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.028: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.028: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:12.028: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:26:12.028: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:12.028: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:26:12.028: MGCP Packet sent to 10.13.1.100:2427--->
200 271294 OK

v=0
o=- 115 2 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8952 RTP/AVP 18
a=rtpmap:18 G.729/8000
a=fmtp:18 annexb=no
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 17:26:12.030: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_ENABLE_TDM_RTCP
*Aug 20 17:26:12.055: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271295 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 17:26:12.055: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:26:12.055: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x80019830, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:12.057: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:12.057: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.057: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.057: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.057: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.057: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:12.057: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:12.057: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:26:12.057: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:12.057: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:26:12.057: MGCP Packet sent to 10.13.1.100:2427--->
200 271295 OK

v=0
o=- 115 3 IN IP4 192.168.11.125
s=Cisco SDP 0
c=IN IP4 192.168.11.125
t=0 0
m=audio 8952 RTP/AVP 0
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 200-202
a=X-cap: 2 image udptl t38
<---

*Aug 20 17:26:13.119: MGCP Packet received from 10.13.1.100:2427--->
RQNT 271296 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#]
S: G/rt
Q: process,loop
<---

*Aug 20 17:26:13.119: //953/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x1000, Params=0x7FD054FF1168, Call Id=953
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:13.120: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:13.120: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:13.120: //953/ED35F1B18582/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Ring Back,
Tone Direction=Network, Params=0x0, Call Id=953
*Aug 20 17:26:13.120: MGCP Packet sent to 10.13.1.100:2427--->
200 271296 OK
<---

*Aug 20 17:26:13.518: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=3182 systime=283350904
*Aug 20 17:26:13.519: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_DSP_SIG_0100]fxols_normal_battery
*Aug 20 17:26:13.519: htsp_timer_stop2
*Aug 20 17:26:18.913: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271298 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: sendrecv
R: L/hu, D/[0-9ABCD*#], FXR/t38
S:
Q: process,loop

v=0
o=- 115 0 IN EPN AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com
s=Cisco SDP 0
t=0 0
m=audio 28108 RTP/AVP 0
c=IN IP4 192.168.11.91
a=X-sqn:0
a=X-cap:1 image udptl t38
<---

*Aug 20 17:26:18.913: //953/ED35F1B18582/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=953
*Aug 20 17:26:18.913: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:26:18.913: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x18E30, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:26:18.914: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:18.914: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:18.915: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:18.915: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:18.915: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:18.915: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:18.915: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:18.915: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:18.915: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:18.915: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:18.915: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:18.915: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:18.915: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:26:18.915: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:18.915: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:26:18.916: MGCP Packet sent to 10.13.1.100:2427--->
200 271298 OK
<---

*Aug 20 17:26:18.917: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_ENABLE_TDM_RTCP
*Aug 20 17:26:18.936: MGCP Packet received from 10.13.1.100:2427--->
RQNT 271299 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hu, D/[0-9ABCD*#], FXR/t38
S:
Q: process,loop
<---

*Aug 20 17:26:18.937: //953/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x1000, Params=0x7FD054FF1168, Call Id=953
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:18.937: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:18.937: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:18.938: MGCP Packet sent to 10.13.1.100:2427--->
200 271299 OK
<---

*Aug 20 17:26:21.131: MGCP Packet received from 10.13.1.100:2427--->
MDCX 271300 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
M: recvonly
R: L/hu, D/[0-9ABCD*#]
S:
Q: process,loop
<---

*Aug 20 17:26:21.131: //953/ED35F1B18582/CCAPI/ccCallModifyExtended:
Nominator=0x7FD054FF0058, Params=0x7FD054FF0FD0, Call Id=953
*Aug 20 17:26:21.131: //954/ED35F1B18582/CCAPI/ccCallModify:
Nominator=0x800, Params=0x7FD054FF0998, Call Id=954
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_call_mod_done_cb:
*Aug 20 17:26:21.132: //953/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:21.132: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:21.132: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.132: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.133: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.133: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.133: //954/ED35F1B18582/CCAPI/cc_api_call_modify_done:
Result=0, Interface=0x7FD04C940768, Call Id=954
*Aug 20 17:26:21.133: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.133: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.133: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.133: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.133: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:21.133: call_info mainst_callID:0x3BA, peer_callID:0x3B9, confID:0x150, spi_type:6, media_flo_thru:1,num_streams:1, swmtpmsp_present:0

*Aug 20 17:26:21.133: //954/xxxxxxxxxxxx/CCAPI/cc_api_ha_call_active_notify:

*Aug 20 17:26:21.133: stream[0]: callid:0x3BA, media_passthrough:0
*Aug 20 17:26:21.133: MGCP Packet sent to 10.13.1.100:2427--->
200 271300 OK
<---

*Aug 20 17:26:21.135: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_ENABLE_TDM_RTCP
*Aug 20 17:26:21.156: MGCP Packet received from 10.13.1.100:2427--->
DLCX 271301 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
C: A00000000152cf6c000000F5
I: 73
X: 0
S:
<---

*Aug 20 17:26:21.156: //953/ED35F1B18582/CCAPI/ccCallReportDigits:
(callID=0x3B9, digit_event=0x0, enable=FALSE, consume=FALSE)
*Aug 20 17:26:21.156: //953/ED35F1B18582/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=953
*Aug 20 17:26:21.156: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_report_digit_control:
*Aug 20 17:26:21.156: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x7FD050F7DBD8, callID=0x3B9, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)
*Aug 20 17:26:21.156: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x7FD050F7DBD8, Call Id=953
*Aug 20 17:26:21.156: //953/ED35F1B18582/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=4000(ms), Inter Digit Timeout=4000(ms))
*Aug 20 17:26:21.156: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_report_digit_control:
Digit Reporting=FALSE
*Aug 20 17:26:21.156: //954/ED35F1B18582/CCAPI/ccGetCallStatistics:
Call Stats=0x7FD0548E2DA0, Call Id=954
*Aug 20 17:26:21.156: //954/ED35F1B18582/CCAPI/ccConferenceDestroy:
Conference Id=0x150, Tag=0x0
*Aug 20 17:26:21.156: //954/ED35F1B18582/CCAPI/ccConferenceDestroy:

*Aug 20 17:26:21.156: confID:0x150; callEntry1 callID1:0x3BA, type:9; callEntry2 callID2:0x3B9, type:6

*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_fpi_event_cb:
Event=E_DSMP_FPI_DISABLE_TDM_RTCP
*Aug 20 17:26:21.157: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.157: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.157: //954/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Aug 20 17:26:21.157: cc_api_get_xcode_stream : 4983
*Aug 20 17:26:21.157: //954/ED35F1B18582/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x150, Source Interface=0x7FD04C940768, Source Call Id=954,
Destination Call Id=953, Disposition=0x0, Tag=0x0
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_bridge_status_cb:
*Aug 20 17:26:21.157: //953/ED35F1B18582/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x150, Source Interface=0x7FD050F7DBD8, Source Call Id=953,
Destination Call Id=954, Disposition=0x0, Tag=0x0
*Aug 20 17:26:21.157: //954/ED35F1B18582/CCAPI/cc_generic_bridge_done:
Conference Id=0x150, Source Interface=0x7FD050F7DBD8, Source Call Id=953,
Destination Call Id=954, Disposition=0x0, Tag=0x0
*Aug 20 17:26:21.157: //953/ED35F1B18582/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Aug 20 17:26:21.157: //953/ED35F1B18582/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Aug 20 17:26:21.157: //953/ED35F1B18582/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
*Aug 20 17:26:21.157: //954/ED35F1B18582/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Aug 20 17:26:21.157: //954/ED35F1B18582/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_DISCONNECT]
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_disconnect:
Cause Value=16
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=283351667
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_pcm_cap_conf_tone_timer_stop:
Timer Stop Time=283351667
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Relay=ENABLED
Primary Fax Protocol=T38_FAX_RELAY, Fallback Fax Protocol=NONE_FAX_RELAY
Fax Relay CM Suppression :=ENABLED, Fax Relay ANS Suppression :=DISABLED
Fax Parameters Set By=MGCP Call Type
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_save_fax_config:
Fax Version:=0, LS Red=0, HS Red=0
*Aug 20 17:26:21.157: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_set_fax_feat_param:
*Aug 20 17:26:21.157: htsp_timer_stop3
*Aug 20 17:26:21.161: //954/ED35F1B18582/CCAPI/cc_api_nw_stats:
Call Stats=0x7FD0537523F8, Call Id=954
*Aug 20 17:26:21.161: //954/ED35F1B18582/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7FD04C940768, Tag=0x0, Call Id=954,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Aug 20 17:26:21.161: //954/ED35F1B18582/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Aug 20 17:26:21.161: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Aug 20 17:26:21.161: :cc_free_feature_vsa freeing 7FD04D99A860
*Aug 20 17:26:21.161: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Aug 20 17:26:21.161: vsacount in free is 1
*Aug 20 17:26:21.161: MGCP Packet sent to 10.13.1.100:2427--->
250 271301 OK
P: PS=1336, OS=143720, PR=1021, OR=82260, PL=0, JI=0, LA=0
<---

*Aug 20 17:26:21.178: MGCP Packet received from 10.13.1.100:2427--->
RQNT 271302 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hd, H/ci
Q: process,loop
<---

*Aug 20 17:26:21.186: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
*Aug 20 17:26:21.214: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
*Aug 20 17:26:21.214: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_dsm_dsp_stats_complete:
*Aug 20 17:26:21.214: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_timer:
Timer Start Time=283351673, Timer Value=2000(ms)
*Aug 20 17:26:21.214: htsp_process_event: [0/1/0, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Aug 20 17:26:21.214: htsp_timer_stop
*Aug 20 17:26:21.214: htsp_timer_stop2
*Aug 20 17:26:21.214: htsp_timer_stop3
*Aug 20 17:26:21.214: [0/1/0] nim_set_sig_state: ABCD=4, timestamp=0, sys_time=283351673
*Aug 20 17:26:21.214: [0/1/0] set signal state = 0x4 timestamp = 0
*Aug 20 17:26:21.214: htsp_timer - 2000 msec
*Aug 20 17:26:21.214: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop:
Timer Stop Time=283351673
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=283351673
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
Coder Rate=5
*Aug 20 17:26:21.215: //953/ED35F1B18582/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle:
DMGR=0x7FD0431B9F78, VTSP CDB=0x7FD054D1A710
*Aug 20 17:26:21.219: //953/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
*Aug 20 17:26:21.219: //953/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:
[state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
*Aug 20 17:26:21.219: //953/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/act_terminate:
*Aug 20 17:26:21.219: //953/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop:
Timer Stop Time=283351674
*Aug 20 17:26:21.219: //953/ED35F1B18582/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7FD050F7DBD8, Tag=0x0, Call Id=953,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Aug 20 17:26:21.219: //953/ED35F1B18582/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Aug 20 17:26:21.219: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Aug 20 17:26:21.219: :cc_free_feature_vsa freeing 7FD04D99A940
*Aug 20 17:26:21.219: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Aug 20 17:26:21.219: vsacount in free is 0
*Aug 20 17:26:21.219: //-1/ED35F1B18582/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb:
CDB=0x7FD054D1A710
*Aug 20 17:26:21.219: MGCP Packet sent to 10.13.1.100:2427--->
400 271302 Endpt not available
<---

*Aug 20 17:26:22.244: MGCP Packet received from 10.13.1.100:2427--->
RQNT 281302 AALN/S0/SU1/0@pica-cer-gw-voz-pro.sni.peru.ibm.com MGCP 0.1
X: 0
R: L/hd, H/ci
Q: process,loop
<---

*Aug 20 17:26:22.244: MGCP Packet sent to 10.13.1.100:2427--->
400 281302 Endpt not available
<---

*Aug 20 17:26:23.214: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Aug 20 17:26:23.221: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=283351874
*Aug 20 17:26:23.221: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]


Thanks a lot!
Edson
0 Helpful

edson_guevara14
Level 1
Level 1
In response to edson_guevara14

‎08-28-2018 07:44 AM

Hi,

Did you guys were able to check the logs? please let me know if you find anything customer is still with the issue.

Regards,
Edson
0 Helpful

R0g22
Cisco Employee
Cisco Employee
In response to edson_guevara14

‎08-31-2018 05:26 AM

This looks like a fax call, can you confirm if that is true or not ? My analysis remains the same. Your Telco is initiating a disconnect. If this is a fax call there would be a couple of more logs required to see what is happening from that perspective.

edson_guevara14
Level 1
Level 1
In response to R0g22

‎09-04-2018 01:00 PM

Hello Nipun,

No this is a normal call no fax involved, thanks for the analysis i believe next step would be to contact the telco so that they can troubleshoot that.

Regards,
Edson
0 Helpful
Customers Also Viewed These Support Documents