I have 2 IPO500's with 9.1 software, essential edition, IP500 Voice Networking 4 licenses and VCM 32's at each site.
I set up the SCN and it works perfectly... for 20 minutes. Then when I try to dial across the network, the line says unobtainable, it kicks me out of System Status and I can't log into manager, even though it sees it, I can, however, log in through the wan port. A simple reboot fixes the problem for another 20 minutes. It only seems to happen on one unit, the side I'm at. But I don't know if that's because no one is initiating a call from the other location. The other location, is does call over here on an overflow from a hunt group, so calls are theoretically being initiated.
Here's the monitor report:
16:20:57 1369962mS CD: CALL: 0.1086.0 BState=Idle Cut=1 Music=0.0 Aend="Downstairs Offi(206)" (0.21) Bend="Brian Smith(128)" [Line 17] (0.0) CalledNum=128 (Brian Smith) CallingNum=206 (Downstairs Offi) Internal=0 Time=1316 AState=Dialled
16:20:57 1369964mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
16:20:57 1369971mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1088
16:21:00 1372250mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1088
16:21:00 1372250mS H323Evt: Shared tcp socket for line 17 disconnected
16:21:00 1372250mS H323Evt: H323Pipe:
isconnectIndication cap H323Pipe(1)
16:21:00 1372250mS H323Evt: H323Pipe:
isconnectIndication cap CmMsg(2)
16:21:00 1372250mS H323Evt: H323Pipe:
isconnectIndication cap SipVideo(10)
16:21:00 1372250mS H323Evt: H323Pipe:
isconnectIndication cap SharedLicence(20)
16:21:00 1372250mS H323Evt: H323Pipe:
isconnectIndication cap ConfServer(40)
16:21:00 1372251mS H323Evt: H323Pipe:
isconnectIndication cap Presentation(80)
16:21:00 1372251mS H323Evt: H323Pipe:
isconnectIndication cap CameraControl(100)
16:21:00 1372251mS H323Evt: H323Pipe:
isconnectIndication cap CMMsgRelay(200)
16:21:00 1372251mS H323Evt: H323Pipe:
isconnectIndication cap Rfc2833(400)
16:21:00 1372251mS H323Evt: H323Pipe:
isconnectIndication cap ResponseToReInvite(800)
16:21:00 1372251mS H323Evt: H323 stack for line 17 is disconnected
16:21:00 1372253mS CMLineRx: v=17
CMReleaseComp
Line: type=IPLine 17 Call: lid=0 id=1088 in=0
Cause=38, Network out of order
16:21:00 1372253mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: Re-target after NetworkOOO - Try: Shortcode(128)
16:21:00 1372253mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: ADD TARGET (N): number=128 type=100 depth=1 nobar=1 setorig=1 ses=0
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: TARGET: Not in dial plan
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: CancelTimer CMTCNoAnswerTimeout
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: PrepareTransferTargets Found 0 target
16:21:00 1372254mS CMCallEvt: 0000000000000000 0.1087.0 19 TargetingEP: RequestEnd 0a010afe00000440 0.1088.0 19 H323TrunkEP
16:21:00 1372254mS CMCallEvt: 0000000000000000 0.1087.0 -1 BaseEP: DELETE CMEndpoint f17e05ec TOTAL NOW=2 CALL_LIST=1
16:21:00 1372255mS CMCallEvt: 0a010afe00000440 0.1088.0 19 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
16:21:00 1372257mS CMLOGGING: CALL:2016/11/2916:20,00:00:00,000,206,O,128,128,DownstairsOffi,,,0,,"",0,n/a
16:21:00 1372257mS CD: CALL: 0.1086.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Downstairs Offi(206)" (0.21) Bend="Brian Smith(128)" [Line 17] (267.1) CalledNum=128 (Brian Smith) CallingNum=206 (Downstairs Offi) Internal=0 Time=3611 AState=Dialled
16:21:00 1372257mS CD: CALL: 0.1086.0 Deleted
16:21:00 1372257mS CMExtnEvt: Downstairs Offi: CALL LOST (CMCauseNetworkOOO)
16:21:00 1372258mS CMExtnEvt: Downstairs Offi: Extn(206) Calling Party Number(206) Type(CMNTypeInternal)
16:21:00 1372258mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
16:21:00 1372258mS CMExtnEvt: v=6 State, new=CMESCompleted old=Proceeding,0,0,Downstairs Offi
16:21:00 1372259mS CMCallEvt: 0a010afe00000440 0.1088.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
16:21:00 1372259mS CMCallEvt: END CALL:19 (f17e1ef8)
16:21:00 1372261mS CMCallEvt: 0a010afe00000440 0.1088.0 -1 BaseEP: DELETE CMEndpoint f17c263c TOTAL NOW=1 CALL_LIST=0
16:21:00 1372262mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f53afdf8) resource busy 0, total 42
16:21:00 1372263mS CMMap: a=0.21 b=0.0 B2
16:21:00 1372513mS CMMap: a=0.21 b=0.0 B0
16:21:00 1372763mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373013mS CMMap: a=0.21 b=0.0 B0
16:21:01 1373263mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373513mS CMMap: a=0.21 b=0.0 B0
16:21:01 1373763mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373838mS CMExtnRx: v=206, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1086 in=0
16:21:01 1373838mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
16:21:01 1373838mS CMExtnEvt: v=6 State, new=PortRecoverDelay old=CMESCompleted,0,0,Downstairs Offi
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: CALL LOST (CMCauseForceClear)
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: Extn(206) Calling Party Number(206) Type(CMNTypeInternal)
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: CMExtnHandler::SetCurrent( id: 1086->0 )
16:21:01 1373839mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.-1: StateChange: END=X CMCSCompleted->CMCSDelete
16:21:01 1373840mS CMTARGET: 0a010afe0000043e 0.1086.0 -1 BaseEP: ~CMTargetHandler f17da29c ep f17cbd08
16:21:01 1373840mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 BaseEP: DELETE CMEndpoint f17cbd08 TOTAL NOW=0 CALL_LIST=0
16:21:01 1373842mS CMMap: a=0.21 b=0.0 B0
16:21:02 1374076mS RES: Tue 29/11/2016 16:21:02 FreeMem=52561740 Heap=52198068(0) Cache=363672 MemObjs=9607(10366) CMMsg=4(5) ASN=0 Buff=5200 1350 1000 7443 5 Links=52432(52813) BTree=499(1135) CPU=03.21% CPUStats=04.03%/3/7/4716/22693/23017/00.00%/0/
02.24% MCR=0 MCW=0
16:21:02 1374076mS RES2: IP 500 V2 9.1.7.0 build 163 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=59 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=18(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:21:02 1374077mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:21:02 1374077mS RES5: CLog MemObjs=29 FreePoolMem(Objs)=3692(71) TotalMem=85350
16:21:03 1375839mS CMExtnEvt: Downstairs Offi: Recover Timer reason=CMTRWrapUp
16:21:03 1375839mS CMExtnEvt: v=6 State, new=Idle old=PortRecoverDelay,0,0,Downstairs Offi
16:21:03 1375840mS CMExtnTx: v=206, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Downstairs Offi Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Downstairs Offi Msgs=0]
Timed: 29/11/16 16:21
Tech support said it might be a bug and I should downgrade to 9.1.6, but it's only happening on one side, so I wanted to check with the community first.
I set up the SCN and it works perfectly... for 20 minutes. Then when I try to dial across the network, the line says unobtainable, it kicks me out of System Status and I can't log into manager, even though it sees it, I can, however, log in through the wan port. A simple reboot fixes the problem for another 20 minutes. It only seems to happen on one unit, the side I'm at. But I don't know if that's because no one is initiating a call from the other location. The other location, is does call over here on an overflow from a hunt group, so calls are theoretically being initiated.
Here's the monitor report:
16:20:57 1369962mS CD: CALL: 0.1086.0 BState=Idle Cut=1 Music=0.0 Aend="Downstairs Offi(206)" (0.21) Bend="Brian Smith(128)" [Line 17] (0.0) CalledNum=128 (Brian Smith) CallingNum=206 (Downstairs Offi) Internal=0 Time=1316 AState=Dialled
16:20:57 1369964mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
16:20:57 1369971mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1088
16:21:00 1372250mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1088
16:21:00 1372250mS H323Evt: Shared tcp socket for line 17 disconnected
16:21:00 1372250mS H323Evt: H323Pipe:
16:21:00 1372250mS H323Evt: H323Pipe:
16:21:00 1372250mS H323Evt: H323Pipe:
16:21:00 1372250mS H323Evt: H323Pipe:
16:21:00 1372250mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323Pipe:
16:21:00 1372251mS H323Evt: H323 stack for line 17 is disconnected
16:21:00 1372253mS CMLineRx: v=17
CMReleaseComp
Line: type=IPLine 17 Call: lid=0 id=1088 in=0
Cause=38, Network out of order
16:21:00 1372253mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: Re-target after NetworkOOO - Try: Shortcode(128)
16:21:00 1372253mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: ADD TARGET (N): number=128 type=100 depth=1 nobar=1 setorig=1 ses=0
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: TARGET: Not in dial plan
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: CancelTimer CMTCNoAnswerTimeout
16:21:00 1372254mS CMTARGET: 0a010afe0000043e 0.1086.0 19 Downstairs Offi.0: PrepareTransferTargets Found 0 target
16:21:00 1372254mS CMCallEvt: 0000000000000000 0.1087.0 19 TargetingEP: RequestEnd 0a010afe00000440 0.1088.0 19 H323TrunkEP
16:21:00 1372254mS CMCallEvt: 0000000000000000 0.1087.0 -1 BaseEP: DELETE CMEndpoint f17e05ec TOTAL NOW=2 CALL_LIST=1
16:21:00 1372255mS CMCallEvt: 0a010afe00000440 0.1088.0 19 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
16:21:00 1372257mS CMLOGGING: CALL:2016/11/2916:20,00:00:00,000,206,O,128,128,DownstairsOffi,,,0,,"",0,n/a
16:21:00 1372257mS CD: CALL: 0.1086.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Downstairs Offi(206)" (0.21) Bend="Brian Smith(128)" [Line 17] (267.1) CalledNum=128 (Brian Smith) CallingNum=206 (Downstairs Offi) Internal=0 Time=3611 AState=Dialled
16:21:00 1372257mS CD: CALL: 0.1086.0 Deleted
16:21:00 1372257mS CMExtnEvt: Downstairs Offi: CALL LOST (CMCauseNetworkOOO)
16:21:00 1372258mS CMExtnEvt: Downstairs Offi: Extn(206) Calling Party Number(206) Type(CMNTypeInternal)
16:21:00 1372258mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
16:21:00 1372258mS CMExtnEvt: v=6 State, new=CMESCompleted old=Proceeding,0,0,Downstairs Offi
16:21:00 1372259mS CMCallEvt: 0a010afe00000440 0.1088.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
16:21:00 1372259mS CMCallEvt: END CALL:19 (f17e1ef8)
16:21:00 1372261mS CMCallEvt: 0a010afe00000440 0.1088.0 -1 BaseEP: DELETE CMEndpoint f17c263c TOTAL NOW=1 CALL_LIST=0
16:21:00 1372262mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f53afdf8) resource busy 0, total 42
16:21:00 1372263mS CMMap: a=0.21 b=0.0 B2
16:21:00 1372513mS CMMap: a=0.21 b=0.0 B0
16:21:00 1372763mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373013mS CMMap: a=0.21 b=0.0 B0
16:21:01 1373263mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373513mS CMMap: a=0.21 b=0.0 B0
16:21:01 1373763mS CMMap: a=0.21 b=0.0 B2
16:21:01 1373838mS CMExtnRx: v=206, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1086 in=0
16:21:01 1373838mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
16:21:01 1373838mS CMExtnEvt: v=6 State, new=PortRecoverDelay old=CMESCompleted,0,0,Downstairs Offi
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: CALL LOST (CMCauseForceClear)
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: Extn(206) Calling Party Number(206) Type(CMNTypeInternal)
16:21:01 1373839mS CMExtnEvt: Downstairs Offi: CMExtnHandler::SetCurrent( id: 1086->0 )
16:21:01 1373839mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 Downstairs Offi.-1: StateChange: END=X CMCSCompleted->CMCSDelete
16:21:01 1373840mS CMTARGET: 0a010afe0000043e 0.1086.0 -1 BaseEP: ~CMTargetHandler f17da29c ep f17cbd08
16:21:01 1373840mS CMCallEvt: 0a010afe0000043e 0.1086.0 -1 BaseEP: DELETE CMEndpoint f17cbd08 TOTAL NOW=0 CALL_LIST=0
16:21:01 1373842mS CMMap: a=0.21 b=0.0 B0
16:21:02 1374076mS RES: Tue 29/11/2016 16:21:02 FreeMem=52561740 Heap=52198068(0) Cache=363672 MemObjs=9607(10366) CMMsg=4(5) ASN=0 Buff=5200 1350 1000 7443 5 Links=52432(52813) BTree=499(1135) CPU=03.21% CPUStats=04.03%/3/7/4716/22693/23017/00.00%/0/
02.24% MCR=0 MCW=0
16:21:02 1374076mS RES2: IP 500 V2 9.1.7.0 build 163 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=59 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=18(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:21:02 1374077mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:21:02 1374077mS RES5: CLog MemObjs=29 FreePoolMem(Objs)=3692(71) TotalMem=85350
16:21:03 1375839mS CMExtnEvt: Downstairs Offi: Recover Timer reason=CMTRWrapUp
16:21:03 1375839mS CMExtnEvt: v=6 State, new=Idle old=PortRecoverDelay,0,0,Downstairs Offi
16:21:03 1375840mS CMExtnTx: v=206, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Downstairs Offi Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Downstairs Offi Msgs=0]
Timed: 29/11/16 16:21
Tech support said it might be a bug and I should downgrade to 9.1.6, but it's only happening on one side, so I wanted to check with the community first.