[Freeswitch-users] opal to sip problem
Gustavo Espeche
gustavo.espeche at upper-soft.com
Mon Dec 13 17:24:12 MSK 2010
Hello list, we are try to do inter-worker between h323 and sip using
opal in freeswitch, but FS don't send the call to our sip gw, follow is
the call flow:
h323 endpoint -->FS->sip gateway
attached a FS debug of call.
if something know or work with opal in freeSwitch and have some tips we
appreciate a lot if advice about it.
Best Regards.
-----------------------------------------------------------------------------------------------------------------------------
2010-12-13 11:58:21.325242 [DEBUG] transports.cxx:1200 Started
connection to 200.117.192.17:19270 (if=72.51.47.100:1720)
2010-12-13 11:58:21.325242 [DEBUG] osutil.cxx:189 File handle high water
mark set: 67 Thread unblock pipe
2010-12-13 11:58:21.325242 [DEBUG] tlibthrd.cxx:587 Thread high water
mark set: 8
2010-12-13 11:58:21.325242 [DEBUG] transports.cxx:666 Waiting on socket
accept on tcp$72.51.47.100:1720
2010-12-13 11:58:21.325242 [DEBUG] h323ep.cxx:501 Awaiting first PDU
2010-12-13 11:58:21.805203 [DEBUG] h323pdu.cxx:80 Receiving PDU:
{
q931pdu = {
protocolDiscriminator = 8
callReference = 22716
from = originator
messageType = Setup
IE: Bearer-Capability = {
88 93 a5
...
}
IE: Display = {
67 75 73 74 61 76 6f 00 gustavo.
}
IE: Called-Party-Number = {
81 32 33 31 35 34 33 35 31 34 32 38 30 36 33
33 .231543514280633
}
IE: User-User = {
20 b8 06 00 08 91 4a 00 06 01 40 06 00 67 00
75 .....J... at ..g.u
00 73 00 74 00 61 00 76 00 6f 22 c0 09 00 00
3d .s.t.a.v.o"....=
...
}
}
h225pdu = {
h323_uu_pdu = {
h323_me
ssage_body = setup {
protocolIdentifier = 0.0.8.2250.0.6
sourceAddress = 1 entries {
[0]=h323_ID 7 characters {
0067 0075 0073 0074 0061 0076 006f gustavo
}
}
sour
ceInfo = {
vendor = {
vendor = {
t35CountryCode = 9
t35Extension = 0
manufacturerCode = 61
}
productId = 3 octets {
00 00 00
(OPAL v3.6
2e 36 29 00 00 .6
)..
}
}
terminal = {
}
mc = false
undefinedNode = false
}
destinationAddress = 1 entries {
[0]=dialedDigits "231543514280633"
}
Log-Func:
Log-Line: 0
User-Data:
destCallSignalAddress = ipAddress {
ip = 4 octets {
48 33 2f 64 H3/d
}
port = 1720
}
activeMC = falets {
4e 76 b2 f2 1d 05 e0 11 9b b7 00 1e 64 1f 33 fe
Nv..........d.3.
}
conferenceGoal = create <<null>>
callType = pointToPoint <<null>>
sourceCallSignalAddress = ipAddress {
ip =
Log-Func:
Log-Line: 0
User-Data:
4 octets {
c8 75 c0 11 .u..
}
port = 19270
}
callIdentifier = {
guid = 16 octets {
3a 76 f 33 fe :v..........d.3.
}
}
fastStart = 8 entries {
[0]= 29 octets {
40 00 00 06 04 01 00 4c 20 13 80 11 1c 00 01 00
@......L .......
c8 75 c0 11 13 de 00 c8 75 c0 11 13
df .u......u....
}
[1]= 19 octets {
00 00 64 0c 20 13 80 0b 0d 00 01 00 c8 75 c0
11 ..d. ........u..
13 df 00 ...
}
[
2]= 35 octets {
40 00 00 06 04 01 00 48 78 00 4a ff 00 80 01 00
@......Hx.J.....
80 11 1c 00 02 00 c8 75 c0 11 13 e0 00 c8 75
c0 .......u......u.
...
}
[3]= 25 octets {
00 00 65 08 78 00 4a ff 00 80 01 00 80 0b 0d
00 ..e.x.J.........
02 00 c8 75 c0 11 13 e1
00 ...u.....
}
[4]= 34 octets {
40 00 00 06 04 01 00 48 68 4a ff 00 80 01
00 80 @......HhJ......
11 1c 00 02 00 c8 75 c0 11 13 e0 00 c8 75 c0
11 ......u......u..
...
}
[5]= 24 octets {
00 00 66 08 68 4a ff 00 80 01 00 80 0b 0d 00
02 ..f.hJ..........
00 c8 75 c0 11 13 e1
00 ..u.....
}
[6]= 34 octets {
40 00 00 06 04 01 00 48 70 4a ff 00 80 01 00 80
@......HpJ......
11 1c 00 02 00 c8 75 c0 11 13 e0 0
0 c8 75 c0 11 ......u......u..
...
}
[7]= 24 octets {
00 00 67 08 70 4a ff 00 80 01 00 80 0b 0d 00
02 ..g.pJ..........
00 c8 75 c0 11 13 e1
00 ..u.....
}
}
mediaWaitForConnect = false
canOverlapSend = false
multipleCalls = false
maintainConnection = false
parallelH245Control = 2 entries {
[0]= 125 octets {
02 70 01 06 00 08 81 75 00 0d 80 13 80 01 f4
00 .p.....u........
01 00 00 01 00 00 01 00 00 0c c0 01 00 01 80
07 ................
...
}
[1]= 7 octets {
01 00 32 80 5d 41 2
b ..2.]A+
}
}
}
h245Tunneling = true
}
}
}
2010-12-13 11:58:21.805203 [DEBUG] h323ep.cxx:510 Incoming call, first
PDU: callReference=22716
2010-12-13 11:58:21.805203 [DEBUG] call.cxx:72 Created Call[Cc70e3cf91]
2010-12-13 11:58:21.805203 [DEBUG] connection.cxx:262 Created connection
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.805203 [DEBUG] rfc2833.cxx:140 Handler created
2010-12-13 11:58:21.805203 [DEBUG] rfc2833.cxx:328 Rx capability set to
"0-16,32,36"
2010-12-13 11:58:21.805203 [DEBUG] rfc2833.cxx:140 Handler created
2010-12-13 11:58:21.805203 [DEBUG] rfc2833.cxx:328 Rx capability set to
"192,193"
2010-12-13 11:58:21.805203 [DEBUG] osutil.cxx:189 File handle high water
mark set: 68 PUDPSocket
2010-12-13 11:58:21.808186 [DEBUG] h4601.cxx:1583 Endpoint Attached
2010-12-13 11:58:21.808186 [DEBUG] h323ep.cxx:552 Created new
connection: tcp$200.117.192.17:19270/22716
2010-12-13 11:58:21.808186 [DEBUG] h323.cxx:559 Handling PDU: Setup
callRef=22716
2010-12-13 11:58:21.808186 [DEBUG] connection.cxx:1516 SetPhase from
UninitialisedPhase to SetUpPhase for Call[Cc70e3cf91]-EP<h323>[tcp
$200.117.192.17:19270/22716]
2010-12-13 11:58:21.808186 [DEBUG] h323.cxx:943 Set protocol version to
6 and implying H.245 version 13
2010-12-13 11:58:21.808186 [DEBUG] h323.cxx:1240 Set remote application
name: " 3.2.6 (OPAL v3.6.6) 9/61 "
2010-12-13 11:58:21.808186 [DEBUG] manager.cxx:1392 Checking incoming
call for NAT: local=72.51.47.100, peer=200.117.192.17,
sig=200.117.192.17
2010-12-13 11:58:21.808186 [DEBUG] h323.cxx:1041 Sending call proceeding
PDU
2010-12-13 11:58:21.811196 [DEBUG] h323pdu.cxx:80 Sending PDU:
{
q931pdu = {
protocolDiscriminator = 8
callReference = 22716
from = destination
messageType = CallProceeding
IE: Display = {
72 6f 6f 74 00
root.
}
IE: User-User = {
21 80 06 00 08 91 4a 00 06 22 c0 09 00 00 3d
1e !.....J.."....=.
56 6f 78 20 4c 75 63 69 64 61 20 50 74 79 2e 20 Vox Lucida
Pty.
...
}
}
h225pdu = {
h323_uu_pdu = {
h323_message_body = callProceeding {
protocolIdentifier = 0.0.8.2250.0.6
destinationInfo = {
vendor = {
vendor = {
t35CountryCode = 9
t35Extensio
n = 0
manufacturerCode = 61
}
productId = 31 octets {
56 6f 78 20 4c 75 63 69 64 61 20 50 74 79 2e 20 Vox
Lucida Pty.
4c 74 64 2e 20 6d 6f 64 5f 6f 70 61 6c 00 00
Log-Line: 0
UINCOMING DATA [(null)]
RECV EVENT
Event-Name: SOCKET_DATA
ser-Data: _undef_
}
}
terminal = {
}
mc = false
undefinedNode = false
}
callIdentifier = {
guid = 16 octets {
3a 76 b2 f2 1d 05 e0 11 9b b7 00 1e 64 1f 33 fe
:v..........d.3.
}
}
multipleCalls = false
maintainConnection = false
}
h245Tunneling = true
}
}
}
2010-12-13 11:58:21.811196 [DEBUG] manager.cxx:600 OnIncoming connection
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.811196 [DEBUG] call.cxx:288 GetOtherPartyConnection
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.811196 [DEBUG] manager.cxx:1200 Searching for route
"h323:root 231543514280633"
2010-12-13 11:58:21.811196 [DEBUG] manager.cxx:1228 Matched regex
"h323:.*"
2010-12-13 11:58:21.811196 [DEBUG] manager.cxx:573 Set up connection to
"local:231543514280633"
2010-12-13 11:58:21.811196 [DEBUG] connection.cxx:262 Created connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.811196 [DEBUG] localep.cxx:205 Created connection
with token "Ldc8d6c462"
2010-12-13 11:58:21.811196 [DEBUG] h323.cxx:1075 Incoming call accepted
2010-12-13 11:58:21.811196 [DEBUG] mod_opal.cpp:770 Matched FS codec
PCMA to OPAL media format G.711-ALaw-64k
2010-12-13 11:58:21.811196 [DEBUG] mod_opal.cpp:770 Matched FS codec
G729 to OPAL media format G.729
2010-12-13 11:58:21.811196 [DEBUG] mod_opal.cpp:770 Matched FS codec
PCMU to OPAL media format G.711-uLaw-64k
2010-12-13 11:58:21.811196 [DEBUG] mod_opal.cpp:770 Matched FS codec
G723 to OPAL media format G.723.1
2010-12-13 11:58:21.814188 [DEBUG] call.cxx:425 GetMediaFormats for
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
G.723.1
G.729
G.711-uLaw-64k
G.711-ALaw-64k
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.723.1"
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
G.723.1 <1>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.729"
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
G.729 <2>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.711-uLaw-64k"
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
G.711-uLaw-64k <3>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.711-ALaw-64k"
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2376 Found capability:
G.723.1 <1>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2376 Found capability:
G.729 <2>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2376 Found capability:
G.711-uLaw-64k <3>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2376 Found capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.814188 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/basicString <6>
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.817197 [DEBUG] call.cxx:288 GetOtherPartyConnection
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.817197 [DEBUG] h323.cxx:3704 SetLocalCapabilities:
Table:
G.723.1 <1>
G.729 <2>
G.711-uLaw-64k <3>
G.711-ALaw-64k <4>
UserInput/hookflash <5>
UserInput/basicString <6>
UserInput/dtmf <7>
UserInput/RFC2833 <8>
Set:
0:
Log-Func:
Log-Line: 0
User-Data:
0:
G.723.1 <1>
G.729 <2>
G.711-uLaw-64k <3>
G.711-ALaw-64k <4>
1:
UserInput/hookflash <5>
2:
UserInput/basicString <6>
UserInput/dtINCOMING DATA [(null)]
RECV EVENT
Event-Name: SOCKET_DATA
2010-12-13 11:58:21.817197 [DEBUG] h323.cxx:1121 Fast start detected
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2594 Could not find
capability: audioData, type g711Alaw64k
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:845 Capability tx frames
left at 20 as remote allows 20
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2294 Added capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:845 Capability tx frames
left at 20 as remote allows 20
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.817197 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] h323caps.cxx:2594 Could not find
capability: videoData, type h261VideoCapability
2010-12-13 11:58:21.820187 [DEBUG] call.cxx:288 GetOtherPartyConnection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.820187 [DEBUG] call.cxx:169 OnSetUp
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.820187 [DEBUG] localep.cxx:240 Incoming call from
gustavo [200.117.192.17]
2010-12-13 11:58:21.820187 [DEBUG] mod_opal.cpp:641 Created switch
caller profile:
username =
dialplan = XML
caller_id_name = gustavo [200.117.192.17]
caller_id_number = 0000000000
network_addr =
source = opal
context
Log-Func:
Log-Line: 0
User-Data:
= default
2010-12-13 11:58:21.823196 [NOTICE] switch_channel.c:784 New Channel
opal/in:231543514280633 [7b4a89ac-b5d7-4fb4-bab5-ddaa8e73485c]
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:647
(opal/in:231543514280633) State Change CS_NEW -> CS_INIT
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:1092 State changed on
connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:931 Kill 3 on connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] connection.cxx:1516 SetPhase from
UninitialisedPhase to AlertingPhase for
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [NOTICE] mod_opal.cpp:676 Ring-Ready
opal/in:231543514280633!
2010-12-13 11:58:21.823196 [DEBUG] manager.cxx:678 OnAlerting
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] call.cxx:196 OnAlerting
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] h323.cxx:2067 SetAlerting
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:320
(opal/in:231543514280633) Running State Change CS_INIT
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:356
(opal/in:231543514280633) State INIT
2010-12-13 11:58:21.823196 [DEBUG] osutil.cxx:189 File handle high water
mark set: 72 Thread unblock pipe
2010-12-13 11:58:21.823196 [DEBUG] tlibthrd.cxx:587 Thread high water
mark set: 10
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:842 Started routing for
connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:843
(opal/in:231543514280633) State Change CS_INIT -> CS_ROUTING
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:1092 State changed on
connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:931 Kill 3 on connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:356
(opal/in:231543514280633) State INIT going to sleep
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:320
(opal/in:231543514280633) Running State Change CS_ROUTING
2010-12-13 11:58:21.823196 [DEBUG] switch_channel.c:1615
(opal/in:231543514280633) Callstate Change DOWN -> RINGING
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:359
(opal/in:231543514280633) State ROUTING
2010-12-13 11:58:21.823196 [DEBUG] mod_opal.cpp:850 Routing connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.823196 [DEBUG] switch_core_state_machine.c:77
opal/in:231543514280633 Standard ROUTING
2010-12-13 11:58:21.823196 [INFO] mod_dialplan_xml.c:331 Processing
gustavo [200.117.192.17] <0000000000>->231543514280633 in context
default
2010-12-13 11:58:21.826206 [DEBUG] h323pdu.cxx:80 Receiving PDU:
request terminalCapabilitySet {
sequenceNumber = 1
protocolIdentifier = 0.0.8.245.0.13
multiplexCapability = h2250Capability {
maximumAudioDelayJitter = 500
receiveMultipointCapabi
lity = {
multicastCapability = false
multiUniCastConference = false
mediaDistributionCapability = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centraliz
edAudio = false
distributedAudio = false
centralizedVideo = false
distributedVideo = false
}
}
}
transmitMultipointCapability = {
multicastCapability = false
multiUniC
astConference = false
mediaDistributionCapability = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centralizedAudio = false
distributedAudio = false
centralizedVideo = false
distributedVideo = false
}
}
}
receiveAndTransmitMultipointCapability = {
multicastCapability = false
multiUniCastConference = false
mediaDistributionCapab
ility = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centralizedAudio = false
distributedAudio = false
centralizedVideo = false
distributedV
ideo = false
}
}
}
mcCapability = {
centralizedConferenceMC = false
decentralizedConferenceMC = false
}
rtcpVideoControlCapability = false
mediaPacketizationCapability = {
h261a
VideoPacketization = false
}
logicalChannelSwitchingCapability = false
t120DynamicPortCapability = true
}
capabilityTable = 8 entries {
[0]={
capabilityTableEntryNumber = 1
capability = receiveAudioCap
ability g711Alaw64k 240
}
[1]={
capabilityTableEntryNumber = 2
capability = receiveVideoCapability h261VideoCapability {
qcifMPI = 1
cifMPI = 1
temporalSpatialTradeOffCapability = false
maxBitRate = 19200
stillImageTransmission = false
videoBadMBsCap = false
}
}
[2]={
capabilityTableEntryNumber = 3
capability = receiveVideoCapability h261VideoCapability {
cifMPI
= 1
temporalSpatialTradeOffCapability = false
maxBitRate = 19200
stillImageTransmission = false
videoBadMBsCap = false
}
}
[3]={
capabilityTableEntryNumber = 4
capability =
receiveVideoCapability h261VideoCapability {
qcifMPI = 1
temporalSpatialTradeOffCapability = false
maxBitRate = 19200
stillImageTransmission = false
videoBadMBsCap = false
}
}
[4
]={
capabilityTableEntryNumber = 5
capability = receiveUserInputCapability hookflash <<null>>
}
[5]={
capabilityTableEntryNumber = 6
capability = receiveUserInputCapability basicString <<null>>
}
[6]={
capabilityTableEntryNumber = 7
capability = receiveUserInputCapability dtmf <<null>>
}
[7]={
capabilityTableEntryNumber = 8
capability = receiveRTPAudioTelephonyEventCapability {
dynamic
RTPPayloadType = 101
audioTelephoneEvent = "0-16"
}
}
}
capabilityDescriptors = 1 entries {
[0]={
capabilityDescriptorNumber = 1
simultaneousCapabilities = 4 entries {
[0]=1 entries {
[0]=1
}
[1]=3 entries {
[0]=2
[1]=3
[2]=4
}
[2]=1 entries {
[0]=5
}
[3]=3 entries {
[0]=6
[1]=7
Log-Func:
Log-Line: 0
User-Data:
[2]=8
2010-12-13 11:58:21.826206 [DEBUG] h323.cxx:2792 Set protocol
version to 13
2010-12-13 11:58:21.826206 [DEBUG] h323neg.cxx:378 Received
TerminalCapabilitySet: state=Idle pduSeq=1 inSeq=4294967295
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:1988
H323Capabilities(ctor)
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
G.723.1 <1>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
G.729 <2>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
G.711-uLaw-64k <3>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/basicString <6>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
G.723.1 <1>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
G.729 <2>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
G.711-uLaw-64k <3>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/basicString <6>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2376 Found capability:
G.711-ALaw-64k <4>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2376 Found capability:
G.711-uLaw-64k <3>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2376 Found capability:
G.723.1 <1>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.723.1(5.3k)"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.723.1 <9>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.723.1A(5.3k)"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.723.1 <10>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.723.1A(6.3k)"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.723.1 <11>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.728"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.728 <12>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2376 Found capability:
G.729 <2>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.729A"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.729A <13>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.729A/B"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.729A/B <14>
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2381 Could not find
capability: "G.729B"
2010-12-13 11:58:21.826206 [DEBUG] h323caps.cxx:2284 Added capability:
G.729B <15>
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2381 Could not find
capability: "GSM-06.10"
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2284 Added capability:
GSM-06.10 <16>
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2381 Could not find
capability: "GSM-AMR"
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2284 Added capability:
GSM-AMR <17>
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2381 Could not find
capability: "T.38"
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2284 Added capability:
T.38 <18>
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.831146 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/basicString <6>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2381 Could not find
capability: "UserInput/generalString"
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/generalString <19>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2381 Could not find
capability: "UserInput/iA5String"
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/iA5String <20>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2381 Could not find
capability: "iLBC"
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
iLBC <21>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/hookflash <22>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/basicString <23>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/dtmf <24>
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
UserInput/RFC2833 <25>
2010-12-13 11:58:21.834192 [CONSOLE] mod_xml_curl.c:312 XML response is
in /tmp/90f1dd7d-a63c-4e15-981c-6eed9e70313b.tmp.xml
Dialplan: opal/in:231543514280633 parsing [default->external]
continue=false
Dialplan: opal/in:231543514280633 Regex (PASS) [external]
destination_number(231543514280633) =~ /^231543514280633/ break=on-false
Dialplan: opal/in:231543514280633 Action set(continue_on_fail=true)
Dialplan: opal/in:231543514280633 Action set(hangup_after_bridge=true)
Dialplan: opal/in:231543514280633 Action set(progress_timeout=15)
Dialplan: opal/in:231543514280633 Action set(proxy_media=false)
Dialplan: opal/in:231543514280633 Action set(bypass_media=true)
Dialplan: opal/in:231543514280633 Action
set(absolute_codec_string=PCMA)
Dialplan: opal/in:231543514280633 Action
bridge(sofia/external/21543514280633 at 200.35.145.149)
2010-12-13 11:58:21.834192 [DEBUG] switch_core_state_machine.c:119
(opal/in:231543514280633) State Change CS_ROUTING -> CS_EXECUTE
2010-12-13 11:58:21.834192 [DEBUG] mod_opal.cpp:1092 State changed on
connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.834192 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.834192 [DEBUG] mod_opal.cpp:931 Kill 3 on connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.834192 [DEBUG] switch_core_state_machine.c:359
(opal/in:231543514280633) State ROUTING going to sleep
2010-12-13 11:58:21.834192 [DEBUG] switch_core_state_machine.c:320
(opal/in:231543514280633) Running State Change CS_EXECUTE
2010-12-13 11:58:21.834192 [DEBUG] h323caps.cxx:2284 Added capability:
H.239-Video+H.239-Video <26>
2010-12-13 11:58:21.834192 [DEBUG] switch_core_state_machine.c:366
(opal/in:231543514280633) State EXECUTE
2010-12-13 11:58:21.834192 [DEBUG] mod_opal.cpp:857 Executing connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.834192 [DEBUG] switch_core_state_machine.c:157
opal/in:231543514280633 Standard EXECUTE
EXECUTE opal/in:231543514280633 set(continue_on_fail=true)
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2284 Added capability:
H.239-Control <27>
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2029 Parsing remote
capabilities
2010-12-13 11:58:21.837191 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.837191 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [continue_on_fail]=[true]
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:819 Capability tx frames
left at 20 as remote allows 240
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2529 Could not find
capability: receiveVideoCapability, type h261VideoCapability
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2529 Could not find
capability: receiveVideoCapability, type h261VideoCapability
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2529 Could not find
capability: receiveVideoCapability, type h261VideoCapability
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2671 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.837191 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633 set(hangup_after_bridge=true)
2010-12-13 11:58:21.837191 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.837191 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [hangup_after_bridge]=[true]
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2411 Could not find
capability: G.711-ALaw-64k <1>
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2294 Added capability:
G.711-ALaw-64k <1>
2010-12-13 11:58:21.837191 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633 set(progress_timeout=15)
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2411 Could not find
capability: UserInput/hookflash <5>
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2411 Could not find
capability: UserInput/basicString <6>
2010-12-13 11:58:21.837191 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.837191 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [progress_timeout]=[15]
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/basicString <6>
2010-12-13 11:58:21.837191 [DEBUG] h323caps.cxx:2411 Could not find
capability: UserInput/dtmf <7>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2411 Could not find
capability: UserInput/RFC2833 <8>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2294 Added capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2355 Found capability:
G.711-ALaw-64k <1>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/hookflash <5>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/basicString <6>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/dtmf <7>
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2355 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633 set(proxy_media=false)
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2777 Capability merge
result:
Table:
G.711-ALaw-64k <1>
UserInput/hookflash <5>
UserInput/basicString <6>
UserInput/dtmf <7>
UserInput/RFC2833 <8>
Set:
0:
0:
Log-Func:
Log-Line: 0
User-Data:
G.711-ALaw-64k <1>
1:
2:
UserInput/hookflash <5>
3:
UserInput/basicString <6>
UserInput/dtmf <INCOMING DATA [(null)]
RECV EVENT
Event-Name: SOCKET_DATA
2010-12-13 11:58:21.840189 [DEBUG] h323caps.cxx:2778 Received capability
set, is accepted
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.840189 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [proxy_media]=[false]
2010-12-13 11:58:21.840189 [DEBUG] h323neg.cxx:341 Sending
TerminalCapabilitySet: outSeq=1
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633 set(bypass_media=true)
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.840189 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [bypass_media]=[true]
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633 set(absolute_codec_string=PCMA)
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.840189 [DEBUG] mod_dptools.c:1028
opal/in:231543514280633 SET [absolute_codec_string]=[PCMA]
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
EXECUTE opal/in:231543514280633
bridge(sofia/external/21543514280633 at 200.35.145.149)
2010-12-13 11:58:21.840189 [DEBUG] mod_opal.cpp:1076 Received message 26
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.840189 [NOTICE] switch_channel.c:784 New Channel
sofia/external/21543514280633 at 200.35.145.149
[f9bf5b9e-a273-400c-b18c-e2c98c84750f]
2010-12-13 11:58:21.840189 [DEBUG] mod_sofia.c:3995
(sofia/external/21543514280633 at 200.35.145.149) State Change CS_NEW ->
CS_INIT
2010-12-13 11:58:21.840189 [DEBUG] switch_core_session.c:1083 Send
signal sofia/external/21543514280633 at 200.35.145.149 [BREAK]
2010-12-13 11:58:21.843189 [DEBUG] h323pdu.cxx:80 Sending PDU:
request terminalCapabilitySet {
sequenceNumber = 1
protocolIdentifier = 0.0.8.245.0.13
multiplexCapability = h2250Capability {
maximumAudioDelayJitter = 250
receiveMultipointCapabili
ty = {
multicastCapability = false
multiUniCastConference = false
mediaDistributionCapability = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centralized
Audio = false
distributedAudio = false
centralizedVideo = false
distributedVideo = false
}
}
}
transmitMultipointCapability = {
multicastCapability = false
multiUniCas
tConference = false
mediaDistributionCapability = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centralizedAudio = false
distributedAudio = false
centralizedVideo = false
distributedVideo = false
}
}
}
receiveAndTransmitMultipointCapability = {
multicastCapability = false
multiUniCastConference = false
mediaDistributionCapabil
ity = 1 entries {
[0]={
centralizedControl = false
distributedControl = false
centralizedAudio = false
distributedAudio = false
centralizedVideo = false
distributedVid
eo = false
}
}
}
mcCapability = {
centralizedConferenceMC = false
decentralizedConferenceMC = false
}
rtcpVideoControlCapability = false
mediaPacketizationCapability = {
h261aVi
deoPacketization = false
}
logicalChannelSwitchingCapability = false
t120DynamicPortCapability = true
}
capabilityTable = 8 entries {
[0]={
capabilityTableEntryNumber = 1
capability = receiveAudioCapab
ility g7231 {
maxAl_sduAudioFrames = 8
silenceSuppression = false
}
}
[1]={
capabilityTableEntryNumber = 2
capability = receiveAudioCapability g729 24
}
[2]={
capabilityTabl
eEntryNumber = 3
capability = receiveAudioCapability g711Ulaw64k 240
}
[3]={
capabilityTableEntryNumber = 4
capability = receiveAudioCapability g711Alaw64k 240
}
[4]={
capabilityTableEntryNumbe
r = 5
capability = receiveUserInputCapability hookflash <<null>>
}
[5]={
capabilityTableEntryNumber = 6
capability = receiveUserInputCapability basicString <<null>>
}
[6]={
capabilityTableEntry
Number = 7
capability = receiveUserInputCapability dtmf <<null>>
}
[7]={
capabilityTableEntryNumber = 8
capability = receiveRTPAudioTelephonyEventCapability {
dynamicRTPPayloadType = 101
audioT
elephoneEvent = "0-16"
}
}
}
capabilityDescriptors = 1 entries {
[0]={
capabilityDescriptorNumber = 1
simultaneousCapabilities = 3 entries {
[0]=4 entries {
[0]=1
[1]=2
[2]=3
[3]=4
}
[1]=1 entries {
[0]=5
}
[2]=3 entries {
[0]=6
[1]=7
[2]=8
}
}
}
}
}
2010-12-13 11:58:21.843189 [DEBUG] h323caps.cxx:2376 Found capability:
UserInput/RFC2833 <8>
2010-12-13 11:58:21.843189 [DEBUG] h323.cxx:3535 User Input RFC2833
payload type set to [pt=101]
2010-12-13 11:58:21.843189 [DEBUG] h323pdu.cxx:80 Sending PDU:
response terminalCapabilitySetAck {
sequenceNumber = 1
}
2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:320
(sofia/external/21543514280633 at 200.35.145.149) Running State Change
CS_INIT
2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:356
(sofia/external/21543514280633 at 200.35.145.149) State INIT
2010-12-13 11:58:21.843189 [DEBUG] mod_sofia.c:86
sofia/external/21543514280633 at 200.35.145.149 SOFIA INIT
2010-12-13 11:58:21.843189 [DEBUG] h323.cxx:3771
InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer
fastStartState=FastStartResponse H.245 is unavailable
2010-12-13 11:58:21.843189 [DEBUG] h323pdu.cxx:80 Receiving PDU:
request masterSlaveDetermination {
terminalType = 50
statusDeterminationNumber = 6111531
}
2010-12-13 11:58:21.843189 [DEBUG] h323neg.cxx:129 Received
MasterSlaveDetermination: state=Idle
2010-12-13 11:58:21.843189 [DEBUG] h323neg.cxx:160
MasterSlaveDetermination: local is master
2010-12-13 11:58:21.843189 [DEBUG] h323pdu.cxx:80 Sending PDU:
response masterSlaveDeterminationAck {
decision = slave <<null>>
}
2010-12-13 11:58:21.843189 [DEBUG] h323.cxx:3771
InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer
fastStartState=FastStartResponse H.245 is ready
2010-12-13 11:58:21.843189 [DEBUG] mod_sofia.c:126
(sofia/external/21543514280633 at 200.35.145.149) State Change CS_INIT ->
CS_ROUTING
2010-12-13 11:58:21.843189 [DEBUG] switch_core_session.c:1083 Send
signal sofia/external/21543514280633 at 200.35.145.149 [BREAK]
2010-12-13 11:58:21.843189 [DEBUG] sofia.c:4604 Channel
sofia/external/21543514280633 at 200.35.145.149 entering state
[terminated][900]
2010-12-13 11:58:21.843189 [DEBUG] h323ep.cxx:1033 OnSendAlerting conn =
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.843189 [DEBUG] switch_channel.c:2455
(sofia/external/21543514280633 at 200.35.145.149) Callstate Change DOWN ->
HANGUP
2010-12-13 11:58:21.843189 [DEBUG] h323.cxx:2110 SetAlerting sending
Alerting PDU
2010-12-13 11:58:21.843189 [NOTICE] sofia.c:5244 Hangup
sofia/external/21543514280633 at 200.35.145.149 [CS_ROUTING]
[NORMAL_UNSPECIFIED]
2010-12-13 11:58:21.843189 [DEBUG] switch_channel.c:2471 Send signal
sofia/external/21543514280633 at 200.35.145.149 [KILL]
2010-12-13 11:58:21.843189 [DEBUG] switch_core_session.c:1083 Send
signal sofia/external/21543514280633 at 200.35.145.149 [BREAK]
2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:356
(sofia/external/21543514280633 at 200.35.145.149) State INIT going to sleep
2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:320
(sofia/external/21543514280633 at 200.35.145.149) Running State Change
CS_HANGUP
2010-12-13 11:58:21.846211 [DEBUG] h323pdu.cxx:80 Sending PDU:
{
q931pdu = {
protocolDiscriminator = 8
callReference = 22716
from = destination
messageType = Alerting
IE: Display = {
72 6f 6f 74 00
root.
}
IE: User-User = {
23 80 06 00 08 91 4a 00 06 22 c0 09 00 00 3d 1e
#.....J.."....=.
56 6f 78 20 4c 75 63 69 64 61 20 50 74 79 2e 20 Vox Lucida
Pty.
...
}
}
h225pdu = {
h323
_uu_pdu = {
h323_message_body = alerting {
protocolIdentifier = 0.0.8.2250.0.6
destinationInfo = {
vendor = {
vendor = {
t35CountryCode = 9
t35Extension = 0
manufacturerCode = 61
}
productId = 31 octets {
56 6f 78 20 4c 75 63 69 64 61 20 50 74 79 2e 20 Vox
Lucida Pty.
4c 74 64 2e 20 6d 6f 64 5f 6f 70 61 6c 00 00 Ltd.
mod_op
Log-Line: 0
User-Data:
}
terminal = {
}
mc = false
undefinedNode = false
}
callIdentifier = {
guid = 16 octets {
3a 76 b2 f2 1d 05 e0 11 9b b7 00 1e 64 1f 33
fe :v........
..d.3.
}
}
multipleCalls = false
maintainConnection = false
}
h245Tunneling = true
h245Control = 3 entries {
[0]= 108 octets {
02 70 01 06 00 08 81 75 00 0d 80
13 80 00 fa 00 .p.....u........
01 00 00 01 00 00 01 00 00 0c c0 01 00 01 80
07 ................
...
}
[1]= 3 octets {
21 80 01 !..
}
[2]= 2 octets {
20 a0 .
}
}
}
}
}
2010-12-13 11:58:21.846211 [DEBUG] h323ep.cxx:1039 OnSentAlerting conn =
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.846211 [DEBUG] h323.cxx:3771
InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer
fastStartState=FastStartResponse H.245 is ready
2010-12-13 11:58:21.846211 [DEBUG] connection.cxx:361
OnSetUpConnectionCall[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.846211 [DEBUG] endpoint.cxx:408 OnSetUpConnection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.846211 [DEBUG] h323.cxx:1701 OnAnswerCall
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716], caller =
gustavo [200.117.192.17]
2010-12-13 11:58:21.846211 [DEBUG] call.cxx:219 OnAnswerCall
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716] caller
"gustavo [200.117.192.17]"
2010-12-13 11:58:21.846211 [DEBUG] h323.cxx:1713 Answering call:
AnswerCallDeferred
2010-12-13 11:58:21.846211 [DEBUG] connection.cxx:541 Answering call:
AnswerCallDeferred
2010-12-13 11:58:21.846211 [DEBUG] h323.cxx:3771
InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer
fastStartState=FastStartResponse H.245 is ready
2010-12-13 11:58:21.846211 [DEBUG] h323.cxx:506 Reading PDUs:
callRef=22716
2010-12-13 11:58:21.846211 [DEBUG] switch_ivr_originate.c:3448 Originate
Resulted in Error Cause: 31 [NORMAL_UNSPECIFIED]
2010-12-13 11:58:21.849192 [INFO] mod_dptools.c:2579 Originate Failed.
Cause: NORMAL_UNSPECIFIED
2010-12-13 11:58:21.849192 [DEBUG] mod_opal.cpp:1076 Received message 27
on connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.849192 [NOTICE] switch_core_state_machine.c:189
opal/in:231543514280633 has executed the last dialplan instruction,
hanging up.
2010-12-13 11:58:21.849192 [DEBUG] switch_channel.c:2455
(opal/in:231543514280633) Callstate Change RINGING -> HANGUP
2010-12-13 11:58:21.849192 [NOTICE] switch_core_state_machine.c:191
Hangup opal/in:231543514280633 [CS_EXECUTE] [NORMAL_CLEARING]
2010-12-13 11:58:21.849192 [DEBUG] switch_channel.c:2471 Send signal
opal/in:231543514280633 [KILL]
2010-12-13 11:58:21.849192 [DEBUG] mod_opal.cpp:931 Kill 1 on connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.849192 [DEBUG] mod_opal.cpp:1092 State changed on
connection Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.849192 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.849192 [DEBUG] mod_opal.cpp:931 Kill 3 on connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:366
(opal/in:231543514280633) State EXECUTE going to sleep
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:320
(opal/in:231543514280633) Running State Change CS_HANGUP
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:557
(sofia/external/21543514280633 at 200.35.145.149) State HANGUP
2010-12-13 11:58:21.849192 [DEBUG] mod_sofia.c:453
sofia/external/21543514280633 at 200.35.145.149 Overriding SIP cause 480
with 900 from the other leg
2010-12-13 11:58:21.849192 [DEBUG] mod_sofia.c:459 Channel
sofia/external/21543514280633 at 200.35.145.149 hanging up, cause:
NORMAL_UNSPECIFIED
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:46
sofia/external/21543514280633 at 200.35.145.149 Standard HANGUP, cause:
NORMAL_UNSPECIFIED
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:557
(sofia/external/21543514280633 at 200.35.145.149) State HANGUP going to
sleep
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:351
(sofia/external/21543514280633 at 200.35.145.149) State Change CS_HANGUP ->
CS_REPORTING
2010-12-13 11:58:21.849192 [DEBUG] switch_core_session.c:1083 Send
signal sofia/external/21543514280633 at 200.35.145.149 [BREAK]
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:320
(sofia/external/21543514280633 at 200.35.145.149) Running State Change
CS_REPORTING
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:617
(sofia/external/21543514280633 at 200.35.145.149) State REPORTING
2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:557
(opal/in:231543514280633) State HANGUP
2010-12-13 11:58:21.849192 [DEBUG] connection.cxx:401 Call end reason
for Call[Cc70e3cf91]-EP<local>[Ldc8d6c462] set to EndedByRemoteUser
2010-12-13 11:58:21.849192 [DEBUG] call.cxx:112 Clearing
Call[Cc70e3cf91] reason=EndedByRemoteUser
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:1516 SetPhase from
SetUpPhase to ReleasingPhase for Call[Cc70e3cf91]-EP<h323>[tcp
$200.117.192.17:19270/22716]
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:459 Releasing
asynchronously Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.852189 [DEBUG] osutil.cxx:196 File handle low water
mark set: 69 Thread unblock pipe
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:1516 SetPhase from
AlertingPhase to ReleasingPhase for
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:448 Releasing
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:489 OnReleased
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:808 Media streams
closed.
2010-12-13 11:58:21.852189 [DEBUG] endpoint.cxx:450 OnReleased
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] manager.cxx:709 OnReleased
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] call.cxx:716 OnReleased
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.852189 [DEBUG] connection.cxx:436 Already released
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:21.856029 [DEBUG] connection.cxx:1516 SetPhase from
ReleasingPhase to ReleasedPhase for
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462]
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:46
opal/in:231543514280633 Standard HANGUP, cause: NORMAL_CLEARING
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:557
(opal/in:231543514280633) State HANGUP going to sleep
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:351
(opal/in:231543514280633) State Change CS_HANGUP -> CS_REPORTING
2010-12-13 11:58:21.856029 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:320
(opal/in:231543514280633) Running State Change CS_REPORTING
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:617
(opal/in:231543514280633) State REPORTING
2010-12-13 11:58:21.856029 [DEBUG] connection.cxx:401 Call end reason
for Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716] set to
EndedByRemoteUser
2010-12-13 11:58:21.856029 [DEBUG] h323.cxx:349 OnReleased: tcp
$200.117.192.17:19270/22716, connectionState=AwaitingLocalAnswer
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:53
sofia/external/21543514280633 at 200.35.145.149 Standard REPORTING, cause:
NORMAL_UNSPECIFIED
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:617
(sofia/external/21543514280633 at 200.35.145.149) State REPORTING going to
sleep
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:345
(sofia/external/21543514280633 at 200.35.145.149) State Change CS_REPORTING
-> CS_DESTROY
2010-12-13 11:58:21.856029 [DEBUG] switch_core_session.c:1083 Send
signal sofia/external/21543514280633 at 200.35.145.149 [BREAK]
2010-12-13 11:58:21.856029 [DEBUG] switch_core_session.c:1250 Session 2
(sofia/external/21543514280633 at 200.35.145.149) Locked, Waiting on
external entities
2010-12-13 11:58:21.856029 [NOTICE] switch_core_session.c:1268 Session 2
(sofia/external/21543514280633 at 200.35.145.149) Ended
2010-12-13 11:58:21.856029 [NOTICE] switch_core_session.c:1270 Close
Channel sofia/external/21543514280633 at 200.35.145.149 [CS_DESTROY]
2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:449
(sofia/external/21543514280633 at 200.35.145.149) Callstate Change HANGUP
-> DOWN
2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:452
(sofia/external/21543514280633 at 200.35.145.149) Running State Change
CS_DESTROY
2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:462
(sofia/external/21543514280633 at 200.35.145.149) State DESTROY
2010-12-13 11:58:21.858228 [DEBUG] mod_sofia.c:364
sofia/external/21543514280633 at 200.35.145.149 SOFIA DESTROY
2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:60
sofia/external/21543514280633 at 200.35.145.149 Standard DESTROY
2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:462
(sofia/external/21543514280633 at 200.35.145.149) State DESTROY going to
sleep
2010-12-13 11:58:21.856029 [DEBUG] h323.cxx:356 Sending release complete
PDU: callRef=22716
2010-12-13 11:58:21.858228 [DEBUG] h323pdu.cxx:80 Sending PDU:
command endSessionCommand disconnect <<null>>
2010-12-13 11:58:21.858228 [DEBUG] h323pdu.cxx:80 Sending PDU:
{
q931pdu = {
protocolDiscriminator = 8
callReference = 22716
from = destination
messageType = ReleaseComplete
IE: Cause - Normal call clearing = {
80 90
..
}
IE: Display = {
72 6f 6f 74 00 root.
}
IE: User-User = {
25 80 06 00 08 91 4a 00 06 01 11 00 3a 76 b2 f2
%.....J.....:v..
Log-Func:
Log-Line: 0
User-Data:
1d 05 e0 11 9b b7 00 1e 64 1f 33 fe 04 c0 01 80 ........d.3.....
...
}
}
h225pdu = {
h323_uu_pdu = {
h323_message_body = releaseComplete {
protocolIdentifier = 0.0.8= {
guid = 16 octets {
3a 76 b2 f2 1d 05 e0 11 9b b7 00 1e 64 1f 33
fe :v..........d.3.
}
}
}
h245Tunneling = true
h245Control = 1 entries {
[0]= 2 octets {
4a 40 J@
}
}
}
}
}
2010-12-13 11:58:21.861189 [DEBUG] h323.cxx:412 Awaiting end session
from remote for 9.997 seconds
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:53
opal/in:231543514280633 Standard REPORTING, cause: NORMAL_CLEARING
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:617
(opal/in:231543514280633) State REPORTING going to sleep
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:345
(opal/in:231543514280633) State Change CS_REPORTING -> CS_DESTROY
2010-12-13 11:58:21.861189 [DEBUG] switch_core_session.c:1083 Send
signal opal/in:231543514280633 [BREAK]
2010-12-13 11:58:21.861189 [DEBUG] switch_core_session.c:1250 Session 1
(opal/in:231543514280633) Locked, Waiting on external entities
2010-12-13 11:58:21.861189 [NOTICE] switch_core_session.c:1268 Session 1
(opal/in:231543514280633) Ended
2010-12-13 11:58:21.861189 [NOTICE] switch_core_session.c:1270 Close
Channel opal/in:231543514280633 [CS_DESTROY]
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:449
(opal/in:231543514280633) Callstate Change HANGUP -> DOWN
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:452
(opal/in:231543514280633) Running State Change CS_DESTROY
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:462
(opal/in:231543514280633) State DESTROY
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:60
opal/in:231543514280633 Standard DESTROY
2010-12-13 11:58:21.861189 [DEBUG] switch_core_state_machine.c:462
(opal/in:231543514280633) State DESTROY going to sleep
2010-12-13 11:58:22.087167 [DEBUG] h323pdu.cxx:80 Receiving PDU:
{
q931pdu = {
protocolDiscriminator = 8
callReference = 22716
from = originator
messageType = Facility
IE: Facility = {
}
IE: Display = {
67 75 73 74
(..........!...
80 .
}
}
h225pdu = {
h323_uu_pdu = {
h323_message_body = empty <<null>>
h245Tunneling = true
h245Control = 2 entries {
[0]= 3 octets {
21 80 01 !..
}
[1]= 2
octets {
20 80 .
}
}
}
}
}
2010-12-13 11:58:22.087167 [DEBUG] h323.cxx:559 Handling PDU: Facility
callRef=22716
2010-12-13 11:58:22.087167 [DEBUG] h323.cxx:2709 Checking for end
session on PDU: response terminalCapabilitySetAck
2010-12-13 11:58:22.087167 [DEBUG] h323.cxx:2709 Checking for end
session on PDU: response masterSlaveDeterminationAck
2010-12-13 11:58:22.087167 [DEBUG] connection.cxx:436 Already released
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.087167 [DEBUG] h323.cxx:549 Signal channel closed.
2010-12-13 11:58:22.087167 [DEBUG] transports.cxx:900 Transport clean up
on termination
2010-12-13 11:58:22.087167 [DEBUG] transports.cxx:885 Transport Close
2010-12-13 11:58:22.090169 [DEBUG] osutil.cxx:196 File handle low water
mark set: 65 PTextFile
2010-12-13 11:58:22.090169 [DEBUG] tlibthrd.cxx:1020 Could not parse
thread stat file /proc/21145/task/21190/stat
2010-12-13 11:58:22.306147 [DEBUG] connection.cxx:489 OnReleased
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.306147 [DEBUG] connection.cxx:808 Media streams
closed.
2010-12-13 11:58:22.306147 [DEBUG] endpoint.cxx:450 OnReleased
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.306147 [DEBUG] manager.cxx:709 OnReleased
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.306147 [DEBUG] call.cxx:716 OnReleased
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.306147 [DEBUG] manager.cxx:535 OnClearedCall
Call[Cc70e3cf91] from "h323:200.117.192.17" to "h323:231543514280633"
2010-12-13 11:58:22.306147 [DEBUG] connection.cxx:1516 SetPhase from
ReleasingPhase to ReleasedPhase for Call[Cc70e3cf91]-EP<h323>[tcp
$200.117.192.17:19270/22716]
2010-12-13 11:58:22.306147 [DEBUG] connection.cxx:480 OnRelease thread
completed for Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716]
2010-12-13 11:58:22.308152 [DEBUG] tlibthrd.cxx:1020 Could not parse
thread stat file /proc/21145/task/21194/stat
2010-12-13 11:58:22.588122 [DEBUG] transports.cxx:900 Transport clean up
on termination
2010-12-13 11:58:22.588122 [DEBUG] transports.cxx:885 Transport Close
2010-12-13 11:58:22.588122 [DEBUG] transports.cxx:1045 Deleted transport
tcp$200.117.192.17:19270<if=tcp$72.51.47.100:1720>
2010-12-13 11:58:22.590122 [DEBUG] h323.cxx:330 Connection tcp
$200.117.192.17:19270/22716 deleted.
2010-12-13 11:58:22.590122 [DEBUG] connection.cxx:343 Connection
Call[Cc70e3cf91]-EP<h323>[tcp$200.117.192.17:19270/22716] destroyed.
2010-12-13 11:58:22.590122 [DEBUG] localep.cxx:211 Deleted connection.
2010-12-13 11:58:22.590122 [DEBUG] connection.cxx:343 Connection
Call[Cc70e3cf91]-EP<local>[Ldc8d6c462] destroyed.
2010-12-13 11:58:23.592039 [DEBUG] call.cxx:86 Call[Cc70e3cf91]
destroyed.
---------------------------------------------------------------------------------------------------------------------------------------------------------------------
Gustavo Espeche
www.easyipcall.com
More information about the FreeSWITCH-users
mailing list