Alex Villacís Lasso
2011-Sep-01 17:16 UTC
[asterisk-users] Unexpected behavior change from Asterisk 1.6.2.14 to Asterisk 1.8.5.0
In our office, we were running an Asterisk 1.6.2.14 machine with DAHDI 2.3.0.1,
FreePBX 2.8.1 and an analog DAHDI card with 8 FXO ports. This machine had
several DAHDI trunks defined in the FreePBX interface, each one containing a
single DAHDI channel. It
also had a few outgoing routes defined in FreePBX, each of those grouping
several of these DAHDI trunks. This setup worked correctly until the hard drive
started failing. After backing up most of the data, we changed the hard drive
and installed Asterisk
1.8.5.0 and DAHDI 2.4.1.2 with the same FreePBX 2.8.1. We then noticed that
outgoing calls using the analog card were failing if the first tried channel was
busy, instead of trying the next channel in the outgoing route. We traced this
problem to a
situation described in a FreePBX ticket: http://www.freepbx.org/v2/ticket/5008 .
The logs in the old hard drive showed the following whenever a channel was busy:
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [s at
macro-dialout-trunk:19] Dial("SIP/514-000007bb",
"DAHDI/4/3904170,300,tTwW") in new stack
[2011-08-30 08:55:39] WARNING[2597] app_dial.c: Unable to create channel of type
'DAHDI' (cause 0 - Unknown)
[2011-08-30 08:55:39] VERBOSE[2597] app_dial.c: == Everyone is busy/congested
at this time (1:0/0/1)
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [s at
macro-dialout-trunk:20] NoOp("SIP/514-000007bb", "Dial failed for
some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 0") in new
stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [s at
macro-dialout-trunk:21] Goto("SIP/514-000007bb",
"s-CHANUNAVAIL,1") in new stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto
(macro-dialout-trunk,s-CHANUNAVAIL,1)
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [s-CHANUNAVAIL at
macro-dialout-trunk:1] Set("SIP/514-000007bb", "RC=0") in
new stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [s-CHANUNAVAIL at
macro-dialout-trunk:2] Goto("SIP/514-000007bb", "0,1") in
new stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto (macro-dialout-trunk,0,1)
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [0 at
macro-dialout-trunk:1] Goto("SIP/514-000007bb",
"continue,1") in new stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto
(macro-dialout-trunk,continue,1)
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [continue at
macro-dialout-trunk:1] GotoIf("SIP/514-000007bb",
"1?noreport") in new stack
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto
(macro-dialout-trunk,continue,3)
[2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing [continue at
macro-dialout-trunk:3] NoOp("SIP/514-000007bb", "TRUNK Dial
failed due to CHANUNAVAIL HANGUPCAUSE: 0 - failing through to other
trunks") in new stack
In the old setup (with Asterisk 1.6.2.14), the error type reported by app_dial
was 0-Unknown and the dialing status was CHANUNAVAIL.
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing [s at
macro-dialout-trunk:19] Dial("SIP/213-000000e7",
"DAHDI/5/2201177,300,tTwW") in new stack
[Aug 31 12:10:13] WARNING[17513] app_dial.c: Unable to create channel of type
'DAHDI' (cause 17 - User busy)
[Aug 31 12:10:13] VERBOSE[17513] app_dial.c: == Everyone is busy/congested at
this time (1:1/0/0)
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing [s at
macro-dialout-trunk:20] NoOp("SIP/213-000000e7", "Dial failed for
some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing [s at
macro-dialout-trunk:21] Goto("SIP/213-000000e7", "s-BUSY,1")
in new stack
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Goto
(macro-dialout-trunk,s-BUSY,1)
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing [s-BUSY at
macro-dialout-trunk:1] NoOp("SIP/213-000000e7", "Dial failed due
to trunk reporting BUSY - giving up") in new stack
[Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing [s-BUSY at
macro-dialout-trunk:2] PlayTones("SIP/213-000000e7", "busy")
in new stack
In the new setup (with Asterisk 1.8.5.0), the error type reported by app_dial is
17-User busy and the dialing status is BUSY.
The FreePBX context is programmed so that it considers BUSY, along with
NOANSWER, INVALIDNMBR and CHANGED, as nonrecoverable errors that abort the
dialout attempt, which seems reasonable. The problem is that the new setup is
returing BUSY instead of
CHANUNAVAIL when the particular channel that was tried is in use by a different
call. We worked around the issue by applying the recommendation suggested in the
ticket (create DAHDI groups in chan_dahdi.conf and use these as trunks).
However, I believe the
previous behavior was correct and the new behavior to be in error. The
workaround suggested by the ticket will not work in a scenario where a DAHDI
group has all of its channels busy with calls, and the administrator intends
additional calls to be routed
through non-DAHDI trunks (such as SIP/IAX trunks or custom trunks).
My questions:
Is the new behavior the intended one?
If the new behavior is intentional, then how should I set up an scenario in
which calls will be routed through SIP when all DAHDI channels are in use, yet
will not try to route calls through SIP when the destination is truly busy?
If the new behavior is a bug and not intentional, at what level should I look
for the problem? At Asterisk, or at the driver level? The card is an OpenVox
card (opvxa1200) for which source code is available.
Richard Mudgett
2011-Sep-01 19:11 UTC
[asterisk-users] Unexpected behavior change from Asterisk 1.6.2.14 to Asterisk 1.8.5.0
> In our office, we were running an Asterisk 1.6.2.14 machine with DAHDI > 2.3.0.1, FreePBX 2.8.1 and an analog DAHDI card with 8 FXO ports. This > machine had several DAHDI trunks defined in the FreePBX interface, > each one containing a single DAHDI channel. It > also had a few outgoing routes defined in FreePBX, each of those > grouping several of these DAHDI trunks. This setup worked correctly > until the hard drive started failing. After backing up most of the > data, we changed the hard drive and installed Asterisk > 1.8.5.0 and DAHDI 2.4.1.2 with the same FreePBX 2.8.1. We then noticed > that outgoing calls using the analog card were failing if the first > tried channel was busy, instead of trying the next channel in the > outgoing route. We traced this problem to a > situation described in a FreePBX ticket: > http://www.freepbx.org/v2/ticket/5008 . The logs in the old hard drive > showed the following whenever a channel was busy: > > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [s at macro-dialout-trunk:19] Dial("SIP/514-000007bb", > "DAHDI/4/3904170,300,tTwW") in new stack > [2011-08-30 08:55:39] WARNING[2597] app_dial.c: Unable to create > channel of type 'DAHDI' (cause 0 - Unknown) > [2011-08-30 08:55:39] VERBOSE[2597] app_dial.c: == Everyone is > busy/congested at this time (1:0/0/1) > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [s at macro-dialout-trunk:20] NoOp("SIP/514-000007bb", "Dial failed for > some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 0") in new > stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [s at macro-dialout-trunk:21] Goto("SIP/514-000007bb", "s-CHANUNAVAIL,1") > in new stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto > (macro-dialout-trunk,s-CHANUNAVAIL,1) > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [s-CHANUNAVAIL at macro-dialout-trunk:1] Set("SIP/514-000007bb", "RC=0") > in new stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [s-CHANUNAVAIL at macro-dialout-trunk:2] Goto("SIP/514-000007bb", "0,1") > in new stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto > (macro-dialout-trunk,0,1) > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [0 at macro-dialout-trunk:1] Goto("SIP/514-000007bb", "continue,1") in > new stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto > (macro-dialout-trunk,continue,1) > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [continue at macro-dialout-trunk:1] GotoIf("SIP/514-000007bb", > "1?noreport") in new stack > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Goto > (macro-dialout-trunk,continue,3) > [2011-08-30 08:55:39] VERBOSE[2597] pbx.c: -- Executing > [continue at macro-dialout-trunk:3] NoOp("SIP/514-000007bb", "TRUNK Dial > failed due to CHANUNAVAIL HANGUPCAUSE: 0 - failing through to other > trunks") in new stack > > In the old setup (with Asterisk 1.6.2.14), the error type reported by > app_dial was 0-Unknown and the dialing status was CHANUNAVAIL. > > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing > [s at macro-dialout-trunk:19] Dial("SIP/213-000000e7", > "DAHDI/5/2201177,300,tTwW") in new stack > [Aug 31 12:10:13] WARNING[17513] app_dial.c: Unable to create channel > of type 'DAHDI' (cause 17 - User busy) > [Aug 31 12:10:13] VERBOSE[17513] app_dial.c: == Everyone is > busy/congested at this time (1:1/0/0) > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing > [s at macro-dialout-trunk:20] NoOp("SIP/213-000000e7", "Dial failed for > some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing > [s at macro-dialout-trunk:21] Goto("SIP/213-000000e7", "s-BUSY,1") in new > stack > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Goto > (macro-dialout-trunk,s-BUSY,1) > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing > [s-BUSY at macro-dialout-trunk:1] NoOp("SIP/213-000000e7", "Dial failed > due to trunk reporting BUSY - giving up") in new stack > [Aug 31 12:10:13] VERBOSE[17513] pbx.c: -- Executing > [s-BUSY at macro-dialout-trunk:2] PlayTones("SIP/213-000000e7", "busy") > in new stack > > In the new setup (with Asterisk 1.8.5.0), the error type reported by > app_dial is 17-User busy and the dialing status is BUSY. > > The FreePBX context is programmed so that it considers BUSY, along > with NOANSWER, INVALIDNMBR and CHANGED, as nonrecoverable errors that > abort the dialout attempt, which seems reasonable. The problem is that > the new setup is returing BUSY instead of > CHANUNAVAIL when the particular channel that was tried is in use by a > different call. We worked around the issue by applying the > recommendation suggested in the ticket (create DAHDI groups in > chan_dahdi.conf and use these as trunks). However, I believe the > previous behavior was correct and the new behavior to be in error. The > workaround suggested by the ticket will not work in a scenario where a > DAHDI group has all of its channels busy with calls, and the > administrator intends additional calls to be routed > through non-DAHDI trunks (such as SIP/IAX trunks or custom trunks). > > My questions: > > Is the new behavior the intended one? > If the new behavior is intentional, then how should I set up an > scenario in which calls will be routed through SIP when all DAHDI > channels are in use, yet will not try to route calls through SIP when > the destination is truly busy? > If the new behavior is a bug and not intentional, at what level should > I look for the problem? At Asterisk, or at the driver level? The card > is an OpenVox card (opvxa1200) for which source code is available. >I think the new behavior is a bug. It is most likely in chan_dahdi.c:dahdi_request() when it finds that the requested channel or no channels in the group are available. Richard