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...@..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@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@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@200.35.145.149 [f9bf5b9e-a273-400c-b18c-e2c98c84750f] 2010-12-13 11:58:21.840189 [DEBUG] mod_sofia.c:3995 (sofia/external/21543514280633@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@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@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@200.35.145.149) State INIT 2010-12-13 11:58:21.843189 [DEBUG] mod_sofia.c:86 sofia/external/21543514280633@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.843189 [DEBUG] sofia.c:4604 Channel sofia/external/21543514280633@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@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@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@200.35.145.149 [KILL] 2010-12-13 11:58:21.843189 [DEBUG] switch_core_session.c:1083 Send signal sofia/external/21543514280633@200.35.145.149 [BREAK] 2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:356 (sofia/external/21543514280633@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@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@200.35.145.149) State HANGUP 2010-12-13 11:58:21.849192 [DEBUG] mod_sofia.c:453 sofia/external/21543514280633@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@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@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@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:320 (sofia/external/21543514280633@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@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@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@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.856029 [DEBUG] switch_core_session.c:1250 Session 2 (sofia/external/21543514280633@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@200.35.145.149) Ended 2010-12-13 11:58:21.856029 [NOTICE] switch_core_session.c:1270 Close Channel sofia/external/21543514280633@200.35.145.149 [CS_DESTROY] 2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:449 (sofia/external/21543514280633@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@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@200.35.145.149) State DESTROY 2010-12-13 11:58:21.858228 [DEBUG] mod_sofia.c:364 sofia/external/21543514280633@200.35.145.149 SOFIA DESTROY 2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:60 sofia/external/21543514280633@200.35.145.149 Standard DESTROY 2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:462 (sofia/external/21543514280633@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
I can't help you with mod_opal, but I use FS with mod_h323 ad sip<->h.323 gateway successfully. Rgds, Nikolay.
-----Original Message----- From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Gustavo Espeche Sent: Monday, December 13, 2010 5:24 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] opal to sip problem
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...@..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@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@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@200.35.145.149 [f9bf5b9e-a273-400c-b18c-e2c98c84750f] 2010-12-13 11:58:21.840189 [DEBUG] mod_sofia.c:3995 (sofia/external/21543514280633@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@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@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@200.35.145.149) State INIT 2010-12-13 11:58:21.843189 [DEBUG] mod_sofia.c:86 sofia/external/21543514280633@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.843189 [DEBUG] sofia.c:4604 Channel sofia/external/21543514280633@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@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@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@200.35.145.149 [KILL] 2010-12-13 11:58:21.843189 [DEBUG] switch_core_session.c:1083 Send signal sofia/external/21543514280633@200.35.145.149 [BREAK] 2010-12-13 11:58:21.843189 [DEBUG] switch_core_state_machine.c:356 (sofia/external/21543514280633@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@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@200.35.145.149) State HANGUP 2010-12-13 11:58:21.849192 [DEBUG] mod_sofia.c:453 sofia/external/21543514280633@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@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@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@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.849192 [DEBUG] switch_core_state_machine.c:320 (sofia/external/21543514280633@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@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@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@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@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@200.35.145.149 [BREAK] 2010-12-13 11:58:21.856029 [DEBUG] switch_core_session.c:1250 Session 2 (sofia/external/21543514280633@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@200.35.145.149) Ended 2010-12-13 11:58:21.856029 [NOTICE] switch_core_session.c:1270 Close Channel sofia/external/21543514280633@200.35.145.149 [CS_DESTROY] 2010-12-13 11:58:21.856029 [DEBUG] switch_core_state_machine.c:449 (sofia/external/21543514280633@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@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@200.35.145.149) State DESTROY 2010-12-13 11:58:21.858228 [DEBUG] mod_sofia.c:364 sofia/external/21543514280633@200.35.145.149 SOFIA DESTROY 2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:60 sofia/external/21543514280633@200.35.145.149 Standard DESTROY 2010-12-13 11:58:21.858228 [DEBUG] switch_core_state_machine.c:462 (sofia/external/21543514280633@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
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freesw itch-users http://www.freeswitch.org
participants (2)
-
Gustavo Espeche
-
Nikolay Kondratyev