Troubleshooting Help

[apparitions]

Hello,

I've been following this forum for a while and it's been very helpful thus far so thanks!

I've had an ongoing issue with our PRI for quite some time. Our service provider (Bell) has done a pretty shoddy job with the troubleshooting on their end.
To make matters worse, they didn't even install our circuit correctly to start with meaning their test center can't even remotely access the pair gains installed in our office.

Our issue is that our PRI drops about once a week. Sometimes the Avaya system recovers automatically and sometimes it just hangs (leaving incoming callers with a fax tone) until we reboot the Avaya system. We're running IP Office Version 9.0.3.0 build 941. I've attached some trace logs below.. any help would be greatly appreciated!


17:17:57 1419718409mS PRN: LAW=U PRI=2, BRI=0, ALOG=0, VCOMP=0, MDM=0, WAN=0, MODU=7 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=4(TOT=5333)
17:18:02 1419723009mS PRN: WARNING:
17:18:02 1419723009mS PRN: PRIU DSP: HRDY timed out, fast read access, addr=0x009b, control=0x45008024
17:18:02 1419723009mS PRN:
17:18:02 1419723009mS PRN: WARNING:
17:18:02 1419723009mS PRN: PRIU DSP 1: check tones, unexpected message ffff
17:18:02 1419723009mS PRN:
17:18:02 1419723009mS PRN: WARNING:
17:18:02 1419723009mS PRN: PRIU DSP: invalid DSP->host queue, wr-ptr 65535, queue size 32
17:18:02 1419723009mS PRN:
17:18:02 1419723010mS ISDNL1Evt: v=1 peb=1,F3 F1
17:18:02 1419723011mS ISDNL1Evt: v=1 peb=1,F4 F3
17:18:02 1419723012mS ISDNL1Evt: v=2 peb=2,F3 F1
17:18:02 1419723014mS ISDNL1Evt: v=2 peb=2,F4 F3
17:18:02 1419723021mS ISDNL1Evt: v=1 peb=1,UnLocked
17:18:02 1419723021mS PRN: Lock To Internal Clock, FPGA_REC_CLK_SELECT = 0x00
17:18:02 1419723462mS RES: Wed 5/11/2014 17:18:02 FreeMem=48723412 47784748(1) CachedMem=938664 CMMsg=5(5) Buff=5200 1372 999 7380 5 Links=28989 BTree=11919 CPU=06.53% CPUStats=6/10/4361/15872/18366/0/0 MCR=0 MCW=0
17:18:02 1419723463mS RES2: IP 500 V2 9.0.3.16 build 2 Tasks=46 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=105 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=20(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
17:18:02 1419723463mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
17:18:02 1419723510mS ISDNL1Evt: v=1 peb=1,PHDI
17:18:02 1419723512mS ISDNL1Evt: v=2 peb=2,PHDI
17:18:02 1419723611mS T1DSP: PRIU DSP 1: is dead
17:18:02 1419723614mS T1DSP: PRIU DSP 1: loading image
17:18:02 1419723614mS PRN: PRIU DSP: loading image to addr 0090, size 32480
17:18:02 1419723951mS PRN: PRIU DSP: checking image
17:18:02 1419723951mS PRN: WARNING:
17:18:02 1419723951mS PRN: PRIU DSP: load error, 0x0090 = 0xffff, expected 0x0000
17:18:02 1419723951mS PRN:
17:18:02 1419723951mS PRN: WARNING:
17:18:02 1419723951mS PRN: PRIU DSP 1: failed to load and run DSP image
17:18:02 1419723951mS PRN:
17:18:02 1419723951mS PRN: WARNING:
17:18:02 1419723951mS PRN: PRIU DSP 1: restart DSP, load image failed
17:18:02 1419723951mS PRN:
17:18:03 1419724455mS RES3: Tasks=(344)OSPZeroTask (1)OSTrigger (1)MonitorTask
17:18:03 1419724455mS RES: Wed 5/11/2014 17:18:02 FreeMem=48723412 47784748(1) CachedMem=938664 CMMsg=5(5) Buff=5200 1370 1000 7380 5 Links=28988 BTree=11919 CPU=38.55% CPUStats=344/348/4361/10288/18366/0/0 MCR=0 MCW=0
17:18:03 1419724456mS RES2: IP 500 V2 9.0.3.16 build 2 Tasks=46 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=108 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=20(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
17:18:03 1419724456mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
17:18:04 1419725010mS PRN: Slot 1, Falc 1: YELLOW ALARM ON
17:18:04 1419725012mS PRN: Slot 1, Falc 2: YELLOW ALARM ON
17:18:07 1419728511mS ISDNL3Evt: v=1 p1=1,p2=1001,p3=4,p4=127,s1=
17:18:07 1419728511mS ISDNL3Evt: v=1 stacknum=1 State, new=NullState, old=Active id=10
17:18:07 1419728511mS ISDNL3Evt: v=1 stacknum=1 State, new=NullState, old=Active id=21652

 

[Gunnaro]

-> ISDNL1Evt: v=1 peb=1,PHDI
The physical line is down.

-> T1DSP: PRIU DSP 1: is dead
That's an amazingly clear text warning (for Monitor trace).

-> PRN: Slot 1, Falc 1: YELLOW ALARM ON
Yellow usually means the providers equipment has a Red alarm, normally their fault.

You could check the wiring, change the cable from the PRI to the T1 modem.
But maybe you should just get another provider, sounds like you are being mistreated.

BTW:
-> CMQueue=0 VPNNQueue=0 [highlight #FCE94F]Monitor=2[/highlight] SSA=1 TCP=20(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034

You have two sessions of Monitor running. If there is no good reason for this (like you or a colleague have initiated these sessions), someone is tapping into your system.



Kind regards

Gunnar
______________________________________
Mille viae ducunt homines per saecula Romam

 

[apparitions]

Thanks for the response. Sorry for all the questions.. this is a system I "inherited" and I'm learning as I go.

When I get the Physical Line down error, does that typically indicate my end or the provider's end?
I know the Yellow alarms means a Red alarm on the other end, but I'm trying to see if anything indicates the source of the outage or why it doesn't recover.

"PRIU DSP 1: failed to load and run DSP image" <- any idea what this means?

This is what I typically see when the system does recover on it's own:

06:38:47 1551693179mS ISDNL1Evt: v=1 peb=1,F4 F1
06:38:47 1551693182mS ISDNL1Evt: v=1 peb=1,F1 F4
06:38:47 1551693182mS PRN: Clock 1: excursion 2
06:38:47 1551693183mS ISDNL1Evt: v=1 peb=1,F3 F1
06:38:47 1551693189mS ISDNL1Evt: v=1 peb=1,UnLocked
06:38:47 1551693189mS ISDNL1Evt: v=2 peb=2,Locked
06:38:47 1551693189mS PRN: Falc: LockToFalc: 2
06:38:47 1551693189mS PRN: MEZZ_PRI_CLOCK_CNTL: f3
06:38:47 1551693189mS PRN: FPGA_REC_CLK_SELECT: 08
06:38:47 1551693189mS PRN: SetSlaveMode: 02
06:38:47 1551693194mS ISDNL1Evt: v=1 peb=1,F1 F3
06:38:47 1551693194mS ISDNL1Evt: v=1 peb=1,F2 F1
06:38:47 1551693195mS ISDNL1Evt: v=1 peb=1,F1 F2
06:38:47 1551693292mS RES: Sun 12/10/2014 06:38:47 FreeMem=48856508 47776076(2) CachedMem=1080432 CMMsg=5(5) Buff=5200 1368 999 7380 5 Links=33641 BTree=11935 CPU=08.15% CPUStats=1/3/3827/15735/17235/0/1 MCR=0 MCW=0
06:38:47 1551693292mS RES2: IP 500 V2 9.0.3.16 build 2 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=101 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=20(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
06:38:47 1551693292mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
06:38:59 1551705160mS ISDNL2Tx: v=2 peb=2
0000 00 01 01 3b ...;
06:38:59 1551705160mS ISDNL1Tx: v=2 peb=2
0000 00 01 01 3b ...;
06:38:59 1551705167mS ISDNL1Rx: v=2 peb=2
0000 00 01 01 a1 ....
06:38:59 1551705167mS ISDNL2Rx: v=2 peb=2
0000 00 01 01 a1 ....
06:39:01 1551707025mS ISDNL2Tx: v=1 peb=1
0000 00 01 01 67 ...g
06:39:01 1551707025mS ISDNL1Tx: v=1 peb=1
0000 00 01 01 67 ...g
06:39:01 1551707032mS ISDNL1Rx: v=1 peb=1
0000 00 01 01 39 ...9
06:39:01 1551707032mS ISDNL2Rx: v=1 peb=1
0000 00 01 01 39 ...9
06:39:17 1551723603mS T1DSP: PRIU DSP 1: is alive

 

[Gunnaro]

DSP = Digital Signal Processor on the PRI card.

Kind regards

Gunnar
______________________________________
Mille viae ducunt homines per saecula Romam