[asterisk-bugs] [Asterisk 0015458]: mISDN rejects calls - NO FREE CHAN IN STACK
Asterisk Bug Tracker
noreply at bugs.digium.com
Tue Jul 7 10:58:35 CDT 2009
A NOTE has been added to this issue.
======================================================================
https://issues.asterisk.org/view.php?id=15458
======================================================================
Reported By: FabienToune
Assigned To: rmudgett
======================================================================
Project: Asterisk
Issue ID: 15458
Category: Channels/chan_misdn
Reproducibility: random
Severity: major
Priority: normal
Status: assigned
Asterisk Version: 1.6.0.9
Regression: No
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
======================================================================
Date Submitted: 2009-07-07 10:36 CDT
Last Modified: 2009-07-07 10:58 CDT
======================================================================
Summary: mISDN rejects calls - NO FREE CHAN IN STACK
Description:
This issue is similar to 0013488 but somehow different because of the
version used.
I use a Beronet 4 BRI ports card, with only 3 ports configured,
mISDN-1_1_9.1
Randomly, with an average frequence of once every two weeks, but sometimes
two days in a row, mISDN starts to be able to use one port only (2 calls).
The rest of the calls are rejected with :
Tue Jul 7 16:47:47 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:3f082
Tue Jul 7 16:47:47 2009: P[ 1] channel with stid:0 not in use!
Tue Jul 7 16:47:47 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:30582
Tue Jul 7 16:47:47 2009: P[ 1] set_channel: bc->channel:0 channel:1
Tue Jul 7 16:47:47 2009: P[ 1] I IND :NEW_CHANNEL oad:488235625
dad:65714545 pid:1974 state:none
Tue Jul 7 16:47:47 2009: P[ 1] --> channel:1 mode:TE cause:16 ocause:16
rad: cad:
Tue Jul 7 16:47:47 2009: P[ 1] --> info_dad: onumplan:2 dnumplan:2
rnumplan: cpnnumplan:0
Tue Jul 7 16:47:47 2009: P[ 1] --> caps:Speech pi:0 keypad:
sending_complete:1
Tue Jul 7 16:47:47 2009: P[ 1] --> screen:0 --> pres:0
Tue Jul 7 16:47:47 2009: P[ 1] --> addr:0 l3id:2013c b_stid:0
layer_id:50020180
Tue Jul 7 16:47:47 2009: P[ 1] --> facility:Fac_None
out_facility:Fac_None
Tue Jul 7 16:47:47 2009: P[ 1] --> bc_state:BCHAN_CLEANED
Tue Jul 7 16:47:47 2009: P[ 1] Chan not existing at the moment
bc->l3id:2013c bc:0x82001d4 event:NEW_CHANNEL port:1 channel:1
Tue Jul 7 16:47:47 2009: P[ 1] NO USERUESRINFO
Tue Jul 7 16:47:47 2009: P[ 1] !! NO FREE CHAN IN STACK
Tue Jul 7 16:47:47 2009: P[ 1] Requested Channel Already in Use
releasing this call with cause 34!!!!
Tue Jul 7 16:47:47 2009: P[ 1] I SEND:RELEASE_COMPLETE oad:488235625
dad:65714545 pid:1974
Tue Jul 7 16:47:47 2009: P[ 1] --> bc_state:BCHAN_CLEANED
Tue Jul 7 16:47:47 2009: P[ 1] --> channel:0 mode:TE cause:16 ocause:34
rad: cad:
Tue Jul 7 16:47:47 2009: P[ 1] --> info_dad: onumplan:2 dnumplan:2
rnumplan: cpnnumplan:0
Tue Jul 7 16:47:47 2009: P[ 1] --> caps:Speech pi:3 keypad:
sending_complete:1
Tue Jul 7 16:47:47 2009: P[ 1] --> screen:0 --> pres:0
Tue Jul 7 16:47:47 2009: P[ 1] --> addr:0 l3id:2013c b_stid:0
layer_id:50020180
Tue Jul 7 16:47:47 2009: P[ 1] --> facility:Fac_None
out_facility:Fac_None
Tue Jul 7 16:47:47 2009: P[ 1] $$$ CLEANUP CALLED pid:1974
Tue Jul 7 16:47:47 2009: P[ 1] couldn't handle event
Tue Jul 7 16:47:47 2009: P[ 1] Sending msg, prim:35a80 addr:41000104
dinfo:2013c
Tue Jul 7 16:47:47 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:35a81
Tue Jul 7 16:47:47 2009: P[ 1] CC_RELEASE_COMPLETE|CONFIRM [TE]
Tue Jul 7 16:47:47 2009: P[ 1] I IND :RELEASE_COMPLETE oad: dad:
pid:1974 state:none
Tue Jul 7 16:47:47 2009: P[ 1] --> channel:0 mode:TE cause:16 ocause:34
rad: cad:
Tue Jul 7 16:47:47 2009: P[ 1] --> info_dad: onumplan:0 dnumplan:0
rnumplan:0 cpnnumplan:0
Tue Jul 7 16:47:47 2009: P[ 1] --> caps:Speech pi:0 keypad:
sending_complete:0
Tue Jul 7 16:47:47 2009: P[ 1] --> screen:0 --> pres:0
Tue Jul 7 16:47:47 2009: P[ 1] --> addr:0 l3id:2013c b_stid:0
layer_id:50020180
Tue Jul 7 16:47:47 2009: P[ 1] --> facility:Fac_None
out_facility:Fac_None
Tue Jul 7 16:47:47 2009: P[ 1] --> bc_state:BCHAN_CLEANED
Tue Jul 7 16:47:47 2009: P[ 1] --> no Ch, so we've already released.
Tue Jul 7 16:47:47 2009: P[ 0] Cannot hangup chan, no ch
Tue Jul 7 16:47:47 2009: P[ 1] release_chan: Ch not found!
Tue Jul 7 16:47:47 2009: P[ 1] $$$ CLEANUP CALLED pid:1974
Tue Jul 7 16:47:47 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:3f182
Tue Jul 7 16:47:47 2009: P[ 1] --> lib: RELEASE_CR Ind with l3id:2013c
Tue Jul 7 16:47:47 2009: P[ 1] --> lib: CLEANING UP l3id: 2013c
Tue Jul 7 16:47:47 2009: P[ 1] $$$ CLEANUP CALLED pid:1974
Other ports are free, but mISDN seems to focus only on port 1...
I usually try to reload mISDN, to restart port 1, port 2, port 3, and
somehow, it works. Today, I restarted ports, but the problem came back very
fast/was not solved... If I restart the server, it's ok, but can't do that
during use...
This is a production server, and it's getting harder to manage...
I'm now trying to change method from round-robin to standard_desc (first
try was standard...)
Here is my misdn.conf
[general]
misdn_init=/etc/misdn-init.conf
debug=4
stop_tone_after_first_digit=yes
bridging=yes
tracefile=/var/log/asterisk/misdn.log
[default]
context=mISDN
language=fr
senddtmf=yes
allowed_bearers=all
nationalprefix=0
internationalprefix=00
rxgain=0
txgain=0
echocancel=yes
te_choose_channel=no
pmp_l1_check=yes
method=standard_dec
dialplan=0
localdialplan=0
cpndialplan=0
early_bconnect=yes
always_immediate=no
immediate=no
hdlc=yes
astdtmf=yes
presentation=-1
screen=-1
block_on_alarm=no
need_more_infos=no
[mISDN]
ports=1,2,3
context=mISDN
msns=*
======================================================================
----------------------------------------------------------------------
(0107451) FabienToune (reporter) - 2009-07-07 10:58
https://issues.asterisk.org/view.php?id=15458#c107451
----------------------------------------------------------------------
I restarted the 3 ports at 12:51:20
Tue Jul 7 12:51:20 2009: P[ 1] Restarting this port.
Tue Jul 7 12:51:20 2009: P[ 1] Stack:0x81ff580
Tue Jul 7 12:51:20 2009: P[ 1] --> queue_hangup
Tue Jul 7 12:51:20 2009: P[ 1] * RELEASING CHANNEL pid:1805 ctx:mISDN
dad: oad:0471636345 state: CONNECTED
Tue Jul 7 12:51:20 2009: P[ 1] --> * State Down
Tue Jul 7 12:51:20 2009: P[ 1] --> Setting AST State to down
Tue Jul 7 12:51:20 2009: P[ 1] empty_chan_in_stack: 1
Tue Jul 7 12:51:20 2009: P[ 1] $$$ CLEANUP CALLED pid:1805
Tue Jul 7 12:51:20 2009: P[ 1] $$$ Cleaning up bc with stid :10010100
pid:1805
Tue Jul 7 12:51:20 2009: P[ 1] --> ec_disable
Tue Jul 7 12:51:20 2009: P[ 1] Sending Control ECHOCAN_OFF
Tue Jul 7 12:51:20 2009: P[ 1] ph_control: c1:2319 c2:0
Tue Jul 7 12:51:20 2009: P[ 1] empty_chan_in_stack: 2
Tue Jul 7 12:51:20 2009: P[ 1] $$$ CLEANUP CALLED pid:1816
Tue Jul 7 12:51:20 2009: P[ 1] BCHAN: MGR_DELLAYER|CNF pid:1805
Tue Jul 7 12:51:20 2009: P[ 1] empty_chan_in_stack: 3
Tue Jul 7 12:51:20 2009: P[ 1] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:23 2009: P[ 2] Restarting this port.
Tue Jul 7 12:51:23 2009: P[ 2] Stack:0x820b2e8
Tue Jul 7 12:51:23 2009: P[ 2] empty_chan_in_stack: 1
Tue Jul 7 12:51:23 2009: P[ 2] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:23 2009: P[ 2] empty_chan_in_stack: 2
Tue Jul 7 12:51:23 2009: P[ 2] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:23 2009: P[ 2] empty_chan_in_stack: 3
Tue Jul 7 12:51:23 2009: P[ 2] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:28 2009: P[ 3] Restarting this port.
Tue Jul 7 12:51:28 2009: P[ 3] Stack:0x8217668
Tue Jul 7 12:51:28 2009: P[ 3] empty_chan_in_stack: 1
Tue Jul 7 12:51:28 2009: P[ 3] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:28 2009: P[ 3] empty_chan_in_stack: 2
Tue Jul 7 12:51:28 2009: P[ 3] $$$ CLEANUP CALLED pid:0
Tue Jul 7 12:51:28 2009: P[ 3] empty_chan_in_stack: 3
Tue Jul 7 12:51:28 2009: P[ 3] $$$ CLEANUP CALLED pid:0
But at 12:51:35 here is what happened again and probably caused the
problem again :
Tue Jul 7 12:51:35 2009: P[ 0] --> Group Call group: mISDN
Tue Jul 7 12:51:35 2009: P[ 1] Group [mISDN] Port [1]
Tue Jul 7 12:51:35 2009: P[ 1] portup:1
Tue Jul 7 12:51:35 2009: P[ 1] channel with stid:0 not in use!
Tue Jul 7 12:51:35 2009: P[ 0] --> * NEW CHANNEL dad:0471636345
oad:(null)
Tue Jul 7 12:51:35 2009: P[ 1] * Queuing chan 0x95036a0
Tue Jul 7 12:51:35 2009: P[ 1] read_config: Getting Config
Tue Jul 7 12:51:35 2009: P[ 1] --> TON: Unknown
Tue Jul 7 12:51:35 2009: P[ 1] --> LTON: Unknown
Tue Jul 7 12:51:35 2009: P[ 1] --> CTON: Unknown
Tue Jul 7 12:51:35 2009: P[ 1] * CALL: g:mISDN/0471636345
Tue Jul 7 12:51:35 2009: P[ 1] --> * dad:0471636345 tech:mISDN/0-u3709
ctx:mISDN
Tue Jul 7 12:51:35 2009: P[ 1] --> * adding2newbc ext 0471636345
--
Tue Jul 7 12:51:35 2009: P[ 1] --> * SEND: State Dialing pid:1817
Tue Jul 7 12:51:35 2009: P[ 1] Sending msg, prim:30580 addr:41000104
dinfo:9039c
Tue Jul 7 12:51:35 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:35a82
Tue Jul 7 12:51:35 2009: P[ 1] I IND :RELEASE_COMPLETE oad:42
dad:0471636345 pid:1817 state:CALLING
Tue Jul 7 12:51:35 2009: P[ 1] --> channel:1 mode:TE cause:44 ocause:16
rad: cad:
Tue Jul 7 12:51:35 2009: P[ 1] --> info_dad: onumplan:0 dnumplan:0
rnumplan:0 cpnnumplan:0
Tue Jul 7 12:51:35 2009: P[ 1] --> caps:Speech pi:0 keypad:
sending_complete:0
Tue Jul 7 12:51:35 2009: P[ 1] --> screen:0 --> pres:0
Tue Jul 7 12:51:35 2009: P[ 1] --> addr:0 l3id:9039c b_stid:0
layer_id:50010180
Tue Jul 7 12:51:35 2009: P[ 1] --> facility:Fac_None
out_facility:Fac_None
Tue Jul 7 12:51:35 2009: P[ 1] --> bc_state:BCHAN_CLEANED
Tue Jul 7 12:51:35 2009: P[ 1] --> queue_hangup
Tue Jul 7 12:51:35 2009: P[ 1] * RELEASING CHANNEL pid:1817 ctx:mISDN
dad:0471636345 oad:0471636345 state: CLEANING
Tue Jul 7 12:51:35 2009: P[ 1] --> * State Down
Tue Jul 7 12:51:35 2009: P[ 1] --> Setting AST State to down
Tue Jul 7 12:51:35 2009: P[ 1] $$$ CLEANUP CALLED pid:1817
Tue Jul 7 12:51:35 2009: P[ 1] **** Received CAUSE:44, so not cleaning
up channel 1
Tue Jul 7 12:51:35 2009: P[ 1] **** This channel is now no longer
available,
Tue Jul 7 12:51:35 2009: P[ 1] set_chan_in_stack: 1
Tue Jul 7 12:51:35 2009: P[ 1] channel already in use:1
Tue Jul 7 12:51:35 2009: P[ 1] Sending Restarts on this port.
Tue Jul 7 12:51:35 2009: P[ 1] Restarting and cleaning channel 1
Tue Jul 7 12:51:35 2009: P[ 1] I SEND:RESTART oad: dad: pid:0
Tue Jul 7 12:51:35 2009: P[ 1] --> bc_state:BCHAN_CLEANED
Tue Jul 7 12:51:35 2009: P[ 1] --> channel:1 mode:TE cause:0 ocause:0
rad: cad:
Tue Jul 7 12:51:35 2009: P[ 1] --> info_dad: onumplan:0 dnumplan:0
rnumplan:0 cpnnumplan:0
Tue Jul 7 12:51:35 2009: P[ 1] --> caps:Speech pi:0 keypad:
sending_complete:0
Tue Jul 7 12:51:35 2009: P[ 1] --> screen:0 --> pres:0
Tue Jul 7 12:51:35 2009: P[ 1] --> addr:0 l3id:ffff0002 b_stid:0
layer_id:0
Tue Jul 7 12:51:35 2009: P[ 1] --> facility:unknown
out_facility:unknown
Tue Jul 7 12:51:35 2009: P[ 1] Restarting channel 1
Tue Jul 7 12:51:35 2009: P[ 1] *HOLDER: find ffff0002
Tue Jul 7 12:51:35 2009: P[ 1] $$$ CLEANUP CALLED pid:1817
Tue Jul 7 12:51:35 2009: P[ 1] * IND : HANGUP pid:1817 ctx:mISDN
dad:0471636345 oad:0471636345 State:CLEANING
Tue Jul 7 12:51:35 2009: P[ 1] *HOLDER: find nothing
Tue Jul 7 12:51:35 2009: P[ 1] handle_frm: frm->addr:42000103
frm->prim:3f182
Tue Jul 7 12:51:35 2009: P[ 1] --> l3id:9039c
Tue Jul 7 12:51:35 2009: P[ 1] --> lib: RELEASE_CR Ind with l3id:9039c
Tue Jul 7 12:51:35 2009: P[ 1] Sending msg, prim:34680 addr:41000104
dinfo:ffff0002
Tue Jul 7 12:51:35 2009: P[ 1] --> cause:16
Tue Jul 7 12:51:35 2009: P[ 1] --> lib: CLEANING UP l3id: 9039c
Tue Jul 7 12:51:35 2009: P[ 1] --> out_cause:16
Tue Jul 7 12:51:35 2009: P[ 1] $$$ CLEANUP CALLED pid:1817
Tue Jul 7 12:51:35 2009: P[ 1] --> state:CLEANING
Tue Jul 7 12:51:35 2009: P[ 1] --> Channel: mISDN/0-u3709 hanguped new
state:CLEANING
Issue History
Date Modified Username Field Change
======================================================================
2009-07-07 10:58 FabienToune Note Added: 0107451
======================================================================
More information about the asterisk-bugs
mailing list