Hello All,
Heres whatI have IP500 V2 8.1 (69) with 4 Comcast phone line trunks. This system was transferred to a new office and a random line will connect and say incoming with no caller ID. The random line will keep getting this incoming every 17 seconds then repeat in a second and is connecting to our auto-attendant. If someone at the site physically disconnects the line from the Comcast box it will stop for a bit and then resume on another random line sometimes two or three. Comcast came out and said it was internal and said they were getting info from there end that was the equivalent of someone picking up but not calling out. Below is the log with Line 1 and 4 misbehaving. Thanks
10:27:21 431620995mS H323Evt: Recv: RegistrationRequest 10.0.8.144; Endpoints registered: 4; Endpoints in registration: 0
10:27:22 431621547mS CMLineRx: v=4
CMReleaseComp
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Cause=16, Normal call clearing
10:27:22 431621547mS CMCallEvt: 4.5.1 35690 Alog Trunk:4: StateChange: END=A CMCSConnected->CMCSCompleted
10:27:22 431621549mS CMLOGGING: CALL:2019/03/0410:27,00:00:17,000,ð,I,3199,,,,,0,,""n/a,0
10:27:22 431621549mS CD: CALL: 4.5.1 BState=Connected Cut=2 Music=0.0 Aend="Line 4" (1.4) Bend="AA USER(3199)" [VoiceMail] (21.43) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=17517 AState=Idle
10:27:22 431621549mS CD: CALL: 4.5.1 Deleted
10:27:22 431621550mS CMCallEvt: 4.5.1 -1 Alog Trunk:4: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:22 431621551mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
10:27:22 431621551mS CMCallEvt: 0.107997.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted
10:27:22 431621551mS CMExtnEvt: v=1013 State, new=PortRecoverDelay old=Connected,0,0,RAS
10:27:22 431621551mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BChan: slot=21 chan=43
Cause=16, Normal call clearing
10:27:22 431621552mS CMMap: a=21.43 b=0.0 T0
10:27:22 431621553mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 107997->0 )
10:27:22 431621553mS CMCallEvt: 0.107997.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:22 431621553mS CMExtnEvt: v=1013 State, new=Idle old=PortRecoverDelay,0,0,RAS
10:27:22 431621553mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
BChan: slot=21 chan=43
Cause=16, Normal call clearing
10:27:22 431621553mS CMCallEvt: 0.107997.0 -1 BaseEP: DELETE CMEndpoint f5139938 TOTAL NOW=3 CALL_LIST=1
10:27:22 431621553mS CMCallEvt: END CALL:35690 (f50f2fd0)
10:27:22 431621554mS CMCallEvt: 4.5.1 -1 BaseEP: DELETE CMEndpoint f50d7bc8 TOTAL NOW=2 CALL_LIST=1
10:27:22 431621556mS CMMap: a=1.4 b=21.43 CheckSpeechPathMonitor (pcp[34]b1r0) unregister
10:27:22 431621556mS PRN: Confer DSP: disabled DTMF detector 1
10:27:22 431621556mS PRN: Confer DSP channel 1: freed DTMF detector 1, 23 free
10:27:22 431621556mS CMMap: PCG::UnmapBChan pcp[34]b1r0 cp_b f5921ed0 other_cp_b f5900d30
10:27:22 431621556mS CMMap: a=1.4 b=21.43 M02
10:27:22 431621557mS CMMap: PCG::UnmapBChan pcp[81]b1r0 cp_b f5900d30 other_cp_b 0
10:27:22 431621566mS H323Evt: Recv: RegistrationRequest 10.0.8.145; Endpoints registered: 4; Endpoints in registration: 0
10:27:22 431621818mS RES: Mon 4/3/2019 10:27:22 FreeMem=59364876 58517004(1) CachedMem=847872 CMMsg=9(11) Buff=5200 1321 996 12462 5 Links=11938 BTree=0 CPU=1/6/2063/14134/24673/1
10:27:22 431621818mS RES2: IP 500 V2 8.1(69) Tasks=49 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=57 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=35 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:27:22 431621818mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
10:27:25 431624385mS CMCallEvt: 0.108001.0 -1 BaseEP: NEW CMEndpoint f50d7bc8 TOTAL NOW=3 CALL_LIST=1
10:27:25 431624385mS CMCallEvt: CREATE CALL:35692 (f50f2fd0)
10:27:25 431624386mS CMCallEvt: 0.108002.0 -1 BaseEP: NEW CMEndpoint f511eb58 TOTAL NOW=4 CALL_LIST=1
10:27:25 431624389mS CMLineRx: v=4
CMSetup
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
Called[] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=1 chan=4
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 132/198/19 50:142
10:27:25 431624390mS CD: CALL: 4.5.1 BState=Idle Cut=1 Music=0.0 Aend="Line 4" (1.4) Bend="" [] (0.0) CalledNum= () CallingNum=ð () Internal=0 Time=4 AState=Idle
10:27:25 431624390mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: LOOKUP CALL ROUTE: type=0 called_party= sub= calling=ð dir=in complete=1 ses=0
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SET BESTMATCH: length 0 vs -1 match= dest=3198
10:27:25 431624390mS CMCallEvt: Priority hike: call 35692 priority 0->1
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: LOOKUP ICR: DDI=4540359 CGPN=ð Matched Time profile: OpenHrs (Destination 3199 ) => CDPN=3199
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD TARGET (N): number=3199 type=0 depth=1 nobar=1 setorig=1 ses=0
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SET USER: AA USER orig=1
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD USER: AA USER depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeUnknown) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0)
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD TARGET (N): number=710 type=100 depth=2 nobar=1 setorig=0 ses=0
10:27:25 431624392mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SYS SC: 710 3 sc=type=AutoAttendant code=710, num="AA:MainAA" callinfop->sending_complete=1 secondary_dialtone=
10:27:25 431624392mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD VM TARGET
10:27:25 431624392mS CMTARGET: **** 4.5.1 35692 Alog Trunk:4: MakeVoicemailTarget pbx=<null> local=1 type=3
10:27:25 431624393mS CMCallEvt: 0.108003.0 -1 BaseEP: NEW CMEndpoint f5139938 TOTAL NOW=5 CALL_LIST=2
10:27:25 431624393mS CMTARGET: 0.108003.0 35692 RAS.0: ADD PRIMARY
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD VM TARGET: SUCCEEDED
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: INITIAL TARGETING SUCCEEDED
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: GetNoAnswerTimer:20
10:27:25 431624394mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSDialInitiated->CMCSDialled
10:27:25 431624394mS CMLineTx: v=4
CMProceeding
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
10:27:25 431624395mS CMCallEvt: 0.108002.0 35692 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:27:25 431624395mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering
10:27:25 431624395mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->108003 )
10:27:25 431624396mS CMExtnTx: v=RAS, p1=0
CMSetup
Line: type=RAS 1 Call: lid=0 id=1012 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant SndComp Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=11
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=AA USER
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=AA USER
IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:1) number=3199
IE CMIEOriginalCalledPartyName (236)(Type=CMNameDefault) name=AA USER
IE CMIEOriginalCalledPartyNumber (238)(P:100 S:100 T:101 N:100 R:1) number=3199
IE CMIEIcrPriorityDetail (239) Priority = 1
IE CMIEDIDNumber (245)(P:100 S:100 T:100 N:100 R:4) number=4540359
IE CMIEMohSourceId (247) MOH Source = 1
Display [ð >AA USER]
Timed: 132/198/19 50:142
Locale: enu
10:27:25 431624396mS CMMap: a=21.11 b=1.254 T
10:27:25 431624400mS CMExtnRx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1012 in=0
10:27:25 431624401mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq
10:27:25 431624401mS CMCallEvt: 0.108002.0 35692 TargetingEP: RequestEnd 0.108003.0 35692 RAS.0
10:27:25 431624401mS CMTARGET: 4.5.1 35692 Alog Trunk:4: CancelTimer CMTCCoverageTimeout
10:27:25 431624401mS CMCallEvt: 0.108002.0 -1 BaseEP: DELETE CMEndpoint f511eb58 TOTAL NOW=4 CALL_LIST=2
10:27:25 431624402mS CMExtnEvt: v=1012 State, new=Connected old=Idle,0,0,RAS
10:27:25 431624402mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSDialled->CMCSOGConnReq
10:27:25 431624403mS CMLineTx: v=4
CMConnect
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=21 chan=11
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=#AA:MainAA
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=#AA:MainAA
IE CMIEDeviceDetail (231) c0a82a010001a5e3 LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=11 features=0x0 rx_gain=32 tx_gain=32 ep_callid=108003 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=AA USER
IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:1) number=3199
10:27:25 431624403mS CMLineRx: v=4
CMConnectAck
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
10:27:25 431624403mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSOGConnReq->CMCSConnected
10:27:25 431624403mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ~CMTargetHandler f50b0810 ep f50d7bc8
10:27:25 431624404mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected
10:27:25 431624405mS CMExtnTx: v=RAS, p1=0
CMConnectAck
Line: type=RAS 1 Call: lid=0 id=1012 in=0
BChan: slot=21 chan=11
10:27:25 431624407mS CMMap: PCG::MapBChan pcp[81]b1r0 cp_b f5900d30 other_cp_b 0 type CGTypeSimple
10:27:25 431624407mS CMMap: PCG::MapBChan pcp[33]b1r0 cp_b f5922778 other_cp_b f5900d30 type CGTypeSimple
10:27:25 431624408mS CMMap: a=1.4 b=21.11 M12
10:27:25 431624408mS CMMap: a=1.4 b=21.11 CheckSpeechPathMonitor (pcp[33]b1r0) register
10:27:25 431624408mS PRN: Confer DSP, channel 1: allocated DTMF detector 1, 22 free
10:27:25 431624408mS PRN: Confer DSP: enabled DTMF detector 1
10:27:25 431624442mS CD: CALL: 4.5.1 BState=Connected Cut=3 Music=0.0 Aend="Line 4" (1.4) Bend="AA USER(3199)" [VoiceMail] (21.11) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=57 AState=Connected
10:27:25 431624444mS CMLineRx: v=4
CMConnectAck
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
10:27:26 431625944mS CMLineRx: v=1
CMReleaseComp
Line: type=AnalogueLine 1 Call: lid=1 id=2 in=1
BChan: slot=1 chan=1
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000002 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=1 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=2 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Cause=16, Normal call clearing
10:27:26 431625944mS CMCallEvt: 1.2.1 35691 Alog Trunk:1: StateChange: END=A CMCSConnected->CMCSCompleted
10:27:26 431625946mS CMLOGGING: CALL:2019/03/0410:27,00:00:17,000,ð,I,3199,,,,,0,,""n/a,0
10:27:26 431625946mS CD: CALL: 1.2.1 BState=Connected Cut=2 Music=0.0 Aend="Line 1" (1.1) Bend="AA USER(3199)" [VoiceMail] (21.42) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=17513 AState=Idle
10:27:26 431625946mS CD: CALL: 1.2.1 Deleted
10:27:26 431625947mS CMCallEvt: 1.2.1 -1 Alog Trunk:1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:26 431625948mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
10:27:26 431625948mS CMCallEvt: 0.108000.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted
10:27:26 431625948mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
10:27:26 431625948mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BChan: slot=21 chan=42
Cause=16, Normal call clearing
10:27:26 431625948mS CMMap: a=21.42 b=0.0 T0
10:27:26 431625950mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 108000->0 )
10:27:26 431625950mS CMCallEvt: 0.108000.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:26 431625950mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
10:27:26 431625950mS 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
10:27:26 431625950mS CMCallEvt: 0.108000.0 -1 BaseEP: DELETE CMEndpoint f5112328 TOTAL NOW=3 CALL_LIST=1
10:27:26 431625951mS CMCallEvt: END CALL:35691 (f513bd88)
10:27:26 431625951mS CMCallEvt: 1.2.1 -1 BaseEP: DELETE CMEndpoint f507b788 TOTAL NOW=2 CALL_LIST=1
10:27:26 431625953mS CMMap: a=1.1 b=21.42 CheckSpeechPathMonitor (pcp[32]b1r0) unregister
10:27:26 431625953mS PRN: Confer DSP: disabled DTMF detector 0
10:27:26 431625953mS PRN: Confer DSP channel 0: freed DTMF detector 0, 23 free
10:27:26 431625953mS CMMap: PCG::UnmapBChan pcp[32]b1r0 cp_b f5923020 other_cp_b f5905b88
10:27:26 431625954mS CMMap: a=1.1 b=21.42 M02
10:27:26 431625954mS CMMap: PCG::UnmapBChan pcp[77]b1r0 cp_b f5905b88 other_cp_b 0
Heres whatI have IP500 V2 8.1 (69) with 4 Comcast phone line trunks. This system was transferred to a new office and a random line will connect and say incoming with no caller ID. The random line will keep getting this incoming every 17 seconds then repeat in a second and is connecting to our auto-attendant. If someone at the site physically disconnects the line from the Comcast box it will stop for a bit and then resume on another random line sometimes two or three. Comcast came out and said it was internal and said they were getting info from there end that was the equivalent of someone picking up but not calling out. Below is the log with Line 1 and 4 misbehaving. Thanks
10:27:21 431620995mS H323Evt: Recv: RegistrationRequest 10.0.8.144; Endpoints registered: 4; Endpoints in registration: 0
10:27:22 431621547mS CMLineRx: v=4
CMReleaseComp
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Cause=16, Normal call clearing
10:27:22 431621547mS CMCallEvt: 4.5.1 35690 Alog Trunk:4: StateChange: END=A CMCSConnected->CMCSCompleted
10:27:22 431621549mS CMLOGGING: CALL:2019/03/0410:27,00:00:17,000,ð,I,3199,,,,,0,,""n/a,0
10:27:22 431621549mS CD: CALL: 4.5.1 BState=Connected Cut=2 Music=0.0 Aend="Line 4" (1.4) Bend="AA USER(3199)" [VoiceMail] (21.43) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=17517 AState=Idle
10:27:22 431621549mS CD: CALL: 4.5.1 Deleted
10:27:22 431621550mS CMCallEvt: 4.5.1 -1 Alog Trunk:4: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:22 431621551mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
10:27:22 431621551mS CMCallEvt: 0.107997.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted
10:27:22 431621551mS CMExtnEvt: v=1013 State, new=PortRecoverDelay old=Connected,0,0,RAS
10:27:22 431621551mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BChan: slot=21 chan=43
Cause=16, Normal call clearing
10:27:22 431621552mS CMMap: a=21.43 b=0.0 T0
10:27:22 431621553mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 107997->0 )
10:27:22 431621553mS CMCallEvt: 0.107997.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:22 431621553mS CMExtnEvt: v=1013 State, new=Idle old=PortRecoverDelay,0,0,RAS
10:27:22 431621553mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
BChan: slot=21 chan=43
Cause=16, Normal call clearing
10:27:22 431621553mS CMCallEvt: 0.107997.0 -1 BaseEP: DELETE CMEndpoint f5139938 TOTAL NOW=3 CALL_LIST=1
10:27:22 431621553mS CMCallEvt: END CALL:35690 (f50f2fd0)
10:27:22 431621554mS CMCallEvt: 4.5.1 -1 BaseEP: DELETE CMEndpoint f50d7bc8 TOTAL NOW=2 CALL_LIST=1
10:27:22 431621556mS CMMap: a=1.4 b=21.43 CheckSpeechPathMonitor (pcp[34]b1r0) unregister
10:27:22 431621556mS PRN: Confer DSP: disabled DTMF detector 1
10:27:22 431621556mS PRN: Confer DSP channel 1: freed DTMF detector 1, 23 free
10:27:22 431621556mS CMMap: PCG::UnmapBChan pcp[34]b1r0 cp_b f5921ed0 other_cp_b f5900d30
10:27:22 431621556mS CMMap: a=1.4 b=21.43 M02
10:27:22 431621557mS CMMap: PCG::UnmapBChan pcp[81]b1r0 cp_b f5900d30 other_cp_b 0
10:27:22 431621566mS H323Evt: Recv: RegistrationRequest 10.0.8.145; Endpoints registered: 4; Endpoints in registration: 0
10:27:22 431621818mS RES: Mon 4/3/2019 10:27:22 FreeMem=59364876 58517004(1) CachedMem=847872 CMMsg=9(11) Buff=5200 1321 996 12462 5 Links=11938 BTree=0 CPU=1/6/2063/14134/24673/1
10:27:22 431621818mS RES2: IP 500 V2 8.1(69) Tasks=49 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=57 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=35 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:27:22 431621818mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
10:27:25 431624385mS CMCallEvt: 0.108001.0 -1 BaseEP: NEW CMEndpoint f50d7bc8 TOTAL NOW=3 CALL_LIST=1
10:27:25 431624385mS CMCallEvt: CREATE CALL:35692 (f50f2fd0)
10:27:25 431624386mS CMCallEvt: 0.108002.0 -1 BaseEP: NEW CMEndpoint f511eb58 TOTAL NOW=4 CALL_LIST=1
10:27:25 431624389mS CMLineRx: v=4
CMSetup
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
Called[] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=1 chan=4
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 132/198/19 50:142
10:27:25 431624390mS CD: CALL: 4.5.1 BState=Idle Cut=1 Music=0.0 Aend="Line 4" (1.4) Bend="" [] (0.0) CalledNum= () CallingNum=ð () Internal=0 Time=4 AState=Idle
10:27:25 431624390mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: LOOKUP CALL ROUTE: type=0 called_party= sub= calling=ð dir=in complete=1 ses=0
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SET BESTMATCH: length 0 vs -1 match= dest=3198
10:27:25 431624390mS CMCallEvt: Priority hike: call 35692 priority 0->1
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: LOOKUP ICR: DDI=4540359 CGPN=ð Matched Time profile: OpenHrs (Destination 3199 ) => CDPN=3199
10:27:25 431624390mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD TARGET (N): number=3199 type=0 depth=1 nobar=1 setorig=1 ses=0
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SET USER: AA USER orig=1
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD USER: AA USER depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeUnknown) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0)
10:27:25 431624391mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD TARGET (N): number=710 type=100 depth=2 nobar=1 setorig=0 ses=0
10:27:25 431624392mS CMTARGET: 4.5.1 35692 Alog Trunk:4: SYS SC: 710 3 sc=type=AutoAttendant code=710, num="AA:MainAA" callinfop->sending_complete=1 secondary_dialtone=
10:27:25 431624392mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD VM TARGET
10:27:25 431624392mS CMTARGET: **** 4.5.1 35692 Alog Trunk:4: MakeVoicemailTarget pbx=<null> local=1 type=3
10:27:25 431624393mS CMCallEvt: 0.108003.0 -1 BaseEP: NEW CMEndpoint f5139938 TOTAL NOW=5 CALL_LIST=2
10:27:25 431624393mS CMTARGET: 0.108003.0 35692 RAS.0: ADD PRIMARY
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ADD VM TARGET: SUCCEEDED
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: INITIAL TARGETING SUCCEEDED
10:27:25 431624393mS CMTARGET: 4.5.1 35692 Alog Trunk:4: GetNoAnswerTimer:20
10:27:25 431624394mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSDialInitiated->CMCSDialled
10:27:25 431624394mS CMLineTx: v=4
CMProceeding
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
10:27:25 431624395mS CMCallEvt: 0.108002.0 35692 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:27:25 431624395mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering
10:27:25 431624395mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->108003 )
10:27:25 431624396mS CMExtnTx: v=RAS, p1=0
CMSetup
Line: type=RAS 1 Call: lid=0 id=1012 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant SndComp Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=11
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=AA USER
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=AA USER
IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:1) number=3199
IE CMIEOriginalCalledPartyName (236)(Type=CMNameDefault) name=AA USER
IE CMIEOriginalCalledPartyNumber (238)(P:100 S:100 T:101 N:100 R:1) number=3199
IE CMIEIcrPriorityDetail (239) Priority = 1
IE CMIEDIDNumber (245)(P:100 S:100 T:100 N:100 R:4) number=4540359
IE CMIEMohSourceId (247) MOH Source = 1
Display [ð >AA USER]
Timed: 132/198/19 50:142
Locale: enu
10:27:25 431624396mS CMMap: a=21.11 b=1.254 T
10:27:25 431624400mS CMExtnRx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1012 in=0
10:27:25 431624401mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq
10:27:25 431624401mS CMCallEvt: 0.108002.0 35692 TargetingEP: RequestEnd 0.108003.0 35692 RAS.0
10:27:25 431624401mS CMTARGET: 4.5.1 35692 Alog Trunk:4: CancelTimer CMTCCoverageTimeout
10:27:25 431624401mS CMCallEvt: 0.108002.0 -1 BaseEP: DELETE CMEndpoint f511eb58 TOTAL NOW=4 CALL_LIST=2
10:27:25 431624402mS CMExtnEvt: v=1012 State, new=Connected old=Idle,0,0,RAS
10:27:25 431624402mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSDialled->CMCSOGConnReq
10:27:25 431624403mS CMLineTx: v=4
CMConnect
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=21 chan=11
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=#AA:MainAA
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=#AA:MainAA
IE CMIEDeviceDetail (231) c0a82a010001a5e3 LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=11 features=0x0 rx_gain=32 tx_gain=32 ep_callid=108003 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=AA USER
IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:1) number=3199
10:27:25 431624403mS CMLineRx: v=4
CMConnectAck
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
10:27:25 431624403mS CMCallEvt: 4.5.1 35692 Alog Trunk:4: StateChange: END=A CMCSOGConnReq->CMCSConnected
10:27:25 431624403mS CMTARGET: 4.5.1 35692 Alog Trunk:4: ~CMTargetHandler f50b0810 ep f50d7bc8
10:27:25 431624404mS CMCallEvt: 0.108003.0 35692 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected
10:27:25 431624405mS CMExtnTx: v=RAS, p1=0
CMConnectAck
Line: type=RAS 1 Call: lid=0 id=1012 in=0
BChan: slot=21 chan=11
10:27:25 431624407mS CMMap: PCG::MapBChan pcp[81]b1r0 cp_b f5900d30 other_cp_b 0 type CGTypeSimple
10:27:25 431624407mS CMMap: PCG::MapBChan pcp[33]b1r0 cp_b f5922778 other_cp_b f5900d30 type CGTypeSimple
10:27:25 431624408mS CMMap: a=1.4 b=21.11 M12
10:27:25 431624408mS CMMap: a=1.4 b=21.11 CheckSpeechPathMonitor (pcp[33]b1r0) register
10:27:25 431624408mS PRN: Confer DSP, channel 1: allocated DTMF detector 1, 22 free
10:27:25 431624408mS PRN: Confer DSP: enabled DTMF detector 1
10:27:25 431624442mS CD: CALL: 4.5.1 BState=Connected Cut=3 Music=0.0 Aend="Line 4" (1.4) Bend="AA USER(3199)" [VoiceMail] (21.11) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=57 AState=Connected
10:27:25 431624444mS CMLineRx: v=4
CMConnectAck
Line: type=AnalogueLine 4 Call: lid=4 id=5 in=1
BChan: slot=1 chan=4
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000005 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=4 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=5 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
10:27:26 431625944mS CMLineRx: v=1
CMReleaseComp
Line: type=AnalogueLine 1 Call: lid=1 id=2 in=1
BChan: slot=1 chan=1
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:0 R:4) number=ð
IE CMIEDeviceDetail (231) c0a82a0100000002 LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=1 channel=0 features=0x21 rx_gain=32 tx_gain=32 ep_callid=2 ipaddr=192.168.42.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Cause=16, Normal call clearing
10:27:26 431625944mS CMCallEvt: 1.2.1 35691 Alog Trunk:1: StateChange: END=A CMCSConnected->CMCSCompleted
10:27:26 431625946mS CMLOGGING: CALL:2019/03/0410:27,00:00:17,000,ð,I,3199,,,,,0,,""n/a,0
10:27:26 431625946mS CD: CALL: 1.2.1 BState=Connected Cut=2 Music=0.0 Aend="Line 1" (1.1) Bend="AA USER(3199)" [VoiceMail] (21.42) CalledNum=#AA:MainAA (AA USER) CallingNum=ð () Internal=0 Time=17513 AState=Idle
10:27:26 431625946mS CD: CALL: 1.2.1 Deleted
10:27:26 431625947mS CMCallEvt: 1.2.1 -1 Alog Trunk:1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:26 431625948mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
10:27:26 431625948mS CMCallEvt: 0.108000.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted
10:27:26 431625948mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
10:27:26 431625948mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[#AA:MainAA] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[ð ] Type=Unknown Plan=Unknown Pres=Allowed (0)
BChan: slot=21 chan=42
Cause=16, Normal call clearing
10:27:26 431625948mS CMMap: a=21.42 b=0.0 T0
10:27:26 431625950mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 108000->0 )
10:27:26 431625950mS CMCallEvt: 0.108000.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:27:26 431625950mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
10:27:26 431625950mS 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
10:27:26 431625950mS CMCallEvt: 0.108000.0 -1 BaseEP: DELETE CMEndpoint f5112328 TOTAL NOW=3 CALL_LIST=1
10:27:26 431625951mS CMCallEvt: END CALL:35691 (f513bd88)
10:27:26 431625951mS CMCallEvt: 1.2.1 -1 BaseEP: DELETE CMEndpoint f507b788 TOTAL NOW=2 CALL_LIST=1
10:27:26 431625953mS CMMap: a=1.1 b=21.42 CheckSpeechPathMonitor (pcp[32]b1r0) unregister
10:27:26 431625953mS PRN: Confer DSP: disabled DTMF detector 0
10:27:26 431625953mS PRN: Confer DSP channel 0: freed DTMF detector 0, 23 free
10:27:26 431625953mS CMMap: PCG::UnmapBChan pcp[32]b1r0 cp_b f5923020 other_cp_b f5905b88
10:27:26 431625954mS CMMap: a=1.1 b=21.42 M02
10:27:26 431625954mS CMMap: PCG::UnmapBChan pcp[77]b1r0 cp_b f5905b88 other_cp_b 0