bill*CLI> h323 set trace 5 H.323 Trace Enabled (Trace Level: 5) bill*CLI> h323 set debug H.323 Debugging Enabled bill*CLI> bill*CLI> 3:01.199 H323 Listener:b6f06b88 transports.cxx(1615) H323TCP Started connection: host=192.168.40.7:53890, if=192.168.40.4:1720, handle=25 3:01.199 H323 Listener:b6f06b88 transports.cxx(1410) TCP Waiting on socket accept on ip$192.168.40.4:1720 3:01.200 H225 Answer:8212b68 transports.cxx(620) H225 Started incoming call thread 3:01.200 H225 Answer:8212b68 transports.cxx(1203) H225 Awaiting first PDU 3:01.203 H225 Answer:8212b68 h323pdu.cxx(575) H225 Receiving PDU [ip$192.168.40.4:1720/ip$192.168.40.7:53890] : { q931pdu = { protocolDiscriminator = 8 callReference = 16 from = originator messageType = Setup IE: Bearer-Capability = { 80 90 a2 ... } IE: Display = { 50 61 76 65 6c 20 4a 65 7a 65 6b Pavel Jezek } IE: Calling-Party-Number = { 01 81 33 32 34 ..324 } IE: Called-Party-Number = { 81 39 36 38 .968 } IE: User-User = { 20 b0 06 00 08 91 4a 00 02 01 40 0a 00 50 00 61 .....J...@..P.a 00 76 00 65 00 6c 00 20 00 4a 00 65 00 7a 00 65 .v.e.l. .J.e.z.e 00 6b 02 00 01 01 00 c9 b0 00 01 b5 3f 99 27 e1 .k..........?.'. 1d 10 00 70 02 c0 a8 66 1b 00 45 0c 07 00 c0 a8 ...p...f..E..... 28 07 06 b8 11 00 00 01 b5 3f 99 27 e1 1d 10 00 (........?.'.... 70 02 c0 a8 66 1b 01 00 01 00 0a a0 01 00 0f 01 p...f........... 40 b5 00 00 12 08 80 a4 00 04 00 01 01 00 @............. } } h225pdu = { h323_uu_pdu = { h323_message_body = setup { protocolIdentifier = 0.0.8.2250.0.2 sourceAddress = 1 entries { [0]=h323_ID 11 characters { 0050 0061 0076 0065 006c 0020 004a 0065 Pavel Je 007a 0065 006b zek } } sourceInfo = { terminal = { } mc = FALSE undefinedNode = FALSE } destinationAddress = 1 entries { [0]=dialedDigits "968" } activeMC = FALSE conferenceID = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } conferenceGoal = create <> callType = pointToPoint <> sourceCallSignalAddress = ipAddress { ip = 4 octets { c0 a8 28 07 ..(. } port = 1720 } callIdentifier = { guid = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } } mediaWaitForConnect = FALSE canOverlapSend = FALSE } h245Tunneling = FALSE nonStandardControl = 1 entries { [0]={ nonStandardIdentifier = h221NonStandard { t35CountryCode = 181 t35Extension = 0 manufacturerCode = 18 } data = 8 octets { 80 a4 00 04 00 01 01 00 ........ } } } } } } 3:01.302 H225 Answer:8212b68 transports.cxx(1212) H225 Incoming call, first PDU: callReference=16 3:01.302 H225 Answer:8212b68 rfc2833.cxx(81) RFC2833 Handler created == New H.323 Connection created. 3:01.302 H225 Answer:8212b68 h323ep.cxx(2741) H323 Created new connection: ip$192.168.40.7:53890/16 Received non-standard Cisco extension data 8 octets { 80 a4 00 04 00 01 01 00 ........ } H323_UU_NonStdInfo = { callMgrParam = { interclusterVersion = 1 enterpriseID = 0 octets { } } } 3:01.303 H225 Answer:8212b68 h323.cxx(1030) H225 Handling PDU: Setup callRef=16 3:01.303 H225 Answer:8212b68 h323.cxx(1076) H225 Set remote application name: "Cisco IOS 12.x 181/18" --Received SETUP message -- Setting up Call -- Call token: [ip$192.168.40.7:53890/16] -- Calling party name: [Pavel Jezek] -- Calling party number: [324] -- Called party name: [968] -- Called party number: [968] -- Calling party IP: [192.168.40.7] 3:01.303 H225 Answer:8212b68 h323neg.cxx(340) H245 Stopping MasterSlaveDetermination: state=Idle 3:01.303 H225 Answer:8212b68 h323neg.cxx(572) H245 Stopping TerminalCapabilitySet: state=Idle 3:01.303 H225 Answer:8212b68 ast_h323.cxx(1218) H225 Fast Start DISABLED! 3:01.304 H225 Answer:8212b68 h323.cxx(1356) H235EP Authentication Failed but allowed by policy 3:01.304 H225 Answer:8212b68 h323.cxx(1300) H225 Set protocol version to 2 and implying H.245 version 3 Setting capabilities to 0x100 (g729) Capabilities in preference order is (g729) 3:01.304 H225 Answer:8212b68 h323caps.cxx(2150) H323 Added capability: G.729A <1> 3:01.304 H225 Answer:8212b68 h323caps.cxx(2150) H323 Added capability: G.729 <2> 3:01.304 H225 Answer:8212b68 h323caps.cxx(2150) H323 Added capability: UserInput/hookflash <3> DTMF mode is 1 3:01.304 H225 Answer:8212b68 h323caps.cxx(2150) H323 Added capability: UserInput/dtmf <4> Allowed Codecs for ip$192.168.40.7:53890/16 (ip$192.168.40.4:1720): Table: G.729A <1> G.729 <2> UserInput/hookflash <3> UserInput/dtmf <4> Set: 0: 0: G.729A <1> G.729 <2> 1: UserInput/hookflash <3> 2: UserInput/dtmf <4> 3:01.305 H225 Answer:8212b68 h323.cxx(1431) H225 Sending call proceeding PDU 3:01.306 H225 Answer:8212b68 h323pdu.cxx(575) H225 Sending PDU [ip$192.168.40.4:1720/ip$192.168.40.7:53890] : { q931pdu = { protocolDiscriminator = 8 callReference = 16 from = destination messageType = CallProceeding IE: Display = { 39 36 38 00 968. } IE: User-User = { 21 80 06 00 08 91 4a 00 02 22 c0 09 00 00 3d 36 !.....J.."....=6 54 68 65 20 4e 75 46 6f 6e 65 20 4e 65 74 77 6f The NuFone Netwo 72 6b 73 20 48 2e 33 32 33 20 43 68 61 6e 6e 65 rks H.323 Channe 6c 20 44 72 69 76 65 72 20 66 6f 72 20 41 73 74 l Driver for Ast 65 72 69 73 6b 00 00 19 31 2e 30 2e 30 20 28 4f erisk...1.0.0 (O 70 65 6e 48 33 32 33 20 76 31 2e 31 39 2e 30 29 penH323 v1.19.0) 00 00 00 f0 20 11 00 00 01 b5 3f 99 27 e1 1d 10 .... .....?.'... 00 70 02 c0 a8 66 1b 01 00 02 80 01 00 .p...f....... } } h225pdu = { h323_uu_pdu = { h323_message_body = callProceeding { protocolIdentifier = 0.0.8.2250.0.2 destinationInfo = { vendor = { vendor = { t35CountryCode = 9 t35Extension = 0 manufacturerCode = 61 } productId = 55 octets { 54 68 65 20 4e 75 46 6f 6e 65 20 4e 65 74 77 6f The NuFone Netwo 72 6b 73 20 48 2e 33 32 33 20 43 68 61 6e 6e 65 rks H.323 Channe 6c 20 44 72 69 76 65 72 20 66 6f 72 20 41 73 74 l Driver for Ast 65 72 69 73 6b 00 00 erisk.. } versionId = 26 octets { 31 2e 30 2e 30 20 28 4f 70 65 6e 48 33 32 33 20 1.0.0 (OpenH323 76 31 2e 31 39 2e 30 29 00 00 v1.19.0).. } } terminal = { } mc = FALSE undefinedNode = FALSE } callIdentifier = { guid = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } } fastConnectRefused = <> } h245Tunneling = FALSE }I> }CLI> }l*CLI> 3:01.313 H225 Answer:8212b68 h323.cxx(1472) H225 Incoming call accepted bill*CLI=-= In OnAnswerCall for call 16 bill*CLI> - Progress Indicator: 0 - Inserting PI of 0 into ALERTING message 3:01.315 H225 Answer:8212b68 h323.cxx(2038) H323 Answering call: AnswerCallDeferred 3:01.315 H225 Answer:8212b68 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer fastStartState=FastStartDisabled 3:01.315 H225 Answer:8212b68 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=AwaitingLocalAnswer fastStartState=FastStartDisabled 3:01.316 H225 Answer:8212b68 h323.cxx(957) H225 Reading PDUs: callRef=16 -- Executing [968@from-ccm:1] Dial("H323/ip$192.168.40.7:53890/16", "SIP/ipbx-gw/968") in new stack == Using SIP RTP CoS mark 5 -- Called ipbx-gw/968 -- SIP/ipbx-gw-08224198 answered H323/ip$192.168.40.7:53890/16 bill*CLIAnswering call ip$192.168.40.7:53890/16 3:01.385 ThreadID=0xb699ebb0 h323.cxx(2038) H323 Answering call: AnswerCallNow 3:01.386 ThreadID=0xb699ebb0 transports.cxx(1561) H225 TCP Listen for H245 on 192.168.40.4:38784 3:01.387 ThreadID=0xb699ebb0 h323pdu.cxx(575) H225 Sending PDU [ip$192.168.40.4:1720/ip$192.168.40.7:53890] : { q931pdu = { protocolDiscriminator = 8 callReference = 16 from = destination messageType = Connect IE: Bearer-Capability = { 80 90 a5 ... } IE: Display = { 39 36 38 00 968. } IE: User-User = { 22 c0 06 00 08 91 4a 00 02 00 c0 a8 28 04 97 80 ".....J.....(... 22 c0 09 00 00 3d 36 54 68 65 20 4e 75 46 6f 6e "....=6The NuFon 65 20 4e 65 74 77 6f 72 6b 73 20 48 2e 33 32 33 e Networks H.323 20 43 68 61 6e 6e 65 6c 20 44 72 69 76 65 72 20 Channel Driver 66 6f 72 20 41 73 74 65 72 69 73 6b 00 00 19 31 for Asterisk...1 2e 30 2e 30 20 28 4f 70 65 6e 48 33 32 33 20 76 .0.0 (OpenH323 v 31 2e 31 39 2e 30 29 00 00 00 00 01 b5 3f 99 27 1.19.0)......?.' e1 1d 10 00 70 02 c0 a8 66 1b 17 00 20 11 00 00 ....p...f... ... 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b 01 ..?.'....p...f.. 00 02 80 01 00 ..... } } h225pdu = { h323_uu_pdu = { h323_message_body = connect { protocolIdentifier = 0.0.8.2250.0.2 h245Address = ipAddress { ip = 4 octets { c0 a8 28 04 ..(. } port = 38784 } destinationInfo = { vendor = { vendor = { t35CountryCode = 9 t35Extension = 0 manufacturerCode = 61 } productId = 55 octets { 54 68 65 20 4e 75 46 6f 6e 65 20 4e 65 74 77 6f The NuFone Netwo 72 6b 73 20 48 2e 33 32 33 20 43 68 61 6e 6e 65 rks H.323 Channe 6c 20 44 72 69 76 65 72 20 66 6f 72 20 41 73 74 l Driver for Ast 65 72 69 73 6b 00 00 erisk.. } versionId = 26 octets { 31 2e 30 2e 30 20 28 4f 70 65 6e 48 33 32 33 20 1.0.0 (OpenH323 76 31 2e 31 39 2e 30 29 00 00 v1.19.0).. } } terminal = { } mc = FALSE undefinedNode = FALSE } conferenceID = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } callIdentifier = { guid = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } } fastConnectRefused = <> } h245Tunneling = FALSE } } } 3:01.388 ThreadID=0xb699ebb0 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=HasExecutedSignalConnect fastStartState=FastStartDisabled 3:01.388 H245:8227a00 transports.cxx(651) H245 Started thread 3:01.388 H245:8227a00 transports.cxx(1816) H245 TCP Accept wait 3:01.403 H245:8227a00 transports.cxx(1615) H323TCP Started connection: host=192.168.40.7:53891, if=192.168.40.4:38784, handle=39 3:01.403 H245:8227a00 h323.cxx(2842) H245 Started control channel 3:01.403 H245:8227a00 h323neg.cxx(560) H245 Sending TerminalCapabilitySet: outSeq=1 3:01.404 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request terminalCapabilitySet { sequenceNumber = 1 protocolIdentifier = 0.0.8.245.0.11 multiplexCapability = h2250Capability { maximumAudioDelayJitter = 250 receiveMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } transmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } }I> receiveAndTransmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } mcCapability = { centralizedConferenceMC = FALSE decentralizedConferenceMC = FALSE }I> rtcpVideoControlCapability = FALSE mediaPacketizationCapability = { h261aVideoPacketization = FALSE }I> logicalChannelSwitchingCapability = FALSE t120DynamicPortCapability = TRUE }CLI> capabilityTable = 4 entries { [0]={ capabilityTableEntryNumber = 1 capability = receiveAudioCapability g729AnnexA 2 }I> [1]={ capabilityTableEntryNumber = 2 capability = receiveAudioCapability g729 2 }I> [2]={ capabilityTableEntryNumber = 3 capability = receiveUserInputCapability hookflash <> }I> [3]={ capabilityTableEntryNumber = 4 capability = receiveUserInputCapability dtmf <> }I> }CLI> capabilityDescriptors = 1 entries { [0]={ capabilityDescriptorNumber = 1 simultaneousCapabilities = 3 entries { [0]=2 entries { [0]=1 [1]=2 } [1]=1 entries { [0]=3 } [2]=1 entries { [0]=4 } } }I> } }l*CLI> 3:01.431 H245:8227a00 h323neg.cxx(323) H245 Sending MasterSlaveDetermination 3:01.432 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request masterSlaveDetermination { terminalType = 50 statusDeterminationNumber = 4394395 } 3:01.436 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=71 pos=0.0 { 02 70 01 06 00 08 81 75 00 03 80 13 80 00 3c 00 p u < 01 00 00 01 00 00 01 00 00 0c c0 01 00 01 00 03 80 00 00 22 80 0f 80 00 2b 85 01 50 80 00 2c 85 " + P , 01 10 80 00 2d 85 01 40 00 80 00 02 00 00 00 00 - @ 00 2b 01 00 2c 00 2d + , - } 3:01.437 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request terminalCapabilitySet { sequenceNumber = 1 protocolIdentifier = 0.0.8.245.0.3 multiplexCapability = h2250Capability { maximumAudioDelayJitter = 60 receiveMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } transmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } receiveAndTransmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } mcCapability = { centralizedConferenceMC = FALSE decentralizedConferenceMC = FALSE }I> rtcpVideoControlCapability = FALSE mediaPacketizationCapability = { h261aVideoPacketization = FALSE } logicalChannelSwitchingCapability = FALSE t120DynamicPortCapability = FALSE } capabilityTable = 4 entries { [0]={ capabilityTableEntryNumber = 1 capability = receiveAudioCapability g729 16 }I> [1]={ capabilityTableEntryNumber = 44 capability = receiveAndTransmitUserInputCapability hookflash <> }I> [2]={ capabilityTableEntryNumber = 45 capability = receiveAndTransmitUserInputCapability basicString <> }I> [3]={ capabilityTableEntryNumber = 46 capability = receiveAndTransmitUserInputCapability dtmf <> }I> }CLI> capabilityDescriptors = 1 entries { [0]={ capabilityDescriptorNumber = 0 simultaneousCapabilities = 3 entries { [0]=1 entries { [0]=1 } [1]=1 entries { [0]=44 } [2]=2 entries { [0]=45 [1]=46 } } }I> } }l*CLI> 3:01.446 H245:8227a00 h323.cxx(3043) H245 Set protocol version to 3 3:01.446 H245:8227a00 h323neg.cxx(591) H245 Received TerminalCapabilitySet: state=InProgress pduSeq=1 inSeq=4294967295 3:01.479 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=HasExecutedSignalConnect fastStartState=FastStartDisabled 3:01.480 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=3 pos=0.0 { 21 80 01 ! } 3:01.480 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response terminalCapabilitySetAck { sequenceNumber = 1 } 3:01.480 H245:8227a00 h323neg.cxx(633) H245 Received TerminalCapabilitySetAck: state=InProgress pduSeq=1 outSeq=1 3:01.480 H245:8227a00 h323neg.cxx(643) H245 TerminalCapabilitySet Sent. 3:01.480 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=HasExecutedSignalConnect fastStartState=FastStartDisabled 3:01.481 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=2 pos=0.0 { 20 a0 } 3:01.481 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response masterSlaveDeterminationAck { decision = slave <> }l*CLI> 3:01.482 H245:8227a00 h323neg.cxx(414) H245 Received MasterSlaveDeterminationAck: state=Outgoing 3:01.482 H245:8227a00 h323neg.cxx(431) H245 MasterSlaveDetermination: remote is master 3:01.483 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response masterSlaveDeterminationAck { decision = master <> } 3:01.483 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=HasExecutedSignalConnect fastStartState=FastStartDisabled 3:01.483 H245:8227a00 h323caps.cxx(2238) H323 FindCapability: "T.120" 3:01.484 H245:8227a00 h323.cxx(3799) H245 Default OnSelectLogicalChannels, FastStartDisabled 3:01.484 H245:8227a00 h323caps.cxx(2274) H323 FindCapability: G.729A <1> 3:01.484 H245:8227a00 h323caps.cxx(2274) H323 FindCapability: G.729 <2> 3:01.485 H245:8227a00 h323caps.cxx(2278) H323 Found capability: G.729 <1> 3:01.485 H245:8227a00 h323.cxx(3864) H323 Selecting G.729 <1> 3:01.485 H245:8227a00 h323neg.cxx(759) H245 Opening channel: T-101 3:01.486 H245:8227a00 channels.cxx(923) H323RTP OnSendingPDU bill*CLI-- Started logical channel: sending G.729 bill*CLI> -- channelsOpen = 1 3:01.487 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request openLogicalChannel { forwardLogicalChannelNumber = 101 forwardLogicalChannelParameters = { dataType = audioData g729 16 multiplexParameters = h2250LogicalChannelParameters { sessionID = 1 mediaGuaranteedDelivery = FALSE mediaControlChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 28 04 ..(. } tsapIdentifier = 17013 } silenceSuppression = FALSE } }CLI> } =-= In OnConnectionEstablished for call 16 -- Connection Established with "Pavel Jezek [192.168.40.7]" 3:01.492 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=20 pos=0.0 { 03 00 00 00 0d 40 01 80 0b 05 00 01 00 c0 a8 28 @ ( 07 0f a1 00 } 3:01.493 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request openLogicalChannel { forwardLogicalChannelNumber = 1 forwardLogicalChannelParameters = { dataType = audioData g729 2 multiplexParameters = h2250LogicalChannelParameters { sessionID = 1 mediaControlChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 28 07 ..(. } tsapIdentifier = 4001 } silenceSuppression = FALSE } }CLI> } 3:01.495 H245:8227a00 h323neg.cxx(851) H245 Received open channel: R-1, state=Released 3:01.495 H245:8227a00 h323.cxx(4045) H323 CreateLogicalChannel - forward channel 3:01.496 H245:8227a00 h323caps.cxx(2337) H323 FindCapability: audioData 3:01.496 H245:8227a00 h323caps.cxx(1020) H323 Capability tx frames reduced from 23 to 2 3:01.496 H245:8227a00 h323caps.cxx(2382) H323 Found capability: G.729 <2> 3:01.496 H245:8227a00 h323caps.cxx(1025) H323 Capability rx frames left at 2 as remote allows 2 3:01.497 H245:8227a00 channels.cxx(982) H323RTP OnReceivedPDU for channel: R-1 3:01.497 H245:8227a00 h323caps.cxx(1025) H323 Capability rx frames left at 2 as remote allows 2 3:01.497 H245:8227a00 channels.cxx(951) H323RTP OnSendOpenAck 3:01.498 H245:8227a00 channels.cxx(972) H323RTP Sending open logical channel ACK: sessionID=1 -- Started logical channel: receiving G.729 bill*CLI> -- channelsOpen = 2 External RTP Session Starting bill*CLI> RTP channel id 1 parameters: -- remoteIpAddress: 192.168.40.7 bill*CLI> -- remotePort: 4000 bill*CLI> -- ExternalIpAddress: 192.168.40.4 bill*CLI> -- ExternalPort: 17012 3:01.499 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response openLogicalChannelAck { forwardLogicalChannelNumber = 1 forwardMultiplexAckParameters = h2250LogicalChannelAckParameters { sessionID = 1 mediaChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 28 04 ..(. } tsapIdentifier = 17012 }I> mediaControlChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 28 04 ..(. } tsapIdentifier = 17013 }I> flowControlToZero = FALSE }CLI> }l*CLI> 3:01.502 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=EstablishedConnection fastStartState=FastStartDisabled 3:01.561 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=23 pos=0.0 { 22 c0 00 64 04 80 10 1c 00 00 c0 a8 66 1b 60 08 " d f ` 00 c0 a8 66 1b 60 09 f ` } 3:01.561 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response openLogicalChannelAck { forwardLogicalChannelNumber = 101 forwardMultiplexAckParameters = h2250LogicalChannelAckParameters { sessionID = 1 mediaChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 66 1b ..f. } tsapIdentifier = 24584 }I> mediaControlChannel = unicastAddress iPAddress { network = 4 octets { c0 a8 66 1b ..f. } tsapIdentifier = 24585 }I> flowControlToZero = FALSE }CLI> }l*CLI> 3:01.564 H245:8227a00 h323neg.cxx(914) H245 Received open channel ack: T-101, state=AwaitingEstablishment 3:01.564 H245:8227a00 channels.cxx(1028) H323RTP OnReceiveOpenAck MyH323_ExternalRTPChannel::OnReceivedAckPDU bill*CLI> -- remoteIpAddress: 192.168.102.27 bill*CLI> -- remotePort: 24584 bill*CLI> External RTP Session Starting bill*CLI> RTP channel id 1 parameters: bill*CLI> -- remoteIpAddress: 192.168.102.27 bill*CLI> -- remotePort: 24584 bill*CLI> -- ExternalIpAddress: 192.168.40.4 bill*CLI> -- ExternalPort: 17012 3:01.567 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=EstablishedConnection fastStartState=FastStartDisabled -- Packet2Packet bridging H323/ip$192.168.40.7:53890/16 and SIP/ipbx-gw-08224198 bill*CLI> bill*CLI> bill*CLI> 3:07.255 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=5 pos=0.0 { 04 00 00 00 00 } 3:07.255 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : request closeLogicalChannel { forwardLogicalChannelNumber = 1 source = user <> reason = unknown (NULL) } 3:07.255 H245:8227a00 h323neg.cxx(1017) H245 Received close channel: R-1, state=Established 3:07.255 H245:8227a00 channels.cxx(688) LogChan Cleaning up R-1 channelsOpen = 1 3:07.256 H245:8227a00 h323ep.cxx(2794) H323 Stopped receiving logical channel: G.729 <2> 3:07.256 H245:8227a00 channels.cxx(716) LogChan Cleaned up R-1 ExternalRTPChannel Destroyed 3:07.256 H245:8227a00 h323.cxx(4294) H323 Bandwidth request: -0.0kb/s, available: 128.0kb/s 3:07.256 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : response closeLogicalChannelAck { forwardLogicalChannelNumber = 1 } 3:07.256 H245:8227a00 h323.cxx(3728) H323 InternalEstablishedConnectionCheck: connectionState=EstablishedConnection fastStartState=FastStartDisabled 3:07.257 H245:8227a00 h323.cxx(2919) H245 Received TPKT: size=2 pos=0.0 { 4a 40 J@ } 3:07.257 H245:8227a00 h323pdu.cxx(575) H245 Receiving PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : command endSessionCommand disconnect <> -- ClearCall: Request to clear call with token ip$192.168.40.7:53890/16, cause EndedByRemoteUser 3:07.257 H245:8227a00 h323ep.cxx(2391) H323 Clearing connection ip$192.168.40.7:53890/16 reason=EndedByRemoteUser 3:07.258 H245:8227a00 h323.cxx(757) H323 Call end reason for ip$192.168.40.7:53890/16 set to EndedByRemoteUser 3:07.258 H245:8227a00 h323.cxx(775) H225 Sending release complete PDU: callRef=16 bill*CLI-- Sending RELEASE COMPLETE 3:07.258 H245:8227a00 h323pdu.cxx(575) H245 Sending PDU [ip$192.168.40.4:38784/ip$192.168.40.7:53891] : command endSessionCommand disconnect <> 3:07.259 H245:8227a00 h323pdu.cxx(575) H225 Sending PDU [ip$192.168.40.4:1720/ip$192.168.40.7:53890] : { q931pdu = { protocolDiscriminator = 8 callReference = 16 from = destination messageType = ReleaseComplete IE: Cause - Normal call clearing = { 80 90 .. } IE: User-User = { 25 80 06 00 08 91 4a 00 02 01 11 00 00 01 b5 3f %.....J........? 99 27 e1 1d 10 00 70 02 c0 a8 66 1b 02 80 01 00 .'....p...f..... }I> } h225pdu = { h323_uu_pdu = { h323_message_body = releaseComplete { protocolIdentifier = 0.0.8.2250.0.2 callIdentifier = { guid = 16 octets { 00 01 b5 3f 99 27 e1 1d 10 00 70 02 c0 a8 66 1b ...?.'....p...f. } } } h245Tunneling = FALSE } } } 3:07.259 H245:8227a00 h323.cxx(2907) H245 Control channel closed. 3:07.259 H323 Cleaner h323ep.cxx(2450) H323 Cleaning up connections 3:07.260 H323 Cleaner h323.cxx(817) H323 Connection ip$192.168.40.7:53890/16 closing: connectionState=EstablishedConnection 3:07.260 H323 Cleaner h323neg.cxx(340) H245 Stopping MasterSlaveDetermination: state=Idle 3:07.260 H323 Cleaner h323neg.cxx(572) H245 Stopping TerminalCapabilitySet: state=Sent 3:07.260 H323 Cleaner channels.cxx(688) LogChan Cleaning up T-101 channelsOpen = 0 3:07.260 H323 Cleaner h323ep.cxx(2794) H323 Stopped sending logical channel: G.729 <1> 3:07.260 H323 Cleaner channels.cxx(716) LogChan Cleaned up T-101 bill*CLIExternalRTPChannel Destroyed 3:07.261 H323 Cleaner h323.cxx(4294) H323 Bandwidth request: -0.0kb/s, available: 128.0kb/s 3:07.262 H323 Cleaner h323.cxx(860) H323 Awaiting end session from remote for 9.997 seconds 3:07.262 H323 Cleaner transports.cxx(1186) H323 H323Transport::Close 3:07.262 H323 Cleaner transports.cxx(1294) H323 H323Transport::CleanUpOnTermination for H245:8227a00 3:07.262 H323 Cleaner transports.cxx(1186) H323 H323Transport::Close 3:07.263 H225 Answer:8212b68 h323pdu.cxx(1420) H225 Read error (4): Interrupted system call bill*CLI-- ClearCall: Request to clear call with token ip$192.168.40.7:53890/16, cause EndedByTransportFail 3:07.263 H225 Answer:8212b68 h323ep.cxx(2391) H323 Clearing connection ip$192.168.40.7:53890/16 reason=EndedByTransportFail 3:07.264 H225 Answer:8212b68 transports.cxx(1186) H323 H323Transport::Close 3:07.264 H225 Answer:8212b68 h323.cxx(971) H225 Signal channel closed. 3:07.265 H323 Cleaner transports.cxx(1294) H323 H323Transport::CleanUpOnTermination for H225 Answer:8212b68 3:07.265 H323 Cleaner h323.cxx(895) H323 Connection ip$192.168.40.7:53890/16 terminated. -- Pavel Jezek [192.168.40.7] has cleared the call bill*CLI== H.323 Connection deleted. 3:07.266 H323 Cleaner h323.cxx(707) H323 Connection ip$192.168.40.7:53890/16 deleted. 3:07.266 H323 Cleaner h323ep.cxx(2450) H323 Cleaning up connections == Spawn extension (from-ccm, 968, 1) exited non-zero on 'H323/ip$192.168.40.7:53890/16' bill*CLI> bill*CLI>