RodneyMcSnow
Technical User
Customer has an IPOffice 500V2 on Rel 9.0.3 firmware runiing sip trunks from Las Vegas to Chicago on an MPLS Circuit.
This has been an ongoing issue for the past few years that when a user calls out local, long distance or toll free they get disconnected within the first 15-30 seconds. I has been intermittent but Today has been almost every call.
This is a capture of what I am seeing: Anyone have any thoughts?
11:24:16 46992246mS PRN: Monitor Status IP 500 9.0.3.0 build 941
11:24:16 46992246mS PRN: LAW=U PRI=0, BRI=0, ALOG=4, VCOMP=64, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=0 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=1(TOT=229)
11:24:26 47002056mS CMExtnRx: v=6920, p1=0
CMReleaseComp
Line: type=DigitalExtn 6 Call: lid=0 id=1765 in=0
11:24:26 47002057mS CMCallEvt: 0.1765.0 229 Trish Zarlingo.0: StateChange: END=A CMCSRingBack->CMCSCompleted
11:24:26 47002058mS CMExtnEvt: v=21 State, new=PortRecoverDelay old=Alerting,0,0,Trish Zarlingo
11:24:26 47002059mS CMLOGGING: CALL:2014/06/2611:23,00:00:00,052,6920,O,17027553279@sip.emcor.net,97027553279,TrishZarlingo,,,0,,""n/a,0
11:24:26 47002059mS CD: CALL: 0.1765.0 BState=Ringing Cut=2 Music=0.0 Aend="TLine 17" (8.23) Bend="Line 17" [Line 17] (0.0) CalledNum=17027553279@sip.emcor.net () CallingNum=6920 (Trish Zarlingo) Internal=0 Time=62788 AState=Idle
11:24:26 47002059mS CD: CALL: 0.1765.0 Deleted
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: CALL LOST (CMCauseNormal)
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: Extn(6920) Calling Party Number(6920) Type(CMNTypeInternal)
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: CMExtnHandler::SetCurrent( id: 1765->0 )
11:24:26 47002060mS CMCallEvt: 0.1765.0 -1 Trish Zarlingo.-1: StateChange: END=X CMCSCompleted->CMCSDelete
11:24:26 47002062mS CMLineTx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=1768 in=0
Cause=16, Normal call clearing
11:24:26 47002062mS Sip: 17.1768.0 -1 SIPTrunk Endpoint(f4d5d36c) received CMReleaseComp
11:24:26 47002064mS SIP Call Tx: 17
CANCEL sip:17027553279@sip.emcor.net SIP/2.0
Via: SIP/2.0/UDP 10.0.215.10:5060;rport;branch=z9hG4bK4a29c7ec73a45f75b4c70998717baf86
Route: <sip:rw-25853dac@10.85.9.21;lr>
Route: <sip:10.85.9.20:15060;transport=udp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:10.85.9.20:15060;transport=tcp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:rw-25853dac@10.85.9.21;lr;transport=TCP>
From: "Trish Zarlingo" <sip:6920@sip.emcor.net>;tag=945901f5851db0e5
To: <sip:17027553279@sip.emcor.net>
Call-ID: f0f63a53659d69dc2955f2bc4d22b053
CSeq: 1144393089 CANCEL
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Reason: Q.850;cause=16;text="Normal call clearing"
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 47002064mS SIP Tx: UDP 10.0.215.10:5060 -> 10.85.9.21:5060
CANCEL sip:17027553279@sip.emcor.net SIP/2.0
Via: SIP/2.0/UDP 10.0.215.10:5060;rport;branch=z9hG4bK4a29c7ec73a45f75b4c70998717baf86
Route: <sip:rw-25853dac@10.85.9.21;lr>
Route: <sip:10.85.9.20:15060;transport=udp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:10.85.9.20:15060;transport=tcp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:rw-25853dac@10.85.9.21;lr;transport=TCP>
From: "Trish Zarlingo" <sip:6920@sip.emcor.net>;tag=945901f5851db0e5
To: <sip:17027553279@sip.emcor.net>
Call-ID: f0f63a53659d69dc2955f2bc4d22b053
CSeq: 1144393089 CANCEL
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Reason: Q.850;cause=16;text="Normal call clearing"
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 47002065mS CMCallEvt: END CALL:229 (f4cc2c64)
11:24:26 47002066mS CMTARGET: 0.1765.0 -1 BaseEP: ~CMTargetHandler f4cd6f34 ep f4d60a0c
11:24:26 47002066mS CMCallEvt: 0.1765.0 -1 BaseEP: DELETE CMEndpoint f4d60a0c TOTAL NOW=1 CALL_LIST=0
11:24:26 47002067mS CMMap: a=8.23 b=0.0 PCGS CPReserveCodec (pcp[541]b0r1) true
11:24:26 47002067mS CMMap: PCG::UnmapBChan pcp[541]b0r1 cp_b f55fe014 other_cp_b f57eafc4
11:24:26 47002067mS CMMap: a=8.23 b=4.33 M02
11:24:26 47002067mS H323Evt: SetOperational 225 10.0.215.10:49154 to 0
11:24:26 47002068mS CMMap: PCG::UnmapBChan pcp[149]b1r0 cp_b f57eafc4 other_cp_b 0
11:24:26 47002068mS CMMap: PlatformConnectionAudioSAP:isconnectVoice rtpRelay ID: 2 Close success
11:24:26 47002068mS CMMap: a=4.17 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 1, total 64
11:24:26 47002126mS RES: Thu 26/6/2014 11:24:25 FreeMem=52065756 51264548(3) CachedMem=801208 CMMsg=7(9) Buff=5200 1372 999 7433 4 Links=29351 BTree=13973 CPU=07.32% CPUStats=10/17/902/20056/21671/0/0 MCR=0 MCW=0
11:24:26 47002126mS RES2: IP 500 9.0.3.0 build 941 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=84 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=64(TLS=2) TAPI=0 CF=UMNT
11:24:26 47002126mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
This has been an ongoing issue for the past few years that when a user calls out local, long distance or toll free they get disconnected within the first 15-30 seconds. I has been intermittent but Today has been almost every call.
This is a capture of what I am seeing: Anyone have any thoughts?
11:24:16 46992246mS PRN: Monitor Status IP 500 9.0.3.0 build 941
11:24:16 46992246mS PRN: LAW=U PRI=0, BRI=0, ALOG=4, VCOMP=64, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=0 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=1(TOT=229)
11:24:26 47002056mS CMExtnRx: v=6920, p1=0
CMReleaseComp
Line: type=DigitalExtn 6 Call: lid=0 id=1765 in=0
11:24:26 47002057mS CMCallEvt: 0.1765.0 229 Trish Zarlingo.0: StateChange: END=A CMCSRingBack->CMCSCompleted
11:24:26 47002058mS CMExtnEvt: v=21 State, new=PortRecoverDelay old=Alerting,0,0,Trish Zarlingo
11:24:26 47002059mS CMLOGGING: CALL:2014/06/2611:23,00:00:00,052,6920,O,17027553279@sip.emcor.net,97027553279,TrishZarlingo,,,0,,""n/a,0
11:24:26 47002059mS CD: CALL: 0.1765.0 BState=Ringing Cut=2 Music=0.0 Aend="TLine 17" (8.23) Bend="Line 17" [Line 17] (0.0) CalledNum=17027553279@sip.emcor.net () CallingNum=6920 (Trish Zarlingo) Internal=0 Time=62788 AState=Idle
11:24:26 47002059mS CD: CALL: 0.1765.0 Deleted
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: CALL LOST (CMCauseNormal)
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: Extn(6920) Calling Party Number(6920) Type(CMNTypeInternal)
11:24:26 47002060mS CMExtnEvt: Trish Zarlingo: CMExtnHandler::SetCurrent( id: 1765->0 )
11:24:26 47002060mS CMCallEvt: 0.1765.0 -1 Trish Zarlingo.-1: StateChange: END=X CMCSCompleted->CMCSDelete
11:24:26 47002062mS CMLineTx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=1768 in=0
Cause=16, Normal call clearing
11:24:26 47002062mS Sip: 17.1768.0 -1 SIPTrunk Endpoint(f4d5d36c) received CMReleaseComp
11:24:26 47002064mS SIP Call Tx: 17
CANCEL sip:17027553279@sip.emcor.net SIP/2.0
Via: SIP/2.0/UDP 10.0.215.10:5060;rport;branch=z9hG4bK4a29c7ec73a45f75b4c70998717baf86
Route: <sip:rw-25853dac@10.85.9.21;lr>
Route: <sip:10.85.9.20:15060;transport=udp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:10.85.9.20:15060;transport=tcp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:rw-25853dac@10.85.9.21;lr;transport=TCP>
From: "Trish Zarlingo" <sip:6920@sip.emcor.net>;tag=945901f5851db0e5
To: <sip:17027553279@sip.emcor.net>
Call-ID: f0f63a53659d69dc2955f2bc4d22b053
CSeq: 1144393089 CANCEL
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Reason: Q.850;cause=16;text="Normal call clearing"
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 47002064mS SIP Tx: UDP 10.0.215.10:5060 -> 10.85.9.21:5060
CANCEL sip:17027553279@sip.emcor.net SIP/2.0
Via: SIP/2.0/UDP 10.0.215.10:5060;rport;branch=z9hG4bK4a29c7ec73a45f75b4c70998717baf86
Route: <sip:rw-25853dac@10.85.9.21;lr>
Route: <sip:10.85.9.20:15060;transport=udp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:10.85.9.20:15060;transport=tcp;ibmsid=local.1390390940471_8845039_8857652;lr;ibmdrr>
Route: <sip:rw-25853dac@10.85.9.21;lr;transport=TCP>
From: "Trish Zarlingo" <sip:6920@sip.emcor.net>;tag=945901f5851db0e5
To: <sip:17027553279@sip.emcor.net>
Call-ID: f0f63a53659d69dc2955f2bc4d22b053
CSeq: 1144393089 CANCEL
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Reason: Q.850;cause=16;text="Normal call clearing"
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 47002065mS CMCallEvt: END CALL:229 (f4cc2c64)
11:24:26 47002066mS CMTARGET: 0.1765.0 -1 BaseEP: ~CMTargetHandler f4cd6f34 ep f4d60a0c
11:24:26 47002066mS CMCallEvt: 0.1765.0 -1 BaseEP: DELETE CMEndpoint f4d60a0c TOTAL NOW=1 CALL_LIST=0
11:24:26 47002067mS CMMap: a=8.23 b=0.0 PCGS CPReserveCodec (pcp[541]b0r1) true
11:24:26 47002067mS CMMap: PCG::UnmapBChan pcp[541]b0r1 cp_b f55fe014 other_cp_b f57eafc4
11:24:26 47002067mS CMMap: a=8.23 b=4.33 M02
11:24:26 47002067mS H323Evt: SetOperational 225 10.0.215.10:49154 to 0
11:24:26 47002068mS CMMap: PCG::UnmapBChan pcp[149]b1r0 cp_b f57eafc4 other_cp_b 0
11:24:26 47002068mS CMMap: PlatformConnectionAudioSAP:isconnectVoice rtpRelay ID: 2 Close success
11:24:26 47002068mS CMMap: a=4.17 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 1, total 64
11:24:26 47002126mS RES: Thu 26/6/2014 11:24:25 FreeMem=52065756 51264548(3) CachedMem=801208 CMMsg=7(9) Buff=5200 1372 999 7433 4 Links=29351 BTree=13973 CPU=07.32% CPUStats=10/17/902/20056/21671/0/0 MCR=0 MCW=0
11:24:26 47002126mS RES2: IP 500 9.0.3.0 build 941 Tasks=45 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=84 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=64(TLS=2) TAPI=0 CF=UMNT
11:24:26 47002126mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)