Can not view Caller ID

[hugomdbaez]

Hello to all ,

I have a publisher, Subscriber recently added both have 7.1.5.30000-1 version. In the new building I have a Cisco 3925, what is happening is that when making a call from outside can not see who perform, does not display the caller ID

[paolo bevilacqua]

Please give full details about the configuration, phone lines type, protocols, etc.

[hugomdbaez]

router#sh call active voice br

: ms. () + pid:

  dur hh:mm:ss tx:/ rx:/

IP : rtt:ms pl:/ms lost://

  delay://ms

media inactive detected: media cntrl rcvd: timestamp:

long duration call detected: long duration call duration : timestamp:

  MODEMPASS buf:/ loss /

   last s dur:/s

FR [int dlci cid] vad: dtmf: seq:

  (payload size)

ATM [int vpi/vci cid] vad: dtmf: seq:

  (payload size)

Tele (callID) [channel_id] tx://ms noise: acom: i/o:/ dBm

  MODEMRELAY info:// xid:/ total://

         speeds(bps): local / remote /

Proxy :

bw: / codec:

  tx:

rx:

Telephony call-legs: 1

SIP call-legs: 0

H323 call-legs: 1

Call agent controlled call-legs: 0

SCCP call-legs: 0

Multicast call-legs: 0

Total call-legs: 2

13E4 : 262 687516410ms.1 (09:47:53.748 BUE Fri Jun 1 2012) +-1 pid:1 Answer 1163974628 connected

dur 00:00:00 tx:0/0 rx:0/0

Tele 0/1/0:0 (262) [0/1/0.1] tx:0/0/0ms None noise:0 acom:0  i/0:0/0 dBm

13E4 : 263 687516410ms.2 (09:47:53.748 BUE Fri Jun 1 2012) +-1 pid:500 Originate 4460 connecting

dur 00:00:00 tx:0/0 rx:0/0

IP 0.0.0.0:0 SRTP: off rtt:0ms pl:0/0ms lost:0/0/0 delay:0/0/0ms g729r8 pre-ietf TextRelay: off

media inactive detected:n media contrl rcvd:n/a timestamp:n/a

long duration call detected:n long duration call duration:n/a timestamp:n/a

Telephony call-legs: 1

SIP call-legs: 0

H323 call-legs: 1

Call agent controlled call-legs: 0

SCCP call-legs: 0

Multicast call-legs: 0

Total call-legs: 2

[hugomdbaez]

The messagge is FROM UNKNOWN NUMBER ; but if I called to the number 5299 4460 ( INT 4460 ) via my CELL

1163974628 and I was see the caller ID ( please refer to the output )

[paolo bevilacqua]

Sometime telco doesn't deliver caller ID. You can check "debug isdn q931" with "term mon".

[hugomdbaez]

Paolo , i have E1 R2 , what`s the correct debug ?

!

controller E1 0/1/0

framing NO-CRC4

ds0-group 0 timeslots 1-15,17-31 type r2-digital r2-compelled ani

cas-custom 0

  country argentina

description Enlace PSTN XXXX XXXX

!

[paolo bevilacqua]

No, for E1 R2 use 'debug vpm signal'.

[hugomdbaez]

router#debug vpm s

Jun  1 15:08:17.519 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:2417340416 1500 bytes is out-of-order; expected seq:2417310008. Reason: TCP reassembly queue overflow - session 10.170.0.250:50644 to 204.2.222.17:80ignal

Voice Port Module signaling debugging is enabled

pcolon-router#sh debug

Voice Port Module signaling debugging is on

outer#

Jun  1 15:08:27.903 BUE: htsp_process_event: [0/1/0:0(2), R2_Q421_OG_ANSWER, E_DSP_SIG_1100]

Jun  1 15:08:27.903 BUE: r2_q421_ic_clr_bwd(0/1/0:0(2)) Rx CLEAR BWD

Jun  1 15:08:27.903 BUE: htsp_timer - 7000 msec

Jun  1 15:08:29.371 BUE: htsp_timer_stop3

Jun  1 15:08:29.387 BUE: htsp_process_event: [0/1/0:0(2), R2_Q421_OG_CLR_BWD, E_HTSP_RELEASE_REQ]

Jun  1 15:08:29.387 BUE: r2_q421_null_release(0/1/0:0(2)) E_HTSP_RELEASE_REQ

Jun  1 15:08:29.407 BUE: htsp_process_event: [0/1/0:0(2), R2_Q421_OG_CLR_BWD, E_DSP_SIG_1000]

Jun  1 15:08:29.407 BUE: r2_q421_clr_bwd_idle(0/1/0:0(2)) Rx IDLE

Jun  1 15:08:29.407 BUE: htsp_timer_stop

Jun  1 15:08:29.407 BUE: r2_q421_clr_bwd_idle(0/1/0:0(2)) Tx IDLEvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(2)] set signal state = 0x8

Jun  1 15:08:29.407 BUE: r2_reg_channel_disconnected(0/1/0:0(2))

Jun  1 15:08:29.407 BUE: r2_reg_process_event: [0/1/0:0(2), R2_REG_CONNECTED, E_R2_REG_DISCONNECT(91)]

Jun  1 15:08:29.407 BUE: r2_reg_disconnect_idle(0/1/0:0(2))

Jun  1 15:08:29.407 BUE: r2_reg_timer_stop(0/1/0:0(2))

Jun  1 15:08:50.043 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:1186044640 211 bytes is out-of-order; expected seq:1186025975. Reason: TCP reassembly queue overflow - session 10.170.0.250:62345 to 65.55.69.140:80

Jun  1 15:09:04.487 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:2418840814 1500 bytes is out-of-order; expected seq:2418821990. Reason: TCP reassembly queue overflow - session 10.170.0.250:54341 to 65.55.69.140:80

Jun  1 15:09:17.139 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:2054942754 1420 bytes is out-of-order; expected seq:2054919498. Reason: TCP reassembly queue overflow - session 10.170.0.250:51804 to 210.173.215.16:80

Jun  1 15:09:29.119 BUE: htsp_timer_stop3

Jun  1 15:09:29.135 BUE: htsp_process_event: [0/1/0:0(13), R2_Q421_OG_ANSWER, E_HTSP_RELEASE_REQ]

Jun  1 15:09:29.135 BUE: r2_q421_clr_fwd(0/1/0:0(13)) E_HTSP_RELEASE_REQ

Jun  1 15:09:29.135 BUE: r2_reg_channel_disconnected(0/1/0:0(13))

Jun  1 15:09:29.135 BUE: r2_q421_clr_fwd(0/1/0:0(13)) Tx CLEAR FWDvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(13)] set signal state = 0x8

Jun  1 15:09:29.135 BUE: htsp_timer - 1000 msec

Jun  1 15:09:29.135 BUE: r2_reg_process_event: [0/1/0:0(13), R2_REG_CONNECTED, E_R2_REG_DISCONNECT(91)]

Jun  1 15:09:29.135 BUE: r2_reg_disconnect_idle(0/1/0:0(13))

Jun  1 15:09:29.135 BUE: r2_reg_timer_stop(0/1/0:0(13))

Jun  1 15:09:29.195 BUE: htsp_process_event: [0/1/0:0(13), R2_Q421_OG_CLR_FWD, E_DSP_SIG_1000]

Jun  1 15:09:29.195 BUE: r2_q421_clr_fwd_idle(0/1/0:0(13)) Rx IDLE

Jun  1 15:09:29.195 BUE: htsp_timer_stop

Jun  1 15:09:29.195 BUE: r2_q421_clr_fwd_idle(0/1/0:0(13)) Tx IDLEvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(13)] set signal state = 0x8

Jun  1 15:09:29.195 BUE: r2_reg_channel_disconnected(0/1/0:0(13))

Jun  1 15:09:29.195 BUE: r2_reg_process_event: [0/1/0:0(13), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]

Jun  1 15:09:29.195 BUE: r2_reg_disconnect_idle(0/1/0:0(13))

Jun  1 15:09:29.195 BUE: r2_reg_timer_stop(0/1/0:0(13))

Jun  1 15:09:41.483 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IDLE, E_DSP_SIG_0000]

Jun  1 15:09:41.483 BUE: r2_q421_ic_seize(0/1/0:0(1)) Rx SEIZURE

Jun  1 15:09:41.483 BUE: r2_reg_start_digit_collection(0/1/0:0(1))

Jun  1 15:09:41.483 BUE: r2_q421_ic_seize(0/1/0:0(1)) Tx SEIZE ACK (with 100ms delay)vnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0x8vnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0xC

Jun  1 15:09:41.483 BUE: htsp_timer - 2000 msec

Jun  1 15:09:41.483 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_IDLE, E_R2_REG_START_COLLECTION(94)]

Jun  1 15:09:41.483 BUE: r2_reg_start_collecting(0/1/0:0(1))

Jun  1 15:09:41.483 BUE: r2_reg_timer_stop(0/1/0:0(1))

Jun  1 15:09:41.483 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_SEIZE, E_HTSP_SETUP_ACK]

Jun  1 15:09:41.483 BUE: r2_q421_ic_setup(0/1/0:0(1)) E_HTSP_SETUP_ACK

Jun  1 15:09:41.483 BUE: htsp_timer_stop

Jun  1 15:09:41.483 BUE: r2_reg_offhook(0/1/0:0(1))

Jun  1 15:09:41.483 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_COLLECTING, E_R2_REG_OFFHOOK(95)]

Jun  1 15:09:41.483 BUE: r2_reg_ic_offhook(0/1/0:0(1))

Jun  1 15:09:41.483 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_IDLE R2 Got Event R2_START

Jun  1 15:09:41.639 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='4'

Jun  1 15:09:41.639 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_PRE_CALLERID R2 Got Event 4

Jun  1 15:09:41.639 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:41.751 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:41.751 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:41.751 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:41.859 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='1'

Jun  1 15:09:41.859 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 1

Jun  1 15:09:41.859 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:41.971 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:41.971 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:41.971 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:42.079 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='1'

Jun  1 15:09:42.079 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 1

Jun  1 15:09:42.079 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:42.187 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:42.187 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:42.187 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:42.299 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='1'

Jun  1 15:09:42.299 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 1

Jun  1 15:09:42.299 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:42.407 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:42.407 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:42.407 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:42.519 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='6'

Jun  1 15:09:42.519 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 6

Jun  1 15:09:42.519 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:42.631 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:42.631 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:42.631 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:42.739 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='3'

Jun  1 15:09:42.739 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 3

Jun  1 15:09:42.739 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:42.851 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:42.851 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:42.851 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:42.959 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='9'

Jun  1 15:09:42.959 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 9

Jun  1 15:09:42.959 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:43.071 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:43.071 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:43.071 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:43.179 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='7'

Jun  1 15:09:43.179 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 7

Jun  1 15:09:43.179 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:43.287 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:43.287 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:43.287 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:43.399 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='2'

Jun  1 15:09:43.399 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 2

Jun  1 15:09:43.399 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:43.507 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:43.507 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:43.507 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:43.619 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='6'

Jun  1 15:09:43.619 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 6

Jun  1 15:09:43.619 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:43.731 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:43.731 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:43.731 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:43.839 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='5'

Jun  1 15:09:43.839 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 5

Jun  1 15:09:43.839 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:43.951 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:43.951 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:43.951 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:44.059 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='0'

Jun  1 15:09:44.059 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 10

Jun  1 15:09:44.059 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '5'

Jun  1 15:09:44.171 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:44.171 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event R2_TONE_OFF

Jun  1 15:09:44.171 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:44.279 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='*'

Jun  1 15:09:44.279 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CALLERID R2 Got Event 15

Jun  1 15:09:44.279 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '1'

Jun  1 15:09:44.387 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:44.387 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jun  1 15:09:44.387 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:44.499 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='4'

Jun  1 15:09:44.499 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 4

Jun  1 15:09:44.499 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '1'

Jun  1 15:09:44.607 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:44.607 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jun  1 15:09:44.607 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:44.719 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='6'

Jun  1 15:09:44.719 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 6

Jun  1 15:09:44.719 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '1'

Jun  1 15:09:44.827 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:44.827 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jun  1 15:09:44.827 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:44.939 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='0'

Jun  1 15:09:44.939 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 10

Jun  1 15:09:44.939 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '1'

Jun  1 15:09:45.051 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:45.051 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event R2_TONE_OFF

Jun  1 15:09:45.051 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:45.159 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='*'

Jun  1 15:09:45.159 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COLLECT_DNIS R2 Got Event 15

Jun  1 15:09:45.159 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '3'

Jun  1 15:09:45.271 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:45.271 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CATEGORY R2 Got Event R2_TONE_OFF

Jun  1 15:09:45.271 BUE: Enter r2_comp_category

Jun  1 15:09:45.271 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:45.379 BUE: htsp_digit_ready_up(0/1/0:0(1)): Rx digit='1'

Jun  1 15:09:45.379 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_CATEGORY R2 Got Event 1

Jun  1 15:09:45.379 BUE: Enter r2_comp_category

Jun  1 15:09:45.379 BUE:  R2 Event : 1

Jun  1 15:09:45.379 BUE:  ####### collect_call_enable = 0

Jun  1 15:09:45.379 BUE: ######## Not Sending B7 ##################

Jun  1 15:09:45.379 BUE: r2_reg_event_proc(0/1/0:0(1)) ADDR_INFO_COLLECTED (DNIS=4460, ANI=1163972650)

Jun  1 15:09:45.379 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_COLLECTING, E_R2_REG_ADDR_COLLECTED(89)]

Jun  1 15:09:45.379 BUE: r2_reg_ic_addr_collected(0/1/0:0(1))htsp_switch_ind

Jun  1 15:09:45.471 BUE: htsp_dialing_done(0/1/0:0(1))

Jun  1 15:09:45.471 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_HTSP_SETUP_ACK]

Jun  1 15:09:45.471 BUE: r2_q421_ic_setup_ack(0/1/0:0(1)) E_HTSP_SETUP_ACK

Jun  1 15:09:45.471 BUE: r2_reg_switch(0/1/0:0(1))

Jun  1 15:09:45.471 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_WAIT_FOR_SWITCH, E_R2_REG_SWITCH(96)]

Jun  1 15:09:45.471 BUE: r2_reg_ic_switched(0/1/0:0(1))

Jun  1 15:09:45.471 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_HTSP_PROCEEDING]

Jun  1 15:09:45.475 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_DSP_SIG_0000]htsp_alert_notify

Jun  1 15:09:45.479 BUE: r2_reg_event_proc(0/1/0:0(1)) ALERTING RECEIVED

Jun  1 15:09:45.479 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_WAIT_REMOTE_ALERT R2 Got Event R2_ALERTING

Jun  1 15:09:45.479 BUE: rx R2_ALERTING in r2_comp_wait_remote_alert

Jun  1 15:09:45.479 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '6'

Jun  1 15:09:45.587 BUE: htsp_digit_ready(0/1/0:0(1)): Rx digit='#'

Jun  1 15:09:45.587 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_COMPLETE R2 Got Event R2_TONE_OFF

Jun  1 15:09:45.587 BUE: r2_reg_generate_digits(0/1/0:0(1)): Tx digit '#'

Jun  1 15:09:45.787 BUE: htsp_dialing_done(0/1/0:0(1))

Jun  1 15:09:46.587 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_WAIT_GUARD R2 Got Event R2_TONE_TIMER

Jun  1 15:09:46.587 BUE: R2_IN_CONNECT: call end dial

Jun  1 15:09:46.587 BUE: r2_reg_end_dial(0/1/0:0(1))htsp_call_service_msghtsp_call_service_msg not EFXS (11)

Jun  1 15:09:54.827 BUE: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (11)

Jun  1 15:09:54.827 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_WAIT_ANSWER, E_HTSP_CONNECT]

Jun  1 15:09:54.827 BUE: r2_q421_ic_answer(0/1/0:0(1)) E_HTSP_CONNECT

Jun  1 15:09:54.827 BUE: r2_q421_ic_answer(0/1/0:0(1)) Tx ANSWER seizure: delay 0 ms,elapsed 13344 msvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0x4

Jun  1 15:09:54.831 BUE: r2_reg_channel_connected(0/1/0:0(1))

Jun  1 15:09:54.831 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_VOICE_CUT_THROUGH]

Jun  1 15:09:54.831 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_WAIT_FOR_CONNECT, E_R2_REG_CONNECT(90)]

Jun  1 15:09:54.831 BUE: r2_reg_connect(0/1/0:0(1))

Jun  1 15:10:04.183 BUE: htsp_timer_stop3

Jun  1 15:10:04.203 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_ANSWER, E_HTSP_RELEASE_REQ]

Jun  1 15:10:04.203 BUE: r2_q421_ic_release(0/1/0:0(1)) E_HTSP_RELEASE_REQ

Jun  1 15:10:04.203 BUE: r2_q421_ic_release(0/1/0:0(1)) Tx CLEAR BWDvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0xC

Jun  1 15:10:04.203 BUE: r2_reg_channel_disconnected(0/1/0:0(1))

Jun  1 15:10:04.203 BUE: htsp_timer - 200 msec

Jun  1 15:10:04.203 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_CONNECTED, E_R2_REG_DISCONNECT(91)]

Jun  1 15:10:04.203 BUE: r2_reg_disconnect_idle(0/1/0:0(1))

Jun  1 15:10:04.203 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP

Jun  1 15:10:04.203 BUE: r2_reg_timer_stop(0/1/0:0(1))

Jun  1 15:10:04.339 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_CLR_BWD, E_DSP_SIG_1000]

Jun  1 15:10:04.339 BUE: r2_q421_ic_clr_bwd_idle(0/1/0:0(1)) Rx IDLE

Jun  1 15:10:04.339 BUE: htsp_timer_stop

Jun  1 15:10:04.339 BUE: htsp_timer - 2000 msec

Jun  1 15:10:06.339 BUE: htsp_process_event: [0/1/0:0(1), R2_Q421_IC_CLR_FWD, E_HTSP_EVENT_TIMER]

Jun  1 15:10:06.339 BUE: htsp_timer_stop

Jun  1 15:10:06.339 BUE: r2_q421_clr_fwd_idle(0/1/0:0(1)) Tx IDLEvnm_dsp_set_sig_state:[R2 Q.421 0/1/0:0(1)] set signal state = 0x8

Jun  1 15:10:06.339 BUE: r2_reg_channel_disconnected(0/1/0:0(1))

Jun  1 15:10:06.339 BUE: r2_reg_process_event: [0/1/0:0(1), R2_REG_IDLE, E_R2_REG_DISCONNECT(91)]

Jun  1 15:10:06.339 BUE: r2_reg_disconnect_idle(0/1/0:0(1))

Jun  1 15:10:06.339 BUE: R2 Incoming Voice(0/0): DSX (E1 0/1/0:0): STATE: R2_IN_IDLE R2 Got Event R2_STOP

Jun  1 15:10:06.339 BUE: r2_reg_timer_stop(0/1/0:0(1))

pcolon-router#

pcolon-router#undl  

Jun  1 15:10:12.579 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:1188616282 1500 bytes is out-of-order; expected seq:1188590002. Reason: TCP reassembly queue overflow - session 10.170.0.250:52869 to 200.42.93.137:80

Jun  1 15:10:15.447 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:3173290892 1500 bytes is out-of-order; expected seq:3173263380. Reason: TCP reassembly queue overflow - session 10.170.0.250:53829 to 69.171.247.69:80und all

                 ^

% Invalid input detected at '^' marker.

router#

Jun  1 15:10:17.271 BUE: %FW-4-TCP_OoO_SEG: Dropping TCP Segment: seq:1582770122 1500 bytes is out-of-order; expected seq:1582736542. Reason: TCP reassembly queue overflow - session 10.170.0.250:62582 to 200.42.93.137:80und all

All possible debugging has been turned off

router#term no mon

[paolo bevilacqua]

You can look at 'Rx digit' to see if telco is sending calling number.

To eliminate 'dropping tcp segment' message, configure 'no ip virtual-reassembly' on all interfaces.

[hugomdbaez]

Hello Paolo ,

when I type

sh call active voice

I can see the Caller ID , I guess that is because the telco is sending OK the caller ID .

What can be the problem in this case ?

Thanks and best regards .

Hugo