[Asterisk-video] 3g calls fails on h324m_loopback() and h324_gw_answer()

Piotr Stankiewicz piotr.stankiewicz at gmail.com
Mon May 25 06:47:09 CDT 2009


Hi!
I've got problem with making 3g video calls from mobile to my asterisk
gateway. The call is placed, then asterisk freezes for about 10-15 seconds
on h324m_loopback() or h324_gw_answer() (no video, no audio), and then it
disconnects with cause 16.
I've found similar topics around the internet and this mailing list, but no
answers. So I post my question - what I am doing wrong? Is it possible that
telco's PRI is causing this problem? Are there any special requirements
which should be meet to get proper 3G gateway?

My system:
asterisk 1.4.22 witch all necessary libraries and apps from
sip.fontventa.com
libpri 1.4.10
dahdi 2.1.0.4

Digium * card TE420

Mobile phone - HTC Touch Diamond

extensions which I've tried:
1)
[from-e1]
exten => _X.,1,Answer(5000)
exten => _X.,n,h324m_loopback()
(I've tried Answer(), and h324m_loopback(av) also)

2)
[from-e1]
exten => _X.,1,H324m_gw(loopback at 3gp_videos)


[3gp_videos]
exten => loopback,1,h324m_gw_answer()
exten => loopback,n,Video_loopback()
exten => loopback,n,Hangup()

/var/log/asterisk/full:


[May 22 14:20:44] VERBOSE[9480] logger.c: < Protocol Discriminator: Q.931
(8)  len=49
[May 22 14:20:44] VERBOSE[9480] logger.c: < Call Ref: len= 2 (reference
7680/0x1E00) (Originator)
[May 22 14:20:44] VERBOSE[9480] logger.c: < Message type: SETUP (5)
[May 22 14:20:44] VERBOSE[9480] logger.c: < [04 02 88 90]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Bearer Capability (len= 4) [
Ext: 1  Q.931 Std: 0  Info transfer capability: Unrestricted digital
information (8)
[May 22 14:20:44] VERBOSE[9480] logger.c: <
Ext: 1  Trans mode/rate: 64kbps, circuit-mode (16)
[May 22 14:20:44] VERBOSE[9480] logger.c: < [18 03 a9 83 9f]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Channel ID (len= 5) [ Ext: 1
IntID: Implicit  PRI  Spare: 0  Exclusive  Dchan: 0
[May 22 14:20:44] VERBOSE[9480] logger.c: <                        ChanSel:
As indicated in following octets
[May 22 14:20:44] VERBOSE[9480] logger.c: <                       Ext: 1
Coding: 0  Number Specified  Channel Type: 3
[May 22 14:20:44] VERBOSE[9480] logger.c: <                       Ext: 1
Channel: 31 ]
[May 22 14:20:44] VERBOSE[9480] logger.c: < [6c 0d 11 83 34 38 37 39 31 37
37 36 30 35 36]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Calling Number (len=15) [ Ext:
0  TON: International Number (1)  NPI: ISDN/Telephony Numbering Plan
(E.164/E.163) (1)
[May 22 14:20:44] VERBOSE[9480] logger.c: <
Presentation: Presentation allowed of network provided number (3)
'4879xxxxxxx' ]
[May 22 14:20:44] VERBOSE[9480] logger.c: < [70 0c 81 33 33 31 37 34 39 30
34 36 30 31]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Called Number (len=14) [ Ext: 1
TON: Unknown Number Type (0)  NPI: ISDN/Telephony Numbering Plan
(E.164/E.163) (1)  '3317xxxxxxx' ]
[May 22 14:20:44] VERBOSE[9480] logger.c: < [7c 03 88 90 a6]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Low-layer Compatability (len= 5)
[ Ext: 1  Q.931 Std: 0  Info transfer capability: Unrestricted digital
information (8)
[May 22 14:20:44] VERBOSE[9480] logger.c: <
Ext: 1  Trans mode/rate: 64kbps, circuit-mode (16)
[May 22 14:20:44] VERBOSE[9480] logger.c: <
User information layer 1: H.223/H.245 Multimedia (38)
[May 22 14:20:44] VERBOSE[9480] logger.c: < [a1]
[May 22 14:20:44] VERBOSE[9480] logger.c: < Sending Complete (len= 1)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Making new call for cr 7680
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing Q.931 Call Setup
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 4 (cs0, Bearer
Capability)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 24 (cs0, Channel
Identification)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 108 (cs0, Calling
Party Number)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 112 (cs0, Called
Party Number)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 124 (cs0,
Low-layer Compatibility)
[May 22 14:20:44] VERBOSE[9480] logger.c: -- Processing IE 161 (cs0, Sending
Complete)
[May 22 14:20:44] VERBOSE[9480] logger.c: q931.c:3562 q931_receive: call
7680 on channel 31 enters state 6 (Call Present)
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: PRI_EVENT_RING: seting incoming
call on channel 31 to law=1
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: PRI_EVENT_RING: user information
layer 1 of incoming call = -1 (0xffffffff)
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: PRI_EVENT_RING: treat incoming
call on channel 31 as ULAW(1)
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: PRI_EVENT_RING: seting incoming
call on channel 31 to law=1
[May 22 14:20:44] VERBOSE[9480] logger.c: q931.c:2827 q931_call_proceeding:
call 7680 on channel 31 enters state 9 (Incoming Call Proceeding)
[May 22 14:20:44] VERBOSE[9480] logger.c: > Protocol Discriminator: Q.931
(8)  len=10
[May 22 14:20:44] VERBOSE[9480] logger.c: > Call Ref: len= 2 (reference
7680/0x1E00) (Terminator)
[May 22 14:20:44] VERBOSE[9480] logger.c: > Message type: CALL PROCEEDING
(2)
[May 22 14:20:44] VERBOSE[9480] logger.c: > [18 03 a9 83 9f]
[May 22 14:20:44] VERBOSE[9480] logger.c: > Channel ID (len= 5) [ Ext: 1
IntID: Implicit  PRI  Spare: 0  Exclusive  Dchan: 0
[May 22 14:20:44] VERBOSE[9480] logger.c: >                        ChanSel:
As indicated in following octets
[May 22 14:20:44] VERBOSE[9480] logger.c: >                       Ext: 1
Coding: 0  Number Specified  Channel Type: 3
[May 22 14:20:44] VERBOSE[9480] logger.c: >                       Ext: 1
Channel: 31 ]
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: PRI_EVENT_RING: zt_new:
law=1,ul1=-1
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: dahdi_new:
ps.curlaw!=DAHDI_LAW_ALAW, setting deflaw to AST_FORMAT_ULAW
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: zt_new: law=DAHDI_LAW_ALAW,
setting deflaw to AST_FORMAT_ULAW
[May 22 14:20:44] VERBOSE[9480] logger.c:     -- Accepting call from
'4879xxxxxxx' to '3317xxxxxxx' on channel 0/31, span 1
[May 22 14:20:44] DEBUG[9480] chan_dahdi.c: Echo cancellation isn't required
on digital connection
[May 22 14:20:44] DEBUG[9895] pbx.c: Launching 'Answer'
[May 22 14:20:44] VERBOSE[9895] logger.c:     -- Executing
[3317xxxxxxxx at from-e1:1] Answer("DAHDI/31-1", "") in new stack
[May 22 14:20:44] DEBUG[9895] devicestate.c: Notification of state change to
be queued on device/channel DAHDI/31
[May 22 14:20:44] DEBUG[9471] devicestate.c: No provider found, checking
channel drivers for DAHDI - 31
[May 22 14:20:44] VERBOSE[9895] logger.c: q931.c:2962 q931_connect: call
7680 on channel 31 enters state 8 (Connect Request)
[May 22 14:20:44] DEBUG[9471] channel.c: Avoiding initial deadlock for
channel '0x822cbe0'
[May 22 14:20:44] VERBOSE[9895] logger.c: > Protocol Discriminator: Q.931
(8)  len=10
[May 22 14:20:44] VERBOSE[9895] logger.c: > Call Ref: len= 2 (reference
7680/0x1E00) (Terminator)
[May 22 14:20:44] VERBOSE[9895] logger.c: > Message type: CONNECT (7)
[May 22 14:20:44] VERBOSE[9895] logger.c: > [18 03 a9 83 9f]
[May 22 14:20:44] VERBOSE[9895] logger.c: > Channel ID (len= 5) [ Ext: 1
IntID: Implicit  PRI  Spare: 0  Exclusive  Dchan: 0
[May 22 14:20:44] VERBOSE[9895] logger.c: >                        ChanSel:
As indicated in following octets
[May 22 14:20:44] VERBOSE[9895] logger.c: >                       Ext: 1
Coding: 0  Number Specified  Channel Type: 3
[May 22 14:20:44] VERBOSE[9895] logger.c: >                       Ext: 1
Channel: 31 ]
[May 22 14:20:44] DEBUG[9895] pbx.c: Launching 'h324m_loopback'
[May 22 14:20:44] VERBOSE[9895] logger.c:     -- Executing
[3317xxxxxxx at from-e1:2] h324m_loopback("DAHDI/31-1", "") in new stack
[May 22 14:20:44] DEBUG[9895] app_h324m.c: h324m_loopback
[May 22 14:20:44] DEBUG[9895] app_h324m.c: H245 TerminalCapabilitySet
TransferRequest
[May 22 14:20:44] DEBUG[9895] app_h324m.c: -WriteControlPDU [request]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: Encode PDU [95]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: Sending CMD [0,87]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: H245 Request
MasterSlaveDetermination
[May 22 14:20:44] DEBUG[9895] app_h324m.c: -WriteControlPDU [request]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: Encode PDU [20]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: Sending CMD [1,7]
[May 22 14:20:44] DEBUG[9895] app_h324m.c: Sending CMD [0] - 1 left
[May 22 14:20:44] DEBUG[9471] devicestate.c: Changing state for DAHDI/31 -
state 2 (In use)
[May 22 14:20:44] DEBUG[9497] app_queue.c: Device 'DAHDI/31' changed to
state '2' (In use) but we don't care because they're not a member of any
queue.
[May 22 14:20:44] VERBOSE[9480] logger.c: < Protocol Discriminator: Q.931
(8)  len=5
[May 22 14:20:44] VERBOSE[9480] logger.c: < Call Ref: len= 2 (reference
7680/0x1E00) (Originator)
[May 22 14:20:44] VERBOSE[9480] logger.c: < Message type: CONNECT
ACKNOWLEDGE (15)
[May 22 14:20:44] VERBOSE[9480] logger.c: q931.c:3722 q931_receive: call
7680 on channel 31 enters state 10 (Active)
[May 22 14:20:58] VERBOSE[9480] logger.c: < Protocol Discriminator: Q.931
(8)  len=9
[May 22 14:20:58] VERBOSE[9480] logger.c: < Call Ref: len= 2 (reference
7680/0x1E00) (Originator)
[May 22 14:20:58] VERBOSE[9480] logger.c: < Message type: DISCONNECT (69)
[May 22 14:20:58] VERBOSE[9480] logger.c: < [08 02 81 90]
[May 22 14:20:58] VERBOSE[9480] logger.c: < Cause (len= 4) [ Ext: 1  Coding:
CCITT (ITU) standard (0)  Spare: 0  Location: Private network serving the
local user (1)
[May 22 14:20:58] VERBOSE[9480] logger.c: <                  Ext: 1  Cause:
Normal Clearing (16), class = Normal Event (1) ]
[May 22 14:20:58] VERBOSE[9480] logger.c: -- Processing IE 8 (cs0, Cause)
[May 22 14:20:58] VERBOSE[9480] logger.c: q931.c:3837 q931_receive: call
7680 on channel 31 enters state 12 (Disconnect Indication)
[May 22 14:20:58] VERBOSE[9480] logger.c:     -- Channel 0/31, span 1 got
hangup request, cause 16
[May 22 14:20:58] DEBUG[9895] app_h324m.c: exit[May 22 14:20:58] DEBUG[9895]
pbx.c: Extension 3317xxxxxxx, priority 2 returned normally even though call
was hung up
[May 22 14:20:58] DEBUG[9895] channel.c: Soft-Hanging up channel
'DAHDI/31-1'
[May 22 14:20:58] DEBUG[9895] channel.c: Hanging up channel 'DAHDI/31-1'
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: dahdi_hangup(DAHDI/31-1)
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Set option AUDIO MODE, value:
ON(1) on DAHDI/31-1
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Hangup: channel: 31 index = 0,
normal = 50, callwait = -1, thirdcall = -1
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Not yet hungup...  Calling
hangup once with icause, and clearing call
[May 22 14:20:58] VERBOSE[9895] logger.c: NEW_HANGUP DEBUG: Calling
q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request
[May 22 14:20:58] VERBOSE[9895] logger.c: q931.c:2978 q931_release: call
7680 on channel 31 enters state 19 (Release Request)
[May 22 14:20:58] VERBOSE[9895] logger.c: > Protocol Discriminator: Q.931
(8)  len=9
[May 22 14:20:58] VERBOSE[9895] logger.c: > Call Ref: len= 2 (reference
7680/0x1E00) (Terminator)
[May 22 14:20:58] VERBOSE[9895] logger.c: > Message type: RELEASE (77)
[May 22 14:20:58] VERBOSE[9895] logger.c: > [08 02 81 90]
[May 22 14:20:58] VERBOSE[9895] logger.c: > Cause (len= 4) [ Ext: 1  Coding:
CCITT (ITU) standard (0)  Spare: 0  Location: Private network serving the
local user (1)
[May 22 14:20:58] VERBOSE[9895] logger.c: >                  Ext: 1  Cause:
Normal Clearing (16), class = Normal Event (1) ]
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: disabled echo cancellation on
channel 31
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Set option TDD MODE, value:
OFF(0) on DAHDI/31-1
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Updated conferencing on 31, with
0 conference users
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: Set option AUDIO MODE, value:
OFF(0) on DAHDI/31-1
[May 22 14:20:58] DEBUG[9895] chan_dahdi.c: disabled echo cancellation on
channel 31
[May 22 14:20:58] VERBOSE[9895] logger.c:     -- Hungup 'DAHDI/31-1'
[May 22 14:20:58] VERBOSE[9480] logger.c: < Protocol Discriminator: Q.931
(8)  len=5
[May 22 14:20:58] VERBOSE[9480] logger.c: < Call Ref: len= 2 (reference
7680/0x1E00) (Originator)
[May 22 14:20:58] VERBOSE[9480] logger.c: < Message type: RELEASE COMPLETE
(90)
[May 22 14:20:58] VERBOSE[9480] logger.c: q931.c:3777 q931_receive: call
7680 on channel 31 enters state 0 (Null)
[May 22 14:20:58] VERBOSE[9480] logger.c: NEW_HANGUP DEBUG: Calling
q931_hangup, ourstate Null, peerstate Null
[May 22 14:20:58] VERBOSE[9480] logger.c: NEW_HANGUP DEBUG: Destroying the
call, ourstate Null, peerstate Null
[May 22 14:20:59] DEBUG[9895] devicestate.c: Notification of state change to
be queued on device/channel DAHDI/31
[May 22 14:20:59] DEBUG[9471] devicestate.c: No provider found, checking
channel drivers for DAHDI - 31
[May 22 14:20:59] DEBUG[9471] devicestate.c: Changing state for DAHDI/31 -
state 0 (Unknown)
[May 22 14:20:59] DEBUG[9497] app_queue.c: Device 'DAHDI/31' changed to
state '0' (Unknown) but we don't care because they're not a member of any
queue.

Incomig audioonly calls are working great, problem exist with videocalls
only.
Thanks for all replies in advance,
Regards,
Void.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-video/attachments/20090525/47b510a5/attachment-0001.htm 


More information about the asterisk-video mailing list