H.323 T.38传真中继问题
目录
简介
T.38传真中继问题通常与思科和第三方T.38传真网关之间的互操作性问题有关。本文档提供了成功和失败的T.38传真中继呼叫的详细debug命令示例。这些debug命令输出包含注释以提供参考点，以便您能够识别和排除此类互操作性问题。本文档还提供相关的故障排除和验证命令。
先决条件
要求
本文档的读者应了解传真中继的基本概念。有关传真中继概念和基本故障排除步骤的详细信息，请参阅《传真中继故障排除指南》。
使用的组件
本文档不限于特定的软件和硬件版本。
本文档中的信息都是基于特定实验室环境中的设备编写的。本文档中使用的所有设备最初均采用原始（默认）配置。如果您使用的是真实网络，请确保您已经了解所有命令的潜在影响。
规则
有关文档规则的详细信息，请参阅 Cisco 技术提示规则。
T.38基础
T.38传真中继问题的常见症状是建立语音呼叫，该呼叫在该呼叫中听到传真音，但传真协商尚未完成，呼叫最终被丢弃。此问题通常与Cisco T.38网关和第三方T.38网关互操作性问题有关。
T.38传真中继是实时传真传输；即，两台相互通信的传真机，好像两台传真机之间有一条直接的电话线。传真中继在网关拨号对等体上配置了一些附加命令，这些命令已经为语音呼叫定义和配置。
思科提供两种传真中继方法：一种思科专有方法和一种基于ITU-T T.38标准的方法。在大多数平台中，如果传真方法未明确配置，则默认使用Cisco传真中继。Cisco传真中继在配置Cisco传真中继中描述。
T.38限制
此时，Cisco T.38传真中继有以下限制：
-
T.38互操作性需要Cisco H.323版本2。
-
带语音压缩模块(VCM)的思科MC3810系列集中器不支持T.38。
-
多媒体会议管理器(MCM)H.323代理不支持T.38。
-
仅对H.323 T.38实施用户数据报协议(UDP)。
-
某些第三方网关和网守与T.38传真中继的思科语音网关不兼容，因为不同制造商可以选择H.323和T.38的某些部分以实施到其网关和网守中。必须执行与这些第三方网关和网守的语音互操作性测试，以确保T.38传真中继能够成功。
T.38协商
本节简要介绍T.38协商在思科网关内的处理方式。有关传真中继基础知识的详细信息，请参阅《传真中继故障排除指南》。
-
在初始设置消息中，始发网关(OGW)通告T.38数据功能。
如果终端网关(TGW)支持T.38数据功能，它可以在发送到OGW的后续消息中中继该信息。
-
一旦建立了语音呼叫，并且TGW处的数字信号处理器(DSP)检测到传真音，语音电话服务提供商(VTSP)状态机通知H.323呼叫段，该呼叫段与OGW协商T.38模式。
-
当确认T.38模式时，音频通道关闭，T.38逻辑通道在两端打开。
-
在VTSP代码级别，将进行传真编码解码器（编解码器）下载。
-
成功下载T.38开放逻辑通道(OLC)和编解码器后，VTSP进入传真模式。
-
在传真传输完成后，呼叫将恢复为语音呼叫。
注意：在T.38模式协商期间，如果另一端不确认T.38模式，则呼叫将恢复为语音呼叫并断开连接。如果从另一端收到关于T.38 OLC的否定确认，则呼叫也会恢复为语音呼叫并断开。
T.38故障排除
H.323或SIP T.38传真中继故障排除提示
要排除T.38传真中继故障，请执行以下步骤：
-
确保您可以进行语音呼叫。确认在您检查传真连接之前可以完成普通语音呼叫。如果没有连接电话，请拔掉传真机并连接普通电话。如果普通语音呼叫未连接，则问题可能与VoX相关，在继续进行传真故障排除之前，您可以将问题作为普通语音连接问题进行故障排除。
-
确保在始发网关和终端网关上都使用fax protocol命令设置了所需的传真协议。
-
确保在全局配置级别或在始发网关和终端网关的拨号对等配置级别将传真协议配置为T.38。
debug 和 show 命令
用于排除T.38传真中继故障的debug和show命令包括：
-
debug voip ccapi inout — 此命令通过呼叫控制应用程序接口(API)跟踪执行路径，该接口用作呼叫会话应用程序和底层网络特定软件之间的接口。您可以使用此命令的输出了解语音网关如何处理呼叫。
-
debug vtsp all — 此命令启用以下debug VTSP命令：debug vtsp session、debug vtsp error 和 debug vtsp dsp。
-
debug h245 asn1 — 此命令显示H.245消息的抽象语法表示法1(ASN.1)内容。要禁用调试输出，请使用此命令的no形式。
-
debug cch323 h245 — 此命令根据已处理的事件提供H.245状态机状态转换的跟踪。要禁用调试输出，请使用此命令的no形式。
-
show call active fax brief — 此命令显示正在进行的存储转发传真传输的呼叫信息。
-
show call history fax — 此命令显示传真的最近呼叫历史记录。
成功的T.38呼叫的输出
本节详细介绍AS5300系列路由器和Cisco 3640模块化接入路由器之间成功建立T.38传真的特点。Cisco AS5300通用网关上捕获了debug和show命令输出，作为TGW IOS 12.2:
| debug vtsp all命令输出 |
|---|
!---After the voice call setup:
!--- Usually, after the call is connected, the ccCallConnect debug !--- message is seen as follows:
May 3 21:41:21.424: ccCallConnect (callID=0x9), prog_ind = 0
May? 3 21:41:21.424: ssaFlushPeerTagQueue cid(9) peer list: (empty)
May 3 21:41:21.424: H.225 SM: process event H225_EVENT_SETUP_CFM, for callID 9
May 3 21:41:21.424: cch323_run_h225_sm:
received event H225_EVENT_SETUP_CFM while at state H225_ALERT
May 3 21:41:21.424: H.225 SM:
changing from H225_ALERT state to H225_ACTIVE state for callID 9
May 3 21:41:21.424: ==== PI in cch323_h225_generic_send_setup_cfm = 0
!---After the voice call is established, the TGW DSP detected fax tone:
May 3 21:41:26.741: vtsp_process_dsp_message: MSG_TX_TONE_DETECT:
type=0 trigger=1 tone_id=0
May 3 21:41:26.741: vtsp:[1:D (10), S_CONNECT, E_DSP_TONE_DETECT]
May 3 21:41:26.745: vtsp_modem_proto_from_cdb: cap_modem_proto 0
May 3 21:41:26.745: cc_api_call_feature: (vdbPtr=0x624130C0,
callID=0xA,feature_ind.type=1
!---Switched to fax mode:
May 3 21:41:26.745: act_lfax_switch:
cap_modem_proto=16, fax_relay_on=1, state=19
May 3 21:41:26.745: vtsp_t38_switchover:2 - data_mode:1
!--- Note that 2 means T.38; 1 means Cisco proprietary.
May 3 21:41:26.745: cc_api_t38_fax_start
(dstVdbPtr=0x61B45A90, dstCallId=0x9, srcCallId=0xA,????
caps={codec=0x10000, fax_rate=0x2, vad=0x2, modem=0x0codec_bytes=160, signal_type=1})
May 3 21:41:26.745: vtsp_timer: 2016656
May 3 21:41:26.745: sess_appl: ev(28=CC_EV_CALL_FEATURE), cid(10), disp(0)
May 3 21:41:26.745: cid(10)st(SSA_CS_ACTIVE)ev(SSA_EV_CALL_FEATURE)
oldst(SSA_CS_CONFERENCED_ALERT)cfid(5)csize(0)in(0)fDest(0)
May 3 21:41:26.745: -cid2(9)st2(SSA_CS_ACTIVE)oldst2(SSA_CS_CONFERENCING_ALERT)
!---H245 ModeRequest was sent to the OGW:
May 3 21:41:26.745: ccCallFeature (callID=0x9, feature.type=1)
Set new event H245_EVENT_MR, for callID 9
May 3 21:41:26.745: cch323_run_h245_mr_sm: received event
H245_EVENT_MR while at state H245_MR_NONE?
!---Above, state H245_MR_NONE refers to ModeRequest state.
May 3 21:41:26.745: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= request : requestMode :
??? {
????? sequenceNumber 1
????? requestedModes
?????{
??????? {
????????? {
??????????? type dataMode :
??????????? {
????????????? application t38fax :
????????????? {
??????????????? t38FaxProtocol udp : NULL
??????????????? t38FaxProfile
??????????? ????{
????????????????? fillBitRemoval FALSE
????????????????? transcodingJBIG FALSE
????????????????? transcodingMMR FALSE
????????????????? version 0
????????????????? t38FaxRateManagement transferredTCF : NULL
????????????????? t38FaxUdpOptions
?????? ???????????{
??????????????????? t38FaxMaxBuffer 200
??????????????????? t38FaxMaxDatagram 72
??????????????????? t38FaxUdpEC t38UDPRedundancy : NULL
????????????????? }
??????????????? }
????????????? }
????????????? bitRate 144
??????????? }
????????? }
??????? }
????? }
??? }
May 3 21:41:26.753: changing from H245_MR_NONE state to H245_MR_WAIT_FOR_ACK state
May 3 21:41:26.861: vtsp_process_dsp_message:
MSG_TX_TONE_DETECT: type=0 trigger=0 tone_id=0
May 3 21:41:26.861: vtsp:[1:D (10), S_LFAX_WAIT_CAPS_ACK, E_DSP_TONE_DETECT]
May 3 21:41:26.865: vtsp_process_event(): prev_state = 0.11 ,
state = S_LFAX_WAIT_CAPS_ACK, event = E_DSP_TONE_DETECT
?Invalid FSM? Input on channel 1:D (10)h323chan_chn_process_read_socket:
fd (3) of type ACCEPTED has data PROCESS_READ: NOT COMPLETE, rc 10, fd=3
May? 3 21:41:27.001: vtsp_process_dsp_message:
MSG_TX_TONE_DETECT: type=0 trigger=1 tone_id=0
May? 3 21:41:27.001: vtsp:[1:D (10), S_LFAX_WAIT_CAPS_ACK, E_DSP_TONE_DETECT]
May? 3 21:41:27.005: vtsp_process_event(): prev_state = 0.11 ,
?state = S_LFAX_WAIT_CAPS_ACK, event = E_DSP_TONE_DETECT
Invalid FSM?Input on channel 1:D (10)
May 3 21:41:27.101: vtsp_process_dsp_message:
MSG_TX_TONE_DETECT: type=0 trigger=0 tone_id=0
May 3 21:41:27.101: vtsp:[1:D (10), S_LFAX_WAIT_CAPS_ACK, E_DSP_TONE_DETECT]
May 3 21:41:27.105: vtsp_process_event(): prev_state = 0.11 ,
state = S_LFAX_WAIT_CAPS_ACK, event = E_DSP_TONE_DETECT
Invalid FSM Input on channel 1:D (10)h323chan_chn_process_read_socket:
fd (3) of type ACCEPTED has data
Hex representation of the received TPKT0321000827000100
May 3 21:41:27.173: ? state = 0 bytesLeftToDecode = 4
May 3 21:41:27.173: H245 MSC INCOMING ENCODE BUFFER::= 27 000100
!---Received ModeRequestAck from the OGW:
May 3 21:41:27.173: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= response : requestModeAck :
??? {
????? sequenceNumber 1
????? response willTransmitMostPreferredMode : NULL
??? }
Set new event H245_EVENT_MR_CFM, for callID 9
May 3 21:41:27.173: cch323_run_h245_mr_sm: received event
H245_EVENT_MR_CFM while at state H245_MR_WAIT_FOR_ACK
!---The voice LC is closed and the T.38 fax data LC is opened:
May 3 21:41:27.173: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= request : closeLogicalChannel :?
!---In the previous line, LogicalChannel refers to the voice LC.
??? {
????? forwardLogicalChannelNumber 1
????? source user : NULL
??? }
May 3 21:41:27.173: H245 MSC OUTGOING ENCODE BUFFER::= 04 00000000
May 3 21:41:27.173: send result :0
May 3 21:41:27.173: changing from H245_OLC_DONE state to H245_OLC_NONE state
May 3 21:41:27.173: cch323_update_new_codec_info: Remote codec 17
May 3 21:41:27.173: cch323_update_new_codec_info: negotiated_codec set(17)(40 bytes)
May 3 21:41:27.173: Changing to new event H245_EVENT_OLC
May 3 21:41:27.177: cch323_h245_olc_sm:
received event H245_EVENT_OLC while at state H245_OLC_NONE
May 3 21:41:27.177: changing from H245_OLC_NONE state to H245_OLC_WAIT state
May 3 21:41:27.177: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= request : openLogicalChannel :?
!---In the previous line, LogicalChannel refers to the T.38 or data LC.
??? {
????? forwardLogicalChannelNumber 2
????? forwardLogicalChannelParameters
????? {
??????? dataType data :
??????? {
????????? application t38fax :
????????? {
??????????? t38FaxProtocol udp : NULL
??????????? t38FaxProfile
??????????? {
????????????? fillBitRemoval FALSE
????????????? transcodingJBIG FALSE
????????????? transcodingMMR FALSE
????????????? version 0
????????????? t38FaxRateManagement transferredTCF : NULL
????????????? t38FaxUdpOptions
??????????? ??{
??????????????? t38FaxMaxBuffer 200
??????????????? t38FaxMaxDatagram 72
??????????????? t38FaxUdpEC t38UDPRedundancy : NULL
????????????? }
??????????? }
????????? }
????????? maxBitRate 144
??????? }
??????? multiplexParameters h2250LogicalChannelParameters :
??????? {
????????? sessionID 3?
!---The previous line refers to the data session ID.
????????? mediaControlChannel unicastAddress : iPAddress :
????????? {
??????????? network 'AB44BA66'H
??????????? tsapIdentifier 17517
????????? }
????????? silenceSuppression FALSE
??????? }
????? }
??? }
May 3 21:41:27.181: H245 MSC OUTGOING ENCODE BUFFER::=
03 00000111 04118601 00805C01 00014007 C00200C8
01484000 90800B05 000300AB 44BA6644 6D00
May 3 21:41:27.181: send result :0
May 3 21:41:27.181: OLC using T38Fax
May 3 21:41:27.181: changing from H245_MR_WAIT_FOR_ACK state to H245_MR_NONE state
h323chan_chn_process_read_socket: fd (3) of type ACCEPTED has data
Hex representation of the received TPKT032100090400000000
May 3 21:41:27.185: ? state = 0 bytesLeftToDecode = 5
May 3 21:41:27.185: H245 MSC INCOMING ENCODE BUFFER::= 04 00000000
May 3 21:41:27.185:
May 3 21:41:27.185: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= request : closeLogicalChannel :??
!---In the previous line, LogicalChannel refers to the voice LC.
??? {
????? forwardLogicalChannelNumber 1
????? source user : NULL
??? }
May? 3 21:41:27.185: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= response
: closeLogicalChannelAck :???
!---In the previous line, LogicalChannel refers to the voice LC.
??? {
????? forwardLogicalChannelNumber 1
??? }
May 3 21:41:27.185: H245 MSC OUTGOING ENCODE BUFFER::= 23 800000
May 3 21:41:27.185: H245 MSC INCOMING ENCODE BUFFER::=
03 00000111 04118601 00805C01 00014007
C00200C8 01484000 90800B05 000300AC 10AF6941 7100
May 3 21:41:27.189: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= request : openLogicalChannel :?
!---In the previous line, LogicalChannel refers to the T.38 or data LC.
??? {
????? forwardLogicalChannelNumber 2
????? forwardLogicalChannelParameters
????? {
??????? dataType data :
??????? {
????????? application t38fax :
????????? {
??????????? t38FaxProtocol udp : NULL
??????????? t38FaxProfile
??????????? {
????????????? fillBitRemoval FALSE
????????????? transcodingJBIG FALSE
????????????? transcodingMMR FALSE
????????????? version 0
????????????? t38FaxRateManagement transferredTCF : NULL
????????????? t38FaxUdpOptions
????????????? {
??????????????? t38FaxMaxBuffer 200
??????????????? t38FaxMaxDatagram 72
??????????????? t38FaxUdpEC t38UDPRedundancy : NULL
????????????? }
??????????? }
????????? }
????????? maxBitRate 144
??????? }
??????? multiplexParameters h2250LogicalChannelParameters :
??????? {
????????? sessionID 3
????????? mediaControlChannel unicastAddress : iPAddress :
????????? {
??????????? network 'AC10AF69'H
??????????? tsapIdentifier 16753
????????? }
????????? silenceSuppression FALSE
???? ???}
????? }
??? }
!---DSP started T.38 fax codec download:
May 3 21:41:27.193: cc_api_t38_fax_start
(dstVdbPtr=0x624130C0, dstCallId=0xA, srcCallId=0x9,
???? caps={codec=0x10000, fax_rate=0x2, vad=0x2, modem=0x
codec_bytes=160, signal_type=1})
May 3 21:41:27.193: vtsp:[1:D (10), S_LFAX_WAIT_CAPS_ACK, E_CC_T38_START]
May 3 21:41:27.193: act_caps_ack_lfax_dnld
May 3 21:41:27.193: vtsp_timer_stop: 2016700
May 3 21:41:27.193: dsp_idle_mode: [1:D (10)]
packet_len=8 channel_id=8481 packet_id=68
May 3 21:41:27.193: cc_api_local_codec_dnld_done
(dstVdbPtr=0x61B45A90, dstCallId=0x9, srcCallId=0xA)
May 3 21:41:27.193: vtsp_timer: 2016700cch323_h245_local_codec_dnld_done:
negotiatedCodec[17]
May 3 21:41:27.197: Changing to new event H245_EVENT_OLC_IND
May 3 21:41:27.197: cch323_h245_olc_sm:
received event H245_EVENT_OLC_IND while at state H245_OLC_WAIT
May 3 21:41:27.197: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= response
: openLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 2
????? forwardMultiplexAckParameters h2250LogicalChannelAckParameters :
????? {
??????? sessionID 1
??????? mediaChannel unicastAddress : iPAddress :
??????? {
????????? network 'AB44BA66'H
????????? tsapIdentifier 17516
??????? }
????? ??mediaControlChannel unicastAddress : iPAddress :
??????? {
????????? network 'AB44BA66'H
????????? tsapIdentifier 17517
??????? }
??????? flowControlToZero FALSE
????? }
??? }
May 3 21:41:27.197: H245 MSC OUTGOING ENCODE BUFFER:
:= 22 C0000104 80145C00 00AB44BA 66446C00 AB44BA66 446D0300 0100
May 3 21:41:27.589: ? state = 0 bytesLeftToDecode = 4
May 3 21:41:27.589: H245 MSC INCOMING ENCODE BUFFER::= 23 800000
May 3 21:41:27.589:
May 3 21:41:27.589: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= response : closeLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 1
??? }
May 3 21:41:27.789: H245 MSC INCOMING ENCODE BUFFER:
:= 22 C0000104 80145C00 00AC10AF 69417000 AC10AF69 41710300 0100
May 3 21:41:27.789: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= response : openLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 2
????? forwardMultiplexAckParameters h2250LogicalChannelAckParameters :
????? {
??????? sessionID 3
??????? mediaChannel unicastAddress : iPAddress :
??????? {
????????? network 'AC10AF69'H
????????? tsapIdentifier 16752
??????? }
??????? mediaControlChannel unicastAddress : iPAddress :
??????? {
????????? network 'AC10AF69'H
????????? tsapIdentifier 16753
??????? }
??????? flowControlToZero FALSE
????? }
??? }
May 3 21:41:27.793: Changing to new event H245_EVENT_OLC_CFM
May 3 21:41:27.793: cch323_h245_olc_sm:
received event H245_EVENT_OLC_CFM while at state H245_OLC_WAIT
May 3 21:41:27.793: changing from H245_OLC_WAIT state to H245_OLC_DONE state
May 3 21:41:27.793: cc_api_t38_fax_start
(dstVdbPtr=0x624130C0, dstCallId=0xA, srcCallId=0x9,
???? caps={codec=0x10000, fax_rate=0x2, vad=0x2,
modem=0x0 codec_bytes=160, signal_type=1})
May 3 21:41:27.793: H.225 SM: process event H225_EVENT_H245_SUCCESS, for callID 9
May 3 21:41:27.793: cch323_run_h225_sm:
received event H225_EVENT_H245_SUCCESS while at state H225_ACTIVE
May 3 21:41:27.793: cc_api_remote_codec_dnld_done
(dstVdbPtr=0x624130C0, dstCallId=0xA, srcCallId=0x9)
May 3 21:41:27.793: vtsp:[1:D (10), S_LFAX_WAIT_FAX, E_CC_T38_START]
May 3 21:41:27.793: vtsp:[1:D (10), S_LFAX_WAIT_FAX, E_CC_T30_CAP_ACK]
May 3 21:41:27.793: act_t38_lfax_mode
May 3 21:41:27.793: vtsp_timer_stop: 2016760
May 3 21:41:27.793: cc_api_set_fax_mode
(dstVdbPtr=0x61B45A90, dstCallId=0x9, srcCallId=0xA)
May 3 21:41:27.793: dsp_idle_mode: [1:D (10)]
packet_len=8 channel_id=8481 packet_id=68
May 3 21:41:27.793: dsp_encap_config: T38
May 3 21:41:27.793: dsp_fax_mode: [1:D (10)] FaxRate 0x2, Codec 0x10000?
dsp_fax_mode() ECM_DISABLE not set,
debug_info not requested
May 3 21:41:27.793: dsp_fax_mode:[1:D (10)]
packet_len=28 channel_id=8481 packet_id=69 max_trans=6 info_size=20,
fax_protocol_type=3,hs_data_len=40, ls_data_red=0, hs_data_red=0,
tcf_handling=2, fax_relay_cntl=0x0 nsf_country = 0xAD, nsf_mfg = 0x0051
May 3 21:41:29.621: ccGetCallActive
(next=1, setup_time=0x0, index=0x0, p=0x6293A8C0)
May 3 21:41:29.621: ccGetCallActive
(next=1, setup_time=0x1EC241, index=0x1, p=0x6293A8C0)
|
T.38呼叫失败的示例
以下是失败T.38调用的debug命令输出示例：
| debug vtsp all命令输出 |
|---|
!---When the ModeRequest was sent, T35 nonStandard was sent instead of T38:
*Jun 14 15:35:01.743: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= request : requestMode :
??? {
????? sequenceNumber 12
????? requestedModes
????? {
??????? {
????????? {
??????????? type dataMode :
??????????? {
????????????? application nonStandard :
????????????? {
??????????????? nonStandardIdentifier h221NonStandard :
??????????????? {
????????????????? t35CountryCode 181
? ????????????????t35Extension 0
????????????????? manufacturerCode 20
??????????????? }
??????????????? data '543338466178554450'H
????????????? }
????????????? bitRate 144
??????????? }
????????? }
??????? }
????? }
??? }
Set new event H245_EVENT_MR_IND, for callID C
*Jun 14 15:35:01.751: cch323_run_h245_mr_sm: received event H245_EVENT_MR_IND wh
ile at state H245_MR_NONE
*Jun 14 15:35:01.751: Scan Preferred List for g729r8PDU DATA = 61593960
value MultimediaSystemControlMessage ::= response : requestModeAck :
??? {
????? sequenceNumber 12
????? response willTransmitMostPreferredMode : NULL
??? }
RAW_BUFFER::=
27 000C00
*Jun 14 15:35:01.751: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= request : closeLogicalChannel :
??? {
?? ???forwardLogicalChannelNumber 2
????? source user : NULL
??? }
RAW_BUFFER::=
04 00000100
*Jun 14 15:35:01.751:
*Jun 14 15:35:01.751: changing from H245_OLC_DONE state to H245_OLC_NONE state
*Jun 14 15:35:01.751: cch323_update_new_codec_info: Remote codec 17
*Jun 14 15:35:01.751: cch323_update_new_codec_info: negotiated_codec set(17)(40
bytes)
*Jun 14 15:35:01.751: Changing to new event H245_EVENT_OLC
*Jun 14 15:35:01.751: cch323_h245_olc_sm:
received event H245_EVENT_OLC while atstate H245_OLC_NONE
*Jun 14 15:35:01.751: changing from H245_OLC_NONE state to H245_OLC_WAIT state
PDU DATA = 61593960
value MultimediaSystemControlMessage ::= request : openLogicalChannel :
??? {
????? forwardLogicalChannelNumber 3
????? forwardLogicalChannelParameters
????? {
??????? dataType data :
??????? {
????????? application nonStandard :
????????? {
??????????? nonStandardIdentifier h221nonStandard :
??????????? {
????????????? t35CountryCode 181
????????????? t35Extension 0
????????????? manufacturerCode 18
? ??????????}
??????????? data '543338466178554450'H
????????? }
????????? maxBitRate 144
??????? }
??????? multiplexParameters h2250LogicalChannelParameters :
??????? {
????????? sessionID 3
????????? mediaControlChannel unicastAddress : iPAddress :
?????? ???{
??????????? network 'C95C381E'H
??????????? tsapIdentifier 18101
????????? }
??????? }
????? }
??? }
RAW_BUFFER::=
03 00000210 08B50000 12095433 38466178 55445000 90800A04 000300C9 5C381E46 B5
*Jun 14 15:35:01.759:
*Jun 14 15:35:01.759: OLC using T38Fax
*Jun 14 15:35:01.783: Changing to new event H245_PROCESS_H245CONTROL
*Jun 14 15:35:01.783: cch323_h245_connection_sm:H245_CONNECT: received event H24
5_PROCESS_H245CONTROL while at H245_CONNECTED state
RAW_BUFFER::=
04 80000100 800100
*Jun 14 15:35:01.783: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= request : closeLogicalChannel :
??? {
????? forwardLogicalChannelNumber 2
????? source user : NULL
????? reason unknown : NULL
??? }
PDU DATA = 61593960
value MultimediaSystemControlMessage ::= response : closeLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 2
??? }
RAW_BUFFER::=
23 800001
*Jun 14 15:35:01.787:
*Jun 14 15:35:01.787: Changing to new event H245_PROCESS_H245CONTROL
*Jun 14 15:35:01.787: cch323_h245_connection_sm:H245_CONNECT: received event H24
5_PROCESS_H245CONTROL while at H245_CONNECTED state
RAW_BUFFER::=
03 00000310 08B50000 14095433 38466178 55445000 90800300 0003
*Jun 14 15:35:01.787: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= request : openLogicalChannel :
??? {
????? forwardLogicalChannelNumber 4
????? forwardLogicalChannelParameters
????? {
??????? dataType data :
??????? {
????????? application nonStandard :
????????? {
??????????? nonStandardIdentifier h221NonStandard :
?? ?????????{
????????????? t35CountryCode 181
????????????? t35Extension 0
????????????? manufacturerCode 20
??????????? }
??????????? data '543338466178554450'H
????????? }
????????? maxBitRate 144
??????? }
??????? multiplexParameters h2250LogicalChannelParameters :
??????? {
????????? sessionID 3
??????? }
????? }
??? }
*Jun 14 15:35:01.831: Changing to new event H245_PROCESS_H245CONTROL
*Jun 14 15:35:01.831: cch323_h245_connection_sm:H245_CONNECT: received event H24
5_PROCESS_H245CONTROL while at H245_CONNECTED state
RAW_BUFFER::=
23 800001
*Jun 14 15:35:01.831: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= response : closeLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 2
??? }
*Jun 14 15:35:01.883: Changing to new event H245_PROCESS_H245CONTROL
*Jun 14 15:35:01.883: cch323_h245_connection_sm:H245_CONNECT: received event H24
5_PROCESS_H245CONTROL while at H245_CONNECTED state
RAW_BUFFER::=
22 C0000204 800C5804 00875C34 CB1B4801 0100
*Jun 14 15:35:01.883: PDU DATA = 61593960
value MultimediaSystemControlMessage ::= response : openLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 3
????? forwardMultiplexAckParameters h2250LogicalChannelAckParameters :
????? {
??????? sessionID 3
??????? mediaChannel unicastAddress : iPAddress :
??????? {
????????? network '875C34CB'H
????????? tsapIdentifier 6984
??????? }
??????? flowControlToZero FALSE
????? }
??? }
*Jun 14 15:35:01.887: Changing to new event H245_EVENT_OLC_CFM
*Jun 14 15:35:01.887: cch323_h245_olc_sm:
received event H245_EVENT_OLC_CFM while at state H245_OLC_WAIT
*Jun 14 15:35:01.887: changing from H245_OLC_WAIT state to H245_OLC_DONE state
cch323_h245_local_codec_dnld_done: negotiatedCodec[17]
*Jun 14 15:35:01.979: Changing to new event H245_EVENT_OLC_IND
*Jun 14 15:35:01.979: cch323_h245_olc_sm: received event H245_EVENT_OLC_IND whil
e at state H245_OLC_DONE
!---Session ID was sent as voice session ID, fallback to voice and the call disconnected:
PDU DATA = 61593960
value MultimediaSystemControlMessage ::= response : openLogicalChannelAck :
??? {
????? forwardLogicalChannelNumber 4
????? forwardMultiplexAckParameters h2250LogicalChannelAckParameters :
????? {
??????? sessionID 1
??????? mediaChannel unicastAddress : iPAddress :
??????? {
??? ??????network 'C95C381E'H
????????? tsapIdentifier 18100
??????? }
??????? mediaControlChannel unicastAddress : iPAddress :
??????? {
????????? network 'C95C381E'H
????????? tsapIdentifier 18101
??????? }
??????? flowControlToZero FALSE
????? }
??? }
RAW_BUFFER::=
22 C0000304 80145C00 00C95C38 1E46B400 C95C381E 46B50300 0100
*Jun 14 15:35:01.983:
|
本节详细介绍AS5300系列路由器和Cisco 3640模块化接入路由器之间成功建立T.38传真的特点。Cisco 3640模块化接入路由器上的debug vtsp all 命令捕获了debug 和show 命令输出，作为TGW IOS 12.4:
| debug vtsp all命令输出 |
|---|
Router# debug vtsp all Voice telephony call control all debugging is on !--- At this point, the VTSP is not aware of anything. The format of this message is //callid/GUID/VTSP:(voice-port):T1-channel_number:DSP_number:DSP_channel_number: •CallEntry ID is -1. •GUID is xxxxxxxxxx. •The voice port is blank. •Channel ID is -1. •DSP ID is -1. •DSP channel ID is -1. *Mar 1 08:23:10.869: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_do_regxrule_translate: !--- The original and the translated calling number are the same (55555) and the original and the translated called number are the same (888545). These numbers are often the same because if a translation rule is applied, it will be on the dial peers or the ports, both of which comes later than these VTSP messages in the Cisco IOS code execution. *Mar 1 08:23:10.869: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp _do_regxrule_translate: calling_number(original)= calling_number(xlated)=55555 called_number(original)= called_number(xlated)=888545 redirectNumber(original)= redirectNumber(xlated)= !--- The VTSP got a call setup indicator from the TSP layer with called number 888545 and calling number 55555. There is no awareness of the CallEntry ID (-1) or the GUID (xxxxxxxxxxxx). *Mar 1 08:23:10.873: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_tsp_call_setup_ind: (sdb=0x634C90EC, tdm_info=0x0, tsp_info=0x63083950, calling_number=55555 calling_oct3 = 0x80, called_number=888545 called_oct3 = 0x80, oct3a=0x0): peer_tag=10002 *Mar 1 08:23:10.873: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_tsp_fill_setup_ind : ev.clg.clir is 0 ev.clg.clid_transparent is 0 ev.clg.null_orig_clg is 0 ev.clg.calling_translated is false *Mar 1 08:23:10.873: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_do_call_setup_ind: . *Mar 1 08:23:10.873: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_allocate_cdb: ,cdb 0x635FC480 *Mar 1 08:23:10.873: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_do_call_setup_ind: *Mar 1 08:23:10.873: source route label !--- At this point, the VTSP is not aware of anything. The format of this message is //callid/GUID/VTSP:(voice-port):T1-channel_number:DSP_number:DSP_channel_number: •CallEntry ID is -1. •GUID is D2F6429A8A8A. •The voice port is 1/0:23 where 23 indicates D channel. •The T1 channel is still unknown at this point (-1). •The digital signal processor (DSP) is 0. •The DSP channel is 4. *Mar 1 08:23:10.873: //-1/D2F6429A8A8A/VTSP:(1/0:23):-1:0:4/vtsp_do_call_setup_ ind: Call ID=101002, guid=635FCB08 !--- The VTSP learns about the B channel (changed from -1 to 22), and the CallEntry ID is still unknown (-1). *Mar 1 08:23:10.873: //-1/D2F6429A8A8A/VTSP: (1/0:23):22:0:4/vtsp_do_call_setup_ind: type=0, under_spec=1615186336, name=, id0=23, id1=0, id2=0, calling=55555,called=888545 subscriber=RegularLinevtsp_do_call_setup_ind: redirect DN = reason = -1 *Mar 1 08:23:10.877: //-1/xxxxxxxxxxxx/VTSP:():-1:-1:-1/vtsp_do_normal_call_setup_ind: . !--- The VTSP learns the CallEntry ID. The format of this message is //callid/GUID/VTSP:(voice-port):T1-channel_number:DSP_number:DSP_channel_number: •CallEntry ID is 899 (changed from -1 to 899) •GUID is D2F6429A8A8A •The voice port is 1/0:23 where 23 indicates D channel •The T1 channel is 22 •The DSP is 12 •The DSP channel is 4 *Mar 1 08:23:10.877: //899/D2F6429A8A8A/VTSP:(1/0:23) :22:12:4/vtsp_insert_cdb:,cdb 0x635FC480, CallID=899 *Mar 1 08:23:10.877: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_open_voice_and_set_params: . !--- In these outputs, VTSP sets some of the voice parameters for this call: •Modem capability •Playout delay •Dial-peer tag 10003 •Digit timeouts *Mar 1 08:23:10.877: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_modem_proto_from_cdb: cap_modem_proto 0 *Mar 1 08:23:10.881: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/set_playout_cdb:playout default *Mar 1 08:23:10.881: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_dsp_echo_canceller_control: echo_cancel: 1 *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP: (1/0:23):22:12:4/vtsp_save_dialpeer_tag: tag = 10003 *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP: (1/0:23):22:12:4/vtsp_report_digit_control: vtsp_report_digit_control: enable=0: *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_report_digit_control: digit reporting disabled *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_get_digit_timeouts: : vtsp_get_digit_timeouts !--- VTSP sends out a call-proceeding message to the POTS leg *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_process_event:vtsp:[1/0:23:899, S_SETUP_INDICATED, E_CC_PROCEEDING] *Mar 1 08:23:10.885: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/act_proceeding: . *Mar 1 08:23:10.941: //899/D2F6429A8A8A/VTSP: (1/0:23):22:12:4/vtsp_get_dialpeer_tag: tag = 10003 *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_get_dialpeer_tag: tag = 10003 !--- VTSP sends out an alerting to the POTS leg; the phone is ringing at this time. *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP: (1/0:23):22:12:4/vtsp_process_event: vtsp:[1/0:23:899, S_PROCEEDING, E_CC_ALERT] *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/act_alert: . *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_timer_stop:3019095 *Mar 1 08:23:18.769: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_get_dialpeer_tag: tag = 10003 !--- The phone gets answered here, a bridge is now set up between the two call legs. *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP: (1/0:23):22:12:4/vtsp_process_event: vtsp:[1/0:23:899, S_PROCEEDING, E_CC_ALERT] *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/act_alert: . *Mar 1 08:23:10.949: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_timer_stop:3019095 *Mar 1 08:23:18.769: //899/D2F6429A8A8A/VTSP:(1/0:23): 22:12:4/vtsp_get_dialpeer_tag: tag = 10003 !--- The call is now connected. Mar 1 08:23:18.769: //899/D2F6429A8A8A/VTSP:(1/0:23) :22:12:4/vtsp_process_event: vtsp:[1/0:23:899, S_ALERTING, E_CC_CONNECT] *Mar 1 08:23:18.769: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/act_alert_connect: . *Mar 1 08:23:18.773: //899/D2F6429A8A8A/VTSP:(1/0:23):22:12:4/vtsp_ring_noan_timer_stop: 3019877 |
相关信息
修订历史记录
| 版本 | 发布日期 | 备注 |
|---|---|---|
1.0 |
22-Aug-2007 |
初始版本 |
反馈