Yet another 9508 Issue..

DBrewsky · Dec 12, 2019

IPO 9.0.0.0 Build 829 - Customer has an IP400 expansion chassis which prevents us from updating past Rls 9.0.x - I believe the latest I can go up to is 9.0.10

Any extension using a "9508" can not play hunt group messages when accessing Visual Voice. When I access visual voice, I can see the hunt group voicemails, but when I access either New or Saved messages and press "Select" then all I hear is an error beep. If I access the users voicemail, then it works fine, but only their voicemail, and not the HXXXX for the Hunt Groups.

I have no issues with 5420 telephones.

I tried two firmware versions:
9508: Rel:0.59 07/29/15
Bootloader: V0.17
Zarlink Image: 009

9508: Rel:0.45 12/13/12
Bootloader: V0.15
Zarlink Image: 009

Any help is appreciative.. Customer does not have Avaya Support and the company I work for is the Avaya vendor.

Trace below is using x2630:

Monitor Trace said:
********** Warning: Logging to Screen Started **********
15:02:56 3742127686mS RES: Thu 12/12/2019 15:02:55 FreeMem=52770788 50997828(1) CachedMem=1772960 CMMsg=9(9) Buff=5200 1356 999 7397 3 Links=436488 BTree=13205 CPU=36.83% CPUStats=3/8/3152/8917/20337/0/1 MCR=0 MCW=0
15:02:56 3742127686mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=45 RTEngine=2 CMRTEngine=0 ExRTEngine=0 Timer=59 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=34(TLS=6) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:02:56 3742127686mS RES4: XML MemObjs=110 PoolMem=2097152(1) FreeMem=2081284(1)
15:02:58 3742129630mS CD: CALLSYNC: cs02
15:02:58 3742129863mS CD: CALLSYNC: cs02
15:03:01 3742132632mS CD: CALLSYNC: cs02
15:03:02 3742133708mS RES: Thu 12/12/2019 15:03:02 FreeMem=52770788 50997828(1) CachedMem=1772960 CMMsg=9(9) Buff=5200 1356 998 7399 3 Links=436488 BTree=13205 CPU=37.02% CPUStats=3/9/3152/8874/20337/0/1 MCR=0 MCW=0
15:03:02 3742133708mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=59 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=34(TLS=6) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:03:02 3742133708mS RES4: XML MemObjs=110 PoolMem=2097152(1) FreeMem=2081284(1)
15:03:03 3742134871mS CD: CALLSYNC: cs02
15:03:04 3742135636mS CD: CALLSYNC: cs02
15:03:04 3742135949mS PRN: 2630: Feature Key Pressed 7CPLFeatureMessages
15:03:04 3742135950mS VMAIL Messaging: Start................. 2802
15:03:04 3742135950mS VMAIL Messaging: Tx PC VMM data=<VMM$SENDMSGD$2802$>
15:03:04 3742135950mS VMAIL Messaging: Tx PC VMM data=<VMH$SENDMSGD$2802$AaBb$2802$>
15:03:04 3742135962mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMS$MBXSUCCESS$1576188185$12/12/2019$%>
15:03:04 3742135963mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMM$MSG00585$O$2019/12/2 11:33$2621$3$0$0$%>
15:03:04 3742135963mS VMAIL Messaging: ProcessVMMData data=<VMM$MSG00585$O$2019/12/2 11:33$2621$3$0$0$%>
15:03:04 3742135964mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMM$MSG00586$O$2019/12/4 14:09$4804157951$23$0$0$%>
15:03:04 3742135964mS VMAIL Messaging: ProcessVMMData data=<VMM$MSG00586$O$2019/12/4 14:09$4804157951$23$0$0$%>
15:03:04 3742135965mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMM$MSG00587$O$2019/12/5 11:17$5203001009$24$0$0$%>
15:03:04 3742135965mS VMAIL Messaging: ProcessVMMData data=<VMM$MSG00587$O$2019/12/5 11:17$5203001009$24$0$0$%>
15:03:04 3742135966mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMM$MSG00588$O$2019/12/12 11:46$5183482300$18$0$0$%>
15:03:04 3742135966mS VMAIL Messaging: ProcessVMMData data=<VMM$MSG00588$O$2019/12/12 11:46$5183482300$18$0$0$%>
15:03:04 3742135966mS VMAIL Messaging: Rx PC VMM for 2802 data=<VMX$MBXERROR$1576188185$%>
15:03:04 3742135967mS VMAIL Messaging: Complete................. 2802
15:03:04 3742135967mS VMAIL Messaging: Complete................. 2802
15:03:04 3742135967mS VMAIL Messaging: Start................. 2803
15:03:04 3742135967mS VMAIL Messaging: Tx PC VMM data=<VMM$SENDMSGD$2803$>
15:03:04 3742135967mS VMAIL Messaging: Tx PC VMM data=<VMH$SENDMSGD$2803$AaBb$2803$>
15:03:04 3742135978mS VMAIL Messaging: Rx PC VMM for 2803 data=<VMS$MBXSUCCESS$1576188185$12/12/2019$%>
15:03:04 3742135979mS VMAIL Messaging: Rx PC VMM for 2803 data=<VMM$MSG00058$S$2018/12/31 13:58$8183866217$26$0$0$%>
15:03:04 3742135979mS VMAIL Messaging: ProcessVMMData data=<VMM$MSG00058$S$2018/12/31 13:58$8183866217$26$0$0$%>
15:03:04 3742135994mS VMAIL Messaging: Rx PC VMM for 2803 data=<VMX$MBXERROR$1576188185$%>
15:03:04 3742135994mS VMAIL Messaging: Complete................. 2803
15:03:04 3742135994mS VMAIL Messaging: Complete................. 2803
15:03:07 3742138640mS CD: CALLSYNC: cs02
15:03:07 3742138900mS CMCallEvt: 0.1468040.0 -1 BaseEP: NEW CMEndpoint f4f136bc TOTAL NOW=1 CALL_LIST=0
15:03:07 3742138900mS CMCallEvt: 0.1468040.0 -1 2630.-1: NEW CMExtnEndpoint f4f136bc, Name=2630, Extn=2630, Phys Extn=2630
15:03:07 3742138900mS CMCallEvt: CREATE CALL:389249 (f4ec4408)
15:03:07 3742138900mS CMCallEvt: 0.1468041.0 -1 BaseEP: NEW CMEndpoint f4f176ac TOTAL NOW=2 CALL_LIST=0
15:03:07 3742138901mS CMExtnEvt: 2630: CMExtnHandler::SetCurrent( id: 0->1468040 )
15:03:07 3742138902mS CMExtnRx: v=2630, p1=0
CMSetup
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
Called[?ELA Ed] Type=Voicemail (102) Reason=CMDRdirect Called SubAddress[oink] Calling[2630] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=2630
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=2630
15:03:07 3742138903mS CMCallEvt: 0.1468040.0 389249 2630.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
15:03:07 3742138903mS CMExtnEvt: v=6 State, new=Dialling old=Idle,0,0,2630
15:03:07 3742138903mS CMTARGET: 0.1468040.0 389249 2630.0: Setting Hard Timer 4000
15:03:07 3742138904mS CMTARGET: 0.1468040.0 389249 2630.0: LOOKUP CALL ROUTE: type=102 called_party=?ELA Ed sub=oink calling=2630 dir=out complete=0 ses=0
15:03:07 3742138904mS CMTARGET: 0.1468040.0 389249 2630.0: ADD TARGET (N): number=?ELA Ed type=102 depth=1 nobar=1 setorig=1 ses=0
15:03:07 3742138904mS CMTARGET: 0.1468040.0 389249 2630.0: ADD VM TARGET
15:03:07 3742138904mS CMTARGET: **** 0.1468040.0 389249 2630.0: MakeVoicemailTarget pbx=<null> local=1 type=1
15:03:07 3742138904mS CMCallEvt: 0.1468042.0 -1 BaseEP: NEW CMEndpoint f4dcc464 TOTAL NOW=3 CALL_LIST=1
15:03:07 3742138905mS CMTARGET: 0.1468042.0 389249 RAS.0: ADD PRIMARY
15:03:07 3742138905mS CMTARGET: 0.1468040.0 389249 2630.0: ADD VM TARGET: SUCCEEDED
15:03:07 3742138905mS CMTARGET: 0.1468040.0 389249 2630.0: CancelTimer CMTCDelayedProcessing
15:03:07 3742138905mS CMTARGET: 0.1468040.0 389249 2630.0: INITIAL TARGETING SUCCEEDED
15:03:07 3742138905mS CMTARGET: 0.1468040.0 389249 2630.0: GetNoAnswerTimer:31
15:03:07 3742138905mS CMCallEvt: 0.1468040.0 389249 2630.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
15:03:07 3742138906mS CMExtnTx: v=2630, p1=0
CMSetupAck
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
BChan: slot=20 chan=14
Timed: 12/12/19 15:03
15:03:07 3742138906mS CMCallEvt: 0.1468041.0 389249 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
15:03:07 3742138907mS CMCallEvt: 0.1468042.0 389249 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering
15:03:07 3742138907mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1468042 )
15:03:07 3742138907mS CMExtnTx: v=RAS, p1=0
CMSetup
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[?ELA Ed] Type=Voicemail (102) Reason=CMDRX_MailboxAccess Called SubAddress[oink] Calling[2630] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=42
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=2630
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=2630
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=2630
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=2630
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2630
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=30 channel=0 rx_gain=32 tx_gain=32 ep_callid=1468040 ipaddr=192.168.1.50 apps=0 loc=0 em_loc=1
IE CMIEMohSourceId (247) MOH Source = 255
Display [2630>?ELA Ed]
Timed: 12/12/19 15:03
Locale: enu
15:03:07 3742138908mS CMMap: a=21.42 b=1.254 T
15:03:07 3742138910mS CMExtnRx: v=RAS, p1=0
CMConnect
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=?ELA Ed
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=Voicemail
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1468042 ipaddr=192.168.1.50 apps=0 loc=0 em_loc=0
15:03:07 3742138910mS CMCallEvt: 0.1468042.0 389249 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq
15:03:07 3742138910mS CMCallEvt: 0.1468041.0 389249 TargetingEP: RequestEnd 0.1468042.0 389249 RAS.0
15:03:07 3742138910mS CMTARGET: 0.1468040.0 389249 2630.0: CancelTimer CMTCNoAnswerTimeout
15:03:07 3742138911mS CMExtnEvt: v=1011 State, new=Connected old=Idle,0,0,RAS
15:03:07 3742138911mS CMCallEvt: 0.1468040.0 389249 2630.0: StateChange: END=A CMCSDialling->CMCSOGConnReq
15:03:07 3742138911mS CMExtnEvt: v=6 State, new=Connected old=Dialling,0,0,2630
15:03:07 3742138912mS CMExtnTx: v=2630, p1=0
CMConnect
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=?ELA Ed
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=Voicemail
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1468042 ipaddr=192.168.1.50 apps=0 loc=0 em_loc=0
Timed: 12/12/19 15:03
15:03:07 3742138912mS CMExtnRx: v=2630, p1=0
CMConnectAck
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
15:03:07 3742138912mS CMCallEvt: 0.1468040.0 389249 2630.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
15:03:07 3742138913mS CMTARGET: 0.1468040.0 389249 2630.0: ~CMTargetHandler f4c6d600 ep f4f136bc
15:03:07 3742138914mS CMCallEvt: 0.1468042.0 389249 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected
15:03:07 3742138914mS CMExtnTx: v=RAS, p1=0
CMConnectAck
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=2630
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=2630
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2630
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=30 channel=0 rx_gain=32 tx_gain=32 ep_callid=1468040 ipaddr=192.168.1.50 apps=0 loc=0 em_loc=1
15:03:07 3742138915mS VMAIL: SESS 16568: CMD=1 Mailbox=ELA Ed Access=9 !Internal!=Y
15:03:07 3742138915mS VMAIL: VMAIL Open [VMMESSAGE_OPEN] info :-
15:03:07 3742138915mS VMAIL: Flags :- 65 6e 75 00 00 05 f0 81
15:03:07 3742138915mS VMAIL: 00 00 00 66 01 00 00 00
15:03:07 3742138915mS VMAIL: Mailbox: ELA Ed Access: 9 !Internal!=Y Locale: enu
15:03:07 3742138915mS VMAIL: Calling Party number: 2630 Display String: 2630>?ELA Ed
15:03:07 3742138915mS VMAIL: Greeting Modifier:
15:03:07 3742138915mS VMAIL: Targeted Party number: ELA Ed Called Party number: ELA Ed
15:03:07 3742138915mS VMAIL: Calling Party name: 2630 Called Party name:
15:03:07 3742138915mS VMAIL: DID number QUEUE: CallAge=0 QueueAge=0 QPos=0 QEta=0 AnnouncmentSync=0
15:03:07 3742138915mS VMAIL: Recording Originator: IP addr. of Recording Originator: 0.0.0.0
15:03:07 3742138915mS VMAIL: Targeted Party Name:
15:03:07 3742138915mS VMAIL: Recording Type: Auto Recording Incoming HuntGroup
15:03:07 3742138915mS VMAIL: Answering Party Number: Answering Party Name:
15:03:07 3742138915mS VMAIL: Targeted Party Offset: 00
15:03:07 3742138915mS VMAIL: Compression Format: input[00] output[00]
15:03:07 3742138915mS VMAIL: Validated Recording: No
15:03:07 3742138916mS VMAIL: UTC Date:
15:03:07 3742138916mS VMAIL: UTC Time:
15:03:07 3742138916mS VMAIL: SESS 16568: CMD=9 Mailbox=ELA Ed Access=9 !Internal!=Y
15:03:07 3742138916mS VMAIL: VMAIL Open [VMMESSAGE_ACTIVE] info :-
15:03:07 3742138916mS VMAIL: Flags :- 65 6e 75 00 00 05 f0 81
15:03:07 3742138916mS VMAIL: 00 00 00 66 01 80 00 00
15:03:07 3742138916mS VMAIL: Mailbox: ELA Ed Access: 9 !Internal!=Y Locale: enu
15:03:07 3742138916mS VMAIL: Calling Party number: 2630 Display String: 2630>?ELA Ed
15:03:07 3742138916mS VMAIL: Greeting Modifier:
15:03:07 3742138916mS VMAIL: Targeted Party number: ELA Ed Called Party number: ELA Ed
15:03:07 3742138917mS VMAIL: Calling Party name: 2630 Called Party name:
15:03:07 3742138917mS VMAIL: DID number QUEUE: CallAge=0 QueueAge=0 QPos=0 QEta=0 AnnouncmentSync=0
15:03:07 3742138917mS VMAIL: Recording Originator: IP addr. of Recording Originator: 0.0.0.0
15:03:07 3742138917mS VMAIL: Targeted Party Name:
15:03:07 3742138917mS VMAIL: Recording Type: Auto Recording Incoming HuntGroup
15:03:07 3742138917mS VMAIL: Answering Party Number: Answering Party Name:
15:03:07 3742138917mS VMAIL: Targeted Party Offset: 00
15:03:07 3742138917mS VMAIL: Compression Format: input[00] output[00]
15:03:07 3742138917mS VMAIL: Validated Recording: No
15:03:07 3742138917mS VMAIL: UTC Date:
15:03:07 3742138917mS VMAIL: UTC Time:
15:03:07 3742138918mS CMCallEvt: 0.1468041.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
15:03:07 3742138918mS CMCallEvt: 0.1468041.0 -1 BaseEP: DELETE CMEndpoint f4f176ac TOTAL NOW=2 CALL_LIST=1
15:03:07 3742138918mS CD: CALL: 0.1468040.0 BState=Connected Cut=3 Music=0.0 Aend="2630(2630)" (20.14) Bend="?ELA Ed(Voicemail)" [VoiceMail] (21.42) CalledNum=?ELA Ed () CallingNum=2630 (2630) Internal=1 Time=18 AState=Connected
15:03:07 3742138919mS CD2: CALL:S 0.1468040.0,0.1468041.0,2,2,1,0,1,0,2630(2630),RAS,,2.6,21.42,100.102,?ELA Ed,100.101,2630,oink,,102,?ELA Ed,100,,0,16,0,0,0.0,,,,,,,1,19,5,0,0,0,enu,,0,,0,0,0,0,,389249,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,
15:03:07 3742138920mS CMMap: PCG::MapBChan pcp[135]b1r0 cp_b f4e76c04 other_cp_b 0 type CGTypeSimple
15:03:07 3742138921mS CMMap: PCG::MapBChan pcp[12]b1r0 cp_b f57d1d74 other_cp_b f4e76c04 type CGTypeSimple
15:03:07 3742138921mS CMMap: a=20.14 b=21.42 M12
15:03:07 3742138934mS CMExtnRx: v=RAS, p1=0
CMVoiceMailMsg
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[Summary] Type=Default (100) Reason=CMDRdirect Calling[0,4,0] Type=Default Plan=Default
Display [ELA Ed]
15:03:07 3742138934mS CMExtnTx: v=2630, p1=0
CMVoiceMailMsg
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
Called[Summary] Type=Default (100) Reason=CMDRdirect Calling[0,4,0] Type=Default Plan=Default
Display [ELA Ed]
Timed: 12/12/19 15:03
15:03:08 3742139228mS RES: Thu 12/12/2019 15:03:07 FreeMem=52746952 50997828(1) CachedMem=1749124 CMMsg=9(9) Buff=5200 1354 999 7399 3 Links=436472 BTree=13201 CPU=39.70% CPUStats=21/29/3152/8580/20337/0/0 MCR=0 MCW=0
15:03:08 3742139228mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=61 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=34(TLS=6) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:03:08 3742139228mS RES4: XML MemObjs=110 PoolMem=2097152(1) FreeMem=2081284(1)
15:03:08 3742139901mS CD: CALLSYNC: cs02

********** SysMonitor v9.0.0.0 build 829 [connected to 192.168.1.50 ] **********
15:03:10 3742141121mS PRN: Monitor Status IP 500 V2 9.0.0.0 build 829
15:03:10 3742141121mS PRN: LAW=U PRI=2, BRI=0, ALOG=0, VCOMP=0, MDM=0, WAN=0, MODU=1 LANM=0 CkSRC=13 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=1(TOT=389249)
15:03:10 3742141646mS CD: CALLSYNC: cs02
15:03:13 3742144655mS CD: CALLSYNC: cs02
15:03:13 3742144917mS CD: CALLSYNC: cs02
15:03:16 3742147611mS CMExtnRx: v=2630, p1=0
CMReleaseComp
Line: type=DigitalExtn 3 Call: lid=0 id=1468040 in=0
15:03:16 3742147611mS CMCallEvt: 0.1468040.0 389249 2630.0: StateChange: END=A CMCSConnected->CMCSCompleted
15:03:16 3742147612mS CMExtnEvt: v=6 State, new=PortRecoverDelay old=Connected,0,0,2630
15:03:16 3742147613mS CMLOGGING: CALL:2019/12/1215:03,00:00:08,000,2630,O,?ELAEd,?ELAEd,2630,,,1,,""n/a,0
15:03:16 3742147614mS CD: CALL: 0.1468040.0 BState=Connected Cut=2 Music=0.0 Aend="2630(2630)" (20.14) Bend="?ELA Ed(Voicemail)" [VoiceMail] (21.42) CalledNum=?ELA Ed () CallingNum=2630 (2630) Internal=1 Time=8714 AState=Idle
15:03:16 3742147614mS CD2: CALL:S 0.1468040.0,0.1468041.0,0,2,0,0,1,0,2630(2630),RAS,,2.6,21.42,100.102,?ELA Ed,100.101,2630,oink,,102,?ELA Ed,100,,0,16,0,0,0.0,,,,,,,1,8714,0,0,8699,0,enu,,0,,0,0,0,0,,389249,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,
15:03:16 3742147614mS CD: CALL: 0.1468040.0 Deleted
15:03:16 3742147614mS CD2: CALL 0.1468040.0,0.1468041.0,389249,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,
15:03:16 3742147615mS CMExtnEvt: 2630: CALL LOST (CMCauseNormal)
15:03:16 3742147615mS CMExtnEvt: 2630: Extn(2630) Calling Party Number(2630) Type(CMNTypeInternal)
15:03:16 3742147615mS CMExtnEvt: 2630: CMExtnHandler::SetCurrent( id: 1468040->0 )
15:03:16 3742147616mS CMCallEvt: 0.1468040.0 -1 2630.-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:03:16 3742147618mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
15:03:16 3742147618mS CMCallEvt: 0.1468042.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted
15:03:16 3742147618mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
15:03:16 3742147618mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[?ELA Ed] Type=Voicemail (102) Reason=CMDRX_MailboxAccess Calling[2630] Type=Internal Plan=Default
BChan: slot=21 chan=42
Cause=16, Normal call clearing
15:03:16 3742147618mS VMAIL: SESS 16568: CMD=2 Mailbox=ELA Ed Access=9 !Internal!=Y
15:03:16 3742147618mS VMAIL: VMAIL Open [VMMESSAGE_CLOSE] info :-
15:03:16 3742147619mS VMAIL: Flags :- 65 6e 75 00 00 05 f0 81
15:03:16 3742147619mS VMAIL: 00 00 10 66 01 80 00 00
15:03:16 3742147619mS VMAIL: Mailbox: ELA Ed Access: 9 !Internal!=Y Locale: enu
15:03:16 3742147619mS VMAIL: Calling Party number: 2630 Display String: 2630>?ELA Ed
15:03:16 3742147619mS VMAIL: Greeting Modifier:
15:03:16 3742147619mS VMAIL: Targeted Party number: ELA Ed Called Party number: ELA Ed
15:03:16 3742147619mS VMAIL: Calling Party name: 2630 Called Party name:
15:03:16 3742147619mS VMAIL: DID number QUEUE: CallAge=0 QueueAge=0 QPos=0 QEta=0 AnnouncmentSync=0
15:03:16 3742147619mS VMAIL: Recording Originator: IP addr. of Recording Originator: 0.0.0.0
15:03:16 3742147619mS VMAIL: Targeted Party Name:
15:03:16 3742147619mS VMAIL: Recording Type: Auto Recording Incoming HuntGroup
15:03:16 3742147619mS VMAIL: Answering Party Number: Answering Party Name:
15:03:16 3742147619mS VMAIL: Targeted Party Offset: 00
15:03:16 3742147619mS VMAIL: Compression Format: input[00] output[00]
15:03:16 3742147619mS VMAIL: Validated Recording: No
15:03:16 3742147619mS VMAIL: UTC Date:
15:03:16 3742147619mS VMAIL: UTC Time:
15:03:16 3742147620mS VMAIL: SESS 16568: END Transmit=69 Discards=0 Recv=0 SeqErrs=0 Empty=0 Purges=0
15:03:16 3742147620mS CMMap: a=21.42 b=0.0 T0
15:03:16 3742147622mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1468042->0 )
15:03:16 3742147622mS CMCallEvt: 0.1468042.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:03:16 3742147622mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
15:03:16 3742147622mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
Cause=16, Normal call clearing
15:03:16 3742147622mS CMCallEvt: 0.1468042.0 -1 BaseEP: DELETE CMEndpoint f4dcc464 TOTAL NOW=1 CALL_LIST=0
15:03:16 3742147623mS CMCallEvt: END CALL:389249 (f4ec4408)
15:03:16 3742147623mS CMCallEvt: 0.1468040.0 -1 BaseEP: DELETE CMEndpoint f4f136bc TOTAL NOW=0 CALL_LIST=0
15:03:16 3742147626mS CMMap: PCG::UnmapBChan pcp[12]b1r0 cp_b f57d1d74 other_cp_b f4e76c04
15:03:16 3742147626mS CMMap: a=20.14 b=21.42 M02
15:03:16 3742147626mS CMMap: PCG::UnmapBChan pcp[135]b1r0 cp_b f4e76c04 other_cp_b 0
15:03:16 3742147635mS VMAIL: ELA Ed,2,0,4,0
15:03:16 3742147660mS RES: Thu 12/12/2019 15:03:16 FreeMem=52772276 50997828(1) CachedMem=1774448 CMMsg=9(9) Buff=5200 1355 999 7399 3 Links=436490 BTree=13202 CPU=34.05% CPUStats=1/6/3152/9247/20337/0/0 MCR=0 MCW=0
15:03:16 3742147660mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=63 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=34(TLS=6) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:03:16 3742147660mS RES4: XML MemObjs=110 PoolMem=2097152(1) FreeMem=2081284(1)
15:03:16 3742147681mS CD: CALLSYNC: cs02
15:03:18 3742149616mS CMExtnEvt: 2630: Recover Timer reason=CMTRWrapUp
15:03:18 3742149616mS CMExtnEvt: v=6 State, new=Idle old=PortRecoverDelay,0,0,2630
15:03:18 3742149617mS CMExtnTx: v=2630, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 3 Call: lid=0 id=-1 in=0
Called[2630 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [2630 Msgs=0]
Timed: 12/12/19 15:03
15:03:18 3742149930mS CD: CALLSYNC: cs02
15:03:19 3742150704mS CD: CALLSYNC: cs02
15:03:22 3742153727mS CD: CALLSYNC: cs02
15:03:23 3742154979mS CD: CALLSYNC: cs02
15:03:25 3742156743mS CD: CALLSYNC: cs02

********** Warning: Logging to Screen Stopped **********

--DB

critchey · Dec 12, 2019

9.0.0 is a horrendous release I would start with upgrading. I would think you could upgrade to R9.0.12(but obviously be sure).

How are you trying different 9508 firmware on the same release?

The truth is just an excuse for lack of imagination.

DBrewsky · Dec 13, 2019

We had another tech on site about a month ago who installed these phones. I downloaded the latest firmware from his laptop thinking that was why the phone was stuck in the Firmware update. The firmware took, and then yesterday I resolved the TFTP issue and used the VM Pro PC which downloaded the installed firmware version.

Does anything stick out in the monitor trace? Which filters do you think I should use?

--DB

critchey · Dec 13, 2019

9508 phones should be grabbing firmware from the system itself not tftp. The phones should run firmware that comes with that release and your release is horrendous and should be upgraded. Until you do these things there is not much else to say sorry.

The truth is just an excuse for lack of imagination.

critchey · Dec 13, 2019

Just to be clear I did look through the trace and do not see anything in there. Since you don't see anything in monitor, and you are running a VERY BAD release, my suggestion is to upgrade your release to the highest service pack which would be R9.0.12. You should also set your system to serve files by memory card which will get your phones on the right firmware based on that release. Once you do all that retest this issue and see if it is resolved. That would be my suggestion.

The truth is just an excuse for lack of imagination.

Tek-Tips is the largest IT community on the Internet today!

Members share and learn making Tek-Tips Forums the best source of peer-reviewed technical information on the Internet!

Yet another 9508 Issue..

DBrewsky

Vendor

critchey

IS-IT--Management

DBrewsky

Vendor

critchey

IS-IT--Management

critchey

IS-IT--Management

Similar threads

Part and Inventory Search

Sponsor