[Asterisk-Users] PRI unable to request channel

[Tony Mountifield]

I wonder if anyone has come across this odd behavour with a T1 PRI using
NI2 signalling from a Nortel switch.

Sometimes, when bringing up a PRI trunk, a channel gets into a state
where asterisk can't request a channel, and gets reason 0, but the
channel is not busy. The only thing so far that clears this state is to
make an incoming call to the channel, which succeeds. After that,
outgoing calls are possible too, and everything seems ok from then on.

This messes up channel groups, because Asterisk thinks the channel is
available, and only fails when it tries to use it.

I have been unable to fix this by restarting asterisk and zaptel, but
don't know whether it is a problem with the switch or the T1 card
(TE405P).

I have a channel in that state at the moment, and here is the output
from "pri intense debug span 1" when attempting to make an outgoing
call:

testbridge*CLI> pri intense debug span 1
Enabled EXTENSIVE debugging on span 1
T203 counter expired, sending RR and scheduling T203 again
Sending Receiver Ready (1)

> [ 00 01 01 03 ]

> Supervisory frame:
> SAPI: 00  C/R: 0 EA: 0
>  TEI: 000        EA: 1
> Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
> N(R): 001 P/F: 1
> 0 bytes of data
-- Restarting T203 counter

< [ 00 01 01 05 ]

< Supervisory frame:
< SAPI: 00  C/R: 0 EA: 0
<  TEI: 000        EA: 1
< Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
< N(R): 002 P/F: 1
< 0 bytes of data
-- ACKing all packets from 1 to (but not including) 2
-- Since there was nothing left, stopping T200 counter
-- Stopping T203 counter since we got an ACK
-- Nothing left, starting T203 counter
-- Got RR response to our frame
-- Restarting T203 counter
    -- Attempting call on Zap/1/01144nnnnnnnnnn for s at demo:1 (Retry 1)
Dec 23 11:15:40 NOTICE[24199]: channel.c:1817 __ast_request_and_dial: Unable to request channel Zap/1/01144nnnnnnnnnn
Dec 23 11:15:40 NOTICE[24199]: pbx_spool.c:232 attempt_thread: Call failed to go through, reason 0
testbridge*CLI>

This is using almost the latest v1_0 branch from CVS (probably a few
weeks old), but I also saw it a month or two ago.

Can anyone (a) explain what might cause the problem, and (b) say if
there is any way to overcome it from the Asterisk end?

Thanks,
Tony

PS. For reference, here is the intense debug output from a successful
call:

testbridge*CLI> pri intense debug span 1
Enabled EXTENSIVE debugging on span 1
T203 counter expired, sending RR and scheduling T203 again
Sending Receiver Ready (1)

> [ 00 01 01 03 ]

> Supervisory frame:
> SAPI: 00  C/R: 0 EA: 0
>  TEI: 000        EA: 1
> Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
> N(R): 001 P/F: 1
> 0 bytes of data
-- Restarting T203 counter

< [ 00 01 01 05 ]

< Supervisory frame:
< SAPI: 00  C/R: 0 EA: 0
<  TEI: 000        EA: 1
< Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
< N(R): 002 P/F: 1
< 0 bytes of data
-- ACKing all packets from 1 to (but not including) 2
-- Since there was nothing left, stopping T200 counter
-- Stopping T203 counter since we got an ACK
-- Nothing left, starting T203 counter
-- Got RR response to our frame
-- Restarting T203 counter
    -- Attempting call on Zap/35/01144nnnnnnnnnn for s at demo:1 (Retry 1)
T203 counter expired, sending RR and scheduling T203 again
Sending Receiver Ready (1)

> [ 00 01 01 03 ]

> Supervisory frame:
> SAPI: 00  C/R: 0 EA: 0
>  TEI: 000        EA: 1
> Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
> N(R): 001 P/F: 1
> 0 bytes of data
-- Restarting T203 counter

< [ 00 01 01 05 ]

< Supervisory frame:
< SAPI: 00  C/R: 0 EA: 0
<  TEI: 000        EA: 1
< Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
< N(R): 002 P/F: 1
< 0 bytes of data
-- ACKing all packets from 1 to (but not including) 2
-- Since there was nothing left, stopping T200 counter
-- Stopping T203 counter since we got an ACK
-- Nothing left, starting T203 counter
-- Got RR response to our frame
-- Restarting T203 counter
       > Channel Zap/35-1 was answered.
    -- Executing Wait("Zap/35-1", "1") in new stack
    -- Executing Answer("Zap/35-1", "") in new stack
    -- Executing DigitTimeout("Zap/35-1", "5") in new stack
    -- Set Digit Timeout to 5
    -- Executing ResponseTimeout("Zap/35-1", "10") in new stack
    -- Set Response Timeout to 10
    -- Executing BackGround("Zap/35-1", "demo-congrats") in new stack
    -- Playing 'demo-congrats' (language 'en')
T203 counter expired, sending RR and scheduling T203 again
Sending Receiver Ready (1)

> [ 00 01 01 03 ]

> Supervisory frame:
> SAPI: 00  C/R: 0 EA: 0
>  TEI: 000        EA: 1
> Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
> N(R): 001 P/F: 1
> 0 bytes of data
-- Restarting T203 counter

< [ 00 01 01 05 ]

< Supervisory frame:
< SAPI: 00  C/R: 0 EA: 0
<  TEI: 000        EA: 1
< Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
< N(R): 002 P/F: 1
< 0 bytes of data
-- ACKing all packets from 1 to (but not including) 2
-- Since there was nothing left, stopping T200 counter
-- Stopping T203 counter since we got an ACK
-- Nothing left, starting T203 counter
-- Got RR response to our frame
-- Restarting T203 counter
    -- Channel 0/11, span 2 got hangup
  == Spawn extension (demo, s, 5) exited non-zero on 'Zap/35-1'
    -- Hungup 'Zap/35-1'
Dec 23 11:27:59 NOTICE[24208]: pbx_spool.c:242 attempt_thread: Call completed to Zap/35/01144nnnnnnnnnn
testbridge*CLI> 

-- 
Tony Mountifield
Work: tony at softins.co.uk - http://www.softins.co.uk
Play: tony at mountifield.org - http://tony.mountifield.org