Hi,<div><br></div><div>How often does this happens?<br><div><br></div><div>Which openr2 version is this? try latest 1.2.0rc2 <a href="http://openr2.googlecode.com/files/openr2-1.2.0rc2.tar.gz">http://openr2.googlecode.com/files/openr2-1.2.0rc2.tar.gz</a>, starting with 1.2.0 I fixed a couple of race conditions that could cause this problem.</div>
<div><br></div><div>Also try compiling Asterisk without optimizations ( it seems the last stack frames are inside asterisk, but ??? means there is no stack information for those frames ).</div><div><br><div class="gmail_quote">
On Fri, Aug 28, 2009 at 2:45 PM, Rafael Prado Rocchi <span dir="ltr"><<a href="mailto:prado@practis.com.br">prado@practis.com.br</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex;">
<div lang="EN-US" link="blue" vlink="purple">
<div>
<p><span lang="PT-BR">Hello Moises, </span></p>
<p><span lang="PT-BR"> </span></p>
<p>We are having a problem that “locks” some
channels, precisely 15 channels when it occurs.</p>
<p> </p>
<p>Description:</p>
<p>Asterisk originate the call</p>
<p>The call gets answered</p>
<p>Asterisk disconnect the call</p>
<p>(asterisk 1.4.26)</p>
<p> </p>
<p> </p>
<p>But from time to time, the channel can’t be used anymore.
It stays in “Clear Forward” state. It can be seen below:</p>
<p> </p>
<p><span style="font-size:9.0pt;font-family:"Courier New";color:red">95 BR 10 4 Yes No CLEAR FO
SEIZE AC</span></p>
<p> </p>
<p>When it occurs, the first 15 channels on the E1 gets this
state. The last 15 channels work normally.</p>
<p>We put an analyzer at the E1 and found that:</p>
<p> </p>
<p>The Clear forward is sent</p>
<p>The ack is received</p>
<p>The channel is released normally</p>
<p> </p>
<p>But asterisk “thinks” it is still in Clear
Forward state, like if it was waiting for the ack.</p>
<p> </p>
<p>Since the hardware and the signaling are working ok, it
seems that some internal flag remains at the old state. And that flag doesn’t
allow asterisk to dial on these channels.</p>
<p> </p>
<p>This is a normal call:</p>
<p> </p>
<p>[16:12:57:551] [Thread: 1123551552] [Chan 120] - CAS Rx
<< [ANSWER] 0x04</p>
<p>[16:12:57:551] [Thread: 1123551552] [Chan 120] -
Attempting to cancel timer timer 3</p>
<p>[16:12:57:551] [Thread: 1123551552] [Chan 120] - timer id
3 found, cancelling it now</p>
<p>[16:12:57:551] [Thread: 1123551552] [Chan 120] -
Attempting to cancel timer timer 0</p>
<p>[16:12:57:551] [Thread: 1123551552] [Chan 120] - Cannot
cancel timer 0</p>
<p>[16:14:26:960] [Thread: 1123551552] [Chan 120] -
Attempting to cancel timer timer 0</p>
<p>[16:14:26:960] [Thread: 1123551552] [Chan 120] - Cannot
cancel timer 0</p>
<p>[16:14:26:960] [Thread: 1123551552] [Chan 120] - CAS Tx
>> [CLEAR FORWARD] 0x08</p>
<p>[16:14:26:960] [Thread: 1123551552] [Chan 120] - CAS Raw
Tx >> 0x09</p>
<p>[16:14:26:992] [Thread: 1093957952] [Chan 120] - Bits
changed from 0x04 to 0x08</p>
<p>[16:14:26:992] [Thread: 1093957952] [Chan 120] - CAS Rx
<< [IDLE] 0x08</p>
<p>[16:14:26:992] [Thread: 1093957952] [Chan 120] - Call
ended</p>
<p>[16:14:26:992] [Thread: 1093957952] [Chan 120] -
Attempting to cancel timer timer 0</p>
<p>[16:14:26:992] [Thread: 1093957952] [Chan 120] - Cannot
cancel timer 0</p>
<p> </p>
<p> </p>
<p> </p>
<p>This is the first problematic call: (at channel 1, span 4)</p>
<p>After this, the channel locks in “CLEAR FO”
state</p>
<p> </p>
<p>[14:46:55:584] [Thread: 1099430208] [Chan 94] - scheduled
timer id 3 (r2_answer)</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - Bits changed
from 0x0C to 0x04</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - CAS Rx
<< [ANSWER] 0x04</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - Attempting
to cancel timer timer 3</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - timer id 3
found, cancelling it now</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - Attempting
to cancel timer timer 0</p>
<p>[14:47:04:857] [Thread: 1099430208] [Chan 94] - Cannot
cancel timer 0</p>
<p>[14:48:00:592] [Thread: 1099430208] [Chan 94] - Attempting
to cancel timer timer 0</p>
<p>[14:48:00:592] [Thread: 1099430208] [Chan 94] - Cannot
cancel timer 0</p>
<p>[14:48:00:592] [Thread: 1099430208] [Chan 94] - CAS Tx
>> [CLEAR FORWARD] 0x08</p>
<p>[14:48:00:592] [Thread: 1099430208] [Chan 94] - CAS Raw Tx
>> 0x09</p>
<p>[15:55:32:843] [Thread: 1146915136] [Chan 94] - Attempting
to cancel timer timer 0</p>
<p>[15:55:32:844] [Thread: 1146915136] [Chan 94] - Cannot
cancel timer 0</p>
<p> </p>
<p> </p>
<p>The logs of the ocurrency in other channels are incomplete
as the the process that is loggin the call seems to be interrupted (the last
line of the log is incomplete, the log is stoped at the middle of the line.</p>
<p> </p>
<p> </p>
<p> </p>
<p> </p>
<p> </p>
<p>We got 3 dumps too:</p>
<p> </p>
<p><span style="font-family:"Courier New";color:red">1)</span></p>
<p><span style="font-family:"Courier New"">(gdb) bt</span></p>
<p><span style="font-family:"Courier New"">#0
0x0000000000000000 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#1
0x00000036af6038c5 in openr2_chan_handle_timers (r2chan=0xf8ec000) at
r2chan.c:318</span></p>
<p><span style="font-family:"Courier New"">#2
0x00000036af6038f6 in openr2_chan_process_event (r2chan=0xf8ec000) at
r2chan.c:331</span></p>
<p><span style="font-family:"Courier New"">#3
0x00002aaaba885f3c in mfcr2_monitor (data=<value optimized out>) at
chan_dahdi.c:9241</span></p>
<p><span style="font-family:"Courier New"">#4
0x00000000004aff7c in dummy_start (data=<value optimized out>) at
utils.c:856</span></p>
<p><span style="font-family:"Courier New"">#5
0x0000003f32606307 in start_thread () from /lib64/libpthread.so.0</span></p>
<p><span style="font-family:"Courier New"">#6 0x0000003f31ad1ded
in clone () from /lib64/libc.so.6</span></p>
<p><span style="font-family:"Courier New""> </span></p>
<p><span style="font-family:"Courier New""> </span></p>
<p><span style="font-family:"Courier New";color:red">2)</span></p>
<p><span style="font-family:"Courier New"">#0
0x0000000000000000 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">(gdb) bt</span></p>
<p><span style="font-family:"Courier New"">#0
0x0000000000000000 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#1
0x00000036af6038c5 in openr2_chan_handle_timers (r2chan=0x2aaaac070fe0) at
r2chan.c:318</span></p>
<p><span style="font-family:"Courier New"">#2
0x00000036af6038f6 in openr2_chan_process_event (r2chan=0x2aaaac070fe0) at
r2chan.c:331</span></p>
<p><span style="font-family:"Courier New"">#3
0x00002aaaba93407c in dahdi_func_read (chan=0x2aaaac070fe0, function=<value
optimized out>, data=0x0,</span></p>
<p><span style="font-family:"Courier New"">
buf=0x36af6086db "H\211\225øþÿÿH\213\205\bÿÿÿH\213\200", len=0) at
chan_dahdi.c:3933</span></p>
<p><span style="font-family:"Courier New"">#4
0x0000000000000013 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#5
0x0000000000000014 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#6
0x0000000000000016 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#7
0x0000000000000017 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#8
0x0000000000000018 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#9
0x0000000000000019 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#10
0x000000000000001a in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#11
0x000000000000001b in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#12
0x000000000000001c in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#13
0x000000000000001d in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#14
0x000000000000001e in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#15
0x000000000000001f in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#16
0x0002000300000020 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#17
0x0000000000000021 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#18
0x0000000000000022 in ?? ()</span></p>
<p><span style="font-family:"Courier New"">#19
0x0000000000000000 in ?? ()</span></p>
<p><span style="font-family:"Courier New""> </span></p>
<p><span style="font-family:"Courier New""> </span></p>
<p><span style="font-family:"Courier New";color:red">3)</span></p>
<p><span style="font-family:"Courier New"">(gdb) bt</span></p>
<p><span style="font-family:"Courier New"">#0
0x00000036af608f40 in set_cas_signal (r2chan=0x7c171c0,
signal=OR2_CAS_CLEAR_FORWARD) at r2proto.c:324</span></p>
<p><span style="font-family:"Courier New"">#1
0x00000036af60e777 in send_clear_forward (r2chan=0x7c171c0) at r2proto.c:2397</span></p>
<p><span style="font-family:"Courier New"">#2
0x00000036af60e8cd in openr2_proto_disconnect_call (r2chan=0x7c171c0,
cause=OR2_CAUSE_NORMAL_CLEARING) at r2proto.c:2460</span></p>
<p><span style="font-family:"Courier New"">#3
0x00000036af60477d in openr2_chan_disconnect_call (r2chan=0x7c171c0,
cause=OR2_CAUSE_NORMAL_CLEARING) at r2chan.c:609</span></p>
<p><span style="font-family:"Courier New"">#4
0x00002aaaba8a89a6 in dahdi_hangup (ast=0x7eb86a0) at chan_dahdi.c:3344</span></p>
<p><span style="font-family:"Courier New"">#5
0x000000000043ccb2 in ast_hangup (chan=0x7eb86a0) at channel.c:1548</span></p>
<p><span style="font-family:"Courier New"">#6
0x00002aaaacd3f6d9 in dial_exec_full (chan=0x2aaac4145930, data=<value
optimized out>, peerflags=0x44bf2560, continue_exec=0x0) at app_dial.c:1822</span></p>
<p><span style="font-family:"Courier New"">#7
0x00002aaaacd42a55 in dial_exec (chan=0x0, data=0x4004da2b) at app_dial.c:1854</span></p>
<p><span style="font-family:"Courier New"">#8
0x00000000004811cd in pbx_extension_helper (c=0x2aaac4145930, con=<value
optimized out>, context=0x2aaac4145b80 "macro-disca-ddd-telefonica",</span></p>
<p><span style="font-family:"Courier New"">
exten=0x2aaac4145bd0 "s", priority=8, label=<value optimized
out>, callerid=0x2aaac4110790 "", action=E_SPAWN) at pbx.c:538</span></p>
<p><span style="font-family:"Courier New"">#9
0x0000000000481603 in ast_spawn_extension (c=0x0, context=0x16 <Address 0x16
out of bounds>,</span></p>
<p><span style="font-family:"Courier New"">
exten=0xffffffffffffffb0 <Address 0xffffffffffffffb0 out of bounds>,
priority=775435825, callerid=<value optimized out>) at pbx.c:2285</span></p>
<p><span style="font-family:"Courier New"">#10
0x00002aaabc7c581a in _macro_exec (chan=0x2aaac4145930, data=<value
optimized out>, exclusive=0) at app_macro.c:352</span></p>
<p><span style="font-family:"Courier New"">#11 0x00000000004811cd
in pbx_extension_helper (c=0x2aaac4145930, con=<value optimized out>,
context=0x2aaac4145b80 "macro-disca-ddd-telefonica",</span></p>
<p><span style="font-family:"Courier New"">
exten=0x2aaac4145bd0 "s", priority=1, label=<value optimized
out>, callerid=0x2aaac4110790 "", action=E_SPAWN) at pbx.c:538</span></p>
<p><span style="font-family:"Courier New"">#12
0x0000000000483852 in __ast_pbx_run (c=0x2aaac4145930) at pbx.c:2285</span></p>
<p><span style="font-family:"Courier New"">#13
0x0000000000484719 in pbx_thread (data=0x0) at pbx.c:2602</span></p>
<p><span style="font-family:"Courier New"">#14
0x00000000004aff7c in dummy_start (data=<value optimized out>) at
utils.c:856</span></p>
<p><span style="font-family:"Courier New"">#15
0x0000003f32606307 in start_thread () from /lib64/libpthread.so.0</span></p>
<p><span style="font-family:"Courier New"">#16
0x0000003f31ad1ded in clone () from /lib64/libc.so.6</span></p>
<p> </p>
<p> </p>
<p> </p>
<p>This is only occurring with “Telefonica E1s”.
Can it be a configuration problem? </p>
<p> </p>
<p>I’ll wait your analysis,</p>
<p>Thanks,</p>
<p>Prado</p>
<p> </p>
<p> </p>
<p> </p>
<p> </p>
<p> </p>
<p> </p>
</div>
</div>
<br>_______________________________________________<br>
--Bandwidth and Colocation Provided by <a href="http://www.api-digital.com--" target="_blank">http://www.api-digital.com--</a><br>
<br>
asterisk-r2 mailing list<br>
To UNSUBSCRIBE or update options visit:<br>
<a href="http://lists.digium.com/mailman/listinfo/asterisk-r2" target="_blank">http://lists.digium.com/mailman/listinfo/asterisk-r2</a><br></blockquote></div><br><br clear="all"><br>-- <br>Moises Silva<br>Software Developer<br>
Sangoma Technologies Inc. | 50 McIntosh Drive, Suite 120, Markham ON L3R 9T3 Canada<br>t. 1 905 474 1990 x 128 | e. <a href="mailto:moy@sangoma.com">moy@sangoma.com</a><br>
</div></div>