Step 8 
Use the show debug command to display call traces enabled during a second call attempt.
Use the show debug command to display call traces enabled during a second call attempt. Router# show debug
CSM Voice:
Voice Call Switching Module debugging is on
The following ISDN debugs are enabled on all DSLs:
debug isdn error is ON.
debug isdn q931 is ON. (filter is OFF)
Router#
Aug 19 02:05:36.349: ISDN Se0:23 Q931: RX <- SETUP pd = 8 callref = 0x0237
Bearer Capability i = 0x8090A2
Standard = CCITT
Transer Capability = Speech
Transfer Mode = Circuit
Transfer Rate = 64 kbit/s
Channel ID i = 0xA98381
Exclusive, Channel 1
Calling Party Number i = 0x2181, '4085550111'
Plan:ISDN, Type:National
Called Party Number i = 0x80, '83101'
Plan:Unknown, Type:Unknown
Aug 19 02:05:36.353: VDEV_ALLOCATE: 1/2 is allocated
Aug 19 02:05:36.353: csm_vtsp_init_tdm: vdev@ 0x6355AAF4, voice_vdev@ 0x6355AA80
Aug 19 02:05:36.353: csm_vtsp_init_tdm: dsprm_tdm_allocate: tdm slot 1, dspm 1, dsp 2, dsp_channel 1
Aug 19 02:05:36.353: csm_vtsp_init_tdm: dsprm_tdm_allocate: tdm stream 4, channel 3, bank 2, bp_channel 1, bp_stream 255
Aug 19 02:05:36.357: VDEV_DEALLOCATE: slot 1, port 4 is deallocated
Aug 19 02:05:36.805: ISDN Se0:23 Q931: TX -> CALL_PROC pd = 8 callref = 0x8237
Channel ID i = 0xA98381
Exclusive, Channel 1
The second call attempt also fails, generating a different IEC:
Aug 19 02:05:36.845: %VOICE_IEC-3-GW: H323: Internal Error (Socket error): IEC=1.1.186.5.7.6 on callID 8 GUID=750AFC91D12011D7800600B0640E6622
Aug 19 02:05:36.865: ISDN Se0:23 Q931: TX -> DISCONNECT pd = 8 callref = 0x8237
Cause i = 0x80A6 - Network out of order
Aug 19 02:05:36.873: ISDN Se0:23 Q931: RX <- RELEASE pd = 8 callref = 0x0237
Cause i = 0x82E4 - Invalid information element contents
Aug 19 02:05:36.877: ISDN Se0:23 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x8237
The following lines show that the subsequent
call failed due to a different socket error. However, in this instance
sending a ping to the remote IP address is successful:
Router> show voice iec description 1.1.186.5.7.6
IEC Version: 1
Entity: 1 (Gateway)
Category: 186 (Signaling socket failure)
Subsystem: 5 (H323)
Error: 7 (Socket error)
Diagnostic Code: 6
Router> ping 172.69.85.107
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 172.69.85.107, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 1/1/4 ms
Use the debug ip tcp transaction, show debug, and debug cch323 h225 commands again.
Router# debug ip tcp transaction
TCP special event debugging is on
Router# show debug
CSM Voice:
Voice Call Switching Module debugging is on
TCP:
TCP special event debugging is on
The following ISDN debugs are enabled on all DSLs:
debug isdn error is ON.
debug isdn q931 is ON. (filter is OFF)
Router# debug cch323 h225
H225 State Machine tracing is enabled
Router#
Aug 19 02:06:36.637: ISDN Se0:23 Q931: RX <- SETUP pd = 8 callref = 0x0238
Bearer Capability i = 0x8090A2
Standard = CCITT
Transer Capability = Speech
Transfer Mode = Circuit
Transfer Rate = 64 kbit/s
Channel ID i = 0xA98381
Exclusive, Channel 1
Calling Party Number i = 0x2181, '4085550111'
Plan:ISDN, Type:National
Called Party Number i = 0x80, '83101'
Plan:Unknown, Type:Unknown
Aug 19 02:06:36.641: VDEV_ALLOCATE: 1/3 is allocated
Aug 19 02:06:36.641: csm_vtsp_init_tdm: vdev@ 0x6355B240, voice_vdev@ 0x6355B1CC
Aug 19 02:06:36.641: csm_vtsp_init_tdm: dsprm_tdm_allocate: tdm slot 1, dspm 1, dsp 3, dsp_channel 1
Aug 19 02:06:36.641: csm_vtsp_init_tdm: dsprm_tdm_allocate: tdm stream 4, channel 5, bank 2, bp_channel 2, bp_stream 255
Aug 19 02:06:36.645: VDEV_DEALLOCATE: slot 1, port 8 is deallocated
Aug 19 02:06:37.089: TCB63604218 created
Aug 19 02:06:37.089: TCB63604218 setting property TCP_PID (8) 632036B4
Aug 19 02:06:37.089: TCB63604218 setting property TCP_NO_DELAY (1) 632036B8
Aug 19 02:06:37.089: TCB63604218 setting property TCP_TOS (11) 632036E0
Aug 19 02:06:37.089: TCB63604218 setting property TCP_NONBLOCKING_WRITE (10) 63203740
Aug 19 02:06:37.089: TCB63604218 setting property TCP_NONBLOCKING_READ (14) 63203740
Aug 19 02:06:37.089: TCB63604218 setting property unknown (15) 63203740
Aug 19 02:06:37.089: TCB63604218 setting property TCP_NO_DELAY (1) 632036FC
Aug 19 02:06:37.089: TCB63604218 setting property TCP_ALWAYSPUSH (17) 632036FC
Aug 19 02:06:37.089: TCB63604218 bound to 172.16.13.16.11001
Aug 19 02:06:37.089: TCP: sending SYN, seq 1593750728, ack 0
Aug 19 02:06:37.093: TCP0: Connection to 172.31.85.107:1720, advertising MSS 536
Aug 19 02:06:37.093: TCP0: state was CLOSED -> SYNSENT [11001 -> 172.31.85.107(1720)]
Aug 19 02:06:37.093: TCP0: state was SYNSENT -> ESTAB [11001 -> 172.31.85.107(1720)]
Aug 19 02:06:37.093: TCP0: Connection to 172.31.85.107:1720, received MSS 1460, MSS is 536
Aug 19 02:06:37.093: //10/98FA43DC8007/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE
Aug 19 02:06:37.093: //10/98FA43DC8007/H323/check_qos_and_send_setup: Setup ccb 0x635F80E8
Aug 19 02:06:37.093: //10/98FA43DC8007/H323/run_h225_sm: Received event H225_EV_FS_SETUP while at state H225_IDLE
Aug 19 02:06:37.093: //10/98FA43DC8007/H323/idle_fsSetup_hdlr: Setup ccb 0x635F80E8
Aug 19 02:06:37.097: //10/98FA43DC8007/H323/generic_send_setup: sending calling IE
Aug 19 02:06:37.097: //10/98FA43DC8007/H323/generic_send_setup: ====== PI = 0
Aug 19 02:06:37.097: //10/98FA43DC8007/H323/generic_send_setup: Send infoXCap=128, infoXRate=157, rateMult=89
Aug 19 02:06:37.097: //10/98FA43DC8007/H323/generic_send_setup: src address = 172.16.13.16; dest address = 172.31.85.107
Aug 19 02:06:37.097: //10/98FA43DC8007/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state
Aug 19 02:06:37.101: TCP0: FIN processed
The following lines show that the router was
able to initialize the TCP session to Cisco CallManager, and the session
went into the established state. After the router sent an H225 SETUP
message it received a TCP RESET message to tear down the TCP session,
indicating Cisco CallManager dropped the connection.
Aug 19 02:06:37.101: TCP0: state was ESTAB -> CLOSEWAIT [11001 -> 172.31.85.107(1720)]
Aug 19 02:06:37.101: TCP0: RST received, Closing connection
Aug 19 02:06:37.101: TCP0: state was CLOSEWAIT -> CLOSED [11001 -> 172.31.85.107(1720)]
Aug 19 02:06:37.105: ISDN Se0:23 Q931: TX -> CALL_PROC pd = 8 callref = 0x8238
Channel ID i = 0xA98381
Exclusive, Channel 1
Aug 19 02:06:37.105: %VOICE_IEC-3-GW: H323: Internal Error (Socket error): IEC=1.1.186.5.7.6 on callID 10 GUID=98FA43DCD12011D7800700B0640E6622
Aug 19 02:06:37.105: TCB 0x63604218 destroyed
Aug 19 02:06:37.105: //10/98FA43DC8007/H323/run_h225_sm: Received event H225_EV_CONN_LOST while at state H225_REQ_FS_SETUP
Aug 19 02:06:37.113: //10/98FA43DC8007/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_REQ_FS_SETUP
Aug 19 02:06:37.113: //10/98FA43DC8007/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_IDLE state
Aug 19 02:06:37.121: ISDN Se0:23 Q931: TX -> DISCONNECT pd = 8 callref = 0x8238
Cause i = 0x80A6 - Network out of order
Aug 19 02:06:37.133: ISDN Se0:23 Q931: RX <- RELEASE pd = 8 callref = 0x0238
Cause i = 0x82E4 - Invalid information element contents
Aug 19 02:06:37.137: ISDN Se0:23 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x8238
No comments:
Post a Comment