Re: [Freeswitch-users] Fwd: mod_opal - call charged before H.225 connect

22 Oct 2009

      On 2009-10-22 16:53 +0200, Tihomir Culjaga wrote freeswitch-users@lists.fre...:

finally i fix this rtp bug, check new wersion please.

TC>>
TC>> TC>
TC>> TC>Do you need some logs ?
TC>>
TC>> try disable medai-proxy, there is issue with rtp now then medai-proxy or
TC>> transcoding enabled.
TC>>
TC>>
TC>Outbound calls:
TC>
TC>disabled rtp proxy and it is still the same issue ... audio delay H323 =>
TC>SIP endpoint.
TC>
TC>
TC>
TC>
TC>
TC>
TC>Inbound calls:
TC>
TC>This is the extension i use to register my Avaya SIP phone to FS.
TC>
TC>
TC><include>
TC>  <user id="1001">
TC>    <params>
TC>      <param name="password" value="$${default_password}"/>
TC>      <param name="vm-password" value="1001"/>
TC>    </params>
TC>    <variables>
TC>      <variable name="toll_allow" value="domestic,international,local"/>
TC>      <variable name="accountcode" value="1001"/>
TC>      <variable name="user_context" value="default"/>
TC>      <variable name="effective_caller_id_name" value="Extension 1001"/>
TC>      <variable name="effective_caller_id_number" value="1001"/>
TC>      <variable name="outbound_caller_id_name"
TC>value="$${outbound_caller_name}"/>
TC>      <variable name="outbound_caller_id_number"
TC>value="$${outbound_caller_id}"/>
TC>      <variable name="callgroup" value="techsupport"/>
TC>    </variables>
TC>  </user>
TC></include>
TC>
TC>
TC>This is my h323.conf.xml
TC>
TC>
TC><configuration name="h323.conf" description="H323 Endpoints">
TC>  <settings>
TC>    <param name="trace-level" value="4"/>
TC>    <param name="context" value="default"/>
TC>    <param name="dialplan" value="XML"/>
TC>    <param name="codec-prefs" value="PCMU,PCMA,GSM,G729,G726"/>
TC>    <param name="gk-address" value=""/>    <!-- empty to disable, "*" to
TC>search LAN -->
TC>    <param name="gk-identifer" value=""/>  <!-- optional name of gk -->
TC>    <param name="gk-interface" value=""/>  <!-- optional listener interface
TC>name -->
TC>  </settings>
TC>  <listeners>
TC>    <listener name="default">
TC>      <param name="h323-ip" value="10.4.62.7"/>
TC>      <param name="h323-port" value="1720"/>
TC>    </listener>
TC>  </listeners>
TC></configuration>
TC>
TC>I'm using default context and an inbound call looks for a registered user in
TC>default context where 1001 user is registered to.
TC>
TC>
TC>
TC>here is the log for an outgoing call:
TC>http://pastebin.freeswitch.org/10799and here is a tshark output:
TC>http://pastebin.freeswitch.org/10800
TC>
TC>
TC>there are 2 thing that are not working here:
TC>
TC>
TC>1. no audio at all!
TC>2. hangup from SIP User side doesn't release the H323 leg
TC>
TC>
TC>
TC>
TC>
TC>
TC>
TC>
TC>
TC>
TC>
TC>two points for your reference in the logs:
TC>
TC>
TC>1. Here, SIP User disconnected the SIP leg, but nothing was triggered in
TC>mod_h323 ... as the callback function "on_hangup" (in mod_h323.cpp) was
TC>never triggered!
TC>
TC>freeswitch@subZero>
TC>freeswitch@subZero>
TC>freeswitch@subZero> recv 371 bytes from udp/[10.4.62.89]:5060 at
TC>14:39:36.714521:
TC>   ------------------------------------------------------------------------
TC>   BYE sip:mod_sofia@10.4.62.7:5060 SIP/2.0
TC>   From: <sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>
TC>;transport=udp>;tag=-22166b474ae08abf-7_T10.4.62.89
TC>   To: sip:1001282166@10.4.62.7 <sip%3A1001282166@10.4.62.7>
TC>;tag=Qpc53NZ2cZc1N
TC>   Call-ID: 8aa825c6-39bb-122d-bb89-00110a5be1f0
TC>   CSeq: 127 BYE
TC>   Via: SIP/2.0/UDP
TC>10.4.62.89;branch=z9hG4bK-7e5dc720_442d0f8-2d8bf1174f235bec_B
TC>   Content-Length: 0
TC>   Max-Forwards: 70
TC>   Supported: replaces
TC>
TC>   ------------------------------------------------------------------------
TC>2009-10-22 16:39:36.714604 [NOTICE] sofia.c:322 Hangup sofia/internal/
TC>sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> [CS_CONSUME_MEDIA]
TC>[NORMAL_CLEARING]
TC>2009-10-22 16:39:36.714604 [DEBUG] switch_channel.c:1683 Send signal
TC>sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> [KILL]
TC>2009-10-22 16:39:36.714604 [DEBUG] switch_core_session.c:932 Send signal
TC>sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> [BREAK]
TC>send 520 bytes to udp/[10.4.62.89]:5060 at 14:39:36.715258:
TC>   ------------------------------------------------------------------------
TC>   SIP/2.0 200 OK
TC>   Via: SIP/2.0/UDP
TC>10.4.62.89;branch=z9hG4bK-7e5dc720_442d0f8-2d8bf1174f235bec_B
TC>   From: <sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>
TC>;transport=udp>;tag=-22166b474ae08abf-7_T10.4.62.89
TC>   To: sip:1001282166@10.4.62.7 <sip%3A1001282166@10.4.62.7>
TC>;tag=Qpc53NZ2cZc1N
TC>   Call-ID: 8aa825c6-39bb-122d-bb89-00110a5be1f0
TC>   CSeq: 127 BYE
TC>   User-Agent: FreeSWITCH-mod_sofia/1.0.4-exported
TC>   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
TC>NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
TC>   Supported: timer, precondition, path, replaces
TC>   Content-Length: 0
TC>
TC>   ------------------------------------------------------------------------
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:503
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State
TC>CONSUME_MEDIA going to sleep
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:398
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) Running State
TC>Change CS_HANGUP
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:434
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State HANGUP
TC>2009-10-22 16:39:36.721097 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
TC>sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> hanging up, cause:
TC>NORMAL_CLEARING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:46
TC>sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> Standard HANGUP,
TC>cause: NORMAL_CLEARING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:434
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State HANGUP
TC>going to sleep
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:476
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State Change
TC>CS_HANGUP -> CS_REPORTING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_session.c:932 Send signal
TC>sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> [BREAK]
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:398
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) Running State
TC>Change CS_REPORTING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:612
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State REPORTING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:53
TC>sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89> Standard
TC>REPORTING, cause: NORMAL_CLEARING
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:612
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State REPORTING
TC>going to sleep
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:411
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) State Change
TC>CS_REPORTING -> CS_DESTROY
TC>2009-10-22 16:39:36.721097 [DEBUG] switch_core_session.c:1068 Session 10
TC>(sofia/internal/sip:1001@10.4.62.89 <sip%3A1001@10.4.62.89>) Locked, Waiting
TC>on external entities
TC>
TC>freeswitch@subZero>
TC>
TC>
TC>
TC>
TC>
TC>2. switch_ivr_originate.c complains => 2009-10-22 16:39:41.630243 [ERR]
TC>switch_ivr_originate.c:1510 Cannot create outgoing channel of type [user]
TC>cause: [NORMAL_CLEARING]
TC>
TC>
TC>freeswitch@subZero>
TC>freeswitch@subZero>
TC>freeswitch@subZero> 2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609
TC>Receiving PDU [ip$10.4.62.7:1720/ip$10.4.62.31:16013] :
TC>  {
TC>    q931pdu = {
TC>      protocolDiscriminator = 8
TC>      callReference = 23
TC>      from = originator
TC>      messageType = ReleaseComplete
TC>      IE: Cause - Normal ca
TC>ll clearing = {
TC>        80 90                                              ..
TC>      }
TC>      IE: User-User = {
TC>        25 80 06 00 08 91 4a 00  04 11 00 11 00 96 40 1f   %.....J.......@.
TC>        4e be 4f 11 de 80 76 ae  99 96 03 ba ff 10 80 01   N.O.
TC>..v.........
TC>        ...
TC>      }
TC>    }
TC>    h225pdu = {
TC>      h323_uu_pdu = {
TC>        h323_message_body = releaseComplete {
TC>          protocolIdentifier = 0.0.8.2250.0.4
TC>          callIdentifier = {
TC>            guid =  16 octets {
TC>              96 40
TC> 1f 4e be 4f 11 de  80 76 ae 99 96 03 ba ff   .@.N.O...v......
TC>            }
TC>          }
TC>        }
TC>        h245Tunneling = true
TC>      }
TC>    }
TC>  }
TC>2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1292 Handling PDU:
TC>ReleaseComplete callRef=23
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:745
TC>======>FSH323Connection::OnReceivedReleaseComplete cause = Normal call
TC>clearing value = 16
TC>2009-10-22 16:39:41.630243 [NOTICE] mod_h323.cpp:749 Hangup h323/1001
TC>[CS_EXECUTE] [NORMAL_CLEARING]
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_channel.c:1683 Send signal
TC>h323/1001 [KILL]
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:840
TC>======>FSH323Connection::kill_channel FSH323Connection
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:841 Kill 1 on connection
TC>FSH323Connection
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_core_session.c:630 Send signal
TC>h323/1001 [BREAK]
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:840
TC>======>FSH323Connection::kill_channel FSH323Connection
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:841 Kill 3 on connection
TC>FSH323Connection
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_ivr_originate.c:2138 Originate
TC>Resulted in Error Cause: 16 [NORMAL_CLEARING]
TC>2009-10-22 16:39:41.630243 [ERR] switch_ivr_originate.c:1510 Cannot create
TC>outgoing channel of type [user] cause: [NORMAL_CLEARING]
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_ivr_originate.c:2138 Originate
TC>Resulted in Error Cause: 16 [NORMAL_CLEARING]
TC>2009-10-22 16:39:41.630243 [INFO] mod_dptools.c:2093 Originate Failed.
TC>Cause: NORMAL_CLEARING
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_dptools.c:2120 Continue on fail
TC>[true]:  Cause: NORMAL_CLEARING
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:491
TC>(h323/1001) State EXECUTE going to sleep
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:398
TC>(h323/1001) Running State Change CS_HANGUP
TC>2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:434
TC>(h323/1001) State HANGUP
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:1454 ======>switch_status_t
TC>on_hangup
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:1459 ----->
TC>2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:1272 Call End Reason Normal
TC>call clearing
TC>2009-10-22 16:39:41.630243 [DEBUG] h323ep.cxx:2694 Clearing connection ip$
TC>10.4.62.31:16013/23 reason=EndedByRemoteUser
TC>2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1034 Call end reason for ip$
TC>10.4.62.31:16013/23 set to EndedByRemoteUser
TC>2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1052 Sending release complete
TC>PDU: callRef=23
TC>2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:764
TC>======>FSH323Connection::OnSendReleaseComplete cause = Normal call clearing
TC>value = 16
TC>2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609 Sending PDU
TC>[(noaddr)/(noaddr)] :
TC>  command endSessionCommand disconnect <<null>>
TC>2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609 Sending PDU [ip$
TC>10.4.62.7:1720/ip$10.4.62.31:16013] :
TC>

C уважением                       With Best Regards
Георгиевский Юрий.                Georgiewskiy Yuriy
+7 4872 711666                    +7 4872 711666
факс +7 4872 711143               fax +7 4872 711143
Компания ООО "Ай Ти Сервис"       IT Service Ltd
http://nkoort.ru                  http://nkoort.ru
JID: GHhost@jabber.tula-ix.net.ru JID: GHhost@jabber.tula-ix.net.ru
YG129-RIPE                        YG129-RIPE