[asterisk-users] strange h323 delay issue

Giedrius Augys voipas at gmail.com
Sun Oct 19 07:01:40 CDT 2008


2008/10/19 Mindaugas Kezys <mkezys at gmail.com>

>  Hi,
>
>
>
> Try downgrade to Asterisk 1.4.18.1. It works for us perfectly with H323.
>
>
>
> Following versions has nasty bugs, not actually related to H323, but who
> knows, maybe it will help to downgrade.
>
>
>
> Regards,
>
> Mindaugas Kezys
>
> http://www.kolmisoft.com
>
> VoIP Billing and Routing Solutions
>
>
>
> *From:* asterisk-users-bounces at lists.digium.com [mailto:
> asterisk-users-bounces at lists.digium.com] *On Behalf Of *Giedrius Augys
> *Sent:* 2008 m. spalio 18 d. 22:08
> *To:* Asterisk Users Mailing List - Non-Commercial Discussion
> *Subject:* [asterisk-users] strange h323 delay issue
>
>
>
> Hello,
>
>   I have a strange h323 issue. After executing command
> "Dial("SIP/333-0d1dfe00", "H323/361737052390920 at ccg|5|tT")"  at Oct 18
> 22:32:23. Meanwile I have sniffing traffic on port 1720. The call was
> established just at Oct 18 22:33:03 (New H.323 Connection created.) and also
> packet sniffer grabs the h323 invites at this time also. So my question is
> what asterisk (h323 channel) was doing for 40 sec??? What reasons could
> invoke this problem? I haven't any problems with SIP channels.
>
> My versions:
> asterisk-1.4.21.1
> asterisk-addons-1.4.6
> openh323_v1_18_0
> pwlib_v1_10_0
>
> My h323.conf configurations:
> [general]
> port = 1720
> bindaddr = 192.168.1.165
> tos=lowdelay
> disallow=all
> allow=g729
> dtmfmode=rfc2833
> gatekeeper = DISABLE
> AllowGKRouted = no
> AcceptAnonymous = no
> context=from-trunk
>
>
> [ccg]
> type=friend
> context=from-trunk
> host=192.168.1.163
> port=1720
> disallow=all
> ;allow=alaw
> ;allow=ulaw
> allow=g729
> fastStart=yes
> h245Tunneling=yes
>
>
> A full log:
>
> [Oct 18 22:32:23] VERBOSE[18236] logger.c:     -- Executing [123 at from-sip:1]
> Dial("SIP/333-0d1d8fb0", "H323/361737052390920 at ccg|5|tT") in new stack
> [Oct 18 22:32:23] DEBUG[18236] chan_h323.c: type=H323, format=8,
> data=361737052390920 at ccg.
> [Oct 18 22:32:23] DEBUG[18236] chan_h323.c: Extension: 361737052390920
> Host: ccg
> [Oct 18 22:32:23] DEBUG[18236] chan_h323.c: Calling to 361737052390920 at ccgon H323/ccg-2
> [Oct 18 22:32:23] VERBOSE[18236] logger.c:     -- Requested transfer
> capability: 0x00 - SPEECH
> [Oct 18 22:32:23] DEBUG[18236] chan_h323.c: Placing outgoing call to
> 361737052390920 at 192.168.1.163:1720, 101
> [Oct 18 22:32:23] VERBOSE[18236] logger.c:  -- Making call to
> 361737052390920 at 192.168.1.163:1720 without gatekeeper.
> [Oct 18 22:32:23] VERBOSE[18236] logger.c: Using 192.168.1.165 for
> outbound call
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:      == New H.323 Connection
> created.
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:      -- root is calling host
> 361737052390920 at 192.168.1.163:1720
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:      -- Call token is
> ip$localhost/6453
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:      -- Call reference is 6453
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:      -- DTMF Payload is [pt=101]
> [Oct 18 22:33:03] VERBOSE[18236] logger.c:     -- Called
> 361737052390920 at ccg
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Setting capabilities for
> connection ip$localhost/6453
> [Oct 18 22:33:03] VERBOSE[18238] logger.c: Setting capabilities to 0x100
> (g729)
> [Oct 18 22:33:03] VERBOSE[18238] logger.c: Capabilities in preference order
> is (g729)
> [Oct 18 22:33:03] VERBOSE[18238] logger.c: Allowed Codecs:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:       Table:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    G.729A <1>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    G.729 <2>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    UserInput/hookflash <3>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    UserInput/RFC2833 <4>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    UserInput/dtmf <5>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:  Set:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:    0:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      0:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:        G.729A <1>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:        G.729 <2>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      1:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:        UserInput/hookflash <3>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      2:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:        UserInput/RFC2833 <4>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:        UserInput/dtmf <5>
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Capabilities for connection
> ip$localhost/6453 is set
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Created RTP channel
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Setting NAT on RTP to 0
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Sending RTP 'US'
> 192.168.1.165:23786
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Sending RTP 'US'
> 192.168.1.165:23786
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Sending RTP 'US'
> 192.168.1.165:23786
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Sending RTP 'US'
> 192.168.1.165:23786
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      -- Sending SETUP message
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      -- Transmitting RFC2833 on
> payload 101
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      -- Started logical channel:
> sending G.729A
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- channelsOpen = 1
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              External RTP
> Session Starting
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              RTP channel id 1
> parameters:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- remoteIpAddress:
> 192.168.1.163
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- remotePort:
> 10626
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              --
> ExternalIpAddress: 192.168.1.165
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- ExternalPort:
> 23786
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Setting up RTP connection for
> ip$localhost/6453
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Native format is set to 256
> from 256 by RTP payload type 18
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: RTP connection prepared for
> ip$localhost/6453
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      -- Started logical channel:
> receiving G.729A
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- channelsOpen = 2
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              External RTP
> Session Starting
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              RTP channel id 1
> parameters:
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- remoteIpAddress:
> 192.168.1.163
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- remotePort:
> 10626
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              --
> ExternalIpAddress: 192.168.1.165
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:              -- ExternalPort:
> 23786
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Setting up RTP connection for
> ip$localhost/6453
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: Native format is set to 256
> from 256 by RTP payload type 18
> [Oct 18 22:33:03] DEBUG[18238] chan_h323.c: RTP connection prepared for
> ip$localhost/6453
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      ExternalRTPChannel
> Destroyed
> [Oct 18 22:33:03] VERBOSE[18238] logger.c:      ExternalRTPChannel
> Destroyed
> [Oct 18 22:33:04] VERBOSE[18238] logger.c:      =-= In OnAlerting for call
> 6453: sessionId=0
> [Oct 18 22:33:04] VERBOSE[18238] logger.c:      -- Ringing phone for
> "361737052390920"
> [Oct 18 22:33:04] VERBOSE[18238] logger.c:              - Progress
> Indicator: 8
> [Oct 18 22:33:04] DEBUG[18238] chan_h323.c: Received ALERT/PROGRESS message
> for inband tones
> [Oct 18 22:33:04] DEBUG[18238] chan_h323.c: Ringing on ip$localhost/6453
> [Oct 18 22:33:04] VERBOSE[18236] logger.c:     -- H323/ccg-2 is making
> progress passing it to SIP/333-0d1d8fb0
> [Oct 18 22:33:04] VERBOSE[18236] logger.c:     -- H323/ccg-2 is ringing
> [Oct 18 22:33:04] VERBOSE[18238] logger.c:      -- Received Facility
> message...
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capability is G.729 <2>
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Found peer capability G.729 <2>,
> Asterisk code is 256, frame size (in ms) is 60
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capability is G.729A <3>
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Found peer capability G.729A
> <3>, Asterisk code is 256, frame size (in ms) is 0
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capability is G.723.1A <4>
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Found peer capability G.723.1A
> <4>, Asterisk code is 1, frame size (in ms) is 60
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capability is
> UserInput/dtmf <7>
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capability is
> UserInput/hookflash <8>
> [Oct 18 22:33:04] VERBOSE[18238] logger.c: Peer capabilities = 0x101
> (g723|g729), ordered list is (g729|g723)
> [Oct 18 22:33:04] DEBUG[18238] chan_h323.c: Got remote capabilities from
> connection ip$localhost/6453
> [Oct 18 22:33:04] DEBUG[18238] chan_h323.c: prefs[0]=g729:60
> [Oct 18 22:33:04] DEBUG[18238] chan_h323.c: prefs[1]=g723:60
> [Oct 18 22:33:04] VERBOSE[18238] logger.c:      -- Received Facility
> message...
> [Oct 18 22:33:08] VERBOSE[18236] logger.c:     -- Nobody picked up in 5000
> ms
> [Oct 18 22:33:08] DEBUG[18236] chan_h323.c: Hanging up and scheduling
> destroy of call H323/ccg-2
> [Oct 18 22:33:08] VERBOSE[18236] logger.c:      -- Sending RELEASE COMPLETE
> [Oct 18 22:33:08] VERBOSE[18236] logger.c:      -- ClearCall: Request to
> clear call with token ip$localhost/6453, cause EndedByRemoteUser
> [Oct 18 22:33:08] VERBOSE[18236] logger.c:   == Auto fallthrough, channel
> 'SIP/333-0d1d8fb0' status is 'NOANSWER'
> [Oct 18 22:33:08] VERBOSE[18215] logger.c:              channelsOpen = 1
> [Oct 18 22:33:08] VERBOSE[18215] logger.c:              channelsOpen = 0
> [Oct 18 22:33:08] VERBOSE[18215] logger.c:      ExternalRTPChannel
> Destroyed
> [Oct 18 22:33:08] VERBOSE[18215] logger.c:      ExternalRTPChannel
> Destroyed
> [Oct 18 22:33:08] VERBOSE[18238] logger.c:      -- ClearCall: Request to
> clear call with token ip$localhost/6453, cause EndedByTransportFail
> [Oct 18 22:33:08] VERBOSE[18215] logger.c: -- 361737052390920 has cleared
> the call
> [Oct 18 22:33:08] DEBUG[18215] chan_h323.c: Cleaning connection to
> ip$localhost/6453
> [Oct 18 22:33:08] DEBUG[18215] chan_h323.c: No connection for
> ip$localhost/6453
> [Oct 18 22:33:08] VERBOSE[18215] logger.c:      == H.323 Connection
> deleted.
>
>
> Thanks
> --
> Pagarbiai  / Best Regards,
> Giedrius Augys
>
> _______________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>   http://lists.digium.com/mailman/listinfo/asterisk-users
>


Not helped...

-- 
Pagarbiai  / Best Regards,
Giedrius Augys
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20081019/25b584dc/attachment-0001.htm 


More information about the asterisk-users mailing list