PBX Rebooted

[pakman]

Hello,

I got an alert that a site rebooted yesterday during the day and the Call Center confirmed they lost phones at the same time. However, I cannot find anything in the logs suggesting the PBX rebooted. I received the alert at 406 and here are all the logs from 406 going back to 3:45.

I see some references to restart but I'm not sure what the root cause is. Do any of these logs point to a root cause? I have Mitel and our vendor troubleshooting an issue and I think they might of caused the issue. What does this mean when the username is blank?

SecurityMgr   UsernameAuthenticate()    Authentication was successful.
SecurityMgr   UsernameAuthenticate()    User profile has been retrieved.
SecurityMgr   RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.


thanks,

Progress Monitor->E2TServiceProvider::StartUpinvoked
Progress Monitor->ServiceLayerCoordinator::ServiceLayerCoordinatorinvoked
EtxOn done
IPN Data Services done
DHCP Lease expired - IP/MAC: 10.182.5.124 / 08000f26a54c10.182.5.125 / 08000f226c4d10.182.5.127 / 08000f2273db10.182.5.131 / 000b97a0b7fe10.182.5.132 / 0014c2d95b92
DHCP Server initialized.
DNS-QryMgr service done
DHCP service done
Management Layer done
IDS_LDAPConnection: initiallizeConnectionData() GET_FirstRecord - record not found.
SWERR unexpected situation,  OFFSET 2:$3B6,  PC: $30BF7ALOG_ID: cpwrtdata#10,  PROCEDURE: update_dept_status,  SEVERITY: cp_minorPID: ($1, $5EF)
SWERR unexpected situation,  OFFSET 2:$3B6,  PC: $30BF7ALOG_ID: cpwrtdata#10,  PROCEDURE: update_dept_status,  SEVERITY: cp_minorPID: ($1, $5EF)

PROGRAMMED SERVICE: Changed Dept 0 to DAY service.   Reason: re-activated service due to restart.

The Admin Group Management application is enabled and running. Admin Group membership has not been exceeded.
System time successfully updated.
Power supply 2 installed.
Power supply 1 installed.
SDS alarm is changed to Clear.
SDS has been enabled.
Temperature sensor 2 warning cleared
Temperature sensor 1 warning cleared
Progress Monitor->ClearAlarmClear Alarm on Temperature, curr=0 max=2 minor=50 major=100 critical=101
Fan 2 running
Fan 1 running
Progress Monitor->ClearAlarmClear Alarm on Fans, curr=0 max=2 minor=50 major=100 critical=101
Progress Monitor->ClearAlarmClear Alarm on Faulty Disk, curr=0 max=2 minor=50 major=50 critical=100
SDS data migration or conversion to configure forms at default sharing scope completes successfully.
SDS data migration or conversion to configure forms at default sharing scope completes successfully.
WAN_port: state=down, cause=dhcp-leasefail, message=
WAN_port: state=down, cause=dhcp-deconfig
WAN_port: state=down, proto=dhcp, cause=wan-start
L2 subsystem completed configuration
Established communication with L2 subsystem
Port 1, 1G, full duplex
WAN_port: state=down, proto=none, cause=wan-disabled
rdisc: state=enable
WAN_port: state=down, proto=none, cause=wan-start
rdisc: state=enable
Accepted connection from L2 subsystem (1).
EntryBlock - Enable Block State VM Not Ready with Mask 0x10
EntryBlock - Disable Block State Resume Restore in progress with Mask 0x8
EntryBlock - Enable Block State Resume Restore in progress with Mask 0x8
EntryBlock - Disable Block State Resume Restore in progress with Mask 0x8
EntryBlock - Enable Block State Resume Restore in progress with Mask 0x8
INFO: SSO Enabled.
INFO: SSO About to startup.
Call Engine Layer proc done
License Violation Status Update. Old = Clear; New = Clear.
slowpoke was not set to run
LOGSYSRTR is ready to route entries Log name: hotel
process_calls_ logged error = nil_swerr    for PID: $00
process_calls_ logged error = nil_swerr    for PID: $00
process_calls_ logged error = nil_swerr    for PID: $00
LOGSYSRTR is ready to route entries Log name: ftsmdr
LOGSYSRTR is ready to route entries Log name: smdr
The link from MCECAAx MN3300 Controller at location 01 1 01 Active         to   MC270Ax Universal T1 at location 06 1 03  is now in SCANNING mode.
The link from MCECAAx MN3300 Controller at location 01 1 01 Active         to   MC266Ax Communication Proc at location 01 1 13  is now in SCANNING mode.
The link from MCECAAx MN3300 Controller at location 01 1 01 Active         to   MCSTHAx ICP Communications at location 01 1 11  is now in SCANNING mode.
The link from MCECAAx MN3300 Controller at location 01 1 01 Active         to   MC266Ax Communication Proc at location 01 1 10  is now in SCANNING mode.
Restart information from hardware status register was  power up
LOGSYSRTR is ready to route entries Log name: maintenance
LOGSYSRTR is ready to route entries Log name: security
LOGSYSRTR is ready to route entries Log name: mobility
TIME: Time change detected 3 time(s): 2017-DEC-19 16:04:39.00    TUE
OS (Store) info: Free memory low water mark is 0072E300 bytes. 
GPAGEMGR: Initializing data structures                                                                                                                                                                                                               
DBMS info: Download Completed.
DBMS Status flag set.  DB Download Complete..
TIME: Time change detected 2 time(s): 2017-DEC-19 16:04:26.00    TUE
DBASRV created: PID = ($0006,$0036)
DBASRV created: PID = ($0005,$0035)
DBASRV created: PID = ($0004,$0034)
DBASRV created: PID = ($0003,$0033)
DBASRV created: PID = ($0002,$0032)
DBASRV created: PID = ($0001,$0031)
DBASRV created: PID = ($0007,$0030)
DBASRV created: PID = ($0006,$002F)
DBASRV created: PID = ($0005,$002E)
MIPSServiceProvider proc done
Internal L2 Switch IP address is 10.182.5.3.
IPN Database done
nvs_BerkConvert: Recovering existing IP Networking database.
appStartupPart2 done
NotifyTimeChangeTime Change Could not be Notified
memory audit started successfully
Progress Monitor->ResourceAlarmStartupResourceAlarmStartup ready
Progress Monitor->SysServices::appStartupPart2 (10.182.5.2)Boot Device: ata=0Host Name: bootHostTarget Name: Target IP address: 10.182.5.2:ffffff00Host IP address: 192.168.1.5Gateway IP address: 10.182.5.1Boot File: /partition1/RTC8260Boot Flag: 0x0
Unexpected Result->SysServices::appStartupPart2 (10.182.5.2)Abnormal reset, cause: (0x103) SOFTWARE_RESET
Progress Monitor->SysServices::appStartupPart2MXeIII Platform (10.182.5.2) Booting Software version: 13.0.1.28System Relink: No relink has been applied.Call Control Relink: No relink has been applied.Abnormal reset, cause: (0x103) SOFTWARE_RESET
ChubSp done
Java Layer proc done
JavaLayer_Init->Received startup notification for JavaLayer. Time waiting was 7s
JavaLayerLifecycleListener::handleNotification()->Received Startup notification for JavaLayer.
JavaLayer_PPC_StartUp->JavaLayer startup has been initiated.
Management Layer AVS proc done
InitSystemTimeZone()->Current Timezone is  US/Central
TRAFORM: Traffic report for period 35 of session 1 completed.

[x-man]

I'm not certain but I think the reason for the restart will be somewhere in the logs; maybe before the time you have posted (they don't look complete from a restart basis) I think the error is usually given at or near the begining....I wonder if there is a hard disk failure involved. The usual one we see for odd reboots like this are stale tasks.(like the controller trying to reach the amc and not having a way to do it for some reason.....usually caused by IT changing something on a router or suchlike......)

[acejavelin]

Look back further in the logs, or take a sys diag snapshot and open a ticket with support... The reason "Abnormal reset, cause: (0x103) SOFTWARE_RESET" is typically because too many errors built up on some device that crossed a threshold and forced a reboot to clear the errors, in theory in order to prevent a lockup condition which would require a manual power cycle. Normally if the errors are insignificant, it would follow your programmed reboot schedule, but it must have been more significant than that, and thus we would hope logged somewhere.

[pakman]

Thanks for the responses. I too would think the logs would be at the beginning of the issue. I have included logs all the way back to 11:30 and don't see anything that would point to a random reboot.

I was wondering about the security logs for the following reasons. I have an open ticket with my phone vendor which turned around and opened one with Mitel. They claim they were not in the system or caused this but the ticket there investigating is this site. In the logs someone logged in at 5:40. I'm really surprised that the system doesn't log a username and just this generic entry two entries. Myself and one other guy has access to these systems and neither of us logged in.

UsernameAuthenticate()    Authentication was successful.
UsernameAuthenticate()    User profile has been retrieved.


TRAFORM: Traffic report for period 34 of session 1 completed.
TRAFORM: Traffic report for period 34 of session 1 begins.
TRAFORM: Traffic report for period 33 of session 1 completed.
TRAFORM: Traffic report for period 33 of session 1 begins.
TRAFORM: Traffic report for period 32 of session 1 completed.
TRAFORM: Traffic report for period 32 of session 1 begins.
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s).) for DEI id (171)
handleHostingChanges()->Failed to delete GDM hosted user service tuple: Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s)..
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s).) for DEI id (171)
handleHostingChanges()->Failed to delete GDM hosted user service tuple: Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s)..
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s).) for DEI id (171)
handleHostingChanges()->Failed to delete GDM hosted user service tuple: Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s)..
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (This directory number is currently programmed as another type of group.) for DEI id (171)
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s).) for DEI id (171)
handleHostingChanges()->Failed to delete GDM hosted user service tuple: Key is associated with one or more users. Delete the corresponding Telephone Directories to remove the user association(s)..
updateDEIRecordIndication()->m_adaptorWithHiddenKeyWrapper.updateTuple failed (This directory number is currently programmed as another type of group.) for DEI id (171)
TRAFORM: Traffic report for period 31 of session 1 completed.
TRAFORM: Traffic report for period 31 of session 1 begins.
UsernameAuthenticate()    Authentication was successful.
UsernameAuthenticate()    User profile has been retrieved.
RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.
TRAFORM: Traffic report for period 30 of session 1 completed.
TRAFORM: Traffic report for period 30 of session 1 begins.
SWERR invalid software id,  OFFSET 2:$1CEA,  PC: $3BD896LOG_ID: cpss4msg#1,  PROCEDURE: cpss4msg_swid_is_cbm_set,  SEVERITY: cp_informPID: ($1, $27A)Cant set CBM on Hunt Grp w Remote 1st Member.
TRAFORM: Traffic report for period 29 of session 1 completed.
TRAFORM: Traffic report for period 29 of session 1 begins.
TRAFORM: Traffic report for period 28 of session 1 completed.
TRAFORM: Traffic report for period 28 of session 1 begins.
TRAFORM: Traffic report for period 27 of session 1 completed.
TRAFORM: Traffic report for period 27 of session 1 begins.
TRAFORM: Traffic report for period 26 of session 1 completed.
TRAFORM: Traffic report for period 26 of session 1 begins.
SWERR invalid software id,  OFFSET 2:$1CEA,  PC: $3BD896LOG_ID: cpss4msg#1,  PROCEDURE: cpss4msg_swid_is_cbm_set,  SEVERITY: cp_informPID: ($3, $4E4)Cant set CBM on Hunt Grp w Remote 1st Member.
SWERR invalid software id,  OFFSET 2:$1CEA,  PC: $3BD896LOG_ID: cpss4msg#1,  PROCEDURE: cpss4msg_swid_is_cbm_set,  SEVERITY: cp_informPID: ($3, $4E4)Cant set CBM on Hunt Grp w Remote 1st Member.
TRAFORM: Traffic report for period 25 of session 1 completed.
TRAFORM: Traffic report for period 25 of session 1 begins.
TRAFORM: Traffic report for period 24 of session 1 completed.
TRAFORM: Traffic report for period 24 of session 1 begins.
TRAFORM: Traffic report for period 23 of session 1 completed.
TRAFORM: Traffic report for period 23 of session 1 begins.
TRAFORM: Traffic report for period 22 of session 1 completed.
TRAFORM: Traffic report for period 22 of session 1 begins.
TRAFORM: Traffic report for period 21 of session 1 completed.
TRAFORM: Traffic report for period 21 of session 1 begins.
UsernameAuthenticate()    Authentication was successful.
UsernameAuthenticate()    User profile has been retrieved.
RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.
TRAFORM: Traffic report for period 20 of session 1 completed.
TRAFORM: Traffic report for period 20 of session 1 begins.
System Diagnostics Collection completed.
System Diagnostics file creation finished.
System Diagnostics file creation started.
System Diagnostics collection started.
UsernameAuthenticate()    Authentication was successful.
UsernameAuthenticate()    User profile has been retrieved.
RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.
System Diagnostics Collection completed.
System Diagnostics file creation finished.
TRAFORM: Traffic report for period 19 of session 1 completed.
TRAFORM: Traffic report for period 19 of session 1 begins.
OS (Store) info: Free memory low water mark is 002ABBC0 bytes. 
System Diagnostics file creation started.
System Diagnostics collection started.
SWERR invalid software id,  OFFSET 2:$1CEA,  PC: $3BD896LOG_ID: cpss4msg#1,  PROCEDURE: cpss4msg_swid_is_cbm_set,  SEVERITY: cp_informPID: ($6, $3D0)Cant set CBM on Hunt Grp w Remote 1st Member.
SWERR invalid software id,  OFFSET 2:$1CEA,  PC: $3BD896LOG_ID: cpss4msg#1,  PROCEDURE: cpss4msg_swid_is_cbm_set,  SEVERITY: cp_informPID: ($6, $3D0)Cant set CBM on Hunt Grp w Remote 1st Member.
UsernameAuthenticate()    Authentication was successful.
UsernameAuthenticate()    User profile has been retrieved.
RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.
UsernameAuthenticate()    Username authentication failed due to invalid Username.
RequestMatchingProfileData()    System is running with GDM Mode. Attempting to retrieve user profile.
TRAFORM: Traffic report for period 18 of session 1 completed.

[Dogbreath]

I'm really surprised that the system doesn't log a username

Audit Trail Logs is the form you want.

[johnp]

Logs without timestamps are worthless

[august]

From THB

0x103 Programmed reset The system software intentionally
restarted the system.