AsteriskGuru Archives

piotr.stankiewicz at gmai · Guest

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@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@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@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.