[cisco-voip] ISDN PRI problem

Mon Nov 23 10:05:10 EST 2009

Dear,
Cisco ISR 3845 (image c3845-spservicesk9-mz.124-21)connected to telco with
ISDN PRI is experiencing ISDN problems. When the problem happens I notice
TIMER_RECOVERY on the layer 2 status and I will do a clear interface serial
2/0:15 and clear controller E1 2/0 which will change the layer 2 status to
MULTIPLE_FRAME_ESTABLISHED. But outgoing calls can not go through unless I
do a reload of the router.I get the following error when I do a debug isdn
q931

Nov 23 07:02:34.385: ISDN Se2/0:15 Q931: TX -> RELEASE_COMP pd = 8  callref
= 0x254F
        Cause i = 0x80E6 - Recovery on timer expiry
Nov 23 07:02:34.385: ISDN Se2/0:15 **ERROR**: CCPCC_CallOrigination: SETUP
timed-out (2nd T303) to NETWORK.  The SETUP failed.
Nov 23 07:02:35.385: ISDN Se2/0:15 Q931: TX -> RELEASE_COMP pd = 8  callref
= 0x254F
        Cause i = 0x80E6 - Recovery on timer expiry

The configuration on the serial interface is as follows

controller E1 2/0
 pri-group timeslots 1-31
 description Temp-Outgoing
!
!
interface Serial2/0:15
 no ip address
 encapsulation hdlc
 isdn switch-type primary-net5
 isdn incoming-voice voice
 isdn map address 012* plan isdn type national
 isdn map address 015* plan isdn type national
 isdn sending-complete
 no cdp enable

I have attached output if debug isdn q921 messages before and after the
reload of the router.

regards,

Abebe Amare
Network Engineer, VivaCell
CCNP, CCNA (Voice)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20091123/a36ceed4/attachment.html>
-------------- next part --------------
Vivacell-VG2#debug isdn q921
debug isdn q921 is              ON.
Vivacell-VG2#
Nov 23 07:54:07.056: ISDN Se2/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:08.056: ISDN Se2/0:15 Q921: S7_T200_EXPIRY: VA = 0, VS = 1
Nov 23 07:54:08.056: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:09.056: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:10.056: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:10.672: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:10.700: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=69
Nov 23 07:54:10.704: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=69
Nov 23 07:54:10.704: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=0
Nov 23 07:54:11.056: ISDN Se2/0:15 Q921: L2_EstablishDataLink: sending SABME
Nov 23 07:54:11.056: ISDN Se2/0:15 Q921: User TX -> SABMEp sapi=0 tei=0
Nov 23 07:54:11.084: ISDN Se2/0:15 Q921: User RX <- UAf sapi=0 tei=0
Nov 23 07:54:15.056: ISDN Se2/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:15.056: ISDN Se2/0:15 **ERROR**: CCPCC_CallOrigination: SETUP timed-out (2nd T303) to NETWORK.  The SETUP failed.
Nov 23 07:54:16.056: ISDN Se2/0:15 Q921: S7_T200_EXPIRY: VA = 0, VS = 1
Nov 23 07:54:16.056: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:17.056: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:18.057: ISDN Se2/0:15 Q921: User TX -> INFOp sapi=0 tei=0, ns=0 nr=0
Nov 23 07:54:19.057: ISDN Se2/0:15 Q921: L2_EstablishDataLink: sending SABME
Nov 23 07:54:19.057: ISDN Se2/0:15 Q921: User TX -> SABMEp sapi=0 tei=0
Nov 23 07:54:19.085: ISDN Se2/0:15 Q921: User RX <- UAf sapi=0 tei=0
Nov 23 07:54:20.705: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:20.733: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=69
Nov 23 07:54:20.737: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=69
Nov 23 07:54:20.737: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=0
Nov 23 07:54:29.085: ISDN Se2/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:30.085: ISDN Se2/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:30.737: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:30.765: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=69
Nov 23 07:54:30.769: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=69
Nov 23 07:54:30.769: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=0
Nov 23 07:54:31.085: ISDN Se2/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:31.837: ISDN Se1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=0 nr=69
Nov 23 07:54:31.837: ISDN Se1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=1
Nov 23 07:54:31.849: ISDN Se1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=69 nr=1
Nov 23 07:54:31.861: ISDN Se1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=70 nr=1
Nov 23 07:54:31.881: ISDN Se1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=70
Nov 23 07:54:31.893: ISDN Se1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=71
Nov 23 07:54:32.085: ISDN Se2/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=0
Nov 23 07:54:33.085: ISDN Se2/0:15 Q921: L2_EstablishDataLink: sending SABME
Nov 23 07:54:33.085: ISDN Se2/0:15 Q921: User TX -> SABMEp sapi=0 tei=0
Nov 23 07:54:33.113: ISDN Se2/0:15 Q921: User RX <- UAf sapi=0 tei=0
Nov 23 07:54:34.213: ISDN Se1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=71 nr=1
Nov 23 07:54:34.245: ISDN Se1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=72
Nov 23 07:54:34.281: ISDN Se1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=1 nr=72
Nov 23 07:54:34.281: ISDN Se1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=2
-------------- next part --------------
Vivacell-VG1#debug isdn q921
debug isdn q921 is              ON.
Nov 23 08:26:04.022: ISDN Se1/1:15 Q921: User RX <- INFO sapi=0 tei=0, ns=27 nr=54
Nov 23 08:26:04.022: ISDN Se1/1:15 Q921: User TX -> RR sapi=0 tei=0 nr=28
Nov 23 08:26:04.030: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=54 nr=28
Nov 23 08:26:04.062: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=55
Nov 23 08:26:04.094: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=55 nr=28
Nov 23 08:26:04.122: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=56
Nov 23 08:26:04.254: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=56 nr=28
Nov 23 08:26:04.286: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=57
Nov 23 08:26:04.314: ISDN Se1/1:15 Q921: User RX <- INFO sapi=0 tei=0, ns=28 nr=57
Nov 23 08:26:04.314: ISDN Se1/1:15 Q921: User TX -> RR sapi=0 tei=0 nr=29
Nov 23 08:26:10.706: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=50
Nov 23 08:26:10.734: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=75
Nov 23 08:26:10.738: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=75
Nov 23 08:26:10.738: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=50
Nov 23 08:26:14.314: ISDN Se1/1:15 Q921: User TX -> RRp sapi=0 tei=0 nr=29
Nov 23 08:26:14.342: ISDN Se1/1:15 Q921: User RX <- RRf sapi=0 tei=0 nr=57
Nov 23 08:26:14.350: ISDN Se1/1:15 Q921: User RX <- RRp sapi=0 tei=0 nr=57
Nov 23 08:26:14.350: ISDN Se1/1:15 Q921: User TX -> RRf sapi=0 tei=0 nr=29
Nov 23 08:26:20.739: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=50
Nov 23 08:26:20.767: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=75
Nov 23 08:26:20.771: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=75
Nov 23 08:26:20.771: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=50
Nov 23 08:26:24.351: ISDN Se1/1:15 Q921: User TX -> RRp sapi=0 tei=0 nr=29
Nov 23 08:26:24.379: ISDN Se1/1:15 Q921: User RX <- RRf sapi=0 tei=0 nr=57
Nov 23 08:26:24.383: ISDN Se1/1:15 Q921: User RX <- RRp sapi=0 tei=0 nr=57
Nov 23 08:26:24.383: ISDN Se1/1:15 Q921: User TX -> RRf sapi=0 tei=0 nr=29
Nov 23 08:26:30.771: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=50
Nov 23 08:26:30.799: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=75
Nov 23 08:26:30.803: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=75
Nov 23 08:26:30.803: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=50
Nov 23 08:26:34.383: ISDN Se1/1:15 Q921: User TX -> RRp sapi=0 tei=0 nr=29
Nov 23 08:26:34.411: ISDN Se1/1:15 Q921: User RX <- RRf sapi=0 tei=0 nr=57
Nov 23 08:26:34.415: ISDN Se1/1:15 Q921: User RX <- RRp sapi=0 tei=0 nr=57
Nov 23 08:26:34.415: ISDN Se1/1:15 Q921: User TX -> RRf sapi=0 tei=0 nr=29
Nov 23 08:26:40.803: ISDN Se1/0:15 Q921: User TX -> RRp sapi=0 tei=0 nr=50
Nov 23 08:26:40.831: ISDN Se1/0:15 Q921: User RX <- RRf sapi=0 tei=0 nr=75
Nov 23 08:26:40.835: ISDN Se1/0:15 Q921: User RX <- RRp sapi=0 tei=0 nr=75
Nov 23 08:26:40.835: ISDN Se1/0:15 Q921: User TX -> RRf sapi=0 tei=0 nr=50
Nov 23 08:26:40.867: ISDN Se1/1:15 Q921: User RX <- INFO sapi=0 tei=0, ns=29 nr=57
Nov 23 08:26:40.867: ISDN Se1/1:15 Q921: User TX -> RR sapi=0 tei=0 nr=30
Nov 23 08:26:40.875: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=57 nr=30
Nov 23 08:26:40.911: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=58
Nov 23 08:26:40.947: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=58 nr=30
Nov 23 08:26:40.979: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=59
Nov 23 08:26:41.099: ISDN Se1/1:15 Q921: User TX -> INFO sapi=0 tei=0, ns=59 nr=30
Nov 23 08:26:41.131: ISDN Se1/1:15 Q921: User RX <- RR sapi=0 tei=0 nr=60
Nov 23 08:26:41.163: ISDN Se1/1:15 Q921: User RX <- INFO sapi=0 tei=0, ns=30 nr=60
Nov 23 08:26:41.163: ISDN Se1/1:15 Q921: User TX -> RR sapi=0 tei=0 nr=31