Collect Calls Issues on E1-R2 Links

[elopesfilho]

Dear,

We are facing some issues when collect calls are placed to a Cisco Voice Gateway with a E1-R2 link. There are some disconect causes 91 that i dont know what it means. Could you help me?

Thanks!

debug vpm signal

Jan 22 16:19:14.937: htsp_process_event: [0/0/0:0(28), R2_Q421_IDLE, E_DSP_SIG_0000]

Jan 22 16:19:14.937: r2_q421_ic_seize(0/0/0:0(28)) Rx SEIZURE

Jan 22 16:19:14.937: r2_reg_start_digit_collection(0/0/0:0(28))

Jan 22 16:19:14.937: r2_q421_ic_seize(0/0/0:0(28)) Tx SEIZE ACK (with 78ms delay)vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(28)] set signal state = 0x8vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(28)] set signal state = 0xC

Jan 22 16:19:14.937: htsp_timer - 2000 msec

Jan 22 16:19:14.937: r2_reg_process_event: [0/0/0:0(28), R2_REG_IDLE, E_R2_REG_START_COLLECTION(94)]

Jan 22 16:19:14.937: r2_reg_start_collecting(0/0/0:0(28))

Jan 22 16:19:14.937: r2_reg_timer_stop(0/0/0:0(28))

Jan 22 16:19:14.937: htsp_process_event: [0/0/0:0(28), R2_Q421_IC_SEIZE, E_HTSP_SETUP_ACK]

Jan 22 16:19:14.937: r2_q421_ic_setup(0/0/0:0(28)) E_HTSP_SETUP_ACK

Jan 22 16:19:14.937: htsp_timer_stop

Jan 22 16:19:14.937: r2_reg_offhook(0/0/0:0(28))

Jan 22 16:19:14.937: r2_reg_process_event: [0/0/0:0(28), R2_REG_COLLECTING, E_R2_REG_OFFHOOK(95)]

Jan 22 16:19:14.937: r2_reg_ic_offhook(0/0/0:0(28))

Jan 22 16:19:14.937: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_IDLE R2 Got Event R2_START

Jan 22 16:19:15.313: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='9'

Jan 22 16:19:15.313: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_PRE_CALLERID R2 Got Event 9

Jan 22 16:19:15.313: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:15.413: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:15.413: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:15.413: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:15.493: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='8'

Jan 22 16:19:15.493: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 8

Jan 22 16:19:15.493: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:15.593: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:15.593: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:15.593: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:15.673: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:15.673: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 1

Jan 22 16:19:15.673: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:15.773: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:15.773: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:15.773: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:15.853: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:15.853: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 1

Jan 22 16:19:15.853: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:15.953: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:15.953: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:15.953: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.033: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='7'

Jan 22 16:19:16.033: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 7

Jan 22 16:19:16.033: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:16.133: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:16.133: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:16.133: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.213: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:16.213: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 1

Jan 22 16:19:16.213: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:16.313: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:16.313: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:16.313: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.389: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='6'

Jan 22 16:19:16.389: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 6

Jan 22 16:19:16.389: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:16.493: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:16.493: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:16.493: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.573: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='9'

Jan 22 16:19:16.573: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 9

Jan 22 16:19:16.573: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:16.669: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:16.669: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:16.669: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.749: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='3'

Jan 22 16:19:16.749: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 3

Jan 22 16:19:16.749: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:16.853: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:16.853: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:16.853: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:16.933: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='9'

Jan 22 16:19:16.933: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 9

Jan 22 16:19:16.933: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:17.029: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.029: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.029: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:17.113: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:17.113: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 1

Jan 22 16:19:17.113: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:17.213: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.213: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.213: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:17.293: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:17.293: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 1

Jan 22 16:19:17.293: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '5'

Jan 22 16:19:17.389: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.389: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.389: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:17.473: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='*'

Jan 22 16:19:17.473: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CALLERID R2 Got Event 15

Jan 22 16:19:17.473: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '1'

Jan 22 16:19:17.573: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.573: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.573: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:17.653: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='0'

Jan 22 16:19:17.653: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event 10

Jan 22 16:19:17.653: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '1'

Jan 22 16:19:17.753: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.753: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.753: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:17.833: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:17.833: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event 1

Jan 22 16:19:17.833: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '1'

Jan 22 16:19:17.933: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:17.933: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jan 22 16:19:17.933: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:18.013: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='1'

Jan 22 16:19:18.013: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event 1

Jan 22 16:19:18.013: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '1'

Jan 22 16:19:18.113: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:18.113: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jan 22 16:19:18.113: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:18.309: htsp_dialing_done(0/0/0:0(28))

Jan 22 16:19:21.013: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_TIMER

Jan 22 16:19:21.013: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '3#'

Jan 22 16:19:21.253: htsp_digit_ready_up(0/0/0:0(28)): Rx digit='8'

Jan 22 16:19:21.253: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CATEGORY R2 Got Event 8

Jan 22 16:19:21.253: Enter r2_comp_category

Jan 22 16:19:21.253:  R2 Event : 8

Jan 22 16:19:21.253:  #######R2_II8 TRUE########

Jan 22 16:19:21.253:  ####### collect_call_enable = 0

Jan 22 16:19:21.253:  ############sending B7 ##########

Jan 22 16:19:21.253: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '7'

Jan 22 16:19:21.353: htsp_digit_ready(0/0/0:0(28)): Rx digit='#'

Jan 22 16:19:21.353: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CATEGORY R2 Got Event R2_TONE_OFF

Jan 22 16:19:21.353: Enter r2_comp_category

Jan 22 16:19:21.353: r2_reg_generate_digits(0/0/0:0(28)): Tx digit '#'

Jan 22 16:19:21.593: htsp_process_event: [0/0/0:0(28), R2_Q421_IC_WAIT_ANSWER, E_DSP_SIG_1000]

Jan 22 16:19:21.593: r2_q421_ic_clr_fwd_idle(0/0/0:0(28)) Rx CLEAR FWD

Jan 22 16:19:21.593: r2_reg_channel_disconnected(0/0/0:0(28))

Jan 22 16:19:21.593: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_CATEGORY R2 Got Event R2_STOP

Jan 22 16:19:21.593: Enter r2_comp_category

Jan 22 16:19:21.593: htsp_timer - 2000 msec

Jan 22 16:19:21.597: htsp_process_event: [0/0/0:0(28), R2_Q421_IC_CLR_FWD, E_HTSP_RELEASE_REQ]

Jan 22 16:19:21.597: r2_q421_null_release(0/0/0:0(28)) E_HTSP_RELEASE_REQ

Jan 22 16:19:21.597: r2_reg_process_event: [0/0/0:0(28), R2_REG_COLLECTING, E_R2_REG_DISCONNECT(91)]

Jan 22 16:19:21.597: r2_reg_disconnect_collect(0/0/0:0(28))

Jan 22 16:19:21.597: r2_reg_timer_stop(0/0/0:0(28))

Jan 22 16:19:23.597: htsp_process_event: [0/0/0:0(28), R2_Q421_IC_CLR_FWD, E_HTSP_EVENT_TIMER]

Jan 22 16:19:23.597: htsp_timer_stop

Jan 22 16:19:23.597: r2_q421_clr_fwd_idle(0/0/0:0(28)) Tx IDLEvnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(28)] set signal state = 0x8

Jan 22 16:19:23.597: r2_reg_channel_disconnected(0/0/0:0(28))

Jan 22 16:19:23.597: r2_reg_process_event: [0/0/0:0(28), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]

Jan 22 16:19:23.597: r2_reg_disconnect_idle(0/0/0:0(28))

Jan 22 16:19:23.597: R2 Incoming Voice(0/0): DSX (E1 0/0/0:27): STATE: R2_IN_IDLE R2 Got Event R2_STOP

Jan 22 16:19:23.597: r2_reg_timer_stop(0/0/0:0(28))

[kebrenna · Accepted solution]

Hi Edson,

Can you try this hidden command on the appropriate interface and see if this helps?

 (config)#controller e1 0/0/0
 (config-controller)#cas-custom 0
 (config-ctrl-cas)#collect-call-enable

Thanks,

K

[elopesfilho]

Thanks a lot Kebrenna!!

I have already opened a TAC SR and the engineer provided this solution.

[Added Solucoes]

Hi

I have same problem. However when a incoming call match the dial-peer voip, it does not routing to CTI from UCCX. I have made the same test using a CFW to an extension number, but did not work.

Called Number: 4350 and 4352

Calling Number: 11976626266

controller E1 0/0/0
 framing NO-CRC4
 line-termination 75-ohm
 ds0-group 0 timeslots 1-15,17-31 type r2-digital r2-compelled ani
 cas-custom 0
  country brazil
  metering
  collect-call-enable
  category 2
  answer-signal group-b 1
 description ------[11-xxxxxxxxx]
!
controller E1 0/0/1
 framing NO-CRC4
 line-termination 75-ohm
 ds0-group 0 timeslots 1-15,17-31 type r2-digital r2-compelled ani
 cas-custom 0
  country brazil
  metering
  collect-call-enable
  category 2
  answer-signal group-b 1
 description ------[11-xxxxxxxxx]


GW-SP01#show logg
Syslog logging: enabled (0 messages dropped, 89 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)

No Active Message Discriminator.



No Inactive Message Discriminator.


    Console logging: level debugging, 4755 messages logged, xml disabled,
                     filtering disabled
    Monitor logging: level debugging, 470 messages logged, xml disabled,
                     filtering disabled
    Buffer logging:  level debugging, 4841 messages logged, xml disabled,
                    filtering disabled
    Exception Logging: size (8192 bytes)
    Count and timestamp logging messages: disabled
    Persistent logging: disabled

No active filter modules.

    Trap logging: level informational, 1108 message lines logged
        Logging Source-Interface:       VRF Name:
          
Log Buffer (3000000 bytes):

Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4350
   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

Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x15243F9C, Call Info(
   Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=33, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/cc_api_call_setup_ind_common:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/cc_api_call_setup_ind_common:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.413: //-1/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.413: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.413: :cc_get_feature_vsa malloc success
Oct 31 00:18:54.413: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.413:  cc_get_feature_vsa count is 5
Oct 31 00:18:54.413: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.413: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422112,feature_id:2022
Oct 31 00:18:54.413: //3323/CDE6839E9BE8/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown))
Oct 31 00:18:54.413: //3323/CDE6839E9BE8/CCAPI/cc_process_call_setup_ind:
   Event=0xAE7EB08
Oct 31 00:18:54.413: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 4350
Oct 31 00:18:54.413: //3323/CDE6839E9BE8/CCAPI/ccCallSetContext:
   Context=0x14216724
Oct 31 00:18:54.413: //3323/CDE6839E9BE8/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 3323 with tag 33 to app "_ManagedAppProcess_Default"
Oct 31 00:18:54.417: //3323/CDE6839E9BE8/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=4001, Params=0x14219054, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Destination Pattern=4..., Called Number=4350, Digit Strip=FALSE
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=, Final Destination Flag=TRUE,
   Guid=CDE6839E-7E9B-11E5-9BE8-867286A493A3, Outgoing Dial-peer=4001
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4350
   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

Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0xADD55EC, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=4001, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:18:54.421: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.421: :cc_get_feature_vsa malloc success
Oct 31 00:18:54.421: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.421:  cc_get_feature_vsa count is 6
Oct 31 00:18:54.421: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.421: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422560,feature_id:2023
Oct 31 00:18:54.421: //3324/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Oct 31 00:18:54.421: //3324/CDE6839E9BE8/CCAPI/ccCallSetContext:
   Context=0x14219004
Oct 31 00:18:54.421: //3323/CDE6839E9BE8/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=4001
Oct 31 00:18:54.421: //3324/CDE6839E9BE8/CCAPI/cc_api_call_proceeding:
   Interface=0xADD55EC, Progress Indication=NULL(0)
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/cc_api_call_disconnected:
   Cause Value=1, Interface=0xADD55EC, Call Id=3324
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
Oct 31 00:18:54.445: //3323/CDE6839E9BE8/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/ccCallSetAAA_Accounting:
   Accounting=1, Call Id=3324
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1)
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0xADD55EC, Tag=0x0, Call Id=3324,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:18:54.445: //3324/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:18:54.445: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:54.445: :cc_free_feature_vsa freeing 199877D8
Oct 31 00:18:54.445: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:54.445:  vsacount in free is 5
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=4002, Params=0x1421CDA4, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Destination Pattern=4..., Called Number=4350, Digit Strip=FALSE
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccCallSetupRequest:
   Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=, Final Destination Flag=TRUE,
   Guid=CDE6839E-7E9B-11E5-9BE8-867286A493A3, Outgoing Dial-peer=4002
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4350
   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
          
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0xADD55EC, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4350(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=4002, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:18:54.449: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.449: :cc_get_feature_vsa malloc success
Oct 31 00:18:54.449: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.449:  cc_get_feature_vsa count is 6
Oct 31 00:18:54.449: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:18:54.449: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422560,feature_id:2024
Oct 31 00:18:54.449: //3325/CDE6839E9BE8/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Oct 31 00:18:54.449: //3325/CDE6839E9BE8/CCAPI/ccCallSetContext:
   Context=0x1421CD54
Oct 31 00:18:54.449: //3323/CDE6839E9BE8/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=4002
Oct 31 00:18:54.453: //3325/CDE6839E9BE8/CCAPI/cc_api_call_proceeding:
   Interface=0xADD55EC, Progress Indication=NULL(0)
Oct 31 00:18:54.477: //3325/CDE6839E9BE8/CCAPI/cc_api_call_disconnected:
   Cause Value=1, Interface=0xADD55EC, Call Id=3325
Oct 31 00:18:54.477: //3325/CDE6839E9BE8/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
Oct 31 00:18:54.477: //3323/CDE6839E9BE8/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
Oct 31 00:18:54.477: //3325/CDE6839E9BE8/CCAPI/ccCallSetAAA_Accounting:
   Accounting=0, Call Id=3325
Oct 31 00:18:54.481: //3325/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1)
Oct 31 00:18:54.481: //3325/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:18:54.481: //3325/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0xADD55EC, Tag=0x0, Call Id=3325,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:18:54.481: //3325/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:18:54.481: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:54.481: :cc_free_feature_vsa freeing 199877D8
Oct 31 00:18:54.481: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:54.481:  vsacount in free is 5
Oct 31 00:18:54.485: //3323/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Oct 31 00:18:54.485: //3323/CDE6839E9BE8/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:18:54.485: //3323/CDE6839E9BE8/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Oct 31 00:18:55.093: //3323/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x15243F9C, Tag=0x0, Call Id=3323,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:18:55.093: //3323/CDE6839E9BE8/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:18:55.093: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:55.093: :cc_free_feature_vsa freeing 19987618
Oct 31 00:18:55.093: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:18:55.093:  vsacount in free is 4
Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4352
   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

Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x15243F9C, Call Info(
   Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=33, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/cc_api_call_setup_ind_common:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/cc_api_call_setup_ind_common:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.801: //-1/D974E9299BF2/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.801: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.801: :cc_get_feature_vsa malloc success
Oct 31 00:19:13.801: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.801:  cc_get_feature_vsa count is 5
Oct 31 00:19:13.801: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.801: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422112,feature_id:2025
Oct 31 00:19:13.801: //3326/D974E9299BF2/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown))
Oct 31 00:19:13.805: //3326/D974E9299BF2/CCAPI/cc_process_call_setup_ind:
   Event=0xAE7EB08
Oct 31 00:19:13.805: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 4352
Oct 31 00:19:13.805: //3326/D974E9299BF2/CCAPI/ccCallSetContext:
   Context=0x1421E1C4
Oct 31 00:19:13.805: //3326/D974E9299BF2/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 3326 with tag 33 to app "_ManagedAppProcess_Default"
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=4001, Params=0x142086A4, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Destination Pattern=4..., Called Number=4352, Digit Strip=FALSE
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=, Final Destination Flag=TRUE,
   Guid=D974E929-7E9B-11E5-9BF2-867286A493A3, Outgoing Dial-peer=4001
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4352
   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

Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0xADD55EC, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=4001, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:19:13.809: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.809: :cc_get_feature_vsa malloc success
Oct 31 00:19:13.809: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.809:  cc_get_feature_vsa count is 6
Oct 31 00:19:13.809: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.809: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422560,feature_id:2026
Oct 31 00:19:13.809: //3327/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Oct 31 00:19:13.809: //3327/D974E9299BF2/CCAPI/ccCallSetContext:
   Context=0x14208654
Oct 31 00:19:13.809: //3326/D974E9299BF2/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=4001
Oct 31 00:19:13.809: //3327/D974E9299BF2/CCAPI/cc_api_call_proceeding:
   Interface=0xADD55EC, Progress Indication=NULL(0)
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/cc_api_call_disconnected:
   Cause Value=1, Interface=0xADD55EC, Call Id=3327
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
Oct 31 00:19:13.873: //3326/D974E9299BF2/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/ccCallSetAAA_Accounting:
   Accounting=1, Call Id=3327
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1)
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0xADD55EC, Tag=0x0, Call Id=3327,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:19:13.873: //3327/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:19:13.873: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:13.873: :cc_free_feature_vsa freeing 199877D8
Oct 31 00:19:13.873: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:13.873:  vsacount in free is 5
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=4002, Params=0x1420ECD4, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccCheckClipClir:
   In: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccCheckClipClir:
   Out: Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Destination Pattern=4..., Called Number=4352, Digit Strip=FALSE
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccCallSetupRequest:
   Calling Number=11976626266(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=, Final Destination Flag=TRUE,
   Guid=D974E929-7E9B-11E5-9BF2-867286A493A3, Outgoing Dial-peer=4002
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=11976626266
   cisco-anitype=1
   cisco-aniplan=5
   cisco-anipi=0
   cisco-anisi=0
   dest=4352
   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

Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0xADD55EC, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=11976626266,(Calling Name=)(TON=International, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4352(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=4002, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:19:13.877: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.877: :cc_get_feature_vsa malloc success
Oct 31 00:19:13.877: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.877:  cc_get_feature_vsa count is 6
Oct 31 00:19:13.877: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Oct 31 00:19:13.877: :FEATURE_VSA attributes are: feature_name:0,feature_time:429422560,feature_id:2027
Oct 31 00:19:13.877: //3328/D974E9299BF2/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Oct 31 00:19:13.877: //3328/D974E9299BF2/CCAPI/ccCallSetContext:
   Context=0x1420EC84
Oct 31 00:19:13.877: //3326/D974E9299BF2/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=4002
Oct 31 00:19:13.877: //3328/D974E9299BF2/CCAPI/cc_api_call_proceeding:
   Interface=0xADD55EC, Progress Indication=NULL(0)
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/cc_api_call_disconnected:
   Cause Value=1, Interface=0xADD55EC, Call Id=3328
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
Oct 31 00:19:13.921: //3326/D974E9299BF2/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/ccCallSetAAA_Accounting:
   Accounting=0, Call Id=3328
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1)
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0xADD55EC, Tag=0x0, Call Id=3328,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:19:13.921: //3328/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:19:13.921: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:13.921: :cc_free_feature_vsa freeing 199877D8
Oct 31 00:19:13.921: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:13.921:  vsacount in free is 5
Oct 31 00:19:13.925: //3326/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Oct 31 00:19:13.925: //3326/D974E9299BF2/CCAPI/ccCallDisconnect:
   Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
Oct 31 00:19:13.925: //3326/D974E9299BF2/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Oct 31 00:19:14.517: //3326/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x15243F9C, Tag=0x0, Call Id=3326,
   Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Oct 31 00:19:14.517: //3326/D974E9299BF2/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Oct 31 00:19:14.517: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:14.517: :cc_free_feature_vsa freeing 19987618
Oct 31 00:19:14.517: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Oct 31 00:19:14.517:  vsacount in free is 4
Oct 31 00:32:16.417: //-1/ABEE8A4C9BFC/CCAPI/cc_api_call_setup_ind_common:
   Sub Calling(TON=International, NPI=Telex, Data=aX^FDKt^B^Tad&p, Length=2)
Oct 31 00:32:16.417: //-1/ABEE8A4C9BFC/CCAPI/cc_api_call_setup_ind_common:
   Sub Called(TON=Unknown, NPI=Unknown, Data=^Ta`^U^]^Ut^B^Tax^FD_^\, Length=116)
Oct 31 00:41:43.085: htsp_process_event: [0/0/0:0(1), R2_Q421_IDLE, E_DSP_SIG_0000]
Oct 31 00:41:43.085: r2_q421_ic_seize(0/0/0:0(1)) Rx SEIZURE
Oct 31 00:41:43.085: r2_reg_start_digit_collection(0/0/0:0(1))
Oct 31 00:41:43.085: r2_q421_ic_seize(0/0/0:0(1)) Tx SEIZE ACK (with 100ms delay)vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0xC
Oct 31 00:41:43.085: htsp_timer - 2000 msec
Oct 31 00:41:43.085: r2_reg_process_event: [0/0/0:0(1), R2_REG_IDLE, E_R2_REG_START_COLLECTION(94)]
Oct 31 00:41:43.085: r2_reg_start_collecting(0/0/0:0(1))
Oct 31 00:41:43.085: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:41:43.085: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_SEIZE, E_HTSP_SETUP_ACK]
Oct 31 00:41:43.085: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=, Called Number=, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:43.085: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_PORT; Incoming Dial-peer=1
Oct 31 00:41:43.085: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Oct 31 00:41:43.085: r2_q421_ic_setup(0/0/0:0(1)) E_HTSP_SETUP_ACK
Oct 31 00:41:43.085: htsp_timer_stop
Oct 31 00:41:43.085: r2_reg_offhook(0/0/0:0(1))
Oct 31 00:41:43.085: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_HTSP_TX_ANSWER]
Oct 31 00:41:43.085: r2_q421_ic_answer(0/0/0:0(1)) E_HTSP_CONNECT
Oct 31 00:41:43.085: r2_q421_ic_answer(0/0/0:0(1)) Tx ANSWER seizure: delay 130 ms,elapsed 0 msvnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x4
Oct 31 00:41:43.085: r2_reg_channel_connected(0/0/0:0(1))
Oct 31 00:41:43.085: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_OFFHOOK(95)]
Oct 31 00:41:43.085: r2_reg_ic_offhook(0/0/0:0(1))
Oct 31 00:41:43.085: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_START
Oct 31 00:41:43.085: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_CONNECT(90)]
Oct 31 00:41:43.313: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='4'
Oct 31 00:41:43.313: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_PRE_CALLERID R2 Got Event 4
Oct 31 00:41:43.313: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:43.413: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:43.413: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:43.413: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:43.541: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:41:43.541: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:41:43.541: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:43.653: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:43.653: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:43.653: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:43.773: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:41:43.773: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:41:43.773: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:43.877: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:43.877: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:43.877: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:43.973: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:41:43.973: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:41:43.973: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:44.065: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:44.065: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:44.065: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:44.161: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='9'
Oct 31 00:41:44.161: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 9
Oct 31 00:41:44.161: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:44.253: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:44.253: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:44.253: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:44.353: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='7'
Oct 31 00:41:44.353: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 7
Oct 31 00:41:44.353: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:44.453: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:44.453: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:44.453: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:44.573: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:41:44.573: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:41:44.573: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:44.673: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:44.673: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:44.673: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:44.773: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:41:44.773: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:41:44.773: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:44.865: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:44.865: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:44.865: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:44.961: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='2'
Oct 31 00:41:44.961: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 2
Oct 31 00:41:44.961: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:45.053: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:45.053: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:45.053: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:45.153: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:41:45.153: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:41:45.153: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:45.241: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:45.241: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:45.241: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:45.353: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='2'
Oct 31 00:41:45.353: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 2
Oct 31 00:41:45.353: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:45.453: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:45.453: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:45.453: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:45.553: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:41:45.553: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:41:45.553: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:45.653: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:45.653: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:45.653: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:45.765: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:41:45.765: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:41:45.765: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:41:45.853: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:45.853: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:41:45.853: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:45.953: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='*'
Oct 31 00:41:45.953: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 15
Oct 31 00:41:45.953: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:41:46.053: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:46.053: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:41:46.053: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:46.173: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='3'
Oct 31 00:41:46.173: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 3
Oct 31 00:41:46.173: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:41:46.273: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:46.273: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:41:46.273: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:46.373: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='5'
Oct 31 00:41:46.373: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 5
Oct 31 00:41:46.373: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:41:46.465: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:46.465: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:41:46.465: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:46.565: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='2'
Oct 31 00:41:46.565: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 2
Oct 31 00:41:46.565: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '3'
Oct 31 00:41:46.653: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:41:46.653: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CATEGORY R2 Got Event R2_TONE_OFF
Oct 31 00:41:46.653: Enter r2_comp_category
Oct 31 00:41:46.653: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:41:46.765: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:41:46.765: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CATEGORY R2 Got Event 1
Oct 31 00:41:46.765: Enter r2_comp_category
Oct 31 00:41:46.765:  R2 Event : 1
Oct 31 00:41:46.765:  ####### collect_call_enable = 0
Oct 31 00:41:46.765: ######## Not Sending B7 ##################
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4352, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:41:46.765: r2_reg_event_proc(0/0/0:0(1)) ADDR_INFO_COLLECTED (DNIS=4352, ANI=11976626266)
Oct 31 00:41:46.765: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_ADDR_COLLECTED(89)]
Oct 31 00:41:46.765: r2_reg_ic_addr_collected(0/0/0:0(1))htsp_switch_ind
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4352, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:41:46.765: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:41:46.853: htsp_dialing_done(0/0/0:0(1))
Oct 31 00:41:46.853: //-1/FFF02E9E9C06/CCAPI/cc_api_call_setup_ind_common:
   Sub Called(TON=Unknown, NPI=Unknown, Data=, Length=218)
Oct 31 00:41:46.853: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_SETUP_ACK]
Oct 31 00:41:46.853: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4352, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.853: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:41:46.853: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4352, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4352
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchSafModulePlugin:
   dialstring=4352, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4352, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4352
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchSafModulePlugin:
   dialstring=4352, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=4352, Called Number=4352, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4352
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=4352, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=4352, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=4001
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=4352, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=4001
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4352, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4352
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=4352, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:41:46.857: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4352, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:41:46.857: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4352
Oct 31 00:41:46.861: //-1/FFF02E9E9C06/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:41:46.861: //-1/FFF02E9E9C06/DPM/dpMatchSafModulePlugin:
   dialstring=4352, saf_enabled=1, saf_dndb_lookup=1, dp_result=0
Oct 31 00:41:46.861: //-1/FFF02E9E9C06/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:41:46.861: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_PROCEEDING]
Oct 31 00:41:46.945: htsp_pre_connect_disconnect, cdb = 197EA8B0 cause = 1

Oct 31 00:41:46.945: r2_reg_event_proc(0/0/0:0(1)) REJECT RECEIVED
Oct 31 00:41:46.945: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_WAIT_REMOTE_ALERT R2 Got Event R2_REJECT
Oct 31 00:41:46.945: rx R2_REJECT in r2_comp_wait_remote_alert, cause: 0x1
Oct 31 00:41:46.945: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '7#'
Oct 31 00:41:46.945: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:41:46.945: r2_reg_event_proc(0/0/0:0(1)) ABORT_DIGIT_COLLECT
Oct 31 00:41:46.945: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_R2_REG_ABORT_DIGIT_COLLECT]
Oct 31 00:41:46.945: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_PRE_CONN_DISC]
Oct 31 00:41:46.945: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_RELEASE_REQ]
Oct 31 00:41:46.945: r2_q421_ic_release(0/0/0:0(1)) E_HTSP_RELEASE_REQ
Oct 31 00:41:46.945: r2_q421_ic_release(0/0/0:0(1)) Tx FORCE RELEASEvnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x0
Oct 31 00:41:46.945: r2_reg_channel_disconnected(0/0/0:0(1))
Oct 31 00:41:46.945: htsp_timer - 200 msec
Oct 31 00:41:46.945: r2_reg_process_event: [0/0/0:0(1), R2_REG_WAIT_FOR_SWITCH, E_R2_REG_DISCONNECT(91)]
Oct 31 00:41:46.945: r2_reg_disconnect_idle(0/0/0:0(1))
Oct 31 00:41:46.945: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:41:46.945: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:41:47.145: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_HTSP_EVENT_TIMER]
Oct 31 00:41:47.145: r2_q421_ic_check_incoming_sig_status(0/0/0:0(1)) E_TIMER_EVENT
Oct 31 00:41:47.145: htsp_timer - 2000 msec
Oct 31 00:41:47.145: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_DSP_SIG_0000]
Oct 31 00:41:47.205: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_DSP_SIG_1000]
Oct 31 00:41:47.205: r2_q421_ic_clr_bwd_idle(0/0/0:0(1)) Rx IDLE
Oct 31 00:41:47.205: htsp_timer_stop
Oct 31 00:41:47.205: htsp_timer - 2000 msec
Oct 31 00:41:47.541: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_FWD, E_DSP_SIG_1100]
Oct 31 00:41:47.541: r2_q421_clr_fwd_blocked(0/0/0:0(1)) Rx BLOCK
Oct 31 00:41:47.541: htsp_timer_stop vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8
Oct 31 00:41:47.541: r2_reg_channel_disconnected(0/0/0:0(1))
Oct 31 00:41:47.541: r2_reg_process_event: [0/0/0:0(1), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]
Oct 31 00:41:47.541: r2_reg_disconnect_idle(0/0/0:0(1))
Oct 31 00:41:47.541: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:41:47.541: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:41:47.581: htsp_process_event: [0/0/0:0(1), R2_Q421_BLOCKED, E_DSP_SIG_1000]
Oct 31 00:41:47.581: r2_q421_go_idle(0/0/0:0(1)) Rx IDLE
Oct 31 00:41:47.581: r2_q421_go_idle(0/0/0:0(1)) Tx IDLE
Oct 31 00:41:47.581: htsp_timer_stop vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8
Oct 31 00:41:47.605: htsp_process_event: [0/0/0:0(1), R2_Q421_IDLE, E_DSP_SIG_1100]
Oct 31 00:41:47.605: r2_q421_blocked(0/0/0:0(1)) Rx BLOCKED
Oct 31 00:41:47.605: htsp_timer_stop
Oct 31 00:41:47.605: r2_reg_channel_disconnected(0/0/0:0(1))
Oct 31 00:41:47.605: r2_reg_process_event: [0/0/0:0(1), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]
Oct 31 00:41:47.605: r2_reg_disconnect_idle(0/0/0:0(1))
Oct 31 00:41:47.605: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:41:47.605: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:41:47.609: htsp_process_event: [0/0/0:0(1), R2_Q421_BLOCKED, E_DSP_SIG_1100]
Oct 31 00:41:47.917: htsp_process_event: [0/0/0:0(1), R2_Q421_BLOCKED, E_DSP_SIG_1000]
Oct 31 00:41:47.917: r2_q421_go_idle(0/0/0:0(1)) Rx IDLE
Oct 31 00:41:47.917: r2_q421_go_idle(0/0/0:0(1)) Tx IDLE
Oct 31 00:41:47.917: htsp_timer_stop vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8
Oct 31 00:42:06.757: htsp_process_event: [0/0/0:0(1), R2_Q421_IDLE, E_DSP_SIG_0000]
Oct 31 00:42:06.757: r2_q421_ic_seize(0/0/0:0(1)) Rx SEIZURE
Oct 31 00:42:06.757: r2_reg_start_digit_collection(0/0/0:0(1))
Oct 31 00:42:06.757: r2_q421_ic_seize(0/0/0:0(1)) Tx SEIZE ACK (with 100ms delay)vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0xC
Oct 31 00:42:06.757: htsp_timer - 2000 msec
Oct 31 00:42:06.761: r2_reg_process_event: [0/0/0:0(1), R2_REG_IDLE, E_R2_REG_START_COLLECTION(94)]
Oct 31 00:42:06.761: r2_reg_start_collecting(0/0/0:0(1))
Oct 31 00:42:06.761: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:42:06.761: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_SEIZE, E_HTSP_SETUP_ACK]
Oct 31 00:42:06.761: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=, Called Number=, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:06.761: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_PORT; Incoming Dial-peer=1
Oct 31 00:42:06.761: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:06.761: r2_q421_ic_setup(0/0/0:0(1)) E_HTSP_SETUP_ACK
Oct 31 00:42:06.761: htsp_timer_stop
Oct 31 00:42:06.761: r2_reg_offhook(0/0/0:0(1))
Oct 31 00:42:06.761: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_HTSP_TX_ANSWER]
Oct 31 00:42:06.761: r2_q421_ic_answer(0/0/0:0(1)) E_HTSP_CONNECT
Oct 31 00:42:06.761: r2_q421_ic_answer(0/0/0:0(1)) Tx ANSWER seizure: delay 126 ms,elapsed 4 msvnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x4
Oct 31 00:42:06.761: r2_reg_channel_connected(0/0/0:0(1))
Oct 31 00:42:06.761: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_OFFHOOK(95)]
Oct 31 00:42:06.761: r2_reg_ic_offhook(0/0/0:0(1))
Oct 31 00:42:06.761: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_START
Oct 31 00:42:06.761: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_CONNECT(90)]
Oct 31 00:42:06.997: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='4'
Oct 31 00:42:06.997: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_PRE_CALLERID R2 Got Event 4
Oct 31 00:42:06.997: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:07.109: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:07.109: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:07.109: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:07.229: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:42:07.229: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:42:07.229: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:07.329: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:07.329: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:07.329: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:07.449: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:42:07.449: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:42:07.449: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:07.549: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:07.549: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:07.549: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:07.645: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:42:07.645: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 1
Oct 31 00:42:07.645: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:07.749: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:07.749: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:07.749: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:07.857: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='9'
Oct 31 00:42:07.857: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 9
Oct 31 00:42:07.857: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:07.969: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:07.969: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:07.969: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:08.077: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='7'
Oct 31 00:42:08.077: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 7
Oct 31 00:42:08.077: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:08.177: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:08.177: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:08.177: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:08.285: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:42:08.285: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:42:08.285: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:08.377: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:08.377: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:08.377: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:08.477: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:42:08.477: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:42:08.477: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:08.577: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:08.577: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:08.577: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:08.685: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='2'
Oct 31 00:42:08.685: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 2
Oct 31 00:42:08.685: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:08.777: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:08.777: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:08.777: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:08.877: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:42:08.877: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:42:08.877: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:08.977: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:08.977: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:08.977: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:09.089: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='2'
Oct 31 00:42:09.089: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 2
Oct 31 00:42:09.089: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:09.185: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:09.185: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:09.185: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:09.297: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:42:09.297: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:42:09.297: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:09.405: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:09.405: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:09.405: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:09.517: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='6'
Oct 31 00:42:09.517: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 6
Oct 31 00:42:09.517: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '5'
Oct 31 00:42:09.617: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:09.617: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF
Oct 31 00:42:09.617: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:09.729: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='*'
Oct 31 00:42:09.729: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CALLERID R2 Got Event 15
Oct 31 00:42:09.729: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:42:09.817: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:09.817: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:42:09.817: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:09.929: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='3'
Oct 31 00:42:09.929: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 3
Oct 31 00:42:09.929: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:42:10.029: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:10.029: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:42:10.029: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:10.149: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='5'
Oct 31 00:42:10.149: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 5
Oct 31 00:42:10.149: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '1'
Oct 31 00:42:10.257: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:10.257: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF
Oct 31 00:42:10.257: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:10.377: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='0'
Oct 31 00:42:10.377: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 10
Oct 31 00:42:10.377: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '3'
Oct 31 00:42:10.477: htsp_digit_ready(0/0/0:0(1)): Rx digit='#'
Oct 31 00:42:10.477: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CATEGORY R2 Got Event R2_TONE_OFF
Oct 31 00:42:10.477: Enter r2_comp_category
Oct 31 00:42:10.477: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '#'
Oct 31 00:42:10.577: htsp_digit_ready_up(0/0/0:0(1)): Rx digit='1'
Oct 31 00:42:10.577: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_CATEGORY R2 Got Event 1
Oct 31 00:42:10.577: Enter r2_comp_category
Oct 31 00:42:10.577:  R2 Event : 1
Oct 31 00:42:10.577:  ####### collect_call_enable = 0
Oct 31 00:42:10.577: ######## Not Sending B7 ##################
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4350, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:10.577: r2_reg_event_proc(0/0/0:0(1)) ADDR_INFO_COLLECTED (DNIS=4350, ANI=11976626266)
Oct 31 00:42:10.577: r2_reg_process_event: [0/0/0:0(1), R2_REG_COLLECTING, E_R2_REG_ADDR_COLLECTED(89)]
Oct 31 00:42:10.577: r2_reg_ic_addr_collected(0/0/0:0(1))htsp_switch_ind
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4350, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:42:10.577: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:10.677: htsp_dialing_done(0/0/0:0(1))
Oct 31 00:42:10.677: //-1/0E2375899C10/CCAPI/cc_api_call_setup_ind_common:
   Sub Called(TON=Unknown, NPI=Unknown, Data=, Length=218)
Oct 31 00:42:10.677: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_SETUP_ACK]
Oct 31 00:42:10.677: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=11976626266, Called Number=4350, Voice-Interface=0x15243F9C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.677: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=33
Oct 31 00:42:10.677: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4350, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4350
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchSafModulePlugin:
   dialstring=4350, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4350, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4350
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchSafModulePlugin:
   dialstring=4350, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:42:10.681: //-1/0E2375899C10/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=4350, Called Number=4350, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4350
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=4350, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=4350, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=4001
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=4350, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=4001
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4350, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4350
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=4350, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Oct 31 00:42:10.681: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:42:10.685: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=4350, Peer Info Type=DIALPEER_INFO_SPEECH
Oct 31 00:42:10.685: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=4350
Oct 31 00:42:10.685: //-1/0E2375899C10/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Oct 31 00:42:10.685: //-1/0E2375899C10/DPM/dpMatchSafModulePlugin:
   dialstring=4350, saf_enabled=1, saf_dndb_lookup=1, dp_result=0
Oct 31 00:42:10.685: //-1/0E2375899C10/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=4001
     2: Dial-peer Tag=4002
Oct 31 00:42:10.685: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_PROCEEDING]
Oct 31 00:42:10.741: htsp_pre_connect_disconnect, cdb = 197EB150 cause = 1

Oct 31 00:42:10.741: r2_reg_event_proc(0/0/0:0(1)) REJECT RECEIVED
Oct 31 00:42:10.741: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_WAIT_REMOTE_ALERT R2 Got Event R2_REJECT
Oct 31 00:42:10.741: rx R2_REJECT in r2_comp_wait_remote_alert, cause: 0x1
Oct 31 00:42:10.741: r2_reg_generate_digits(0/0/0:0(1)): Tx digit '7#'
Oct 31 00:42:10.741: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:42:10.741: r2_reg_event_proc(0/0/0:0(1)) ABORT_DIGIT_COLLECT
Oct 31 00:42:10.741: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_R2_REG_ABORT_DIGIT_COLLECT]
Oct 31 00:42:10.741: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_PRE_CONN_DISC]
Oct 31 00:42:10.741: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_RELEASE_REQ]
Oct 31 00:42:10.741: r2_q421_ic_release(0/0/0:0(1)) E_HTSP_RELEASE_REQ
Oct 31 00:42:10.741: r2_q421_ic_release(0/0/0:0(1)) Tx FORCE RELEASEvnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x0
Oct 31 00:42:10.741: r2_reg_channel_disconnected(0/0/0:0(1))
Oct 31 00:42:10.741: htsp_timer - 200 msec
Oct 31 00:42:10.741: r2_reg_process_event: [0/0/0:0(1), R2_REG_WAIT_FOR_SWITCH, E_R2_REG_DISCONNECT(91)]
Oct 31 00:42:10.741: r2_reg_disconnect_idle(0/0/0:0(1))
Oct 31 00:42:10.741: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:42:10.741: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:42:10.941: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_HTSP_EVENT_TIMER]
Oct 31 00:42:10.941: r2_q421_ic_check_incoming_sig_status(0/0/0:0(1)) E_TIMER_EVENT
Oct 31 00:42:10.941: htsp_timer - 2000 msec
Oct 31 00:42:10.941: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_DSP_SIG_0000]
Oct 31 00:42:11.005: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_BWD, E_DSP_SIG_1000]
Oct 31 00:42:11.005: r2_q421_ic_clr_bwd_idle(0/0/0:0(1)) Rx IDLE
Oct 31 00:42:11.005: htsp_timer_stop
Oct 31 00:42:11.005: htsp_timer - 2000 msec
Oct 31 00:42:11.345: htsp_process_event: [0/0/0:0(1), R2_Q421_IC_CLR_FWD, E_DSP_SIG_1100]
Oct 31 00:42:11.345: r2_q421_clr_fwd_blocked(0/0/0:0(1)) Rx BLOCK
Oct 31 00:42:11.345: htsp_timer_stop vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8
Oct 31 00:42:11.345: r2_reg_channel_disconnected(0/0/0:0(1))
Oct 31 00:42:11.345: r2_reg_process_event: [0/0/0:0(1), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]
Oct 31 00:42:11.345: r2_reg_disconnect_idle(0/0/0:0(1))
Oct 31 00:42:11.345: R2 Incoming Voice(0/0): DSX (E1 0/0/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP
Oct 31 00:42:11.345: r2_reg_timer_stop(0/0/0:0(1))
Oct 31 00:42:11.381: htsp_process_event: [0/0/0:0(1), R2_Q421_BLOCKED, E_DSP_SIG_1000]
Oct 31 00:42:11.381: r2_q421_go_idle(0/0/0:0(1)) Rx IDLE
Oct 31 00:42:11.381: r2_q421_go_idle(0/0/0:0(1)) Tx IDLE
Oct 31 00:42:11.381: htsp_timer_stop vnm_dsp_set_sig_state:[R2 Q.421 0/0/0:0(1)] set signal state = 0x8

[Leonardo Santana]

By default the double-answer is disable just to ensure check if he is disable and follow the instructions of Kebrenna.

Thanks

[Marcos Cardoso]

Hi Edson,

I'd like to know how you solved this issue, because I got the same situation and did the instruction related here, but I´m still not able to making call through the PSTN.

Could you help me?

Thanks

Marcos Cardoso

[elopesfilho]

Hi Marcos,

I have solved this issue by applying following commands on E1 controller:

 (config)#controller e1 0/0/0
 (config-controller)#cas-custom 0
 (config-ctrl-cas)#collect-call-enable > This is a Hidden Command! 

[W S H FERNANDO]

Hi Edson

I'm facing the same issue, I tried to apply this command under cas-custm 0, but this command is not available. Please guide me how to issue this command. (collect-call-enable     is not available)

Regds

$

[Leonardo Santana]

Hello Fernando

The double-answer is enabled?

Regards

Leonardo Santana

[Marcos Eusebio]

I had this issue, and due to the VPM debug also showed the message "R2_REG_IDLE, E_R2_REG_DISCONNECT(91)" solved it adding two commands under the voice-port interface (in my case):

voice-port 0/1/0:0
no vad  <--- To disable the the voice activity detection
cptone MX <--- to set the tone frequency used in my country