chaunymony
Programmer
Hi all,
So I just turned up 20 SIP trunks last night with a carrier that we have used before. Configurations are exactly the same as other systems I have done. Doing a Midsize server at the latest 8.1 release. Issue I'm having is one call will work fine but any inbound or outbound after will not ring in and outbound gets a waiting for line. I then get congestion errors on SSA for no available SIP license, even though I have 20 of them and they are valid. In monitor I'm getting a LINE with group ID 1 has no channel and then an Incoming call in excess of license and a 503 service unavailable error. Below is the monitor capture. Any help would be greatly appreciated as the provider is asking me why the system is sending them a 503 error.
********** SysMonitor v10.1 (67) [connected to 10.128.0.10 ] **********
1268633mS PRN: Monitor Status S-Edition Primary 8.1.97 (25)
1268633mS PRN: Linux Whoo
1269369mS H323Evt: Recv: RegistrationRequest 10.128.0.90; Endpoints registered: 60; Endpoints in registration: 0
1270367mS H323Evt: Recv: RegistrationRequest 10.128.0.65; Endpoints registered: 60; Endpoints in registration: 0
1270382mS CMCallEvt: 0.1046.0 -1 BaseEP: NEW CMEndpoint e18f7b38 TOTAL NOW=3 CALL_LIST=1
1270382mS CMCallEvt: 0.1046.0 -1 Server Room.-1: NEW CMExtnEndpoint e18f7b38, Name=Server Room, Extn=5725, Phys Extn=5725
1270382mS CMCallEvt: CREATE CALL:13 (e18ffa20)
1270382mS CMCallEvt: 0.1047.0 -1 BaseEP: NEW CMEndpoint e1909cb8 TOTAL NOW=4 CALL_LIST=1
1270382mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 0->1046 )
1270382mS CMExtnRx: v=5725, p1=0
CMSetup
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
Called[92183917569] Type=Default (100) Reason=CMDRdirect SndComp Calling[5725] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Server Room
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Server Room
1270382mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
1270382mS CMExtnEvt: v=24 State, new=Dialling old=Idle,0,0,Server Room
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: LOOKUP CALL ROUTE: type=100 called_party=92183917569 sub= calling=5725 dir=out complete=1 ses=0
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: ADD TARGET (N): number=92183917569 type=100 depth=1 nobar=1 setorig=1 ses=0
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: SYS SC: 92183917569 2 2183917569 sc=type=Dial code=9N, num=N callinfop->sending_complete=1 secondary_dialtone=
1270382mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
1270382mS CMARS: MakeCallTarget - Called Number: 2183917569
1270382mS CMCallEvt: 0.1048.0 -1 BaseEP: NEW CMEndpoint e190c708 TOTAL NOW=5 CALL_LIST=2
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: INITIAL TARGETING SUCCEEDED
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: GetNoAnswerTimer:20
1270382mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSDialInitiated->CMCSDialled
1270382mS CMExtnEvt: v=24 State, new=Proceeding old=Dialling,0,0,Server Room
1270382mS CMExtnTx: v=5725, p1=0
CMProceeding
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
Timed: 21/06/13 10:00
1270382mS CMCallEvt: 0.1047.0 13 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
1270383mS CMCallEvt: 0.1047.0 13 TargetingEP: RequestEnd 0.1048.0 13 ARS for Main
1270383mS CMTARGET: 378.1046.0 13 Server Room.0: CancelTimer CMTCNoAnswerTimeout
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
1270383mS CMARS: FORM: Main - Received Number: 2183917569
1270383mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: N - Called_Party: 2183917569 - Line Group Id: 1
1270383mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
1270383mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
1270383mS Sip: License, Valid 1, Available 1, Consumed 1
1270383mS Sip: SIP Line (9): Outgoing Call in excess of License: Consumed: 1, Available: 1
1270383mS CMARS: LINE with group ID: 1 HAS NO CHANNEL: 34 - ATTEMPT OTHER TARGETS
1270383mS Sip: License, Valid 1, Available 1, Consumed 1
1270383mS Sip: SIP Line (9): Outgoing Call in excess of License: Consumed: 1, Available: 1
1270383mS CMARS: No Alternate ARS Or User Priority lower than ARS Priority - Remain on the Current Form: Main
1270383mS CMARS: CMARSTargetingBusy
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=B CMCSOverlapRecv->CMCSAccept
1270383mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSDialled->CMCSRingBack
1270383mS CMExtnEvt: v=24 State, new=Alerting old=Proceeding,0,0,Server Room
1270383mS CMExtnTx: v=5725, p1=0
CMProgress
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 21/06/13 10:00
1270383mS CMExtnTx: v=5725, p1=11227
CMFacility
Line: type=IPLine 350 Call: lid=378 id=24 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1270383mS CMCallEvt: 0.1047.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
1270383mS CMCallEvt: 0.1047.0 -1 BaseEP: DELETE CMEndpoint e1909cb8 TOTAL NOW=4 CALL_LIST=2
1270383mS CD: CALL: 378.1046.0 BState=Ringing Cut=3 Music=0.0 Aend="Server Room(5725)" (0.0) Bend="" [] (0.0) CalledNum=92183917569 () CallingNum=5725 (Server Room) Internal=1 Time=1 AState=Ringing
1270384mS CMMap: PCG::MapBChan pcp[273]b0r1 cp_b e1906f74 other_cp_b ee800e98 type CGTypeDTMF
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (connect) pcp[273]b0r1 echo_cancellation set to 0
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[273]b0r1 Configure 1.112
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[273]b0r1 ConnectIndication 1.112
1270384mS CMMap: DTMF:
layTones g T[23] ,EEEEE
1270384mS CMMap: Started playing tones, cp[273]b0r1 (from g null)
1270384mS CMMap: cp[273]b0r1 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
1270652mS SIP Rx: UDP 10.59.0.11:5060 -> 10.0.9.190:5060
INVITE sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>
CSeq: 788304190 INVITE
Expires: 120
Min-SE: 1800
Session-Expires: 1800
Supported: timer
Call-ID: 6906319660a0a1e
Remote-Party-ID: "Krech O "<sip:2183911040@10.59.0.11;user=phone>;party=calling;id-type=subscriber;privacy=off;screen=yes
Max-Forwards: 69
Contact: <sip:+12183911040@10.59.0.11:5060;isup-oli=0;user=phone;transport=udp>
Content-Type: application/sdp
Content-Length: 257
v=0
o=- 3580815645 3580815645 IN IP4 10.59.0.10
s=-
c=IN IP4 10.59.0.10
t=0 0
m=audio 57960 RTP/AVP 0 18 101
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no
1270652mS SIP Call Rx: 9
INVITE sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>
CSeq: 788304190 INVITE
Expires: 120
Min-SE: 1800
Session-Expires: 1800
Supported: timer
Call-ID: 6906319660a0a1e
Remote-Party-ID: "Krech O "<sip:2183911040@10.59.0.11;user=phone>;party=calling;id-type=subscriber;privacy=off;screen=yes
Max-Forwards: 69
Contact: <sip:+12183911040@10.59.0.11:5060;isup-oli=0;user=phone;transport=udp>
Content-Type: application/sdp
Content-Length: 257
v=0
o=- 3580815645 3580815645 IN IP4 10.59.0.10
s=-
c=IN IP4 10.59.0.10
t=0 0
m=audio 57960 RTP/AVP 0 18 101
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no
1270652mS CMCallEvt: 0.1049.0 -1 BaseEP: NEW CMEndpoint f2264000 TOTAL NOW=5 CALL_LIST=2
1270652mS Sip: SIPDialog f225e298 created, size 2
1270652mS Sip: License, Valid 1, Available 1, Consumed 1
1270652mS Sip: Incoming Call in excess of License: Consumed: 1, Available: 1
1270653mS SIP Call Tx: 9
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O " <sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
CSeq: 788304190 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Server: IP Office 8.1 (67)
Content-Length: 0
1270653mS SIP Tx: UDP 10.0.9.190:5060 -> 10.59.0.11:5060
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O " <sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
CSeq: 788304190 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Server: IP Office 8.1 (67)
Content-Length: 0
1270661mS SIP Rx: UDP 10.59.0.11:5060 -> 10.0.9.190:5060
ACK sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
CSeq: 788304190 ACK
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
Max-Forwards: 69
Content-Length: 0
1270661mS SIP Call Rx: 9
ACK sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
CSeq: 788304190 ACK
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
Max-Forwards: 69
Content-Length: 0
1271484mS H323Evt: Recv: RegistrationRequest 10.128.0.66; Endpoints registered: 60; Endpoints in registration: 0
1271661mS Sip: SIPDialog f225e298 destroyed, size 1
1271661mS CMCallEvt: 9.1049.1 -1 SIPTrunk Endpoint: StateChange: END=X CMCSIdle->CMCSDelete
1271661mS CMTARGET: 9.1049.1 -1 BaseEP: ~CMTargetHandler f2259368 ep f2264000
1271661mS CMCallEvt: 9.1049.1 -1 BaseEP: DELETE CMEndpoint f2264000 TOTAL NOW=4 CALL_LIST=2
1271661mS CMMap: a=1.114 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
1272475mS H323Evt: Recv: RegistrationRequest 10.128.0.64; Endpoints registered: 60; Endpoints in registration: 0
1272786mS CMMap: PCG::UnmapBChan pcp[273]b0r1 cp_b e1906f74 other_cp_b ee800e98
1273284mS CMExtnTx: v=5725, p1=11227
CMFacility
Line: type=IPLine 350 Call: lid=378 id=24 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1273284mS CMExtnRx: v=5725, p1=0
CMReleaseComp
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
1273284mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSRingBack->CMCSCompleted
1273284mS CMExtnEvt: v=24 State, new=PortRecoverDelay old=Alerting,0,0,Server Room
1273284mS CMExtnTx: v=5725, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 21/06/13 10:00
1273284mS CMLOGGING: CALL:2013/06/2110:00,00:00:00,000,5725,O,92183917569,92183917569,ServerRoom,,,1,,""n/a,0
1273284mS CD: CALL: 378.1046.0 BState=Ringing Cut=2 Music=0.0 Aend="Server Room(5725)" (0.0) Bend="" [] (0.0) CalledNum=92183917569 () CallingNum=5725 (Server Room) Internal=1 Time=2902 AState=Idle
1273284mS CD: CALL: 378.1046.0 Deleted
1273284mS CMExtnEvt: Server Room: CALL LOST (CMCauseNormal)
1273284mS CMExtnEvt: Server Room: Extn(5725) Calling Party Number(5725) Type(CMNTypeInternal)
1273284mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 1046->0 )
1273284mS CMCallEvt: 378.1046.0 -1 Server Room.-1: StateChange: END=X CMCSCompleted->CMCSDelete
1273284mS CMARS: CMARSEndpoint::CallLost(cause=16) - Address: 0.1048.0 13 ARS for Main - Call State: CMCSAccept
1273284mS CMCallEvt: 0.1048.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
1273284mS CMCallEvt: 0.1048.0 -1 BaseEP: DELETE CMEndpoint e190c708 TOTAL NOW=3 CALL_LIST=1
1273284mS CMCallEvt: END CALL:13 (e18ffa20)
1273284mS CMTARGET: 378.1046.0 -1 BaseEP: ~CMTargetHandler e190b0f0 ep e18f7b38
1273284mS CMCallEvt: 378.1046.0 -1 BaseEP: DELETE CMEndpoint e18f7b38 TOTAL NOW=2 CALL_LIST=1
1273285mS CMMap: a=1.112 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
1273474mS H323Evt: Recv: RegistrationRequest 10.128.0.70; Endpoints registered: 60; Endpoints in registration: 0
1273838mS RES: Fri 21/6/2013 10:00:04 FreeMem=10000 10000(1) CachedMem=0 CMMsg=6(6) Buff=5000 10000 15000 39999 500 Links=71571 BTree=0
1273838mS RES2: (SE-P) S-Edition Primary 8.1.97 (25) Tasks=35 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=120 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=140 TAPI=1
1273863mS ERR: TCP Connection error 113 for Src=0x0a0009be:4406 Dst=0x0a80020a:1720
1273863mS H323Evt: Shared tcp socket for line 2 disconnected
1274480mS H323Evt: Recv: RegistrationRequest 10.128.0.95; Endpoints registered: 60; Endpoints in registration: 0
1275285mS CMExtnEvt: Server Room: Recover Timer reason=CMTRWrapUp
1275285mS CMExtnEvt: v=24 State, new=Idle old=PortRecoverDelay,0,0,Server Room
1275285mS CMExtnTx: v=5725, p1=0
CMVoiceMailStatus
Line: type=IPLine 350 Call: lid=0 id=-1 in=0
Called[Server Room Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Server Room Msgs=0]
Timed: 21/06/13 10:00
1275476mS H323Evt: Recv: RegistrationRequest 10.128.0.113; Endpoints registered: 60; Endpoints in registration: 0
1275897mS PRN: WhoIsTCPSession: created
1276016mS PRN: WhoIsTCPSession: created
********** Warning: Logging to Screen Stopped **********
ACSS-SME
ACIS-SME
So I just turned up 20 SIP trunks last night with a carrier that we have used before. Configurations are exactly the same as other systems I have done. Doing a Midsize server at the latest 8.1 release. Issue I'm having is one call will work fine but any inbound or outbound after will not ring in and outbound gets a waiting for line. I then get congestion errors on SSA for no available SIP license, even though I have 20 of them and they are valid. In monitor I'm getting a LINE with group ID 1 has no channel and then an Incoming call in excess of license and a 503 service unavailable error. Below is the monitor capture. Any help would be greatly appreciated as the provider is asking me why the system is sending them a 503 error.
********** SysMonitor v10.1 (67) [connected to 10.128.0.10 ] **********
1268633mS PRN: Monitor Status S-Edition Primary 8.1.97 (25)
1268633mS PRN: Linux Whoo
1269369mS H323Evt: Recv: RegistrationRequest 10.128.0.90; Endpoints registered: 60; Endpoints in registration: 0
1270367mS H323Evt: Recv: RegistrationRequest 10.128.0.65; Endpoints registered: 60; Endpoints in registration: 0
1270382mS CMCallEvt: 0.1046.0 -1 BaseEP: NEW CMEndpoint e18f7b38 TOTAL NOW=3 CALL_LIST=1
1270382mS CMCallEvt: 0.1046.0 -1 Server Room.-1: NEW CMExtnEndpoint e18f7b38, Name=Server Room, Extn=5725, Phys Extn=5725
1270382mS CMCallEvt: CREATE CALL:13 (e18ffa20)
1270382mS CMCallEvt: 0.1047.0 -1 BaseEP: NEW CMEndpoint e1909cb8 TOTAL NOW=4 CALL_LIST=1
1270382mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 0->1046 )
1270382mS CMExtnRx: v=5725, p1=0
CMSetup
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
Called[92183917569] Type=Default (100) Reason=CMDRdirect SndComp Calling[5725] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Server Room
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Server Room
1270382mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
1270382mS CMExtnEvt: v=24 State, new=Dialling old=Idle,0,0,Server Room
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: LOOKUP CALL ROUTE: type=100 called_party=92183917569 sub= calling=5725 dir=out complete=1 ses=0
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: ADD TARGET (N): number=92183917569 type=100 depth=1 nobar=1 setorig=1 ses=0
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: SYS SC: 92183917569 2 2183917569 sc=type=Dial code=9N, num=N callinfop->sending_complete=1 secondary_dialtone=
1270382mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
1270382mS CMARS: MakeCallTarget - Called Number: 2183917569
1270382mS CMCallEvt: 0.1048.0 -1 BaseEP: NEW CMEndpoint e190c708 TOTAL NOW=5 CALL_LIST=2
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: INITIAL TARGETING SUCCEEDED
1270382mS CMTARGET: 378.1046.0 13 Server Room.0: GetNoAnswerTimer:20
1270382mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSDialInitiated->CMCSDialled
1270382mS CMExtnEvt: v=24 State, new=Proceeding old=Dialling,0,0,Server Room
1270382mS CMExtnTx: v=5725, p1=0
CMProceeding
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
Timed: 21/06/13 10:00
1270382mS CMCallEvt: 0.1047.0 13 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
1270383mS CMCallEvt: 0.1047.0 13 TargetingEP: RequestEnd 0.1048.0 13 ARS for Main
1270383mS CMTARGET: 378.1046.0 13 Server Room.0: CancelTimer CMTCNoAnswerTimeout
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
1270383mS CMARS: FORM: Main - Received Number: 2183917569
1270383mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: N - Called_Party: 2183917569 - Line Group Id: 1
1270383mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
1270383mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
1270383mS Sip: License, Valid 1, Available 1, Consumed 1
1270383mS Sip: SIP Line (9): Outgoing Call in excess of License: Consumed: 1, Available: 1
1270383mS CMARS: LINE with group ID: 1 HAS NO CHANNEL: 34 - ATTEMPT OTHER TARGETS
1270383mS Sip: License, Valid 1, Available 1, Consumed 1
1270383mS Sip: SIP Line (9): Outgoing Call in excess of License: Consumed: 1, Available: 1
1270383mS CMARS: No Alternate ARS Or User Priority lower than ARS Priority - Remain on the Current Form: Main
1270383mS CMARS: CMARSTargetingBusy
1270383mS CMCallEvt: 0.1048.0 13 ARS for Main: StateChange: END=B CMCSOverlapRecv->CMCSAccept
1270383mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSDialled->CMCSRingBack
1270383mS CMExtnEvt: v=24 State, new=Alerting old=Proceeding,0,0,Server Room
1270383mS CMExtnTx: v=5725, p1=0
CMProgress
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 21/06/13 10:00
1270383mS CMExtnTx: v=5725, p1=11227
CMFacility
Line: type=IPLine 350 Call: lid=378 id=24 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1270383mS CMCallEvt: 0.1047.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
1270383mS CMCallEvt: 0.1047.0 -1 BaseEP: DELETE CMEndpoint e1909cb8 TOTAL NOW=4 CALL_LIST=2
1270383mS CD: CALL: 378.1046.0 BState=Ringing Cut=3 Music=0.0 Aend="Server Room(5725)" (0.0) Bend="" [] (0.0) CalledNum=92183917569 () CallingNum=5725 (Server Room) Internal=1 Time=1 AState=Ringing
1270384mS CMMap: PCG::MapBChan pcp[273]b0r1 cp_b e1906f74 other_cp_b ee800e98 type CGTypeDTMF
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (connect) pcp[273]b0r1 echo_cancellation set to 0
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[273]b0r1 Configure 1.112
1270384mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[273]b0r1 ConnectIndication 1.112
1270384mS CMMap: DTMF:
1270384mS CMMap: Started playing tones, cp[273]b0r1 (from g null)
1270384mS CMMap: cp[273]b0r1 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
1270652mS SIP Rx: UDP 10.59.0.11:5060 -> 10.0.9.190:5060
INVITE sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>
CSeq: 788304190 INVITE
Expires: 120
Min-SE: 1800
Session-Expires: 1800
Supported: timer
Call-ID: 6906319660a0a1e
Remote-Party-ID: "Krech O "<sip:2183911040@10.59.0.11;user=phone>;party=calling;id-type=subscriber;privacy=off;screen=yes
Max-Forwards: 69
Contact: <sip:+12183911040@10.59.0.11:5060;isup-oli=0;user=phone;transport=udp>
Content-Type: application/sdp
Content-Length: 257
v=0
o=- 3580815645 3580815645 IN IP4 10.59.0.10
s=-
c=IN IP4 10.59.0.10
t=0 0
m=audio 57960 RTP/AVP 0 18 101
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no
1270652mS SIP Call Rx: 9
INVITE sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>
CSeq: 788304190 INVITE
Expires: 120
Min-SE: 1800
Session-Expires: 1800
Supported: timer
Call-ID: 6906319660a0a1e
Remote-Party-ID: "Krech O "<sip:2183911040@10.59.0.11;user=phone>;party=calling;id-type=subscriber;privacy=off;screen=yes
Max-Forwards: 69
Contact: <sip:+12183911040@10.59.0.11:5060;isup-oli=0;user=phone;transport=udp>
Content-Type: application/sdp
Content-Length: 257
v=0
o=- 3580815645 3580815645 IN IP4 10.59.0.10
s=-
c=IN IP4 10.59.0.10
t=0 0
m=audio 57960 RTP/AVP 0 18 101
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no
1270652mS CMCallEvt: 0.1049.0 -1 BaseEP: NEW CMEndpoint f2264000 TOTAL NOW=5 CALL_LIST=2
1270652mS Sip: SIPDialog f225e298 created, size 2
1270652mS Sip: License, Valid 1, Available 1, Consumed 1
1270652mS Sip: Incoming Call in excess of License: Consumed: 1, Available: 1
1270653mS SIP Call Tx: 9
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O " <sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
CSeq: 788304190 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Server: IP Office 8.1 (67)
Content-Length: 0
1270653mS SIP Tx: UDP 10.0.9.190:5060 -> 10.59.0.11:5060
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
From: "Krech O " <sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
CSeq: 788304190 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Server: IP Office 8.1 (67)
Content-Length: 0
1270661mS SIP Rx: UDP 10.59.0.11:5060 -> 10.0.9.190:5060
ACK sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
CSeq: 788304190 ACK
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
Max-Forwards: 69
Content-Length: 0
1270661mS SIP Call Rx: 9
ACK sip:6122382234@10.0.9.190:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.59.0.11:5060;branch=z9hG4bK2g0sbo0090f13l4ep0p0.1
CSeq: 788304190 ACK
From: "Krech O "<sip:2183911040@10.59.0.11;isup-oli=0;user=phone>;tag=660a0a1e+1+772d00e5+73f92e43
To: <sip:6122382234@10.0.9.190;user=phone>;tag=d429c6a8ce53e48c
Call-ID: 6906319660a0a1e
Max-Forwards: 69
Content-Length: 0
1271484mS H323Evt: Recv: RegistrationRequest 10.128.0.66; Endpoints registered: 60; Endpoints in registration: 0
1271661mS Sip: SIPDialog f225e298 destroyed, size 1
1271661mS CMCallEvt: 9.1049.1 -1 SIPTrunk Endpoint: StateChange: END=X CMCSIdle->CMCSDelete
1271661mS CMTARGET: 9.1049.1 -1 BaseEP: ~CMTargetHandler f2259368 ep f2264000
1271661mS CMCallEvt: 9.1049.1 -1 BaseEP: DELETE CMEndpoint f2264000 TOTAL NOW=4 CALL_LIST=2
1271661mS CMMap: a=1.114 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
1272475mS H323Evt: Recv: RegistrationRequest 10.128.0.64; Endpoints registered: 60; Endpoints in registration: 0
1272786mS CMMap: PCG::UnmapBChan pcp[273]b0r1 cp_b e1906f74 other_cp_b ee800e98
1273284mS CMExtnTx: v=5725, p1=11227
CMFacility
Line: type=IPLine 350 Call: lid=378 id=24 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1273284mS CMExtnRx: v=5725, p1=0
CMReleaseComp
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
1273284mS CMCallEvt: 378.1046.0 13 Server Room.0: StateChange: END=A CMCSRingBack->CMCSCompleted
1273284mS CMExtnEvt: v=24 State, new=PortRecoverDelay old=Alerting,0,0,Server Room
1273284mS CMExtnTx: v=5725, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=378 id=1046 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 21/06/13 10:00
1273284mS CMLOGGING: CALL:2013/06/2110:00,00:00:00,000,5725,O,92183917569,92183917569,ServerRoom,,,1,,""n/a,0
1273284mS CD: CALL: 378.1046.0 BState=Ringing Cut=2 Music=0.0 Aend="Server Room(5725)" (0.0) Bend="" [] (0.0) CalledNum=92183917569 () CallingNum=5725 (Server Room) Internal=1 Time=2902 AState=Idle
1273284mS CD: CALL: 378.1046.0 Deleted
1273284mS CMExtnEvt: Server Room: CALL LOST (CMCauseNormal)
1273284mS CMExtnEvt: Server Room: Extn(5725) Calling Party Number(5725) Type(CMNTypeInternal)
1273284mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 1046->0 )
1273284mS CMCallEvt: 378.1046.0 -1 Server Room.-1: StateChange: END=X CMCSCompleted->CMCSDelete
1273284mS CMARS: CMARSEndpoint::CallLost(cause=16) - Address: 0.1048.0 13 ARS for Main - Call State: CMCSAccept
1273284mS CMCallEvt: 0.1048.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
1273284mS CMCallEvt: 0.1048.0 -1 BaseEP: DELETE CMEndpoint e190c708 TOTAL NOW=3 CALL_LIST=1
1273284mS CMCallEvt: END CALL:13 (e18ffa20)
1273284mS CMTARGET: 378.1046.0 -1 BaseEP: ~CMTargetHandler e190b0f0 ep e18f7b38
1273284mS CMCallEvt: 378.1046.0 -1 BaseEP: DELETE CMEndpoint e18f7b38 TOTAL NOW=2 CALL_LIST=1
1273285mS CMMap: a=1.112 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
1273474mS H323Evt: Recv: RegistrationRequest 10.128.0.70; Endpoints registered: 60; Endpoints in registration: 0
1273838mS RES: Fri 21/6/2013 10:00:04 FreeMem=10000 10000(1) CachedMem=0 CMMsg=6(6) Buff=5000 10000 15000 39999 500 Links=71571 BTree=0
1273838mS RES2: (SE-P) S-Edition Primary 8.1.97 (25) Tasks=35 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=120 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=140 TAPI=1
1273863mS ERR: TCP Connection error 113 for Src=0x0a0009be:4406 Dst=0x0a80020a:1720
1273863mS H323Evt: Shared tcp socket for line 2 disconnected
1274480mS H323Evt: Recv: RegistrationRequest 10.128.0.95; Endpoints registered: 60; Endpoints in registration: 0
1275285mS CMExtnEvt: Server Room: Recover Timer reason=CMTRWrapUp
1275285mS CMExtnEvt: v=24 State, new=Idle old=PortRecoverDelay,0,0,Server Room
1275285mS CMExtnTx: v=5725, p1=0
CMVoiceMailStatus
Line: type=IPLine 350 Call: lid=0 id=-1 in=0
Called[Server Room Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Server Room Msgs=0]
Timed: 21/06/13 10:00
1275476mS H323Evt: Recv: RegistrationRequest 10.128.0.113; Endpoints registered: 60; Endpoints in registration: 0
1275897mS PRN: WhoIsTCPSession: created
1276016mS PRN: WhoIsTCPSession: created
********** Warning: Logging to Screen Stopped **********
ACSS-SME
ACIS-SME