[Freeswitch-users] opal to sip problem

13 Dec 2010

      Hello list, we are try to do inter-worker between h323 and sip using
opal in freeswitch, but FS don't send the call to our sip gw, follow is
the  call flow:

h323 endpoint -->FS->sip gateway

attached a FS debug of call.

if something know or work with opal in freeSwitch and have some tips we
appreciate a lot if advice about it.
Best Regards.
-----------------------------------------------------------------------------------------------------------------------------
2010-12-13 11:58:21.325242 [DEBUG] transports.cxx:1200 Started
connection to 200.117.192.17:19270 (if=72.51.47.100:1720)
2010-12-13 11:58:21.325242 [DEBUG] osutil.cxx:189 File handle high water
mark set: 67 Thread unblock pipe
2010-12-13 11:58:21.325242 [DEBUG] tlibthrd.cxx:587 Thread high water
mark set: 8
2010-12-13 11:58:21.325242 [DEBUG] transports.cxx:666 Waiting on socket
accept on tcp$72.51.47.100:1720
2010-12-13 11:58:21.325242 [DEBUG] h323ep.cxx:501 Awaiting first PDU
2010-12-13 11:58:21.805203 [DEBUG] h323pdu.cxx:80 Receiving PDU:
  {
    q931pdu = {
      protocolDiscriminator = 8
      callReference = 22716
      from = originator
      messageType = Setup
      IE: Bearer-Capability = {
        88 93 a5                            
               ...
      }
      IE: Display = {
        67 75 73 74 61 76 6f 00                            gustavo.
      }
      IE: Called-Party-Number = {
        81 32 33 31 35 34 33 35  31 34 32 38 30 36 33
33   .231543514280633
      }

IE: User-User = {
        20 b8 06 00 08 91 4a 00  06 01 40 06 00 67 00
75    .....J...@..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