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

Tihomir Culjaga tculjaga at gmail.com
Thu Oct 22 07:53:06 PDT 2009


>
> TC>
> TC>Do you need some logs ?
>
> try disable medai-proxy, there is issue with rtp now then medai-proxy or
> transcoding enabled.
>
>
Outbound calls:

disabled rtp proxy and it is still the same issue ... audio delay H323 =>
SIP endpoint.






Inbound calls:

This is the extension i use to register my Avaya SIP phone to FS.


<include>
  <user id="1001">
    <params>
      <param name="password" value="$${default_password}"/>
      <param name="vm-password" value="1001"/>
    </params>
    <variables>
      <variable name="toll_allow" value="domestic,international,local"/>
      <variable name="accountcode" value="1001"/>
      <variable name="user_context" value="default"/>
      <variable name="effective_caller_id_name" value="Extension 1001"/>
      <variable name="effective_caller_id_number" value="1001"/>
      <variable name="outbound_caller_id_name"
value="$${outbound_caller_name}"/>
      <variable name="outbound_caller_id_number"
value="$${outbound_caller_id}"/>
      <variable name="callgroup" value="techsupport"/>
    </variables>
  </user>
</include>


This is my h323.conf.xml


<configuration name="h323.conf" description="H323 Endpoints">
  <settings>
    <param name="trace-level" value="4"/>
    <param name="context" value="default"/>
    <param name="dialplan" value="XML"/>
    <param name="codec-prefs" value="PCMU,PCMA,GSM,G729,G726"/>
    <param name="gk-address" value=""/>    <!-- empty to disable, "*" to
search LAN -->
    <param name="gk-identifer" value=""/>  <!-- optional name of gk -->
    <param name="gk-interface" value=""/>  <!-- optional listener interface
name -->
  </settings>
  <listeners>
    <listener name="default">
      <param name="h323-ip" value="10.4.62.7"/>
      <param name="h323-port" value="1720"/>
    </listener>
  </listeners>
</configuration>

I'm using default context and an inbound call looks for a registered user in
default context where 1001 user is registered to.



here is the log for an outgoing call:
http://pastebin.freeswitch.org/10799and here is a tshark output:
http://pastebin.freeswitch.org/10800


there are 2 thing that are not working here:


1. no audio at all!
2. hangup from SIP User side doesn't release the H323 leg











two points for your reference in the logs:


1. Here, SIP User disconnected the SIP leg, but nothing was triggered in
mod_h323 ... as the callback function "on_hangup" (in mod_h323.cpp) was
never triggered!

freeswitch at subZero>
freeswitch at subZero>
freeswitch at subZero> recv 371 bytes from udp/[10.4.62.89]:5060 at
14:39:36.714521:
   ------------------------------------------------------------------------
   BYE sip:mod_sofia at 10.4.62.7:5060 SIP/2.0
   From: <sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>
;transport=udp>;tag=-22166b474ae08abf-7_T10.4.62.89
   To: sip:1001282166 at 10.4.62.7 <sip%3A1001282166 at 10.4.62.7>
;tag=Qpc53NZ2cZc1N
   Call-ID: 8aa825c6-39bb-122d-bb89-00110a5be1f0
   CSeq: 127 BYE
   Via: SIP/2.0/UDP
10.4.62.89;branch=z9hG4bK-7e5dc720_442d0f8-2d8bf1174f235bec_B
   Content-Length: 0
   Max-Forwards: 70
   Supported: replaces

   ------------------------------------------------------------------------
2009-10-22 16:39:36.714604 [NOTICE] sofia.c:322 Hangup sofia/internal/
sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> [CS_CONSUME_MEDIA]
[NORMAL_CLEARING]
2009-10-22 16:39:36.714604 [DEBUG] switch_channel.c:1683 Send signal
sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> [KILL]
2009-10-22 16:39:36.714604 [DEBUG] switch_core_session.c:932 Send signal
sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> [BREAK]
send 520 bytes to udp/[10.4.62.89]:5060 at 14:39:36.715258:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP
10.4.62.89;branch=z9hG4bK-7e5dc720_442d0f8-2d8bf1174f235bec_B
   From: <sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>
;transport=udp>;tag=-22166b474ae08abf-7_T10.4.62.89
   To: sip:1001282166 at 10.4.62.7 <sip%3A1001282166 at 10.4.62.7>
;tag=Qpc53NZ2cZc1N
   Call-ID: 8aa825c6-39bb-122d-bb89-00110a5be1f0
   CSeq: 127 BYE
   User-Agent: FreeSWITCH-mod_sofia/1.0.4-exported
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Content-Length: 0

   ------------------------------------------------------------------------
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:503
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State
CONSUME_MEDIA going to sleep
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) Running State
Change CS_HANGUP
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State HANGUP
2009-10-22 16:39:36.721097 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> hanging up, cause:
NORMAL_CLEARING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> Standard HANGUP,
cause: NORMAL_CLEARING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State HANGUP
going to sleep
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State Change
CS_HANGUP -> CS_REPORTING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_session.c:932 Send signal
sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> [BREAK]
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) Running State
Change CS_REPORTING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:612
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State REPORTING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89> Standard
REPORTING, cause: NORMAL_CLEARING
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:612
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State REPORTING
going to sleep
2009-10-22 16:39:36.721097 [DEBUG] switch_core_state_machine.c:411
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) State Change
CS_REPORTING -> CS_DESTROY
2009-10-22 16:39:36.721097 [DEBUG] switch_core_session.c:1068 Session 10
(sofia/internal/sip:1001 at 10.4.62.89 <sip%3A1001 at 10.4.62.89>) Locked, Waiting
on external entities

freeswitch at subZero>





2. switch_ivr_originate.c complains => 2009-10-22 16:39:41.630243 [ERR]
switch_ivr_originate.c:1510 Cannot create outgoing channel of type [user]
cause: [NORMAL_CLEARING]


freeswitch at subZero>
freeswitch at subZero>
freeswitch at subZero> 2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609
Receiving PDU [ip$10.4.62.7:1720/ip$10.4.62.31:16013] :
  {
    q931pdu = {
      protocolDiscriminator = 8
      callReference = 23
      from = originator
      messageType = ReleaseComplete
      IE: Cause - Normal ca
ll clearing = {
        80 90                                              ..
      }
      IE: User-User = {
        25 80 06 00 08 91 4a 00  04 11 00 11 00 96 40 1f   %.....J....... at .
        4e be 4f 11 de 80 76 ae  99 96 03 ba ff 10 80 01   N.O.
..v.........
        ...
      }
    }
    h225pdu = {
      h323_uu_pdu = {
        h323_message_body = releaseComplete {
          protocolIdentifier = 0.0.8.2250.0.4
          callIdentifier = {
            guid =  16 octets {
              96 40
 1f 4e be 4f 11 de  80 76 ae 99 96 03 ba ff   . at .N.O...v......
            }
          }
        }
        h245Tunneling = true
      }
    }
  }
2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1292 Handling PDU:
ReleaseComplete callRef=23
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:745
======>FSH323Connection::OnReceivedReleaseComplete cause = Normal call
clearing value = 16
2009-10-22 16:39:41.630243 [NOTICE] mod_h323.cpp:749 Hangup h323/1001
[CS_EXECUTE] [NORMAL_CLEARING]
2009-10-22 16:39:41.630243 [DEBUG] switch_channel.c:1683 Send signal
h323/1001 [KILL]
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:840
======>FSH323Connection::kill_channel FSH323Connection
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:841 Kill 1 on connection
FSH323Connection
2009-10-22 16:39:41.630243 [DEBUG] switch_core_session.c:630 Send signal
h323/1001 [BREAK]
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:840
======>FSH323Connection::kill_channel FSH323Connection
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:841 Kill 3 on connection
FSH323Connection
2009-10-22 16:39:41.630243 [DEBUG] switch_ivr_originate.c:2138 Originate
Resulted in Error Cause: 16 [NORMAL_CLEARING]
2009-10-22 16:39:41.630243 [ERR] switch_ivr_originate.c:1510 Cannot create
outgoing channel of type [user] cause: [NORMAL_CLEARING]
2009-10-22 16:39:41.630243 [DEBUG] switch_ivr_originate.c:2138 Originate
Resulted in Error Cause: 16 [NORMAL_CLEARING]
2009-10-22 16:39:41.630243 [INFO] mod_dptools.c:2093 Originate Failed.
Cause: NORMAL_CLEARING
2009-10-22 16:39:41.630243 [DEBUG] mod_dptools.c:2120 Continue on fail
[true]:  Cause: NORMAL_CLEARING
2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:491
(h323/1001) State EXECUTE going to sleep
2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:398
(h323/1001) Running State Change CS_HANGUP
2009-10-22 16:39:41.630243 [DEBUG] switch_core_state_machine.c:434
(h323/1001) State HANGUP
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:1454 ======>switch_status_t
on_hangup
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:1459 ----->
2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:1272 Call End Reason Normal
call clearing
2009-10-22 16:39:41.630243 [DEBUG] h323ep.cxx:2694 Clearing connection ip$
10.4.62.31:16013/23 reason=EndedByRemoteUser
2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1034 Call end reason for ip$
10.4.62.31:16013/23 set to EndedByRemoteUser
2009-10-22 16:39:41.630243 [DEBUG] h323.cxx:1052 Sending release complete
PDU: callRef=23
2009-10-22 16:39:41.630243 [DEBUG] mod_h323.cpp:764
======>FSH323Connection::OnSendReleaseComplete cause = Normal call clearing
value = 16
2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609 Sending PDU
[(noaddr)/(noaddr)] :
  command endSessionCommand disconnect <<null>>
2009-10-22 16:39:41.630243 [DEBUG] h323pdu.cxx:609 Sending PDU [ip$
10.4.62.7:1720/ip$10.4.62.31:16013] :
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20091022/fbd61d8d/attachment-0002.html 


More information about the FreeSWITCH-users mailing list