[asterisk-bugs] [LibPRI 0017570]: [patch] ISDN BRI does not recover from line faults

Mon Aug 30 17:31:42 CDT 2010

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=17570 
====================================================================== 
Reported By:                jcovert
Assigned To:                rmudgett
====================================================================== 
Project:                    LibPRI
Issue ID:                   17570
Category:                   General
Reproducibility:            random
Severity:                   major
Priority:                   normal
Status:                     closed
Target Version:             1.6.2.13
Asterisk Version:           1.6.0 - SECURITY ONLY! Test 1.6.2 
JIRA:                       SWP-1799 
libpri Version:             1.4.11.3 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Disclaimer on File?:        N/A 
Request Review:              
Resolution:                 fixed
Fixed in Version:           
====================================================================== 
Date Submitted:             2010-06-30 08:30 CDT
Last Modified:              2010-08-30 17:31 CDT
====================================================================== 
Summary:                    [patch] ISDN BRI does not recover from line faults
Description: 
DAHDI Version: 2.3.0.1 Echo Canceller: MG2
Libpri version: libpri-1.4.11.1

About once every 3-4 weeks, some sort of error occurs on one or more of
three Sovitel ISDN BRI circuits.  Afterwards, all calls fail, and there is
no logging information available on call attempts:

The following appeared in the messages log about the time of the failure:

[Jun 30 12:13:16] WARNING[3241] chan_dahdi.c: Detected alarm on channel 5:
Red Alarm
[Jun 30 12:13:16] NOTICE[3239] chan_dahdi.c: PRI got event: Alarm (4) on
Primary D-channel of span 2
[Jun 30 12:13:16] WARNING[3239] chan_dahdi.c: No D-channels available! 
Using Primary channel 6 as D-channel anyway!
[Jun 30 12:13:16] WARNING[2131] chan_dahdi.c: Detected alarm on channel 4:
Red Alarm
[Jun 30 12:13:44] NOTICE[2131] chan_dahdi.c: Alarm cleared on channel 4
[Jun 30 12:13:44] NOTICE[3241] chan_dahdi.c: Alarm cleared on channel 5
[Jun 30 12:13:44] NOTICE[3239] chan_dahdi.c: PRI got event: No more alarm
(5) on Primary D-channel of span 2

Further outgoing call attempts reported:

Moscow-Asterisk*CLI> pri intensive debug span 2 
Enabled EXTENSIVE debugging on span 2
    -- Accepting AUTHENTICATED call from 205.153.37.207:
       > requested format = gsm,
       > requested prefs = (gsm|ulaw|alaw),
       > actual format = ulaw,
       > host prefs = (ulaw|alaw),
       > priority = mine
    -- Executing [800954100 at from-dc:1] Dial("IAX2/npr-dc-pbx-11375",
"DAHDI/4/100,120") in new stack
[Jun 30 16:21:08] WARNING[3894]: app_dial.c:1502 dial_exec_full: Unable to
create channel of type 'DAHDI' (cause 0 - Unknown)
  == Everyone is busy/congested at this time (1:0/0/1)

While in failure, we have seen the following messages:

TEI: 125 State 2CLI> 
V(S) 0 V(A) 0 V(R) 0
K 1, RC 0, l3initiated 0, reject_except 0 ack_pend 0
T200 0, N200 3, T203 0

< [ fe ff 03 0f 00 00 04 ff ]

< Unnumbered frame:
< SAPI: 63  C/R: 1 EA: 0
<  TEI: 127        EA: 1
<   M3: 0   P/F: 0 M2: 0 11: 3  [ UI (unnumbered information) ]
< 5 bytes of data
< MDL Message: TEI Identity Check Request (4)
< RI: 0
< Ai: 127 E:1
Received MDL message
  == Spawn extension (from-dc, 109, 5) exited non-zero on
'IAX2/npr-dc-pbx-10603'
    -- Executing [h at from-dc:1] ExecIf("IAX2/npr-dc-pbx-10603", "0?System(
\; )") in new stack
    -- Hungup 'IAX2/npr-dc-pbx-10603'
TEI: 125 State 2
V(S) 0 V(A) 0 V(R) 0
K 1, RC 0, l3initiated 0, reject_except 0 ack_pend 0
T200 0, N200 3, T203 0

< [ fe ff 03 0f 00 00 04 ff ]

< Unnumbered frame:
< SAPI: 63  C/R: 1 EA: 0
<  TEI: 127        EA: 1
<   M3: 0   P/F: 0 M2: 0 11: 3  [ UI (unnumbered information) ]
< 5 bytes of data
< MDL Message: TEI Identity Check Request (4)
< RI: 0
< Ai: 127 E:1
Received MDL message

We have provided the office staff a special dial code which restarts DAHDI
and emails us:

    -- Executing [109 at privileged-station:3]
System("Local/109 at privileged-station-8477;2", "asterisk -rx 'dahdi
restart'") in new stack
    -- Remote UNIX connection
 Destroying channels and reloading DAHDI configuration.
    -- User hung up> 
  == Spawn extension (macro-astextn, s, 7) exited non-zero on 'DAHDI/4-1'
in macro 'astextn'
  == Spawn extension (macro-astextn, s, 7) exited non-zero on 'DAHDI/4-1'
    -- Executing [h at macro-astextn:1] ExecIf("DAHDI/4-1",
"1?System(/usr/local/bin/sipsak -H 172.19.19.240 -i -M -B '' -s
sip:x3293 at 172.19.19.105:1024 \; )") in new stack
    -- Hungup 'DAHDI/4-1'
  == Unregistered channel -2
  == Unregistered channel 1
  == Unregistered channel 2
  == Unregistered channel 4
  == Unregistered channel 5
  == Unregistered channel 7
  == Unregistered channel 8
  == Parsing '/etc/asterisk/chan_dahdi.conf':   == Found
  == Parsing '/etc/asterisk/users.conf':   == Found
    -- Reconfigured channel 1, ISDN BRI Point to MultiPoint signalling
    -- Reconfigured channel 2, ISDN BRI Point to MultiPoint signalling
    -- Reconfigured channel 4, ISDN BRI Point to MultiPoint signalling
    -- Reconfigured channel 5, ISDN BRI Point to MultiPoint signalling
    -- Reconfigured channel 7, ISDN BRI Point to MultiPoint signalling
    -- Reconfigured channel 8, ISDN BRI Point to MultiPoint signalling
  == Starting D-Channel on span 1
  == Starting D-Channel on span 2
  == Starting D-Channel on span 3
  == Primary D-Channel on span 2 up
  == Primary D-Channel on span 3 up
  == Primary D-Channel on span 1 up

If there is any further information we could collect prior to the restart
that would help debug, please let us know.

====================================================================== 

---------------------------------------------------------------------- 
 (0126457) svnbot (reporter) - 2010-08-30 17:31
 https://issues.asterisk.org/view.php?id=17570#c126457 
---------------------------------------------------------------------- 
Repository: libpri
Revision: 1948

U   tags/1.4.11.4/q921.c

------------------------------------------------------------------------
r1948 | rmudgett | 2010-08-30 17:31:41 -0500 (Mon, 30 Aug 2010) | 48 lines

Merged revisions 1918 via svnmerge from 
https://origsvn.digium.com/svn/libpri/branches/1.4

........
  r1918 | rmudgett | 2010-08-30 12:53:33 -0500 (Mon, 30 Aug 2010) | 41
lines

  ISDN BRI does not recover from line faults

  Q.921 was getting stuck in state 2 (Q921_ASSIGN_AWAITING_TEI).  For some
  reason the network was removing the TEI.  Libpri then immediately tried
to
  get a new TEI assigned.  The network did not reply to the N202(3)
attempts
  to get a new TEI.  Libpri then just gave up trying but did not leave the
  state.  Some paths in Q.921 Figure B.3 were not implemented.

  Q.921 now transitions to the Q921_TEI_UNASSIGNED state when the N202
count
  is exceeded.  Q.921 will wait there until an incoming or outgoing call
is
  attempted.

  * Fixed initializing the n202_counter.  Not initializing the
n202_counter
  would cause the Q921_TEI_IDENTITY_REQUEST to unexpectedly not go out and
  due to how state transitions were done, Q.921 would get stuck in the
  Q921_ASSIGN_AWAITING_TEI state.

  * Fixed start T202 timer fail causing Q.921 to get stuck in the
  Q921_ASSIGN_AWAITING_TEI state if the network did not respond to the
  request.

  * Fixed handling of Q921_TEI_IDENTITY_REMOVE to do the MDL-REMOVE
  primitive (q921_mdl_remove()) instead of transitioning directly to the
  Q921_TEI_UNASSIGNED state.  Necessary state clean-up was not getting
done.

  * Minor tweaks to q921_mdl_remove().  The worst problem was erroneously
  generating an error message.

  * Fixed potential for sending I-frames with an invalid TEI.  The I-frame
  could have been queued when Q.921 did not have an assigned TEI.

  * Fixed testing of the q931_receive() return value when a UI-frame is
  received.

  (closes issue https://issues.asterisk.org/view.php?id=17570)
  Reported by: jcovert
  Patches:
        issue17570_v1.4.11.3_v3.patch uploaded by rmudgett (license 664)
        issue17570_v1.4_v3.patch uploaded by rmudgett (license 664)
  Tested by: jcovert, rmudgett
........

------------------------------------------------------------------------

http://svn.digium.com/view/libpri?view=rev&revision=1948 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2010-08-30 17:31 svnbot         Checkin                                      
2010-08-30 17:31 svnbot         Note Added: 0126457                          
======================================================================