IP500v2 8.0.44 reboots on conference calls

[pdob]

Just a quick one...

When callers call into our conference bridge it knocks out the system and causing it to reboot. It was stable for couple of months after upgrading it to R6 to R8.
System on SCN (10 sites) mixed of R8 and R8.1 For now, we stopped using our conference bridge to isolate if problem is on our network.

Here's the trace before it reboots. Hope it's enough info.

Thanks in advance.

2323675716mS PRN: CallRefused reason=No Channel
2323675717mS CMLineTx: v=14
CMReleaseComp
Line: type=Q931Line 14 Call: lid=14 id=16 in=1
Called[3899] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[442082690998] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=6
Cause=34, No cct/chan available
2323675786mS CMTARGET: ISDN BChannel 10: in-service check = 1
2323675786mS ISDNL3Evt: v=14 stacknum=14 State, new=Present, old=NullState id=20
2323675787mS CMTARGET: ISDN BChannel 11: in-service check = 1
2323675787mS ISDNL3Evt: v=14 stacknum=14 State, new=Present, old=NullState id=7
2323675801mS ISDNL3Evt: v=14 stacknum=14 State, new=NullState, old=Present id=16
2323675804mS PRN: Task CMRtEngine waiting on Call Model Semaphore held by CM
2323675804mS CMLineRx: v=14
CMSetup
Line: type=Q931Line 14 Call: lid=14 id=20 in=1
Called[3899] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[3109098589] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=10
2323675804mS PRN: Q931Trunk: Found QBChannel to match 0.10 --> 7.43
2323681974mS PRN: Not calling SendTrap for EventType=50; AlarmKey=1
2323681974mS PRN: SNMP::module=f55c4f80, SNMP::module->trapper=f55c4f14, AlarmDescr=00000000
2323681974mS PRN: CallRefused reason=No Channel
2323681974mS CMLineTx: v=14
CMReleaseComp
Line: type=Q931Line 14 Call: lid=14 id=20 in=1
Called[3899] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[3109098589] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=10
Cause=34, No cct/chan available
2323682045mS ISDNL3Evt: v=14 stacknum=14 State, new=ReleaseReq, old=Active id=22
2323682046mS CMTARGET: ISDN BChannel 12: in-service check = 1
2323682046mS ISDNL3Evt: v=14 stacknum=14 State, new=Present, old=NullState id=12
2323682047mS CMTARGET: ISDN BChannel 13: in-service check = 1
2323682047mS ISDNL3Evt: v=14 stacknum=14 State, new=Present, old=NullState id=9
2323682053mS RES: Tue 16/10/2012 10:00:16 FreeMem=48524352(1) CMMsg=7 (9) Buff=5200 966 990 6704 3 Links=8511
2323682053mS RES2: IP 500 V2 8.0(18) Tasks=53 RTEngine=541 CMRTEngine=113 ExRTEngine=0 Timer=45 Poll=0 Ready=27 CMReady=4 CMQueue=3 VPNNQueue=0 Monitor=1 SSA=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2323682054mS PRN: SCNTFTP::SendPacket (3) seq=38683 len=494 retries=3 dest 192.168.5.100
2323682054mS PRN: SCNTFTP::SendPacket (2) seq=1271 len=513 retries=3 dest 192.168.5.100
2323682057mS PRN: GODTDMLink missed more than 5 Hello ACKs id=7
2323682057mS CMExtnEvt: Robert: ExtnFault now 1
2323682058mS CMExtnEvt: Igor: ExtnFault now 1
2323682059mS CMExtnEvt: Mike: ExtnFault now 1
2323682061mS CMExtnEvt: Server Rm: ExtnFault now 1
2323682062mS CMExtnEvt: Raul: ExtnFault now 1
2323682063mS CMExtnEvt: Michael: ExtnFault now 1
2323682064mS CMExtnEvt: Jaime: ExtnFault now 1
2323682065mS CMExtnEvt: Conf Rm Dev: ExtnFault now 1
2323682067mS CMExtnEvt: Luz: ExtnFault now 1
2323682068mS CMExtnEvt: Jas: ExtnFault now 1
2323682069mS CMExtnEvt: Chris: ExtnFault now 1
2323682070mS CMExtnEvt: Susan: ExtnFault now 1
2323682072mS CMExtnEvt: Extn3815: ExtnFault now 1
2323682073mS CMExtnEvt: Rachel: ExtnFault now 1
2323682074mS CMExtnEvt: Kris: ExtnFault now 1
2323682075mS CMExtnEvt: Karen: ExtnFault now 1
2323682077mS CMExtnEvt: Maria: ExtnFault now 1
2323682078mS CMExtnEvt: Neel: ExtnFault now 1
2323682079mS CMExtnEvt: Jann: ExtnFault now 1
2323682080mS CMExtnEvt: Comm Rm: ExtnFault now 1
2323682082mS CMExtnEvt: Timothy: ExtnFault now 1
2323682083mS CMExtnEvt: Smithi: ExtnFault now 1
2323682084mS CMExtnEvt: Yuri: ExtnFault now 1
2323682085mS CMExtnEvt: Iren: ExtnFault now 1
2323682087mS CMExtnEvt: Ash: ExtnFault now 1
2323682088mS CMExtnEvt: Ho: ExtnFault now 1
2323682089mS PRN: GODTDMLink::LinkDown line id 7 transitioned to down
2323688272mS PRN: Callback ../god/god_link.cpp Line 154 took 6215ms
2323688275mS CMLineRx: v=14
CMSetup
Line: type=Q931Line 14 Call: lid=14 id=7 in=1
Called[3899] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[447725954241] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=11
2323688276mS PRN: Q931Trunk: Found QBChannel to match 0.11 --> 7.44
2323694465mS PRN: Not calling SendTrap for EventType=50; AlarmKey=1
2323694465mS PRN: SNMP::module=f55c4f80, SNMP::module->trapper=f55c4f14, AlarmDescr=00000000
2323694465mS PRN: CallRefused reason=No Channel
2323694466mS CMLineTx: v=14
CMReleaseComp
Line: type=Q931Line 14 Call: lid=14 id=7 in=1
Called[3899] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[447725954241] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=11
Cause=34, No cct/chan available
2323694553mS ISDNL3Evt: v=13 stacknum=13 State, new=ReleaseReq, old=Active id=88610
2323694555mS ISDNL3Evt: v=14 stacknum=14 State, new=NullState, old=Active id=19
2323694555mS ISDNL3Evt: v=14 stacknum=14 State, new=ReleaseReq, old=Active id=18
2323694556mS ISDNL3Evt: v=14 stacknum=14 State, new=ReleaseReq, old=Active id=11
2323694557mS ISDNL3Evt: v=14 stacknum=14 State, new=ReleaseReq, old=Active id=14
2323694559mS PRN: GODTDMLink::LinkUp line id 7 transitioned to up
2323697052mS PRN: .WATCHDOG TIMEOUT CM stack f00a4418 f0312110 f0314d20 f0317618 f057f24c f016869c f057e710 f015a010 f057ee98 f02d5708 f02d5b30 f0156324 f0364d7c f036d170 f036d2fc f02e4cbc f02e4c68 IP 500 V2 8.0(18)

********** contact lost with 192.168.0.9 at 10:00:52 16/10/2012 - reselect = 1 **********
******************************************************************

********** SysMonitor v10.0 (44) **********

********** contact made with 192.168.0.9 at 10:01:35 16/10/2012 **********

********** System (192.168.0.9) has been up and running for 28secs(28084mS) **********

********** Warning: TEXT File Logging selected **********


********** Warning: TEXT Logging to File STARTED on 16/10/2012 10:01:35 **********
28084mS PRN: Monitor Started IP=192.168.0.10 IP 500 V2 8.0(18) AFEX Encino
(IP Office: Supports Unicode, System Locale is enu)
28085mS PRN: LAW=U PRI=2, BRI=0, ALOG=8, ADSL=0 VCOMP=32, MDM=0, WAN=0, MODU=3 LANM=0 CkSRC=0 VMAIL=0(VER=0 TYP=1) CALLS=0(TOT=0)
29110mS PRN: Config Write Wake Up
29110mS ISDNL1Evt: v=14 peb=14,F2 F3
29121mS LIC: INFO: 0 power user licenses 0 5
29123mS PRN: Created external MOH Source 1
29128mS PRN: A:\system\ws already existed with attr 10
29135mS PRN: A:\system\ws\up already existed with attr 10
29601mS ISDNL1Evt: v=14 peb=14,F1 F2
29602mS ISDNL1Evt: v=14 peb=14,F3 F1
29605mS PRN: QMC RESREC f5e83ae4 7 f5e83ee4 f7dc96d8 f7dc9ed8 0 0 2048
29605mS PRN: QMC RESREC f5e836b4 8 f5e83ee4 f7dc9718 f7dc9f18 1 64 2112
29605mS PRN: QMC RESREC f5e7b31c 9 f5e7b71c f7dca7e0 f7dcafe0 0 0 2048
29608mS PRN: VPNN: change locaddr for pbx 192.168.10.5
29609mS PRN: VPNN: last_activity set for pbx 192.168.10.5
29611mS PRN: Sorting User List...
29613mS PRN: User List Sorted
29616mS PRN: Sorting Hunt Group List...
29616mS PRN: Networked Hunt Group List Sorted
29618mS PRN: A:\system\ws\br already existed with attr 10
29618mS PRN: [UWS 8829//ws_upgrade.cpp 0029618ms] Reading session data from SD card
29619mS PRN: Check for duplicates took 0 ms
29619mS PRN: Sorting Directory List...
29620mS PRN: Sorted Directory List.
29622mS PRN: Config Write Completed
29630mS ISDNL1Evt: v=13 peb=13,F1 F2
29631mS PRN: [UWS 9570//ws_upgrade.cpp 0029631ms] Erasing UWSSD session backup
29631mS PRN: [UWS 9580//ws_upgrade.cpp 0029631ms] Erase UWSSD session backup 2
29648mS PRN: System Started from System Card, Primary Directory
29648mS PRN: WARNING:
29649mS PRN: System was not Shutdown correctly
29649mS PRN:
29649mS PRN: Last Shutdown/Reboot: Wed 19/09/2012 12:32:15

 

[amriddle01]

Looks like a Dig 30 module goes down and when it comes back up takes the whole system down

 

[pdob]

Thanks amriddle.

We have 3 DS30 here. Could you tell which one is going down?

 

[pdob]

Figured it out from the user name. Module 2.

Thanks again amriddle.

 

[Bucky101]

Also, This is a known bug that we reported to Avaya which they fixed in the 1Q12 update, is that the one you have installed

 

[tlpeter]

This is the module:

2323682057mS PRN: GODTDMLink missed more than 5 Hello ACKs id=7

But this comes by a couple of times too:

Cause=34, No cct/chan available

BAZINGA!

I'm not insane, my mother had me tested!

 

[IPGuru]

It may be a red herring but accidentally connecting a network card to a ds port will cause the module to enter a reboot cycle until the error is cleared.
This doesn't usually cause a full system reboot though


A Maintenance contract is essential, not a Luxury.
Do things on the cheap & it will cost you dear

 

[pdob]

@Bucky - yes, it's on Q1 2012 release 8.0.44 I checked the Q3 release but nothing about conference rebooting the system.

@tlpeter - The error "Cause=34, No cct/chan available" happens only when there are conference calls.

Another thing I want to add. On that DS30 we have (18) 6408D+ phones. I remember seeing that you can have up 24 6408D+ phones before it goes wierd.
Could it be power supply on the DS30?