Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for
- Cisco Community
- Technology and Support
- Collaboration
- IP Telephony and Phones
- Troubleshooting transcoder between H.323/G.729 and SIP/G.711
Options
- Subscribe to RSS Feed
- Mark Topic as New
- Mark Topic as Read
- Float this Topic for Current User
- Bookmark
- Subscribe
- Mute
- Printer Friendly Page
4924
Views
0
Helpful
7
Replies
Troubleshooting transcoder between H.323/G.729 and SIP/G.711
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-04-2010 01:27 PM - edited 03-16-2019 01:09 AM
Software versions are as follows:
CUCM - 7.2
ISR - CME 7.1
R3 - CME 4.1
I am trying to configure a transcoder between two call legs. One call leg uses SIP and G.711 while other uses H.323 and G.729 (see diagram).
When CUCM phone 1001 calls R3/CME phone 3001 the call should route over a SIP trunk using G.711 from CUCM to ISR, then route to R3 via H.323 using G.729. ISR should be doing the transcoding for the G.711 to G.729 conversion.
When I place the call from 1001, extension 3001 rings but I get fast busy when I pick up 3001. Calls to extension 6001 on my transcoder CME (ISR) from R3 and CUCM work fine. What am I missing?
Configs attached.
Thanks,
-mike
Labels:
- Labels:
-
Other IP Telephony
7 Replies 7
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-04-2010 01:48 PM
Also, it looks like the transcoder resource is registering with the CME successfully.
ISR#sh sccp all
SCCP Admin State: UP
Gateway Local Interface: Loopback0
IPv4 Address: 6.6.6.6
Port Number: 2000
IP Precedence: 5
User Masked Codec list: None
Call Manager: 6.6.6.6, Port Number: 2000
Priority: N/A, Version: 7.0, Identifier: 1
Trustpoint: N/A
Transcoding Oper State: ACTIVE - Cause Code: NONE
Active Call Manager: 6.6.6.6, Port Number: 2000
TCP Link Status: CONNECTED, Profile Identifier: 1
Reported Max Streams: 6, Reported Max OOS Streams: 0
Supported Codec: g711ulaw, Maximum Packetization Period: 30
Supported Codec: g711alaw, Maximum Packetization Period: 30
Supported Codec: g729ar8, Maximum Packetization Period: 60
Supported Codec: g729abr8, Maximum Packetization Period: 60
Supported Codec: rfc2833 dtmf, Maximum Packetization Period: 30
Supported Codec: rfc2833 pass-thru, Maximum Packetization Period: 30
Supported Codec: inband-dtmf to rfc2833 conversion, Maximum Packetization Period: 30
SCCP Application Service(s) Statistics:
Profile Identifier: 1, Service Type: Transcoding
TCP packets rx 125, tx 127
Unsupported pkts rx 0, Unrecognized pkts rx 0
Register tx 1, successful 1, rejected 0, failed 0
Unregister tx 0, successful 0
KeepAlive tx 122, successful 122, failed 0
OpenReceiveChannel rx 0, successful 0, failed 0
CloseReceiveChannel rx 0, successful 0, failed 0
StartMediaTransmission rx 0, successful 0, failed 0
StopMediaTransmission rx 0, successful 0, failed 0
PortReq rx 0
PortRes tx 0, successful 0, failed 0
PortClose rx 0
QosListen rx 0
QosPath rx 0
QosTeardown rx 0, send 0, recv 0, sendrecv 0
QosResvNotify tx 0, send 0, recv 0, sendrecv 0
QosErrorNotify tx 0, send 0, recv 0, sendrecv 0
err0 0, err1 0, err2 0, err3 0, err4 0, err5 0,
err6 0, err7 0, err8 0, err9 0, err10 0, err11 0,
err12 0
QosModify rx 0, send 0, recv 0, sendrecv 0
UpdateDscp rx 0
Reset rx 0, successful 0, failed 0
MediaStreamingFailure rx 0
MediaStreamingFailure tx 0
Switchover 0, Switchback 0
CCM Group Identifier: 1
Description: None
Binded Interface: Loopback0
IPv4 Address: 6.6.6.6
Associated CCM Id: 1, Priority in this CCM Group: 1
Associated Profile: 1, Registration Name: ISR_XCODER
Registration Retries: 3, Registration Timeout: 10 sec
Keepalive Retries: 3, Keepalive Timeout: 30 sec
CCM Connect Retries: 3, CCM Connect Interval: 10 sec
Switchover Method: GRACEFUL, Switchback Method: GRACEFUL_GUARD
Switchback Interval: 10 sec, Switchback Timeout: 7200 sec
Signaling DSCP value: cs3, Audio DSCP value: ef
Total number of active session(s) 0, and connection(s) 0
Total number of active session(s) 0, and connection(s) 0
Total number of active session(s) 0, connection(s) 0, and callegs 0
SCCP Application Service(s) Statistics Summary:
Total Conferencing Sessions: 0, Connections: 0
Total Transcoding Sessions: 0, Connections: 0
Total MTP Sessions: 0, Connections: 0
Total ALG-Phone Sessions: 0, Connections: 0
Total BRI-Phone Sessions: 0, Connections: 0
Total SCCP Sessions: 0, Connections: 0
Total active sessions 0, connections 0, rsvp sessions 0
Statistic Count
------------------------- -----------
Send queue enqueue error 0
Socket send error 0
Msgs discarded upon error 0
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 06:32 AM
Glancing at your configuration, my guess is that you aren't matching the inbound dial-peer which you think you are matching.
Take a read of this document:
http://www.cisco.com/en/US/tech/tk652/tk90/technologies_tech_note09186a008010fed1.shtml
You can verify with:
debug voip ccapi inout
debug ccsip mess
debug h225 asn1
debug h245 asn1
debug cch323 all
Collect debugs as follows:
Router(config)# service sequence
Router(config)# service timestamps debug datetime msec
Router(config)# logging buffered 10000000 7
Router(config)# no logging con
Router(config)# no logging mon
Router(config)# voice iec syslog
Router# term len 0
Router# sh logg
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 07:28 AM
Updated ISR config:
Current configuration : 6952 bytes
!
! Last configuration change at 10:27:00 EDT Tue Oct 5 2010 by cisco
!
version 12.4
service timestamps debug datetime msec localtime
service timestamps log datetime msec localtime
no service password-encryption
service sequence-numbers
!
hostname ISR
!
boot-start-marker
boot-end-marker
!
card type t1 0 0
card type t1 0 1
logging message-counter syslog
logging buffered 10000000
no logging console
no logging monitor
enable secret 5 $1$I0fn$B9kWDZrOkvTRj/bwbmdn2.
!
no aaa new-model
clock timezone EST -5
clock summer-time EDT recurring
network-clock-participate wic 0
network-clock-participate wic 1
!
dot11 syslog
ip source-route
!
!
ip cef
!
!
no ip domain lookup
no ipv6 cef
multilink bundle-name authenticated
!
!
!
!
isdn switch-type primary-ni
!
!
!
voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
fax protocol cisco
sip
bind control source-interface Loopback1
bind media source-interface Loopback1
!
!
!
!
!
!
!
!
!
!
!
!
!
!
voice iec syslog
!
!
voice-card 0
dsp services dspfarm
!
!
!
!
!
username cisco privilege 15 password 0 cisco
archive
log config
hidekeys
!
!
controller T1 0/0/0
cablelength long 0db
pri-group timeslots 1-3,24 service mgcp
!
controller T1 0/1/0
cablelength long 0db
!
!
!
!
!
interface Loopback0
description CME Interface
ip address 6.6.6.6 255.255.255.255
!
interface Loopback1
description CUBE Interface
ip address 6.6.6.7 255.255.255.255
h323-gateway voip interface
h323-gateway voip bind srcaddr 6.6.6.7
!
interface FastEthernet0/0
ip address 192.168.10.7 255.255.255.0
duplex auto
speed auto
!
interface FastEthernet0/1
no ip address
shutdown
duplex auto
speed auto
!
interface Serial0/0/0:23
no ip address
encapsulation hdlc
isdn switch-type primary-ni
isdn incoming-voice voice
no cdp enable
!
router ospf 100
log-adjacency-changes
network 0.0.0.0 255.255.255.255 area 0
!
ip forward-protocol nd
ip route 0.0.0.0 0.0.0.0 192.168.10.1
!
no ip http server
no ip http secure-server
ip http path flash:/gui
!
!
!
!
tftp-server flash:Desktops/320x212x12/CampusNight.png
tftp-server flash:Desktops/320x212x12/CiscoFountain.png
tftp-server flash:Desktops/320x212x12/MorroRock.png
tftp-server flash:Desktops/320x212x12/NantucketFlowers.png
tftp-server flash:Desktops/320x212x12/TN-CampusNight.png
tftp-server flash:Desktops/320x212x12/TN-CiscoFountain.png
tftp-server flash:Desktops/320x212x12/TN-Fountain.png
tftp-server flash:Desktops/320x212x12/TN-MorroRock.png
tftp-server flash:Desktops/320x212x12/TN-NantucketFlowers.png
tftp-server flash:Desktops/320x212x12/Fountain.png
tftp-server flash:Desktops/320x212x12/CiscoLogo.png
tftp-server flash:Desktops/320x212x12/TN-CiscoLogo.png
tftp-server flash:Desktops/320x212x12/List.xml
tftp-server flash:Desktops/320x216x16/List.xml
tftp-server flash:Desktops/320x212x16/List.xml
tftp-server flash:gui/admin_user.html
tftp-server flash:gui/admin_user.js
tftp-server flash:gui/CiscoLogo.gif
tftp-server flash:gui/Delete.gif
tftp-server flash:gui/dom.js
tftp-server flash:gui/downarrow.gif
tftp-server flash:gui/ephone_admin.html
tftp-server flash:gui/logohome.gif
tftp-server flash:gui/normal_user.html
tftp-server flash:gui/normal_user.js
tftp-server flash:gui/Plus.gif
tftp-server flash:gui/sxiconad.gif
tftp-server flash:gui/Tab.gif
tftp-server flash:gui/telephony_service.html
tftp-server flash:gui/uparrow.gif
tftp-server flash:gui/xml-test.html
tftp-server flash:gui/xml.template
tftp-server flash:ringtones/Analog1.raw
tftp-server flash:ringtones/Analog2.raw
tftp-server flash:ringtones/AreYouThere.raw
tftp-server flash:ringtones/AreYouThereF.raw
tftp-server flash:ringtones/Bass.raw
tftp-server flash:ringtones/CallBack.raw
tftp-server flash:ringtones/Chime.raw
tftp-server flash:ringtones/Classic1.raw
tftp-server flash:ringtones/Classic2.raw
tftp-server flash:ringtones/ClockShop.raw
tftp-server flash:ringtones/DistinctiveRingList.xml
tftp-server flash:ringtones/Drums1.raw
tftp-server flash:ringtones/Drums2.raw
tftp-server flash:ringtones/FilmScore.raw
tftp-server flash:ringtones/HarpSynth.raw
tftp-server flash:ringtones/Jamaica.raw
tftp-server flash:ringtones/KotoEffect.raw
tftp-server flash:ringtones/MusicBox.raw
tftp-server flash:ringtones/Piano1.raw
tftp-server flash:ringtones/Piano2.raw
tftp-server flash:ringtones/Pop.raw
tftp-server flash:ringtones/Pulse1.raw
tftp-server flash:ringtones/Ring1.raw
tftp-server flash:ringtones/Ring2.raw
tftp-server flash:ringtones/Ring3.raw
tftp-server flash:ringtones/Ring4.raw
tftp-server flash:ringtones/Ring5.raw
tftp-server flash:ringtones/Ring6.raw
tftp-server flash:ringtones/Ring7.raw
tftp-server flash:ringtones/RingList.xml
tftp-server flash:ringtones/Sax1.raw
tftp-server flash:ringtones/Sax2.raw
tftp-server flash:ringtones/Vibe.raw
tftp-server flash:APPS-1.2.1.SBN
tftp-server flash:SYS-1.2.1.SBN
tftp-server flash:GUI-1.2.1.SBN
tftp-server flash:CP7921G-1.2.1.LOADS
tftp-server flash:TNUX-1.2.1.SBN
tftp-server flash:TNUXR-1.2.1.SBN
tftp-server flash:WLAN-1.2.1.SBN
tftp-server flash:apps37sccp.1-2-1-0.bin
tftp-server flash:APPSH-1.3.1.SBN
tftp-server flash:GUIH-1.3.1.SBN
tftp-server flash:CP7925G-1.3.1.LOADS
tftp-server flash:SYSH-1.3.1.SBN
tftp-server flash:TNUXH-1.3.1.SBN
tftp-server flash:WLANH-1.3.1.SBN
!
control-plane
!
!
!
voice-port 0/0/0:23
!
voice-port 0/2/0
!
voice-port 0/2/1
!
voice-port 0/2/2
!
voice-port 0/2/3
!
voice-port 0/3/0
!
voice-port 0/3/1
!
voice-port 0/3/2
!
voice-port 0/3/3
!
!
!
sccp local Loopback0
sccp ccm 6.6.6.6 identifier 1 version 7.0
sccp
!
sccp ccm group 1
bind interface Loopback0
associate ccm 1 priority 1
associate profile 1 register ISR_XCODER
!
dspfarm profile 1 transcode
codec g711ulaw
codec g711alaw
codec g729ar8
codec g729abr8
maximum sessions 3
associate application SCCP
!
!
dial-peer voice 1000 voip
destination-pattern 1...
session target ipv4:10.1.200.20
codec g711ulaw
!
dial-peer voice 3000 voip
destination-pattern 3...
session target ipv4:3.3.3.3
!
dial-peer voice 3001 voip
incoming called-number 3...
codec g711ulaw
!
!
gateway
timer receive-rtp 1200
!
sip-ua
!
!
telephony-service
sdspfarm units 1
sdspfarm transcode sessions 3
sdspfarm tag 1 ISR_XCODER
max-ephones 2
max-dn 4
ip source-address 6.6.6.6 port 2000
system message ISR-CME
max-conferences 8 gain -6
transfer-system full-consult
create cnf-files version-stamp 7960 Oct 04 2010 15:28:25
!
!
ephone-dn 1 dual-line
number 6001
description ISR Phone
!
!
ephone 1
mac-address 0023.339B.2314
type 7945
button 1:1
!
!
alias exec s show ip int br
alias exec sr show run
alias exec srt sh ip route
alias exec srb sh run | b
alias exec sri sh run | i
alias exec sv show voice port summ
alias exec sca show call active voice
!
line con 0
logging synchronous
line aux 0
login local
line vty 0 4
exec-timeout 0 0
logging synchronous
login local
!
scheduler allocate 20000 1000
ntp server 192.168.10.1
end
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 07:31 AM
Debug output is below. I'm matching dial-peer 3001 which is what I would expect (incoming called-number taking priority over destination-pattern). I posted the new ISR config in a previous post.
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.10.05 10:20:33 =~=~=~=~=~=~=~=~=~=~=~=
sh logg
Syslog logging: enabled (0 messages dropped, 3 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: disabled
Buffer logging: level debugging, 504 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 58 message lines logged
Log Buffer (10000000 bytes):
000054: Oct 5 10:18:52.683: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_RAS_PERIODIC_RRQ_TIMER] expired
000055: Oct 5 10:18:52.683: //-1/xxxxxxxxxxxx/H323/cch323_send_event_to_ras: Queued event CCH323_RAS_EVENT_SEND_LT_RRQ to RAS Global SM
000056: Oct 5 10:18:52.683: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xA internal event to RAS Global SM
000057: Oct 5 10:18:52.683: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_SEND_LT_RRQ while at CCH323_RAS_STATE_IDLE state
000058: Oct 5 10:18:52.683: RAS OUTGOING PDU ::=
value RasMessage ::= registrationRequest :
{
requestSeqNum 1262
protocolIdentifier { 0 0 8 2250 0 4 }
discoveryComplete TRUE
callSignalAddress
{
}
rasAddress
{
ipAddress :
{
ip '06060607'H
port 63383
}
}
terminalType
{
mc FALSE
undefinedNode FALSE
}
gatekeeperIdentifier {"ZONE_01"}
endpointVendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
timeToLive 60
keepAlive TRUE
endpointIdentifier {"672C9F6C00000001"}
willSupplyUUIEs FALSE
maintainConnection TRUE
}
000059: Oct 5 10:18:52.687: RAS OUTGOING ENCODE BUFFER::= 0E4004ED060008914A00048000010006060607F7970006005A004F004E0045005F0030003100B5000012288F000002003B0180211E003600370032004300390046003600430030003000300030003000300030003101000180
000060: Oct 5 10:18:52.687:
000061: Oct 5 10:18:52.687: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_RRQ state
000062: Oct 5 10:18:52.751: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
000063: Oct 5 10:18:52.751: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D57F60, len=70, msgPtr=0x49D566E8
000064: Oct 5 10:18:52.751: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for RAS
000065: Oct 5 10:18:52.751: RAS INCOMING ENCODE BUFFER::= 124004ED060008914A0004000C005A004F004E0045005F003000311E0036003700320043003900460036004300300030003000300030003000300031208A0002003B01000180
000066: Oct 5 10:18:52.751:
000067: Oct 5 10:18:52.751: RAS INCOMING PDU ::=
value RasMessage ::= registrationConfirm :
{
requestSeqNum 1262
protocolIdentifier { 0 0 8 2250 0 4 }
callSignalAddress
{
}
gatekeeperIdentifier {"ZONE_01"}
endpointIdentifier {"672C9F6C00000001"}
timeToLive 60
willRespondToIRR FALSE
maintainConnection TRUE
}
000068: Oct 5 10:18:52.755: //-1/xxxxxxxxxxxx/H323/cch323_ras_handle_recv_msg: received msg of type RCF_CHOSEN
000069: Oct 5 10:18:52.755: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_RCF while at CCH323_RAS_STATE_RRQ state
000070: Oct 5 10:18:52.755: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_IDLE state
000071: Oct 5 10:19:37.755: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_RAS_PERIODIC_RRQ_TIMER] expired
000072: Oct 5 10:19:37.755: //-1/xxxxxxxxxxxx/H323/cch323_send_event_to_ras: Queued event CCH323_RAS_EVENT_SEND_LT_RRQ to RAS Global SM
000073: Oct 5 10:19:37.755: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xA internal event to RAS Global SM
000074: Oct 5 10:19:37.755: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_SEND_LT_RRQ while at CCH323_RAS_STATE_IDLE state
000075: Oct 5 10:19:37.755: RAS OUTGOING PDU ::=
value RasMessage ::= registrationRequest :
{
requestSeqNum 1263
protocolIdentifier { 0 0 8 2250 0 4 }
discoveryComplete TRUE
callSignalAddress
{
}
rasAddress
{
ipAddress :
{
ip '06060607'H
port 63383
}
}
terminalType
{
mc FALSE
undefinedNode FALSE
}
gatekeeperIdentifier {"ZONE_01"}
endpointVendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
timeToLive 60
keepAlive TRUE
endpointIdentifier {"672C9F6C00000001"}
willSupplyUUIEs FALSE
maintainConnection TRUE
}
000076: Oct 5 10:19:37.759: RAS OUTGOING ENCODE BUFFER::= 0E4004EE060008914A00048000010006060607F7970006005A004F004E0045005F0030003100B5000012288F000002003B0180211E003600370032004300390046003600430030003000300030003000300030003101000180
000077: Oct 5 10:19:37.759:
000078: Oct 5 10:19:37.759: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_RRQ state
000079: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
000080: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D57F60, len=70, msgPtr=0x49D568B8
000081: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for RAS
000082: Oct 5 10:19:37.819: RAS INCOMING ENCODE BUFFER::= 124004EE060008914A0004000C005A004F004E0045005F003000311E0036003700320043003900460036004300300030003000300030003000300031208A0002003B01000180
000083: Oct 5 10:19:37.819:
000084: Oct 5 10:19:37.819: RAS INCOMING PDU ::=
value RasMessage ::= registrationConfirm :
{
requestSeqNum 1263
protocolIdentifier { 0 0 8 2250 0 4 }
callSignalAddress
{
}
gatekeeperIdentifier {"ZONE_01"}
endpointIdentifier {"672C9F6C00000001"}
timeToLive 60
willRespondToIRR FALSE
maintainConnection TRUE
}
000085: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_ras_handle_recv_msg: received msg of type RCF_CHOSEN
000086: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_RCF while at CCH323_RAS_STATE_RRQ state
000087: Oct 5 10:19:37.819: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_IDLE state
000088: Oct 5 10:19:56.112: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:3001@6.6.6.7:5060 SIP/2.0
Date: Tue, 05 Oct 2010 14:19:55 GMT
Call-Info: <10.1.200.20:5060>;method="NOTIFY;Event=telephone-event;Duration=500"
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772497
Allow-Events: presence, kpml
P-Asserted-Identity: <1001>
Supported: timer,resource-priority,replaces
Supported: Geolocation
Min-SE: 1800
Remote-Party-ID: <1001>;party=calling;screen=yes;privacy=off
Content-Length: 0
User-Agent: Cisco-CUCM7.1
To: <3001>
Contact: <1001>
Expires: 180
Call-ID: 9ee9bd00-cab1340b-1d-14c8010a@10.1.200.20
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2423dd8b96
CSeq: 101 INVITE
Session-Expires: 1800
Max-Forwards: 70
000089: Oct 5 10:19:56.120: //-1/7661A559800A/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=1001
----- ccCallInfo IE subfields -----
cisco-ani=1001
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=3001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
000090: Oct 5 10:19:56.124: //-1/7661A559800A/CCAPI/cc_api_call_setup_ind_common:
Interface=0x4705BD7C, Call Info(
Calling Number=1001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=3001, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=9
000091: Oct 5 10:19:56.124: //-1/7661A559800A/CCAPI/ccCheckClipClir:
In: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
000092: Oct 5 10:19:56.124: //-1/7661A559800A/CCAPI/ccCheckClipClir:
Out: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
000093: Oct 5 10:19:56.124: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000094: Oct 5 10:19:56.124: :cc_get_feature_vsa malloc success
000095: Oct 5 10:19:56.124: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000096: Oct 5 10:19:56.124: cc_get_feature_vsa count is 1
000097: Oct 5 10:19:56.124: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000098: Oct 5 10:19:56.124: :FEATURE_VSA attributes are: feature_name:0,feature_time:1239945304,feature_id:9
000099: Oct 5 10:19:56.124: //9/7661A559800A/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown))
000100: Oct 5 10:19:56.128: //9/7661A559800A/CCAPI/cc_process_call_setup_ind:
Event=0x472D5190
000101: Oct 5 10:19:56.128: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 3001
000102: Oct 5 10:19:56.132: //9/7661A559800A/CCAPI/ccCallSetContext:
Context=0x464789A4
000103: Oct 5 10:19:56.132: //9/7661A559800A/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 9 with tag 3001 to app "_ManagedAppProcess_Default"
000104: Oct 5 10:19:56.132: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2423dd8b96
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772497
To: <3001>
Date: Tue, 05 Oct 2010 14:19:56 GMT
Call-ID: 9ee9bd00-cab1340b-1d-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
000105: Oct 5 10:19:56.136: //9/7661A559800A/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
000106: Oct 5 10:19:56.136: //9/7661A559800A/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=3000, Params=0x46479CFC, Progress Indication=NULL(0)
000107: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/ccCheckClipClir:
In: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
000108: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/ccCheckClipClir:
Out: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
000109: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/ccCallSetupRequest:
Destination Pattern=3..., Called Number=3001, Digit Strip=FALSE
000110: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/ccCallSetupRequest:
Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=1001, Final Destination Flag=TRUE,
Guid=7661A559-CFC2-11DF-800A-B8130721089B, Outgoing Dial-peer=3000
000111: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=1001
----- ccCallInfo IE subfields -----
cisco-ani=1001
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=3001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
000112: Oct 5 10:19:56.140: //9/7661A559800A/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x478B1418, Interface Type=1, Destination=, Mode=0x0,
Call Params(Calling Number=1001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=3000, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
000113: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000114: Oct 5 10:19:56.140: :cc_get_feature_vsa malloc success
000115: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000116: Oct 5 10:19:56.140: cc_get_feature_vsa count is 2
000117: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
000118: Oct 5 10:19:56.140: :FEATURE_VSA attributes are: feature_name:0,feature_time:1239945080,feature_id:10
000119: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=10
000120: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0
000121: Oct 5 10:19:56.140: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0
000122: Oct 5 10:19:56.140: //10/7661A559800A/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
000123: Oct 5 10:19:56.144: //10/7661A559800A/CCAPI/ccCallSetContext:
Context=0x46479CAC
000124: Oct 5 10:19:56.144: //9/7661A559800A/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=3000
000125: Oct 5 10:19:56.144: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x49F6FE00) is in use
000126: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_call_setup: gw_id=1
000127: Oct 5 10:19:56.144: //-1/xxxxxxxxxxxx/H323/h323_TD_get_mlpp_info: callID=10, tag=(CC_TAG_MLPP_INFO), Failed AV get
000128: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_call_setup: Inserted ccb
000129: Oct 5 10:19:56.144: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container:
cch323_create_call_info_type_container: creating callInfoType container for callID = 10
000130: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_set_h245_state_mc_mode_outgoing: call_spi_mode = 3
000131: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_set_h245_state_mc_mode_outgoing: h245 state m/c mode=0x4F0, h323_ctl=0x0
000132: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: Entry
000133: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: Have peer
000134: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: faxrate[45] proto[3] bitmask[10082] t38_inhibit[0] global_fax[0] t38fax[0]
000135: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=16(20)
000136: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: Preferred codec set to G729IETF with Bytes = 20
000137: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH
000138: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_get_peer_info: peer: 48B19904, peer->voice_peer_tag: BB8, ccb: 49F6FE00
000139: Oct 5 10:19:56.144: //10/7661A559800A/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007]
000140: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028]
000141: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_update_setup_callinfo: callingNumber = 1001
000142: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_update_setup_callinfo: called_oct3 = 0x0, calling_oct3 = 0x0, calling_oct3a = 0x81
000143: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 1264
000144: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20
000145: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_call_setup: No account/pin number available
000146: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
000147: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_call_setup_normal: Entry
000148: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_call_setup_normal: SETUP_NTF_TIMER is not running. Continue processing.
000149: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_IDLE state
000150: Oct 5 10:19:56.148: //10/7661A559800A/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
000151: Oct 5 10:19:56.212: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000152: Oct 5 10:19:56.212: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM
000153: Oct 5 10:19:56.212: //10/7661A559800A/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE
000154: Oct 5 10:19:56.212: //10/7661A559800A/H323/check_qos_and_send_setup: Setup ccb 0x49F6FE00
000155: Oct 5 10:19:56.212: //10/7661A559800A/H323/cch323_rotary_validate: No peer_ccb available
000156: Oct 5 10:19:56.212: //10/7661A559800A/H323/send_setup: Entry
000157: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup: Entry
000158: Oct 5 10:19:56.212: //10/7661A559800A/H323/copy_token_from_ccb: copy_token_from_ccb: Entered
000159: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup:
generic_send_setup: is_overlap = 0, info_complete = 0
000160: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup: sending calling IE
000161: Oct 5 10:19:56.212: //10/7661A559800A/H323/cch323_get_embedded_obj_from_ccb: ccb=0x49F6FE00, tag=24, size=88
000162: Oct 5 10:19:56.212: //10/7661A559800A/H323/cch323_get_embedded_obj_from_ccb: Extraction FAILED
000163: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup: ====== PI = 0
000164: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup: Send infoXCap=128, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163
000165: Oct 5 10:19:56.212: //10/7661A559800A/H323/generic_send_setup: src address = 6.6.6.7; dest address = 3.3.3.3
000166: Oct 5 10:19:56.212: H225.0 OUTGOING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body setup :
{
protocolIdentifier { 0 0 8 2250 0 4 }
sourceInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
productId '436973636F47617465776179'H
versionId '32'H
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
}
}, h323 :
{
supportedPrefixes
{
}
}
}
}
mc FALSE
undefinedNode FALSE
}
activeMC FALSE
conferenceID '7661A559CFC211DF800AB8130721089B'H
conferenceGoal create : NULL
callType pointToPoint : NULL
sourceCallSignalAddress ipAddress :
{
ip '06060607'H
port 38972
}
callIdentifier
{
guid '7662DDA9CFC211DF800CB8130721089B'H
}
mediaWaitForConnect FALSE
canOverlapSend FALSE
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
000167: Oct 5 10:19:56.220: H225.0 OUTGOING ENCODE BUFFER::= 2080060008914A000428C0B50000120B436973636F47617465776179003240023C0501002C050100007661A559CFC211DF800AB8130721089B00CD0D8000070006060607983C11007662DDA9CFC211DF800CB8130721089B010001000180018010800100
000168: Oct 5 10:19:56.220:
000169: Oct 5 10:19:56.224: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_SETUP state
000170: Oct 5 10:19:56.224: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000171: Oct 5 10:19:56.476: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000172: Oct 5 10:19:56.476: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D55E4C, len=68, msgPtr=0x49D8C710
000173: Oct 5 10:19:56.476: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
000174: Oct 5 10:19:56.476: H225.0 INCOMING ENCODE BUFFER::= 21C0060008914A00042800B500001240013C05040100204000030303038152110C11007662DDA9CFC211DF800CB8130721089B0180018010800100
000175: Oct 5 10:19:56.476:
000176: Oct 5 10:19:56.476: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body callProceeding :
{
protocolIdentifier { 0 0 8 2250 0 4 }
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
h245Address ipAddress :
{
ip '03030303'H
port 33106
}
callIdentifier
{
guid '7662DDA9CFC211DF800CB8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
000177: Oct 5 10:19:56.484: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type CALLPROCIND_CHOSEN
000178: Oct 5 10:19:56.484: //10/7661A559800A/H323/callproc_ind: Entry
000179: Oct 5 10:19:56.484: //10/7661A559800A/H323/callproc_ind: ====== PI = 0
000180: Oct 5 10:19:56.484: //10/7661A559800A/H323/cch323_h225_receiver: CALLPROCIND_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
000181: Oct 5 10:19:56.484: //10/7661A559800A/H323/run_h225_sm: Received event H225_EV_CALLPROC_IND while at state H225_SETUP
000182: Oct 5 10:19:56.484: //10/7661A559800A/H323/h245_address_ind: ev=0
000183: Oct 5 10:19:56.484: //10/7661A559800A/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
000184: Oct 5 10:19:56.484: //10/7661A559800A/H323/callproc_notify: Peer not ready so not starting TCP
000185: Oct 5 10:19:56.484: //10/7661A559800A/H323/generic_callproc_notify: Entry
000186: Oct 5 10:19:56.484: //10/7661A559800A/CCAPI/cc_api_call_proceeding:
Interface=0x478B1418, Progress Indication=NULL(0)
000187: Oct 5 10:19:56.484: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_SETUP state to H225_CALLPROC state
000188: Oct 5 10:19:56.836: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000189: Oct 5 10:19:56.836: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D55E4C, len=74, msgPtr=0x49D55C08
000190: Oct 5 10:19:56.836: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
000191: Oct 5 10:19:56.836: H225.0 INCOMING ENCODE BUFFER::= 23C0060008914A00042800B500001240013C050401002040000303030381521B0C0011007662DDA9CFC211DF800CB8130721089B0180018010800100
000192: Oct 5 10:19:56.836:
000193: Oct 5 10:19:56.836: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body alerting :
{
protocolIdentifier { 0 0 8 2250 0 4 }
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
h245Address ipAddress :
{
ip '03030303'H
port 33106
}
callIdentifier
{
guid '7662DDA9CFC211DF800CB8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
000194: Oct 5 10:19:56.840: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type ALERTIND_CHOSEN
000195: Oct 5 10:19:56.844: //10/7661A559800A/H323/alert_ind: ====== PI = 0
000196: Oct 5 10:19:56.844: //10/7661A559800A/H323/alert_ind: alert ind ie_bit_mask 0x5E60, displayInfo
000197: Oct 5 10:19:56.844: //10/7661A559800A/H323/alert_ind: Rcvd ALERT Display Info IE =
000198: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_put_embedded_obj_to_ccb: ccb=0x49F6FE00, tag=17, size=83
000199: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_put_embedded_obj_to_ccb: Insertion PASSED, embedded at 0x49F72638
000200: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_h225_receiver: ALERTIND_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
000201: Oct 5 10:19:56.844: //10/7661A559800A/H323/run_h225_sm: Received event H225_EV_ALERT_IND while at state H225_CALLPROC
000202: Oct 5 10:19:56.844: //10/7661A559800A/H323/h245_address_ind: ev=0
000203: Oct 5 10:19:56.844: //10/7661A559800A/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
000204: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_get_embedded_obj_from_ccb: ccb=0x49F6FE00, tag=17, size=83
000205: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_get_embedded_obj_from_ccb: Extraction PASSED from 0x49F72638
000206: Oct 5 10:19:56.844: //10/7661A559800A/H323/generic_alert_notify: aData display_info
000207: Oct 5 10:19:56.844: //10/7661A559800A/CCAPI/cc_api_call_alert:
Interface=0x478B1418, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
000208: Oct 5 10:19:56.844: //10/7661A559800A/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
000209: Oct 5 10:19:56.844: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_CALLPROC state to H225_ALERT state
000210: Oct 5 10:19:56.844: //9/7661A559800A/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
000211: Oct 5 10:19:56.844: //9/7661A559800A/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
000212: Oct 5 10:19:56.848: //9/7661A559800A/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=9
000213: Oct 5 10:19:56.848: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2423dd8b96
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772497
To: <3001>;tag=39F76DC-E92
Date: Tue, 05 Oct 2010 14:19:56 GMT
Call-ID: 9ee9bd00-cab1340b-1d-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <3001>;party=called;screen=no;privacy=off
Contact: <3001>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
000214: Oct 5 10:20:04.448: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000215: Oct 5 10:20:04.448: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D55E4C, len=93, msgPtr=0x49D55CF0
000216: Oct 5 10:20:04.448: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
000217: Oct 5 10:20:04.448: H225.0 INCOMING ENCODE BUFFER::= 22C0060008914A0004000303030381522800B500001240013C050401002040007661A559CFC211DF800AB8130721089B1D0C0011007662DDA9CFC211DF800CB8130721089B0180018010800100
000218: Oct 5 10:20:04.448:
000219: Oct 5 10:20:04.448: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body connect :
{
protocolIdentifier { 0 0 8 2250 0 4 }
h245Address ipAddress :
{
ip '03030303'H
port 33106
}
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
conferenceID '7661A559CFC211DF800AB8130721089B'H
callIdentifier
{
guid '7662DDA9CFC211DF800CB8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
000220: Oct 5 10:20:04.456: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type SETUPCFM_CHOSEN
000221: Oct 5 10:20:04.456: //10/7661A559800A/H323/setup_cfm_ind: ====== PI = 0
000222: Oct 5 10:20:04.456: //10/7661A559800A/H323/setup_cfm_ind: Set new event H225_EV_SETUP_CFM_IND
000223: Oct 5 10:20:04.456: //10/7661A559800A/H323/setup_cfm_ind: Rcvd CONNECT Display Info IE =
000224: Oct 5 10:20:04.456: //10/7661A559800A/H323/setup_cfm_ind: setup_cfm_ind:- Insertion PASSED
000225: Oct 5 10:20:04.456: //10/7661A559800A/H323/cch323_h225_receiver: SETUPCFM_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
000226: Oct 5 10:20:04.456: //10/7661A559800A/H323/run_h225_sm: Received event H225_EV_SETUP_CFM_IND while at state H225_ALERT
000227: Oct 5 10:20:04.456: //10/7661A559800A/H323/setup_cfm_notify: status = 8000009
000228: Oct 5 10:20:04.456: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_ALERT state to H225_WAIT_FOR_H245 state
000229: Oct 5 10:20:04.456: //10/7661A559800A/H323/h245_address_ind: ev=2
000230: Oct 5 10:20:04.456: //10/7661A559800A/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
000231: Oct 5 10:20:04.456: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H245 IWF SM
000232: Oct 5 10:20:04.456: //10/7661A559800A/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECT_REQ while at state IWF_IDLE
000233: Oct 5 10:20:04.456: //10/7661A559800A/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_CONNECT_REQ_EVENT
000234: Oct 5 10:20:04.456: //10/7661A559800A/H323/cch323_h245_connection_sm: state=0, event=1, ccb=49F6FE00, listen state=0
000235: Oct 5 10:20:04.456: //10/7661A559800A/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_CONNECT_REQ_EVENT while at H245_NONE state
000236: Oct 5 10:20:04.460: //10/7661A559800A/H323/cch323_h245_set_new_state: Changing from H245_NONE state to H245_WAITING state
000237: Oct 5 10:20:04.460: //10/7661A559800A/H323/h245_iwf_set_new_state: changing from IWF_IDLE state to IWF_AWAIT_H245_CONN state
000238: Oct 5 10:20:04.460: //10/7661A559800A/H323/h245_connect_init: connection pending
000239: Oct 5 10:20:04.512: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
000240: Oct 5 10:20:04.512: //10/7661A559800A/H323/cch323_h245_channel_established_ind: Using fd=4 to send msgs
000241: Oct 5 10:20:04.512: //10/7661A559800A/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_ESTABLISHED_EVENT
000242: Oct 5 10:20:04.512: //10/7661A559800A/H323/cch323_h245_connection_sm: state=1, event=2, ccb=49F6FE00, listen state=0
000243: Oct 5 10:20:04.512: //10/7661A559800A/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_ESTABLISHED_EVENT while at H245_WAITING state
000244: Oct 5 10:20:04.512: //10/7661A559800A/H323/cch323_h245_set_new_state: Changing from H245_WAITING state to H245_CONNECTED state
000245: Oct 5 10:20:04.512: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2 internal event to H245 IWF SM
000246: Oct 5 10:20:04.512: //10/7661A559800A/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECTED while at state IWF_AWAIT_H245_CONN
000247: Oct 5 10:20:04.512: //10/7661A559800A/H323/h245_iwf_set_new_state: changing from IWF_AWAIT_H245_CONN state to IWF_H245_CONNECTED state
000248: Oct 5 10:20:04.512: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
000249: Oct 5 10:20:04.712: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
000250: Oct 5 10:20:04.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49F6FE00, len=286, msgPtr=0x49F72AE0
000251: Oct 5 10:20:04.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245
000252: Oct 5 10:20:04.712: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 286
000253: Oct 5 10:20:04.712: H245 MSC INCOMING ENCODE BUFFER::= 027001060008817500078013800014000100000100000100000CC001000100148000184810B50000120C52747044746D6652656C6179000080001E83015080001D83014080001A83011080001421C0138000132180138000122140138000102020B500001209436C6561724368696480000522C00180000422800180000C2400010180000D2408010180000E220000C0000F2020B5000012074737323331617280000A22000040000220C0138000032040138000092240078000082020B500001207473732367233328000072020B500001207473732367232348000062020B50000120747373236723136008001021100040005000C000D0002000300060007000800100009000F000E000A000A00120013001402001D001A001800001E
000254: Oct 5 10:20:04.716:
000255: Oct 5 10:20:04.716: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= request : terminalCapabilitySet :
{
sequenceNumber 1
protocolIdentifier { 0 0 8 245 0 7 }
multiplexCapability h2250Capability :
{
maximumAudioDelayJitter 20
receiveMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
transmitMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
receiveAndTransmitMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
mcCapability
{
centralizedConferenceMC FALSE
decentralizedConferenceMC FALSE
}
rtcpVideoControlCapability FALSE
mediaPacketizationCapability
{
h261aVideoPacketization FALSE
}
logicalChannelSwitchingCapability FALSE
t120DynamicPortCapability FALSE
}
capabilityTable
{
{
capabilityTableEntryNumber 25
capability receiveAndTransmitDataApplicationCapability :
{
application nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '52747044746D6652656C6179'H
}
maxBitRate 0
}
},
{
capabilityTableEntryNumber 31
capability receiveUserInputCapability : hookflash : NULL
},
{
capabilityTableEntryNumber 30
capability receiveUserInputCapability : dtmf : NULL
},
{
capabilityTableEntryNumber 27
capability receiveUserInputCapability : basicString : NULL
},
{
capabilityTableEntryNumber 21
capability receiveAudioCapability : g722-48k : 20
},
{
capabilityTableEntryNumber 20
capability receiveAudioCapability : g722-56k : 20
},
{
capabilityTableEntryNumber 19
capability receiveAudioCapability : g722-64k : 20
},
{
capabilityTableEntryNumber 17
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '436C65617243686964'H
}
},
{
capabilityTableEntryNumber 6
capability receiveAudioCapability : g729AnnexA : 2
},
{
capabilityTableEntryNumber 5
capability receiveAudioCapability : g729 : 2
},
{
capabilityTableEntryNumber 13
capability receiveAudioCapability : g729wAnnexB : 2
},
{
capabilityTableEntryNumber 14
capability receiveAudioCapability : g729AnnexAwAnnexB : 2
},
{
capabilityTableEntryNumber 15
capability receiveAudioCapability : g7231 :
{
maxAl-sduAudioFrames 1
silenceSuppression TRUE
}
},
{
capabilityTableEntryNumber 16
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373233316172'H
}
},
{
capabilityTableEntryNumber 11
capability receiveAudioCapability : g7231 :
{
maxAl-sduAudioFrames 1
silenceSuppression FALSE
}
},
{
capabilityTableEntryNumber 3
capability receiveAudioCapability : g711Ulaw64k : 20
},
{
capabilityTableEntryNumber 4
capability receiveAudioCapability : g711Alaw64k : 20
},
{
capabilityTableEntryNumber 10
capability receiveAudioCapability : g728 : 8
},
{
capabilityTableEntryNumber 9
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723332'H
}
},
{
capabilityTableEntryNumber 8
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723234'H
}
},
{
capabilityTableEntryNumber 7
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723136'H
}
}
}
capabilityDescriptors
{
{
capabilityDescriptorNumber 1
simultaneousCapabilities
{
{
5,
6,
13,
14,
3,
4,
7,
8,
9,
17,
10,
16,
15,
11,
11,
19,
20,
21
},
{
30,
27,
25
},
{
31
}
}
}
}
}
000256: Oct 5 10:20:04.740: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
000257: Oct 5 10:20:04.740: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
000258: Oct 5 10:20:04.740: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(10):setting mask for 729ar8also as 729 is configured
000259: Oct 5 10:20:04.740: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(10):setting mask for 729ar8also as 729 is configured
000260: Oct 5 10:20:04.740: //10/7661A559800A/H323/cch323_h245_cap_ind: Masks au=0x7000B9FF data=0x2 uinp=0x32
000261: Oct 5 10:20:04.740: //10/7661A559800A/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_IND while at state IDLE
000262: Oct 5 10:20:04.744: //10/7661A559800A/H323/h245_cap_in_set_new_state: changing from IDLE state to AWAITING_RESPONSE state
000263: Oct 5 10:20:04.744: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x4 internal event to H245 IWF SM
000264: Oct 5 10:20:04.744: //10/7661A559800A/H323/run_h245_iwf_sm: received IWF_EV_CAP_IND while at state IWF_H245_CONNECTED
000265: Oct 5 10:20:04.744: //10/7661A559800A/H323/h323_validate_cap_ind: Remote Pref Codecs UnOrdered (0x7000B9FF) = [G729IETF] [G729a] [G729b] [G729ab] [G711_ULAW_64K] [G711_ALAW_64K] [G726r16] [G726r24] [G726r32] [CLEARCHANNEL] [G728] [G723ar63] [G723r63] [G72264] [G72256] [G72248] []
000266: Oct 5 10:20:04.744: //10/7661A559800A/H323/h245_handle_cap_ind: TCS received from remote end. Setting h245 status flag H245_CAP_REQUEST_RCVD
000267: Oct 5 10:20:04.744: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(10):setting mask for 729ar8also as 729 is configured
000268: Oct 5 10:20:04.744: //10/7661A559800A/H323/cch323_set_extended_caps: Copying codec list into extended caps structure
000269: Oct 5 10:20:04.744: //10/7661A559800A/H323/cch323_set_extended_caps: G729IETF
000270: Oct 5 10:20:04.744: //10/7661A559800A/H323/cch323_set_extended_caps: G729a
000271: Oct 5 10:20:04.744: //10/7661A559800A/H323/cch323_iwf_cap_notify: Mask sent to other leg=C
000272: Oct 5 10:20:04.744: //10/7661A559800A/CCAPI/cc_api_caps_ind:
Destination Interface=0x0, Destination Call Id=-1, Source Call Id=10,
Caps(Codec=0xC, Fax Rate=0x2, Vad=0x2,
Modem=0x0, Codec Bytes=20, Signal Type=2)
000273: Oct 5 10:20:04.744: //10/7661A559800A/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
000274: Oct 5 10:20:04.748: //9/7661A559800A/CCAPI/cc_api_call_disconnected:
Cause Value=65, Interface=0x4705BD7C, Call Id=9
000275: Oct 5 10:20:04.748: //9/7661A559800A/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=65, Retry Count=0)
000276: Oct 5 10:20:04.748: //9/7661A559800A/CCAPI/cc_api_caps_ack:
Destination Interface=0x0, Destination Call Id=-1, Source Call Id=9,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=2050)
000277: Oct 5 10:20:04.748: //10/7661A559800A/H323/cch323_h225_sent_deferred_setup_cfm_notify: ====== PI = 0; status = 8000019
000278: Oct 5 10:20:04.748: //10/7661A559800A/CCAPI/cc_api_call_connected:
Interface=0x478B1418, Data Bitmask=0x1, Progress Indication=NULL(0),
Connection Handle=0
000279: Oct 5 10:20:04.748: //10/7661A559800A/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
000280: Oct 5 10:20:04.748: //10/7661A559800A/H323/cch323_modify_rtcp_session_parameters: updating RTP session params, h245.iwf_state = 2,h245.status = 21020040, in_type = 3, flag = 0
000281: Oct 5 10:20:04.748: //10/7661A559800A/H323/h245_handle_cap_ind: TCS ack is deferred
000282: Oct 5 10:20:04.752: //10/7661A559800A/H323/h245_iwf_set_new_state: changing from IWF_H245_CONNECTED state to IWF_AWAIT_PEER_CAP state
000283: Oct 5 10:20:04.752: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 501 Not Implemented
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2423dd8b96
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772497
To: <3001>;tag=39F76DC-E92
Date: Tue, 05 Oct 2010 14:19:56 GMT
Call-ID: 9ee9bd00-cab1340b-1d-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow-Events: telephone-event
Reason: Q.850;cause=65
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
000284: Oct 5 10:20:04.756: //-1/xxxxxxxxxxxx/H323/cch323_post_call_statistics: callID=10
000285: Oct 5 10:20:04.756: //10/7661A559800A/CCAPI/ccCallDisconnect:
Cause Value=65, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
000286: Oct 5 10:20:04.756: //10/7661A559800A/CCAPI/ccCallDisconnect:
Cause Value=65, Call Entry(Responsed=TRUE, Cause Value=65)
000287: Oct 5 10:20:04.756: //10/7661A559800A/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
000288: Oct 5 10:20:04.756: //9/7661A559800A/CCAPI/ccCallDisconnect:
Cause Value=65, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=65)
000289: Oct 5 10:20:04.756: //9/7661A559800A/CCAPI/ccCallDisconnect:
Cause Value=65, Call Entry(Responsed=TRUE, Cause Value=65)
000290: Oct 5 10:20:04.760: //9/7661A559800A/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x4705BD7C, Tag=0x0, Call Id=9,
Call Entry(Disconnect Cause=65, Voice Class Cause Code=0, Retry Count=0)
000291: Oct 5 10:20:04.760: //9/7661A559800A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
000292: Oct 5 10:20:04.760: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
000293: Oct 5 10:20:04.760: :cc_free_feature_vsa freeing 49E81050
000294: Oct 5 10:20:04.760: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
000295: Oct 5 10:20:04.760: vsacount in free is 1
000296: Oct 5 10:20:04.764: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:3001@6.6.6.7:5060 SIP/2.0
Date: Tue, 05 Oct 2010 14:19:55 GMT
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772497
Allow-Events: presence, kpml
Content-Length: 0
To: <3001>;tag=39F76DC-E92
Call-ID: 9ee9bd00-cab1340b-1d-14c8010a@10.1.200.20
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2423dd8b96
CSeq: 101 ACK
Max-Forwards: 70
000297: Oct 5 10:20:04.768: //10/7661A559800A/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm
000298: Oct 5 10:20:04.768: //10/7661A559800A/H323/run_h245_iwf_sm: received IWF_EV_PEER_CAPS_ACK while at state IWF_AWAIT_PEER_CAP
000299: Oct 5 10:20:04.768: //10/7661A559800A/H323/cch323_do_call_disconnect: gw_id=1, discCause=65
000300: Oct 5 10:20:04.768: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM
000301: Oct 5 10:20:04.768: //10/7661A559800A/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_WAIT_FOR_H245
000302: Oct 5 10:20:04.768: //10/7661A559800A/H323/cch323_h225_send_release: Cause = 65; Location = 0
000303: Oct 5 10:20:04.768: //10/7661A559800A/H323/cch323_h225_send_release: h225TerminateRequest: src address = 101058055; dest address = 3.3.3.3
000304: Oct 5 10:20:04.768: H225.0 OUTGOING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body releaseComplete :
{
protocolIdentifier { 0 0 8 2250 0 4 }
callIdentifier
{
guid '7662DDA9CFC211DF800CB8130721089B'H
}
}
h245Tunneling FALSE
}
}
000305: Oct 5 10:20:04.768: H225.0 OUTGOING ENCODE BUFFER::= 2580060008914A0004110011007662DDA9CFC211DF800CB8130721089B10800100
000306: Oct 5 10:20:04.768:
000307: Oct 5 10:20:04.772: //10/7661A559800A/H323/cch323_h225_set_new_state: Changing from H225_WAIT_FOR_H245 state to H225_IDLE state
000308: Oct 5 10:20:04.772: //10/7661A559800A/H323/cch323_call_generic_cleanup: Disconnected flag 1
000309: Oct 5 10:20:04.772: //10/7661A559800A/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
000310: Oct 5 10:20:04.772: //10/7661A559800A/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
000311: Oct 5 10:20:04.772: //10/7661A559800A/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_AWAIT_PEER_CAP
000312: Oct 5 10:20:04.772: //10/7661A559800A/H323/defaultHdlr: DEFAULT: Received IWF_EV_H245_DISCONN in state IWF_AWAIT_PEER_CAP
000313: Oct 5 10:20:04.772: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 4
000314: Oct 5 10:20:04.772: //10/7661A559800A/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x478B1418, Tag=0x0, Call Id=10,
Call Entry(Disconnect Cause=65, Voice Class Cause Code=0, Retry Count=0)
000315: Oct 5 10:20:04.772: //10/7661A559800A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
000316: Oct 5 10:20:04.772: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
000317: Oct 5 10:20:04.776: :cc_free_feature_vsa freeing 49E80F70
000318: Oct 5 10:20:04.776: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
000319: Oct 5 10:20:04.776: vsacount in free is 0
000320: Oct 5 10:20:04.776: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x49F6FE00)
000321: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
000322: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D55E4C, len=46, msgPtr=0x49D8C6B8
000323: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
000324: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/validate_crv: No CCB for crv: 0x9
000325: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Parse error RXDATA_NONE
000326: Oct 5 10:20:05.104: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: CRV entry not found, returning
000327: Oct 5 10:20:22.820: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_RAS_PERIODIC_RRQ_TIMER] expired
000328: Oct 5 10:20:22.820: //-1/xxxxxxxxxxxx/H323/cch323_send_event_to_ras: Queued event CCH323_RAS_EVENT_SEND_LT_RRQ to RAS Global SM
000329: Oct 5 10:20:22.820: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xA internal event to RAS Global SM
000330: Oct 5 10:20:22.820: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_SEND_LT_RRQ while at CCH323_RAS_STATE_IDLE state
000331: Oct 5 10:20:22.820: RAS OUTGOING PDU ::=
value RasMessage ::= registrationRequest :
{
requestSeqNum 1264
protocolIdentifier { 0 0 8 2250 0 4 }
discoveryComplete TRUE
callSignalAddress
{
}
rasAddress
{
ipAddress :
{
ip '06060607'H
port 63383
}
}
terminalType
{
mc FALSE
undefinedNode FALSE
}
gatekeeperIdentifier {"ZONE_01"}
endpointVendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
timeToLive 60
keepAlive TRUE
endpointIdentifier {"672C9F6C00000001"}
willSupplyUUIEs FALSE
maintainConnection TRUE
}
000332: Oct 5 10:20:22.824: RAS OUTGOING ENCODE BUFFER::= 0E4004EF060008914A00048000010006060607F7970006005A004F004E0045005F0030003100B5000012288F000002003B0180211E003600370032004300390046003600430030003000300030003000300030003101000180
000333: Oct 5 10:20:22.824:
000334: Oct 5 10:20:22.824: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_RRQ state
000335: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
000336: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D57F60, len=70, msgPtr=0x49D564A4
000337: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for RAS
000338: Oct 5 10:20:22.888: RAS INCOMING ENCODE BUFFER::= 124004EF060008914A0004000C005A004F004E0045005F003000311E0036003700320043003900460036004300300030003000300030003000300031208A0002003B01000180
000339: Oct 5 10:20:22.888:
000340: Oct 5 10:20:22.888: RAS INCOMING PDU ::=
value RasMessage ::= registrationConfirm :
{
requestSeqNum 1264
protocolIdentifier { 0 0 8 2250 0 4 }
callSignalAddress
{
}
gatekeeperIdentifier {"ZONE_01"}
endpointIdentifier {"672C9F6C00000001"}
timeToLive 60
willRespondToIRR FALSE
maintainConnection TRUE
}
000341: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_ras_handle_recv_msg: received msg of type RCF_CHOSEN
000342: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_RCF while at CCH323_RAS_STATE_RRQ state
000343: Oct 5 10:20:22.888: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_IDLE state
ISR#
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 07:53 AM
You're matching 3001 in, and 3000 out:
dial-peer voice 3000 voip
destination-pattern 3...
session target ipv4:3.3.3.3
!
dial-peer voice 3001 voip
incoming called-number 3...
codec g711ulaw
Your transcoder has the following codecs configured:
dspfarm profile 1 transcode
codec g711ulaw
codec g711alaw
codec g729ar8
codec g729abr8
codec g711ulaw
codec g711alaw
codec g729ar8
codec g729abr8
The (default) codec configured under peer 3000 is g729r8. Hence, this call is going to need to do g729r8<->g711ulaw. The transcoder doesn't have g729r8 configured, though. Hence, there is a codec mismatch on the h323 peer when the TCS comes in, so we never negotiate h245 to send the 200 OK out the SIP leg with media.
Try adding g729r8 to the transcoder profile.
Also, you are missing some commands on these peers; add:
dial-peer voice 3000 voip
dtmf-relay h245-alpha
dial-peer voice 3001 voip
session protocol sip
drmf-relay rtp-nte
If you still see issues after this, collect the debugs and new config again and we'll look at things further.
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 08:40 AM
Steven,
Thanks for taking a look at this. I made the changes you mentioned but I still get fast busy on 1001 when 3001 picks up. I even did a "no sccp, sccp" on the router to see if that did anything.
----- Config -----
dspfarm profile 1 transcode
codec g711ulaw
codec g711alaw
codec g729ar8
codec g729abr8
codec g729r8
maximum sessions 3
associate application SCCP
dial-peer voice 3000 voip
destination-pattern 3...
session target ipv4:3.3.3.3
dtmf-relay h245-alphanumeric
!
dial-peer voice 3001 voip
session protocol sipv2
incoming called-number 3...
dtmf-relay rtp-nte
codec g711ulaw
------ Debug ------
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.10.05 11:11:11 =~=~=~=~=~=~=~=~=~=~=~=
sh log
Syslog logging: enabled (0 messages dropped, 3 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: disabled
Buffer logging: level debugging, 3535 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 66 message lines logged
Log Buffer (10000000 bytes):
002197: Oct 5 11:10:43.511: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_RAS_PERIODIC_RRQ_TIMER] expired
002198: Oct 5 11:10:43.511: //-1/xxxxxxxxxxxx/H323/cch323_send_event_to_ras: Queued event CCH323_RAS_EVENT_SEND_LT_RRQ to RAS Global SM
002199: Oct 5 11:10:43.511: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xA internal event to RAS Global SM
002200: Oct 5 11:10:43.511: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_SEND_LT_RRQ while at CCH323_RAS_STATE_IDLE state
002201: Oct 5 11:10:43.511: RAS OUTGOING PDU ::=
value RasMessage ::= registrationRequest :
{
requestSeqNum 1331
protocolIdentifier { 0 0 8 2250 0 4 }
discoveryComplete TRUE
callSignalAddress
{
}
rasAddress
{
ipAddress :
{
ip '06060607'H
port 63383
}
}
terminalType
{
mc FALSE
undefinedNode FALSE
}
gatekeeperIdentifier {"ZONE_01"}
endpointVendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
timeToLive 60
keepAlive TRUE
endpointIdentifier {"672C9F6C00000001"}
willSupplyUUIEs FALSE
maintainConnection TRUE
}
002202: Oct 5 11:10:43.515: RAS OUTGOING ENCODE BUFFER::=
0E400532060008914A00048000010006060607F7970006005A004F004E0045005F0030003100B5000012288F000002003B0180211E0036003700320043003900460036004300300030003000
30003000300030003101000180
002203: Oct 5 11:10:43.515:
002204: Oct 5 11:10:43.515: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_RRQ state
002205: Oct 5 11:10:43.575: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
002206: Oct 5 11:10:43.575: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D57F60, len=70, msgPtr=0x49D564A4
002207: Oct 5 11:10:43.575: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for RAS
002208: Oct 5 11:10:43.575: RAS INCOMING ENCODE BUFFER::=
12400532060008914A0004000C005A004F004E0045005F003000311E0036003700320043003900460036004300300030003000300030003000300031208A0002003B01000180
002209: Oct 5 11:10:43.579:
002210: Oct 5 11:10:43.579: RAS INCOMING PDU ::=
value RasMessage ::= registrationConfirm :
{
requestSeqNum 1331
protocolIdentifier { 0 0 8 2250 0 4 }
callSignalAddress
{
}
gatekeeperIdentifier {"ZONE_01"}
endpointIdentifier {"672C9F6C00000001"}
timeToLive 60
willRespondToIRR FALSE
maintainConnection TRUE
}
002211: Oct 5 11:10:43.579: //-1/xxxxxxxxxxxx/H323/cch323_ras_handle_recv_msg: received msg of type RCF_CHOSEN
002212: Oct 5 11:10:43.579: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: received event CCH323_RAS_EVENT_RCF while at CCH323_RAS_STATE_RRQ state
002213: Oct 5 11:10:43.579: //-1/xxxxxxxxxxxx/H323/cch323_run_ras_sm: changing to CCH323_RAS_STATE_IDLE state
002214: Oct 5 11:10:45.539: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:3001@6.6.6.7:5060 SIP/2.0
Date: Tue, 05 Oct 2010 15:10:45 GMT
Call-Info: <10.1.200.20:5060>;method="NOTIFY;Event=telephone-event;Duration=500"
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772505
Allow-Events: presence, kpml
P-Asserted-Identity: <1001>
Supported: timer,resource-priority,replaces
Supported: Geolocation
Min-SE: 1800
Remote-Party-ID: <1001>;party=calling;screen=yes;privacy=off
Content-Length: 0
User-Agent: Cisco-CUCM7.1
To: <3001>
Contact: <1001>
Expires: 180
Call-ID: b8dace00-cab13ff5-21-14c8010a@10.1.200.20
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2819902ba8
CSeq: 101 INVITE
Session-Expires: 1800
Max-Forwards: 70
002215: Oct 5 11:10:45.547: //-1/8FFB61928022/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=1001
----- ccCallInfo IE subfields -----
cisco-ani=1001
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=3001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
002216: Oct 5 11:10:45.551: //-1/8FFB61928022/CCAPI/cc_api_call_setup_ind_common:
Interface=0x4705BD7C, Call Info(
Calling Number=1001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=3001, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=17
002217: Oct 5 11:10:45.551: //-1/8FFB61928022/CCAPI/ccCheckClipClir:
In: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
002218: Oct 5 11:10:45.551: //-1/8FFB61928022/CCAPI/ccCheckClipClir:
Out: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
002219: Oct 5 11:10:45.551: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002220: Oct 5 11:10:45.551: :cc_get_feature_vsa malloc success
002221: Oct 5 11:10:45.551: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002222: Oct 5 11:10:45.551: cc_get_feature_vsa count is 1
002223: Oct 5 11:10:45.551: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002224: Oct 5 11:10:45.551: :FEATURE_VSA attributes are: feature_name:0,feature_time:1199917512,feature_id:17
002225: Oct 5 11:10:45.551: //17/8FFB61928022/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown))
002226: Oct 5 11:10:45.555: //17/8FFB61928022/CCAPI/cc_process_call_setup_ind:
Event=0x472D5190
002227: Oct 5 11:10:45.555: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 3001
002228: Oct 5 11:10:45.555: //17/8FFB61928022/CCAPI/ccCallSetContext:
Context=0x464821E4
002229: Oct 5 11:10:45.555: //17/8FFB61928022/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 17 with tag 3001 to app "_ManagedAppProcess_Default"
002230: Oct 5 11:10:45.555: //17/8FFB61928022/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
002231: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=3000, Params=0x4648353C, Progress Indication=NULL(0)
002232: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/ccCheckClipClir:
In: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
002233: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/ccCheckClipClir:
Out: Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
002234: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/ccCallSetupRequest:
Destination Pattern=3..., Called Number=3001, Digit Strip=FALSE
002235: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/ccCallSetupRequest:
Calling Number=1001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=1001, Final Destination Flag=TRUE,
Guid=8FFB6192-CFC9-11DF-8022-B8130721089B, Outgoing Dial-peer=3000
002236: Oct 5 11:10:45.559: //17/8FFB61928022/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=1001
----- ccCallInfo IE subfields -----
cisco-ani=1001
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=3001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
002237: Oct 5 11:10:45.563: //17/8FFB61928022/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x478B1418, Interface Type=1, Destination=, Mode=0x0,
Call Params(Calling Number=1001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=3001(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=3000, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
002238: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002239: Oct 5 11:10:45.563: :cc_get_feature_vsa malloc success
002240: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002241: Oct 5 11:10:45.563: cc_get_feature_vsa count is 2
002242: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002243: Oct 5 11:10:45.563: :FEATURE_VSA attributes are: feature_name:0,feature_time:1199917288,feature_id:18
002244: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=18
002245: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0
002246: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0
002247: Oct 5 11:10:45.563: //18/8FFB61928022/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
002248: Oct 5 11:10:45.563: //18/8FFB61928022/CCAPI/ccCallSetContext:
Context=0x464834EC
002249: Oct 5 11:10:45.563: //17/8FFB61928022/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=3000
002250: Oct 5 11:10:45.563: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x49F6FE00) is in use
002251: Oct 5 11:10:45.563: //18/8FFB61928022/H323/cch323_call_setup: gw_id=1
002252: Oct 5 11:10:45.567: //-1/xxxxxxxxxxxx/H323/h323_TD_get_mlpp_info: callID=18, tag=(CC_TAG_MLPP_INFO), Failed AV get
002253: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_call_setup: Inserted ccb
002254: Oct 5 11:10:45.567: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container:
cch323_create_call_info_type_container: creating callInfoType container for callID = 18
002255: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h245_state_mc_mode_outgoing: call_spi_mode = 3
002256: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h245_state_mc_mode_outgoing: h245 state m/c mode=0x4F0, h323_ctl=0x0
002257: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: Entry
002258: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: Have peer
002259: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: faxrate[45] proto[3] bitmask[10082] t38_inhibit[0] global_fax[0] t38fax[0]
002260: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=16(20)
002261: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: Preferred codec set to G729IETF with Bytes = 20
002262: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH
002263: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_get_peer_info: peer: 48B19904, peer->voice_peer_tag: BB8, ccb: 49F6FE00
002264: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007]
002265: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028]
002266: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_update_setup_callinfo: callingNumber = 1001
002267: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_update_setup_callinfo: called_oct3 = 0x0, calling_oct3 = 0x0, calling_oct3a = 0x81
002268: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 1264
002269: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20
002270: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_call_setup: No account/pin number available
002271: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
002272: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_call_setup_normal: Entry
002273: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_call_setup_normal: SETUP_NTF_TIMER is not running. Continue processing.
002274: Oct 5 11:10:45.567: //-1/xxxxxxxxxxxx/H323/cch323_h225FD_Print: fd [3] Accepts newcall
002275: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_IDLE state
002276: Oct 5 11:10:45.567: //18/8FFB61928022/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
002277: Oct 5 11:10:45.571: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM
002278: Oct 5 11:10:45.571: //18/8FFB61928022/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE
002279: Oct 5 11:10:45.571: //18/8FFB61928022/H323/check_qos_and_send_setup: Setup ccb 0x49F6FE00
002280: Oct 5 11:10:45.571: //18/8FFB61928022/H323/cch323_rotary_validate: No peer_ccb available
002281: Oct 5 11:10:45.571: //18/8FFB61928022/H323/send_setup: Entry
002282: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup: Entry
002283: Oct 5 11:10:45.571: //18/8FFB61928022/H323/copy_token_from_ccb: copy_token_from_ccb: Entered
002284: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup:
generic_send_setup: is_overlap = 0, info_complete = 0
002285: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup: sending calling IE
002286: Oct 5 11:10:45.571: //18/8FFB61928022/H323/cch323_get_embedded_obj_from_ccb: ccb=0x49F6FE00, tag=24, size=88
002287: Oct 5 11:10:45.571: //18/8FFB61928022/H323/cch323_get_embedded_obj_from_ccb: Extraction FAILED
002288: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup: ====== PI = 0
002289: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup: Send infoXCap=128, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163
002290: Oct 5 11:10:45.571: //18/8FFB61928022/H323/generic_send_setup: src address = 6.6.6.7; dest address = 3.3.3.3
002291: Oct 5 11:10:45.571: H225.0 OUTGOING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body setup :
{
protocolIdentifier { 0 0 8 2250 0 4 }
sourceInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
productId '436973636F47617465776179'H
versionId '32'H
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
}
}, h323 :
{
supportedPrefixes
{
}
}
}
}
mc FALSE
undefinedNode FALSE
}
activeMC FALSE
conferenceID '8FFB6192CFC911DF8022B8130721089B'H
conferenceGoal create : NULL
callType pointToPoint : NULL
sourceCallSignalAddress ipAddress :
{
ip '06060607'H
port 33693
}
callIdentifier
{
guid '8FFC9A7BCFC911DF8024B8130721089B'H
}
mediaWaitForConnect FALSE
canOverlapSend FALSE
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling TRUE
}
}
002292: Oct 5 11:10:45.579: H225.0 OUTGOING ENCODE BUFFER::=
2080060008914A000428C0B50000120B436973636F47617465776179003240023C0501002C050100008FFB6192CFC911DF8022B8130721089B00CD0D8000070006060607839D11008FFC9A7B
CFC911DF8024B8130721089B010001000180018010800180
002293: Oct 5 11:10:45.579:
002294: Oct 5 11:10:45.579: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_SETUP state
002295: Oct 5 11:10:45.579: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2819902ba8
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772505
To: <3001>
Date: Tue, 05 Oct 2010 15:10:45 GMT
Call-ID: b8dace00-cab13ff5-21-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
002296: Oct 5 11:10:46.135: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
002297: Oct 5 11:10:46.135: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D56518, len=68, msgPtr=0x49D8C500
002298: Oct 5 11:10:46.135: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
002299: Oct 5 11:10:46.135: H225.0 INCOMING ENCODE BUFFER::=
21C0060008914A00042800B500001240013C05040100204000030303039173110C11008FFC9A7BCFC911DF8024B8130721089B0180018010800100
002300: Oct 5 11:10:46.135:
002301: Oct 5 11:10:46.135: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body callProceeding :
{
protocolIdentifier { 0 0 8 2250 0 4 }
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
h245Address ipAddress :
{
ip '03030303'H
port 37235
}
callIdentifier
{
guid '8FFC9A7BCFC911DF8024B8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
002302: Oct 5 11:10:46.143: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type CALLPROCIND_CHOSEN
002303: Oct 5 11:10:46.143: //18/8FFB61928022/H323/callproc_ind: Entry
002304: Oct 5 11:10:46.143: //18/8FFB61928022/H323/callproc_ind: ====== PI = 0
002305: Oct 5 11:10:46.143: //18/8FFB61928022/H323/cch323_h225_process_h245_tunneling: Other end of call is dropping tunneling
002306: Oct 5 11:10:46.143: //18/8FFB61928022/H323/cch323_h225_receiver: CALLPROCIND_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
002307: Oct 5 11:10:46.143: //18/8FFB61928022/H323/run_h225_sm: Received event H225_EV_CALLPROC_IND while at state H225_SETUP
002308: Oct 5 11:10:46.143: //18/8FFB61928022/H323/h245_address_ind: ev=0
002309: Oct 5 11:10:46.143: //18/8FFB61928022/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
002310: Oct 5 11:10:46.143: //18/8FFB61928022/H323/callproc_notify: Peer not ready so not starting TCP
002311: Oct 5 11:10:46.143: //18/8FFB61928022/H323/generic_callproc_notify: Entry
002312: Oct 5 11:10:46.143: //18/8FFB61928022/CCAPI/cc_api_call_proceeding:
Interface=0x478B1418, Progress Indication=NULL(0)
002313: Oct 5 11:10:46.143: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_SETUP state to H225_CALLPROC state
002314: Oct 5 11:10:46.199: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
002315: Oct 5 11:10:46.199: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D56518, len=74, msgPtr=0x49D55B94
002316: Oct 5 11:10:46.199: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
002317: Oct 5 11:10:46.199: H225.0 INCOMING ENCODE BUFFER::=
23C0060008914A00042800B500001240013C050401002040000303030391731B0C0011008FFC9A7BCFC911DF8024B8130721089B0180018010800100
002318: Oct 5 11:10:46.199:
002319: Oct 5 11:10:46.199: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body alerting :
{
protocolIdentifier { 0 0 8 2250 0 4 }
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
h245Address ipAddress :
{
ip '03030303'H
port 37235
}
callIdentifier
{
guid '8FFC9A7BCFC911DF8024B8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
002320: Oct 5 11:10:46.203: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type ALERTIND_CHOSEN
002321: Oct 5 11:10:46.203: //18/8FFB61928022/H323/alert_ind: ====== PI = 0
002322: Oct 5 11:10:46.203: //18/8FFB61928022/H323/alert_ind: alert ind ie_bit_mask 0x5E60, displayInfo
002323: Oct 5 11:10:46.203: //18/8FFB61928022/H323/alert_ind: Rcvd ALERT Display Info IE =
002324: Oct 5 11:10:46.203: //18/8FFB61928022/H323/cch323_put_embedded_obj_to_ccb: ccb=0x49F6FE00, tag=17, size=83
002325: Oct 5 11:10:46.203: //18/8FFB61928022/H323/cch323_put_embedded_obj_to_ccb: Insertion PASSED, embedded at 0x49F72638
002326: Oct 5 11:10:46.207: //18/8FFB61928022/H323/cch323_h225_receiver: ALERTIND_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
002327: Oct 5 11:10:46.207: //18/8FFB61928022/H323/run_h225_sm: Received event H225_EV_ALERT_IND while at state H225_CALLPROC
002328: Oct 5 11:10:46.207: //18/8FFB61928022/H323/h245_address_ind: ev=0
002329: Oct 5 11:10:46.207: //18/8FFB61928022/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
002330: Oct 5 11:10:46.207: //18/8FFB61928022/H323/cch323_get_embedded_obj_from_ccb: ccb=0x49F6FE00, tag=17, size=83
002331: Oct 5 11:10:46.207: //18/8FFB61928022/H323/cch323_get_embedded_obj_from_ccb: Extraction PASSED from 0x49F72638
002332: Oct 5 11:10:46.207: //18/8FFB61928022/H323/generic_alert_notify: aData display_info
002333: Oct 5 11:10:46.207: //18/8FFB61928022/CCAPI/cc_api_call_alert:
Interface=0x478B1418, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
002334: Oct 5 11:10:46.207: //18/8FFB61928022/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
002335: Oct 5 11:10:46.207: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_CALLPROC state to H225_ALERT state
002336: Oct 5 11:10:46.207: //17/8FFB61928022/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
002337: Oct 5 11:10:46.207: //17/8FFB61928022/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
002338: Oct 5 11:10:46.207: //17/8FFB61928022/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=17
002339: Oct 5 11:10:46.211: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2819902ba8
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772505
To: <3001>;tag=3CDFE50-155
Date: Tue, 05 Oct 2010 15:10:45 GMT
Call-ID: b8dace00-cab13ff5-21-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <3001>;party=called;screen=no;privacy=off
Contact: <3001>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
002340: Oct 5 11:10:48.507: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
002341: Oct 5 11:10:48.507: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D56518, len=93, msgPtr=0x49D558DC
002342: Oct 5 11:10:48.507: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
002343: Oct 5 11:10:48.507: H225.0 INCOMING ENCODE BUFFER::=
22C0060008914A0004000303030391732800B500001240013C050401002040008FFB6192CFC911DF8022B8130721089B1D0C0011008FFC9A7BCFC911DF8024B8130721089B01800180108001
00
002344: Oct 5 11:10:48.507:
002345: Oct 5 11:10:48.507: H225.0 INCOMING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body connect :
{
protocolIdentifier { 0 0 8 2250 0 4 }
h245Address ipAddress :
{
ip '03030303'H
port 37235
}
destinationInfo
{
vendor
{
vendor
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
}
gateway
{
protocol
{
voice :
{
supportedPrefixes
{
{
prefix dialedDigits : "1#"
}
}
}
}
}
mc FALSE
undefinedNode FALSE
}
conferenceID '8FFB6192CFC911DF8022B8130721089B'H
callIdentifier
{
guid '8FFC9A7BCFC911DF8024B8130721089B'H
}
multipleCalls TRUE
maintainConnection TRUE
}
h245Tunneling FALSE
}
}
002346: Oct 5 11:10:48.515: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type SETUPCFM_CHOSEN
002347: Oct 5 11:10:48.515: //18/8FFB61928022/H323/setup_cfm_ind: ====== PI = 0
002348: Oct 5 11:10:48.515: //18/8FFB61928022/H323/setup_cfm_ind: Set new event H225_EV_SETUP_CFM_IND
002349: Oct 5 11:10:48.515: //18/8FFB61928022/H323/setup_cfm_ind: Rcvd CONNECT Display Info IE =
002350: Oct 5 11:10:48.515: //18/8FFB61928022/H323/setup_cfm_ind: setup_cfm_ind:- Insertion PASSED
002351: Oct 5 11:10:48.515: //18/8FFB61928022/H323/cch323_h225_receiver: SETUPCFM_CHOSEN: src address = 6.6.6.7; dest address = 3.3.3.3
002352: Oct 5 11:10:48.515: //18/8FFB61928022/H323/run_h225_sm: Received event H225_EV_SETUP_CFM_IND while at state H225_ALERT
002353: Oct 5 11:10:48.515: //18/8FFB61928022/H323/setup_cfm_notify: status = 8000009
002354: Oct 5 11:10:48.515: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_ALERT state to H225_WAIT_FOR_H245 state
002355: Oct 5 11:10:48.515: //18/8FFB61928022/H323/h245_address_ind: ev=2
002356: Oct 5 11:10:48.515: //18/8FFB61928022/CCAPI/ccIsInfoRingback:
Returning dpRingBack=0
002357: Oct 5 11:10:48.515: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H245 IWF SM
002358: Oct 5 11:10:48.515: //18/8FFB61928022/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECT_REQ while at state IWF_IDLE
002359: Oct 5 11:10:48.515: //18/8FFB61928022/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_CONNECT_REQ_EVENT
002360: Oct 5 11:10:48.515: //18/8FFB61928022/H323/cch323_h245_connection_sm: state=0, event=1, ccb=49F6FE00, listen state=0
002361: Oct 5 11:10:48.515: //18/8FFB61928022/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_CONNECT_REQ_EVENT while at H245_NONE
state
002362: Oct 5 11:10:48.519: //18/8FFB61928022/H323/cch323_h245_set_new_state: Changing from H245_NONE state to H245_WAITING state
002363: Oct 5 11:10:48.519: //18/8FFB61928022/H323/h245_iwf_set_new_state: changing from IWF_IDLE state to IWF_AWAIT_H245_CONN state
002364: Oct 5 11:10:48.519: //18/8FFB61928022/H323/h245_connect_init: connection pending
002365: Oct 5 11:10:48.619: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
002366: Oct 5 11:10:48.619: //18/8FFB61928022/H323/cch323_h245_channel_established_ind: Using fd=4 to send msgs
002367: Oct 5 11:10:48.619: //18/8FFB61928022/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_ESTABLISHED_EVENT
002368: Oct 5 11:10:48.619: //18/8FFB61928022/H323/cch323_h245_connection_sm: state=1, event=2, ccb=49F6FE00, listen state=0
002369: Oct 5 11:10:48.619: //18/8FFB61928022/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_ESTABLISHED_EVENT while at H245_WAITING
state
002370: Oct 5 11:10:48.619: //18/8FFB61928022/H323/cch323_h245_set_new_state: Changing from H245_WAITING state to H245_CONNECTED state
002371: Oct 5 11:10:48.619: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2 internal event to H245 IWF SM
002372: Oct 5 11:10:48.619: //18/8FFB61928022/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECTED while at state IWF_AWAIT_H245_CONN
002373: Oct 5 11:10:48.619: //18/8FFB61928022/H323/h245_iwf_set_new_state: changing from IWF_AWAIT_H245_CONN state to IWF_H245_CONNECTED state
002374: Oct 5 11:10:48.619: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
002375: Oct 5 11:10:48.723: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1
002376: Oct 5 11:10:48.723: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49F6FE00, len=286, msgPtr=0x46BD2774
002377: Oct 5 11:10:48.723: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245
002378: Oct 5 11:10:48.727: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 286
002379: Oct 5 11:10:48.727: H245 MSC INCOMING ENCODE BUFFER::=
027001060008817500078013800014000100000100000100000CC001000100148000184810B50000120C52747044746D6652656C6179000080001E83015080001D83014080001A8301108000
1421C0138000132180138000122140138000102020B500001209436C6561724368696480000522C00180000422800180000C2400010180000D2408010180000E220000C0000F2020B5000012
074737323331617280000A22000040000220C0138000032040138000092240078000082020B500001207473732367233328000072020B500001207473732367232348000062020B500001207
47373236723136008001021100040005000C000D0002000300060007000800100009000F000E000A000A00120013001402001D001A001800001E
002380: Oct 5 11:10:48.727:
002381: Oct 5 11:10:48.727: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= request : terminalCapabilitySet :
{
sequenceNumber 1
protocolIdentifier { 0 0 8 245 0 7 }
multiplexCapability h2250Capability :
{
maximumAudioDelayJitter 20
receiveMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
transmitMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
receiveAndTransmitMultipointCapability
{
multicastCapability FALSE
multiUniCastConference FALSE
mediaDistributionCapability
{
{
centralizedControl FALSE
distributedControl FALSE
centralizedAudio FALSE
distributedAudio FALSE
centralizedVideo FALSE
distributedVideo FALSE
}
}
}
mcCapability
{
centralizedConferenceMC FALSE
decentralizedConferenceMC FALSE
}
rtcpVideoControlCapability FALSE
mediaPacketizationCapability
{
h261aVideoPacketization FALSE
}
logicalChannelSwitchingCapability FALSE
t120DynamicPortCapability FALSE
}
capabilityTable
{
{
capabilityTableEntryNumber 25
capability receiveAndTransmitDataApplicationCapability :
{
application nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '52747044746D6652656C6179'H
}
maxBitRate 0
}
},
{
capabilityTableEntryNumber 31
capability receiveUserInputCapability : hookflash : NULL
},
{
capabilityTableEntryNumber 30
capability receiveUserInputCapability : dtmf : NULL
},
{
capabilityTableEntryNumber 27
capability receiveUserInputCapability : basicString : NULL
},
{
capabilityTableEntryNumber 21
capability receiveAudioCapability : g722-48k : 20
},
{
capabilityTableEntryNumber 20
capability receiveAudioCapability : g722-56k : 20
},
{
capabilityTableEntryNumber 19
capability receiveAudioCapability : g722-64k : 20
},
{
capabilityTableEntryNumber 17
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '436C65617243686964'H
}
},
{
capabilityTableEntryNumber 6
capability receiveAudioCapability : g729AnnexA : 2
},
{
capabilityTableEntryNumber 5
capability receiveAudioCapability : g729 : 2
},
{
capabilityTableEntryNumber 13
capability receiveAudioCapability : g729wAnnexB : 2
},
{
capabilityTableEntryNumber 14
capability receiveAudioCapability : g729AnnexAwAnnexB : 2
},
{
capabilityTableEntryNumber 15
capability receiveAudioCapability : g7231 :
{
maxAl-sduAudioFrames 1
silenceSuppression TRUE
}
},
{
capabilityTableEntryNumber 16
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373233316172'H
}
},
{
capabilityTableEntryNumber 11
capability receiveAudioCapability : g7231 :
{
maxAl-sduAudioFrames 1
silenceSuppression FALSE
}
},
{
capabilityTableEntryNumber 3
capability receiveAudioCapability : g711Ulaw64k : 20
},
{
capabilityTableEntryNumber 4
capability receiveAudioCapability : g711Alaw64k : 20
},
{
capabilityTableEntryNumber 10
capability receiveAudioCapability : g728 : 8
},
{
capabilityTableEntryNumber 9
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723332'H
}
},
{
capabilityTableEntryNumber 8
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723234'H
}
},
{
capabilityTableEntryNumber 7
capability receiveAudioCapability : nonStandard :
{
nonStandardIdentifier h221NonStandard :
{
t35CountryCode 181
t35Extension 0
manufacturerCode 18
}
data '47373236723136'H
}
}
}
capabilityDescriptors
{
{
capabilityDescriptorNumber 1
simultaneousCapabilities
{
{
5,
6,
13,
14,
3,
4,
7,
8,
9,
17,
10,
16,
15,
11,
11,
19,
20,
21
},
{
30,
27,
25
},
{
31
}
}
}
}
}
002382: Oct 5 11:10:48.751: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
002383: Oct 5 11:10:48.751: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
002384: Oct 5 11:10:48.751: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(18):setting mask for 729ar8also as 729 is configured
002385: Oct 5 11:10:48.751: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(18):setting mask for 729ar8also as 729 is configured
002386: Oct 5 11:10:48.751: //18/8FFB61928022/H323/cch323_h245_cap_ind: Masks au=0x7000B9FF data=0x2 uinp=0x32
002387: Oct 5 11:10:48.755: //18/8FFB61928022/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_IND while at state IDLE
002388: Oct 5 11:10:48.755: //18/8FFB61928022/H323/h245_cap_in_set_new_state: changing from IDLE state to AWAITING_RESPONSE state
002389: Oct 5 11:10:48.755: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x4 internal event to H245 IWF SM
002390: Oct 5 11:10:48.755: //18/8FFB61928022/H323/run_h245_iwf_sm: received IWF_EV_CAP_IND while at state IWF_H245_CONNECTED
002391: Oct 5 11:10:48.755: //18/8FFB61928022/H323/h323_validate_cap_ind: Remote Pref Codecs UnOrdered (0x7000B9FF) = [G729IETF] [G729a] [G729b]
[G729ab] [G711_ULAW_64K] [G711_ALAW_64K] [G726r16] [G726r24] [G726r32] [CLEARCHANNEL] [G728] [G723ar63] [G723r63] [G72264] [G72256] [G72248] []
002392: Oct 5 11:10:48.755: //18/8FFB61928022/H323/h245_handle_cap_ind: TCS received from remote end. Setting h245 status flag H245_CAP_REQUEST_RCVD
002393: Oct 5 11:10:48.755: //-1/xxxxxxxxxxxx/H323/cch323_get_dp_pref_mask:
cch323_get_dp_pref_mask:IPIPGW(18):setting mask for 729ar8also as 729 is configured
002394: Oct 5 11:10:48.755: //18/8FFB61928022/H323/cch323_set_extended_caps: Copying codec list into extended caps structure
002395: Oct 5 11:10:48.755: //18/8FFB61928022/H323/cch323_set_extended_caps: G729IETF
002396: Oct 5 11:10:48.755: //18/8FFB61928022/H323/cch323_set_extended_caps: G729a
002397: Oct 5 11:10:48.755: //18/8FFB61928022/H323/cch323_iwf_cap_notify: Mask sent to other leg=C
002398: Oct 5 11:10:48.755: //18/8FFB61928022/CCAPI/cc_api_caps_ind:
Destination Interface=0x0, Destination Call Id=-1, Source Call Id=18,
Caps(Codec=0xC, Fax Rate=0x2, Vad=0x2,
Modem=0x0, Codec Bytes=20, Signal Type=2)
002399: Oct 5 11:10:48.755: //18/8FFB61928022/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
002400: Oct 5 11:10:48.759: //17/8FFB61928022/CCAPI/cc_api_call_disconnected:
Cause Value=65, Interface=0x4705BD7C, Call Id=17
002401: Oct 5 11:10:48.759: //17/8FFB61928022/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=65, Retry Count=0)
002402: Oct 5 11:10:48.759: //17/8FFB61928022/CCAPI/cc_api_caps_ack:
Destination Interface=0x0, Destination Call Id=-1, Source Call Id=17,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=2531)
002403: Oct 5 11:10:48.759: //18/8FFB61928022/H323/cch323_h225_sent_deferred_setup_cfm_notify: ====== PI = 0; status = 8000019
002404: Oct 5 11:10:48.759: //18/8FFB61928022/CCAPI/cc_api_call_connected:
Interface=0x478B1418, Data Bitmask=0x1, Progress Indication=NULL(0),
Connection Handle=0
002405: Oct 5 11:10:48.759: //18/8FFB61928022/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
002406: Oct 5 11:10:48.759: //18/8FFB61928022/H323/cch323_modify_rtcp_session_parameters: updating RTP session params, h245.iwf_state = 2,h245.status =
21020040, in_type = 3, flag = 0
002407: Oct 5 11:10:48.759: //18/8FFB61928022/H323/h245_handle_cap_ind: TCS ack is deferred
002408: Oct 5 11:10:48.759: //18/8FFB61928022/H323/h245_iwf_set_new_state: changing from IWF_H245_CONNECTED state to IWF_AWAIT_PEER_CAP state
002409: Oct 5 11:10:48.763: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 501 Not Implemented
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2819902ba8
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772505
To: <3001>;tag=3CDFE50-155
Date: Tue, 05 Oct 2010 15:10:45 GMT
Call-ID: b8dace00-cab13ff5-21-14c8010a@10.1.200.20
CSeq: 101 INVITE
Allow-Events: telephone-event
Reason: Q.850;cause=65
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
002410: Oct 5 11:10:48.763: //-1/xxxxxxxxxxxx/H323/cch323_post_call_statistics: callID=18
002411: Oct 5 11:10:48.763: //18/8FFB61928022/CCAPI/ccCallDisconnect:
Cause Value=65, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
002412: Oct 5 11:10:48.763: //18/8FFB61928022/CCAPI/ccCallDisconnect:
Cause Value=65, Call Entry(Responsed=TRUE, Cause Value=65)
002413: Oct 5 11:10:48.763: //18/8FFB61928022/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
002414: Oct 5 11:10:48.767: //17/8FFB61928022/CCAPI/ccCallDisconnect:
Cause Value=65, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=65)
002415: Oct 5 11:10:48.767: //17/8FFB61928022/CCAPI/ccCallDisconnect:
Cause Value=65, Call Entry(Responsed=TRUE, Cause Value=65)
002416: Oct 5 11:10:48.771: //17/8FFB61928022/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x4705BD7C, Tag=0x0, Call Id=17,
Call Entry(Disconnect Cause=65, Voice Class Cause Code=0, Retry Count=0)
002417: Oct 5 11:10:48.771: //17/8FFB61928022/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
002418: Oct 5 11:10:48.771: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002419: Oct 5 11:10:48.771: :cc_free_feature_vsa freeing 478549C0
002420: Oct 5 11:10:48.771: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002421: Oct 5 11:10:48.771: vsacount in free is 1
002422: Oct 5 11:10:48.775: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:3001@6.6.6.7:5060 SIP/2.0
Date: Tue, 05 Oct 2010 15:10:45 GMT
From: <1001>;tag=672f0396-d595-4a92-b33d-446800d37753-27772505
Allow-Events: presence, kpml
Content-Length: 0
To: <3001>;tag=3CDFE50-155
Call-ID: b8dace00-cab13ff5-21-14c8010a@10.1.200.20
Via: SIP/2.0/TCP 10.1.200.20:5060;branch=z9hG4bK2819902ba8
CSeq: 101 ACK
Max-Forwards: 70
002423: Oct 5 11:10:48.775: //18/8FFB61928022/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm
002424: Oct 5 11:10:48.775: //18/8FFB61928022/H323/run_h245_iwf_sm: received IWF_EV_PEER_CAPS_ACK while at state IWF_AWAIT_PEER_CAP
002425: Oct 5 11:10:48.775: //18/8FFB61928022/H323/cch323_do_call_disconnect: gw_id=1, discCause=65
002426: Oct 5 11:10:48.775: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM
002427: Oct 5 11:10:48.775: //18/8FFB61928022/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_WAIT_FOR_H245
002428: Oct 5 11:10:48.775: //18/8FFB61928022/H323/cch323_h225_send_release: Cause = 65; Location = 0
002429: Oct 5 11:10:48.779: //18/8FFB61928022/H323/cch323_h225_send_release: h225TerminateRequest: src address = 101058055; dest address = 3.3.3.3
002430: Oct 5 11:10:48.779: H225.0 OUTGOING PDU ::=
value H323_UserInformation ::=
{
h323-uu-pdu
{
h323-message-body releaseComplete :
{
protocolIdentifier { 0 0 8 2250 0 4 }
callIdentifier
{
guid '8FFC9A7BCFC911DF8024B8130721089B'H
}
}
h245Tunneling FALSE
}
}
002431: Oct 5 11:10:48.779: H225.0 OUTGOING ENCODE BUFFER::= 2580060008914A0004110011008FFC9A7BCFC911DF8024B8130721089B10800100
002432: Oct 5 11:10:48.779:
002433: Oct 5 11:10:48.779: //18/8FFB61928022/H323/cch323_h225_set_new_state: Changing from H225_WAIT_FOR_H245 state to H225_IDLE state
002434: Oct 5 11:10:48.779: //18/8FFB61928022/H323/cch323_call_generic_cleanup: Disconnected flag 1
002435: Oct 5 11:10:48.779: //18/8FFB61928022/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
002436: Oct 5 11:10:48.779: //18/8FFB61928022/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 1000, Fax 300
002437: Oct 5 11:10:48.779: //18/8FFB61928022/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_AWAIT_PEER_CAP
002438: Oct 5 11:10:48.783: //18/8FFB61928022/H323/defaultHdlr: DEFAULT: Received IWF_EV_H245_DISCONN in state IWF_AWAIT_PEER_CAP
002439: Oct 5 11:10:48.783: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 4
002440: Oct 5 11:10:48.783: //18/8FFB61928022/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x478B1418, Tag=0x0, Call Id=18,
Call Entry(Disconnect Cause=65, Voice Class Cause Code=0, Retry Count=0)
002441: Oct 5 11:10:48.783: //18/8FFB61928022/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
002442: Oct 5 11:10:48.783: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002443: Oct 5 11:10:48.783: :cc_free_feature_vsa freeing 478548E0
002444: Oct 5 11:10:48.783: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002445: Oct 5 11:10:48.783: vsacount in free is 0
002446: Oct 5 11:10:48.783: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x49F6FE00)
002447: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1
002448: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x49D56518, len=46, msgPtr=0x49D8C6B8
002449: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
002450: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/validate_crv: No CCB for crv: 0xD
002451: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Parse error RXDATA_NONE
002452: Oct 5 11:10:49.051: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: CRV entry not found, returning
ISR#
Options
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
10-05-2010 09:05 AM
That's odd. The transcoder is registered and we're forcing a codec mismatch, bu the h323 leg still throws a codec mismatch when the TCS comes in. Something doesn't seem right here. What version of IOS are you running? Is it an old CUBE release? If it were me, I'd run 15.1(2)T1 on CUBE if you have the capacity to do so, since it has some large CUBE improvements like voice-class codec support.
I'd be interested to see what occurs if you can get the inbound SIP INVITE to be early offer. What device is on the other side of the SIP leg? Do you have the capability to get that device to send early-offer (SDP with INVITE), and the receiving h323 leg to accept inbound fast start?
Also, what happens if you configure the SIP peer for g729r8? I'm just curious to see how that behaves, and if we send the 200 OK with SDP out to the other side in that scenario.
Learn, share, save
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide
Customers Also Viewed These Support Documents