[Home]

Summary:ASTERISK-16448: Bridge with sip channel fails; channel format 0x0 (nothing)
Reporter:Jacco van Tuijl (jacco)Labels:
Date Opened:2010-07-28 04:16:50Date Closed:2011-06-07 14:05:22
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) bridge_failed__loop_with_5_sec_pause.png
( 1) bridge_okay.png
( 2) sip_2010.08.03_124118.pcap
( 3) tshark_cap.txt
Description:about once evey ten times, when trying to bridge an active sip channel with an active sip channel on a trunk, it fails with the following warning:
[Jul 27 17:28:42] WARNING[5064]: features.c:4583 bridge_exec: Bridge failed because channel SIP/xxx.xxx.xxx.xxx-000000xx does not exists or we cannot get its lock (where SIP/xxx.xxx.xxx.xxx-000000xx is SU201 in the additional information)




****** ADDITIONAL INFORMATION ******

when typing "sip show channels"
when bridge is working correct it shows:

Peer User/ANR Call ID Format
169.254.100.50 SU201 ElUyqtC9mpc0XW- 0x8 (alaw)
169.254.100.70 4801 1558a1f74f647b3 0x8 (alaw)

when bridging fails it show:

Peer User/ANR Call ID Format
169.254.100.50 SU201 ElUyqtC9mpc0XW- 0x0 (nothing)
169.254.100.70 4801 1558a1f74f647b3 0x8 (alaw)

SU201 is an (asterisk) sip client that makes calls without registration

the Tshark trace when the bridging fails shows all RTP streams are PCMA/ALAW:
========================= RTP Streams ========================
   Src IP addr Port Dest IP addr Port SSRC Payload Pkts Lost Max Delta(ms) Max Jitter(ms) Mean Jitter(ms) Problems?
169.254.100.50 4004 169.254.100.71 12256 0x04F4AA67 ITU-T G.711 PCMA 2703 0 (0.0%) 27.66 1.14 0.38
169.254.100.71 12256 169.254.100.50 4004 0x2BAE802A ITU-T G.711 PCMA 536 0 (0.0%) 21.35 0.23 0.02
169.254.100.71 17850 169.254.100.70 13442 0x5FAE4716 ITU-T G.711 PCMA 46 0 (0.0%) 20.33 0.05 0.03
169.254.100.70 13442 169.254.100.71 17850 0x2AB8646C ITU-T G.711 PCMA 406 0 (0.0%) 37.18 13.80 13.31


some debug output from when bridging fails:

[Jul 27 10:48:03] DEBUG[7319]: rtp.c:3878 ast_rtp_write: Ooh, format changed from unknown to alaw
[Jul 27 10:48:03] DEBUG[7319]: rtp.c:3904 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Jul 27 10:48:03] DEBUG[7319]: channel.c:4441 ast_channel_masquerade: Planning to masquerade channel SIP/IPdect-0000007e into the structure of Local/100@callfiles-5ebc;1
[Jul 27 10:48:03] DEBUG[7319]: channel.c:4453 ast_channel_masquerade: Done planning to masquerade channel SIP/IPdect-0000007e into the structure of Local/100@callfiles-5ebc;1
[Jul 27 10:48:03] DEBUG[7319]: chan_local.c:363 local_write: Not posting to queue since already masked on 'Local/100@callfiles-5ebc;2'
[Jul 27 10:48:03] DEBUG[7316]: channel.c:4579 ast_do_masquerade: Actually Masquerading SIP/IPdect-0000007e(6) into the structure of Local/100@callfiles-5ebc;1(6)
[Jul 27 10:48:03] DEBUG[7316]: channel.c:4592 ast_do_masquerade: Got clone lock for masquerade on 'SIP/IPdect-0000007e' at 0x8632d20
[Jul 27 10:48:03] DEBUG[7316]: channel.c:3881 set_format: Set channel SIP/IPdect-0000007e to write format slin
[Jul 27 10:48:03] DEBUG[7316]: channel.c:3881 set_format: Set channel SIP/IPdect-0000007e to read format slin
[Jul 27 10:48:03] DEBUG[7316]: channel.c:4778 ast_do_masquerade: Putting channel SIP/IPdect-0000007e in 64/64 formats
[Jul 27 10:48:03] DEBUG[7316]: chan_sip.c:6367 sip_fixup: SIP Fixup: New owner for dialogue 45021b6b0c8cf9ba090714e96f2eaad0@169.254.100.71: SIP/IPdect-0000007e (Old parent: Local/100@callfiles-5ebc;1<ZOMBIE>)
[Jul 27 10:48:03] DEBUG[7316]: channel.c:4824 ast_do_masquerade: Released clone lock on 'Local/100@callfiles-5ebc;1<ZOMBIE>'
[Jul 27 10:48:03] DEBUG[7316]: channel.c:4833 ast_do_masquerade: Done Masquerading SIP/IPdect-0000007e (6)
[Jul 27 10:48:03] DEBUG[7319]: channel.c:5044 ast_generic_bridge: Didn't get a frame from channel: Local/100@callfiles-5ebc;2
[Jul 27 10:48:03] DEBUG[7319]: channel.c:5472 ast_channel_bridge: Bridge stops bridging channels Local/100@callfiles-5ebc;2 and Local/100@callfiles-5ebc;1<ZOMBIE>
[Jul 27 10:48:03] DEBUG[7319]: channel.c:1824 ast_hangup: Hanging up zombie 'Local/100@callfiles-5ebc;1<ZOMBIE>'
[Jul 27 10:48:03] DEBUG[7319]: app_dial.c:2317 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[Jul 27 10:48:03] DEBUG[7319]: pbx.c:4317 __ast_pbx_run: Spawn extension (callfiles,100,32) exited non-zero on 'Local/100@callfiles-5ebc;2'
 == Spawn extension (callfiles, 100, 32) exited non-zero on 'Local/100@callfiles-5ebc;2'

The same thing happens in version 1.6.2.8, 1.6.2.9, 1.6.2.10 and 1.6.2.11-rc2
Comments:By: Jacco van Tuijl (jacco) 2010-07-28 09:43:29

it also happens in 1.6.1.20
it also happens when trying to bridge 2 sip clients not using any trunk
By: Stefan Schmidt (schmidts) 2010-07-28 15:55:49

do you use answer in your extensions? if yes than have a look at issue 17641. maybe this is your problem.
By: Jacco van Tuijl (jacco) 2010-07-29 09:34:01

I applied the patch but it did not fix my problem
By: Jacco van Tuijl (jacco) 2010-08-03 06:02:28

asterisk seems to be sending a status: 603 declined
at the moment of bridging when bridging fails.

I added an attachemnt; some more wireshark trace .
The capture is started when there is already an rtp connection with de client we are trying to bridge with that channel with some othe existing channel.

the 169.254.100.71 is the asterisk server and the 169.254.100.44 is a softsip client


By: Jacco van Tuijl (jacco) 2010-08-03 06:09:45

to problem seems to get worst when other asychronus calls are waiting for system() commands to finish execution


By: Jacco van Tuijl (jacco) 2010-11-05 07:56:23

close this one; eror in dialplan
By: Paul Belanger (pabelanger) 2010-11-05 08:04:48

Thanks for your comments. This does not appear to be a bug report and we are closing it. We appreciate the difficulties you are facing, but it would make more sense to raise your question in the support tracker, http://www.asterisk.org/support