Authentication to Embedded Mailbox Causing system to reboot

[wheelma2]

I have an IPO 500 V2 (software 8.0) with Embedded Voicemail enabled on a HuntGroup. When the responsible staff member attempts to check messages on this mailbox, the entire system reboots. Here is the sequence of events...
[ol 1]
[li]User at x2422 lifts handset and presses MESSAGES[/li]
[li]She is prompted for her mailbox. She dials 2420#[/li]
[li]She is prompted for the password. She dials 8520#[/li]
[li]The system reboots. A minute or two later, phones come back online.[/li]
[/ol]

NOTE: If she attempts to check her own voicemail (2422), it works just fine. The system does not reboot after she enters the password for mailbox 2422.
NOTE: On my workbench system, I am able to check my huntgroup's mailbox (2540) from the phone at x2542. It isn't behaving the same as the system I have in production.

I used system status to trace x2422 while she is trying to login to hut group mailbox 2420. It doesn't reveal much...

1/3/13 3:48:20 PM-626ms Extension = 2422, Switchhook, Status = Off
1/3/13 3:48:20 PM-631ms Call Ref = 1, Originator State = Seized, Type = User, Destination Type = none
1/3/13 3:48:22 PM-921ms Extension = 2422, Pressed Fixed Feature, Button =
1/3/13 3:48:22 PM-926ms My buttons = 1, Call Ref = 1, Originator State = Dialling, Type = User, Destination State = Seized, Type = Target List
1/3/13 3:48:22 PM-931ms My buttons = 1, Call Ref = 1, Originator State = Connected, Type = User, Destination State = Connected, Type = Mailbox
1/3/13 3:48:30 PM-048ms Extension = 2422, Digit dialed, Digit = 2
1/3/13 3:48:30 PM-773ms Extension = 2422, Digit dialed, Digit = 4
1/3/13 3:48:31 PM-223ms Extension = 2422, Digit dialed, Digit = 2
1/3/13 3:48:32 PM-861ms Extension = 2422, Digit dialed, Digit = 0
1/3/13 3:48:33 PM-711ms Extension = 2422, Digit dialed, Digit = #
1/3/13 3:48:37 PM-436ms Extension = 2422, Digit dialed, Digit = 8
1/3/13 3:48:37 PM-861ms Extension = 2422, Digit dialed, Digit = 5
1/3/13 3:48:38 PM-261ms Extension = 2422, Digit dialed, Digit = 2
1/3/13 3:48:38 PM-961ms Extension = 2422, Digit dialed, Digit = 0​

The PBX is rebooting the moment she presses # after dialing the password of 8520, thus the trace is being cut off between the 8520 and the #.

Any suggestions?

 

[wheelma2]

I figure it may be worth mentioning... There are 214 messages in the affected mailbox. Could this have anything to do with it? Too full?

I recently inherited this system and made them aware of the fact that they have a mailbox with over 200 new messages. Thus the need to start monitoring this mailbox.

 

[CarGoSki]

15 hours of mailbox time is default for embedded mail. Not limited by the number of messages per box.

Could be that the embedded card was never upgraded correctly

Has this been an ongoing issue with several boxes or only the one with over 200 messages?

 

[wheelma2]

Well, I'm still learning their business and how they use this system, but so far I think this is the only mailbox that has collected messages. All other mailboxes currenlty have 0 messages (new, old, saved, etc.) according to System Status.

Is there a way I can mass-delete the 214 old messages? They do not intend to follow up on them now anyhow. They were just going to dial and and start deleteing. They'll being monitoring this mailbox going forward.

 

[tlpeter]

Make a monitor trace and don't use SSA for this.
So try it again and post the trace please.


BAZINGA!

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

 

[wheelma2]

Here is what I believe to be the relative logs....

66096229mS PRN: Begin Stack Trace
66096229mS PRN: pc=f1302b60
66096229mS PRN: lr=f02f0220
66096229mS PRN: findfunc f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8 f0219c50 f0253ed4 f020e5d8 f02516d4 f0251aa0
66096229mS PRN: findfunc f0251b58 f020dca8 f01f8990 f01fa238 f0268478 f0268560 f02e4cb0 f02e4c5c 00000000 00000000
66096229mS PRN: End Stack Trace
66096229mS PRN: ScheduleHistory NOT enabled: Task = LVMTicker File = ../platform/platform.cpp Line = 1196
66096229mS PRN: .FATAL TLB Data address=4f5f3238 d=5 pc=f1302b60 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8 IP 500 V2 8.0(16)

********** contact lost with 172.23.82.15 at 10:11:08 4/1/2013 - reselect = 1 **********
******************************************************************​

And here is the same data but with more history... the third line below is where she began dialing the mailbox 2420#... then the password 8520#... then the final few logs before the FATAL and loss of connection....

66083281mS RES: Fri 4/1/2013 10:10:37 FreeMem=62122356(1) CMMsg=6 (8) Buff=5200 909 1000 7463 5 Links=6913
66083282mS RES2: IP 500 V2 8.0(16) Tasks=42 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=46 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
66089455mS PRN: 2422: Digit Pressed 2
66089455mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
66089456mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66090068mS PRN: 2422: Digit Pressed 4
66090068mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
66090069mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66090443mS PRN: 2422: Digit Pressed 2
66090443mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
66090444mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66090782mS RES: Fri 4/1/2013 10:10:44 FreeMem=62124548(1) CMMsg=6 (8) Buff=5200 955 1000 7463 5 Links=6963
66090782mS RES2: IP 500 V2 8.0(16) Tasks=42 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=46 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
66090868mS PRN: 2422: Digit Pressed 0
66090868mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
66090869mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66091243mS PRN: 2422: Digit Pressed #
66091243mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[#] Type=Default (100) Reason=CMDRdirect
66091244mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[#] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66094256mS PRN: 2422: Digit Pressed 8
66094256mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[8] Type=Default (100) Reason=CMDRdirect
66094257mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[8] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66094656mS PRN: 2422: Digit Pressed 5
66094656mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[5] Type=Default (100) Reason=CMDRdirect
66094657mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[5] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66095018mS PRN: 2422: Digit Pressed 2
66095018mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
66095019mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66095481mS PRN: 2422: Digit Pressed 0
66095481mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
66095482mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66096206mS PRN: 2422: Digit Pressed #
66096206mS CMExtnRx: v=2422, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1286 in=0
Called[#] Type=Default (100) Reason=CMDRdirect
66096207mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[#] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Judy Hodges
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Judith Hodges
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2422
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceStdPhone type=78 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1286 ipaddr=172.23.82.15 apps=0
66096229mS PRN: Begin Stack Trace
66096229mS PRN: pc=f1302b60
66096229mS PRN: lr=f02f0220
66096229mS PRN: findfunc f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8 f0219c50 f0253ed4 f020e5d8 f02516d4 f0251aa0
66096229mS PRN: findfunc f0251b58 f020dca8 f01f8990 f01fa238 f0268478 f0268560 f02e4cb0 f02e4c5c 00000000 00000000
66096229mS PRN: End Stack Trace
66096229mS PRN: ScheduleHistory NOT enabled: Task = LVMTicker File = ../platform/platform.cpp Line = 1196
66096229mS PRN: .FATAL TLB Data address=4f5f3238 d=5 pc=f1302b60 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8 IP 500 V2 8.0(16)

********** contact lost with 172.23.82.15 at 10:11:08 4/1/2013 - reselect = 1 **********
******************************************************************
​

I'd love to address the root cause, but at this point I'd even be ok with just deleting the message files. I found an old ticket where the technician who formerly supported this lot of (10) IPOs had a similar issue in another of the offices. His notes just say he deleted messages and told them not to let them build up again. I'm just not sure how to go about deleting messages without access to the Serial/DTE on the backplane. I only have remote access to these systems via WAN.

Thanks for the guidance!

 

[tlpeter]

Do they have a SCN? (multiple sites connected to each other)
If yes then this is unsupported.
The only supported voicemail in a SCN is voicemail pro.

BAZINGA!

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

 

[wheelma2]

Negative. Each is standalone with embedded voicemail (for now).

 

[tlpeter]

Which version of 8.0 is it running?


BAZINGA!

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

 

[wheelma2]

IP 500 V2 8.0(16)

 

[tlpeter]

Then i suggest to upgrade it to 8.0.51
8.0.16 was the first 8.0 release and there a lot of bug fixes done.


BAZINGA!

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

 

[wheelma2]

Thanks. I will look into upgrading. In the meantime, is there a way for me to delete messages?

I also just found these alarms in MONITOR...

2805947mS PRN: ALARM: 03/01/2013 15:26:50 IP 500 V2 8.0(16) <DSI Excep> CRIT RAISED addr=3237004e d=5 pc=f1302b28 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8
2805947mS PRN: ALARM: 03/01/2013 15:29:53 IP 500 V2 8.0(16) <DSI Excep> CRIT RAISED addr=3237004e d=5 pc=f1302b28 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8
2805947mS PRN: ALARM: 03/01/2013 15:39:39 IP 500 V2 8.0(16) <DSI Excep> CRIT RAISED addr=3237004e d=5 pc=f1302b28 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8
2805947mS PRN: ALARM: 03/01/2013 15:48:39 IP 500 V2 8.0(16) <DSI Excep> CRIT RAISED addr=3237004e d=5 pc=f1302b28 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8
2805947mS PRN: ALARM: 04/01/2013 10:10:50 IP 500 V2 8.0(16) <TLB Data > CRIT RAISED addr=4f5f3238 d=5 pc=f1302b60 f02f01f8 f02f0328 f022b054 f01ffbe0 f020ddf8​

They all correspond to reboots caused by our testing. But I wonder what was different about all of the events from yesterday that were <DSI Excep> and the one from this morning was <TLB Data > ?

 

[tlpeter]

You need to delete them by hand, one by one.

BAZINGA!

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

 

[wheelma2]

Could you elaborate. How do we "delete them by hand" if we cannot authenticate via TUI without causing the entire system to reboot?

 

[tlpeter]

The extension that has the messages should delete them.
What you are trying to do is from a different phone.


BAZINGA!

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

 

[wheelma2]

But that's because mailbox 2420 is for a HuntGroup. No physical phone is associated with a HuntGroup, thus they must check messages from another phone.

 

[CarGoSki]

A a visual voicemail button to a phone. In that user goto Sourcenumber tab and add h+huntgroup name or extension number. Spelling counts.
If you do it correctly then you can use the visual voicemail button to view personal and group messages. delete-delete-delete etc

 

[yankblan]

Scrap the MB entirely and recreate it. You will save hours

http://interconnexionsld.ca/

 

[wheelma2]

Thanks for the suggestions, but I was still convinced there had to be a way to access the message files from within IPO Manager. I found it... File > Advanced > Embedded File Management. Once you've connected to the IPO with the "Embedded File Management" utility, navigate to System SD > DYNAMIC > LVMAIL. Here you'll find the CLP files. Unfortunatley the CLP files for every extension are in this one directory, but I can live with that. Select a file then Right click > Delete.

 

[wheelma2]

Update: After deleting all but 16 CLP files, I noticed System Status still showed over 200 new messages in that mailbox. I had her try authenticateing anyways, and it still caused the system to reboot. Upon reboot, the voicemail database must've self-corrected and now "System Status" showed 16 messages in that mailbox. Now she could authenticate and retrieve those 16 most recent messages. So it took me deleting messages from the SD card and a database cleanup. We invoked the database cleanup by reboot, but I'm curious if the database would've looked better after the next interval of the health check that occurs every 5 minutes. I wish I'd waited for that before having her try to authenticate... oh well.

I still plan to upgrade the software on this thing...