BenForMile
Technical User
- Jul 14, 2010
- 33
Hi,
A client of ours has a (Lync to Sip gateway to IP Office) setup without a problem on several IP Offices in their SCN. This setup is working fine on several of their IPO system. But on one particular system in Brasil they are having trouble dialing an outside number from Lynch to the IP Office. As in the logs the Sip gateway is sending the correct number 9N. Now when the IP office try to send it to the E1 R2 DIOD lines they get no ringing tone. It appears the call is being made but they hear nothing. If you look at the monitor logs it seems to me the IP Office is trying to find the right tone for this call. After it doesn't find it it declares it as busy.
Here is the Monitor logs.
A client of ours has a (Lync to Sip gateway to IP Office) setup without a problem on several IP Offices in their SCN. This setup is working fine on several of their IPO system. But on one particular system in Brasil they are having trouble dialing an outside number from Lynch to the IP Office. As in the logs the Sip gateway is sending the correct number 9N. Now when the IP office try to send it to the E1 R2 DIOD lines they get no ringing tone. It appears the call is being made but they hear nothing. If you look at the monitor logs it seems to me the IP Office is trying to find the right tone for this call. After it doesn't find it it declares it as busy.
Here is the Monitor logs.
Code:
UNICODE-UTF8
ptb
1159709mS PRN: SCNTFTP::Process (2) RESET received from 172.16.200.200
1159709mS PRN: VPNN: PBX 172.16.200.200 Not Responding - error code 4
1159709mS PRN: VPNN: PBX 172.16.200.200 Not Responding or Reset AU=106
1159835mS PRN: VPNN: last_activity set for pbx 172.16.200.200
1159836mS PRN: ======= VPNN_RIP_PLATFORM_INFO 7.0.36 ========
1159838mS PRN: VPNN: - New connection 172.16.200.200
1161332mS PRN: ParseRemoteBLF from 172.16.200.200: non-matching lengths? expected=0 len=28
1163642mS PRN: SCNTFTP::SendPacket (3) seq=1520 len=343 retries=3 dest 172.16.40.200
1167392mS PRN: SCNTFTP::SendPacket (3) seq=2008 len=343 retries=3 dest 172.16.120.200
1168275mS PRN: SCNTFTP::Process (3) DATA seq=2264 repeated len 291 dest 172.16.81.200
1168781mS PRN: SCNTFTP::SendPacket (3) seq=1835 len=330 retries=3 dest 172.16.64.200
1171187mS PRN: SCNTFTP::Process (3) DATA seq=1905 repeated len 330 dest 172.16.100.200
1173198mS SIP Call Rx: 11
INVITE sip:935296143@172.16.60.200;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac2109129077
Max-Forwards: 70
From: "Adolfo Blanco - Celistics" <sip:+31000@M2K.celistics.com>;tag=1c2109117812
To: <sip:935296143@172.16.60.200;user=phone>
Call-ID: 21091165202612201217047@172.16.160.17
CSeq: 1 INVITE
Contact: <sip:172.16.160.17:5060>
Supported: em,100rel,timer,replaces,path,early-session,resource-priority,sdp-anat
Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE
User-Agent: Audiocodes-Sip-Gateway-Mediant 2000/v.6.40A.029.008
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 259
v=0
o=AudiocodesGW 2109099967 2109099597 IN IP4 172.16.160.17
s=Phone-Call
c=IN IP4 172.16.160.17
t=0 0
m=audio 6020 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
1173198mS CMCallEvt: 0.1021.0 -1 BaseEP: NEW CMEndpoint f4910174 TOTAL NOW=1 CALL_LIST=0
1173199mS Stun: Info: media ports will not be mapped with STUN.
1173199mS Sip: License, Valid 1, Available 10, Consumed 0
1173202mS SIP Call Tx: 11
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac2109129077
From: "Adolfo Blanco - Celistics" <sip:+31000@M2K.celistics.com>;tag=1c2109117812
To: <sip:935296143@172.16.60.200;user=phone>;tag=0f3767a06a7dfdf9
Call-ID: 21091165202612201217047@172.16.160.17
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Content-Length: 0
1173204mS Sip: 11.1021.1 -1 SIPTrunk Endpoint(f490ef30) SetRemoteRTPAddress to 172.16.160.17:6020 (index 0)
1173205mS CMCallEvt: CREATE CALL:6 (f490ada8)
1173206mS CMCallEvt: 0.1022.0 -1 BaseEP: NEW CMEndpoint f49098e4 TOTAL NOW=2 CALL_LIST=0
1173208mS CMLineRx: v=0
CMSetup
Line: type=SIPLine 11 Call: lid=11 id=1021 in=1
Called[935296143] Type=Default (100) Reason=CMDRdirect SndComp Calling[0031000@M2K.celistics.com] Type=NetworkSpecific Plan=Default Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Adolfo Blanco - Celistics
IE CMIERespondingPartyNumber (230)(P:0 S:100 T:3 N:100 R:4) number=0031000@M2K.celistics.com
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceSIPTrunk type=0 number=11 channel=1 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=172.16.60.200 apps=0
1173209mS CD: CALL: 11.1021.1 BState=Idle Cut=1 Music=0.0 Aend="Line 11" (0.0) Bend="" [] (0.0) CalledNum=935296143 () CallingNum=0031000@M2K.celistics.com (Adolfo Blanco - Celistics) Internal=0 Time=4 AState=Idle
1173209mS CMCallEvt: 11.1021.1 6 SIPTrunk Endpoint: StateChange: END=A CMCSIdle->CMCSDialInitiated
1173209mS CMCallEvt: Priority hike: call 6 priority 0->1
1173211mS CMARS: FindActiveARSByGroupID GroupID=53 - Found
********** Warning: Missed 2 packet(s) Total late 0 packet(s) **********
1173212mS CMCallEvt: 11.1021.1 6 SIPTrunk Endpoint: StateChange: END=A CMCSDialInitiated->CMCSDialled
********** Warning: Missed 2 packet(s) Total late 0 packet(s) **********
1173214mS CMCallEvt: 0.1022.0 6 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
1173215mS CMCallEvt: 0.1023.0 6 ARS for Saida_E1: StateChange: END=T CMCSIdle->CMCSOffering
1173215mS CMCallEvt: 0.1022.0 6 TargetingEP: RequestEnd 0.1023.0 6 ARS for Saida_E1
1173216mS CMCallEvt: 0.1023.0 6 ARS for Saida_E1: StateChange: END=B CMCSOffering->CMCSOverlapRecv
1173217mS CMARS: FORM: Saida_E1 - Received Number: 35296143
1173217mS CMARS: FOUND A SHORT CODE - short_code: 3XXXXXXX; - Tel: 3N - Called_Party: 35296143 - Line Group Id: 1
1173217mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
1173218mS R2Line: line: 9.1: State= Idle ep none CanMakeCall: Yes
1173218mS CMCallEvt: 0.1024.0 -1 BaseEP: NEW CMEndpoint f4900074 TOTAL NOW=4 CALL_LIST=1
1173220mS CMARS: FOUND LINE - Line Id: 9 - using line group id: 1 - Called Number: 35296143 - Calling Number: 0031000@M2K.celistics.com
1173220mS CMARS: SEND Setup TO LINE
1173221mS CMCallEvt: 0.1024.0 6 R2 Trunk:9 CHAN=1: StateChange: END=child CMCSIdle->CMCSOffering
1173221mS CMLineTx: v=9
CMSetup
Line: type=R2Line 9 Call: lid=0 id=1024 in=0
Called[35296143] Type=Default (100) Reason=CMDRdirect SndComp Calling[0031000@M2K.celistics.com] Type=NetworkSpecific Plan=Default Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Adolfo Blanco - Celistics
IE CMIEDIDNumber (245)(P:100 S:100 T:100 N:100 R:4) number=935296143
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Adolfo Blanco - Celistics
IE CMIERespondingPartyNumber (230)(P:0 S:100 T:3 N:100 R:4) number=0031000@M2K.celistics.com
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceSIPTrunk type=0 number=11 channel=1 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=172.16.60.200 apps=0
IE CMIEIcrPriorityDetail (239) Priority = 1
IE CMIEMohSourceId (247) MOH Source = 1
Locale: ptb
1173221mS R2Line: line: 9.1: State: Idle CMMessage: CMSetup
1173221mS R2Line: line: 9.1: State Change Idle -> Initiated
1173221mS R2Line: line: 9.1: Sending LL Message Seize
1173222mS CMLineRx: v=9
CMSetupAck
Line: type=R2Line 9 Call: lid=0 id=1024 in=0
BChan: slot=5 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceR2Trunk type=0 number=9 channel=1 rx_gain=32 tx_gain=32 ep_callid=1024 ipaddr=172.16.60.200 apps=0
1173222mS CMARS: LINE ep Received: CMSetupAck - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
1173222mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
1173222mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1023.0 6 ARS for Saida_E1 - Call State: CMCSOverlapRecv
1173223mS CMCallEvt: 0.1023.0 -1 ARS for Saida_E1: StateChange: END=X CMCSOverlapRecv->CMCSDelete
1173224mS CMCallEvt: 0.1024.0 6 R2 Trunk:9 CHAN=1: StateChange: END=B CMCSOffering->CMCSOverlapRecv
1173224mS CMLineRx: v=9
CMProceeding
Line: type=R2Line 9 Call: lid=0 id=1024 in=0
BChan: slot=5 chan=2
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceR2Trunk type=0 number=9 channel=1 rx_gain=32 tx_gain=32 ep_callid=1024 ipaddr=172.16.60.200 apps=0
1173224mS CMCallEvt: 0.1024.0 6 R2 Trunk:9 CHAN=1: StateChange: END=B CMCSOverlapRecv->CMCSAccept
1173225mS CMCallEvt: 0.1023.0 -1 BaseEP: DELETE CMEndpoint f4902a00 TOTAL NOW=3 CALL_LIST=1
1173225mS CMCallEvt: 0.1022.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
1173228mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), set gains tx 10, rx 10
1173228mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), set log-law, system A-Law, line A-Law
1173228mS R2Channel R2_BRA_9.1: State Change Idle -> Seized
1173229mS R2Channel R2_BRA_9.1: EventTx: Seize State: Seized
1173229mS PRN: R2 CAS: R2_BRA_9.1:: Transmit: 1001 -> 0001
1173229mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), speech path off
1173230mS CD: CALL: 11.1021.1 BState=Ringing Cut=3 Music=0.0 Aend="Line 11" (0.0) Bend="Line 9" [Line 9] (5.2) CalledNum=35296143 () CallingNum=0031000@M2K.celistics.com (Adolfo Blanco - Celistics) Internal=0 Time=25 AState=Dialled
1173286mS PRN: R2 CAS: R2_BRA_9.1:: Receive: 1001 -> 1101
1173287mS R2Channel R2_BRA_9.1: EventRx: SeizeAck State: Seized
1173287mS R2Channel R2_BRA_9.1: State Change Seized -> SeizeAck
1173287mS R2Channel R2_BRA_9.1: EventTx: SeizeAck State: SeizeAck
1173287mS R2Channel R2_BRA_9.1: State Change SeizeAck -> Dialling
1173287mS R2Channel R2_BRA_9.1: EventTx: Dialling State: Dialling
1173288mS R2Line: line: 9.1: State= Initiated RxMessage: StartDial
1173289mS R2Line: line: 9.1: State Change Initiated -> OverlapSend
1173289mS R2Line: line: 9.1: Sending LL Message DialDigits
1173291mS R2Dialler: R2_BRA_9.1: MFC State Change: Idle -> Fwd 0
1173291mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), digit receiver R2 backwards
********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
1173291mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 3 (tone 19)
1173477mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x01
1173477mS R2Dialler: R2_BRA_9.1: State: Fwd 0 RX Bwd MFC: A.1 - SendNextDigit
1173478mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.5 - "5"
1173478mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1173536mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1173536mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 5 (tone 21)
1173628mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1173628mS R2Dialler: R2_BRA_9.1: State: Fwd 0 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1173628mS R2Dialler: R2_BRA_9.1: State: Fwd 0 TX Fwd MFC: II.1 - OrdinarySubscriber
1173629mS R2Dialler: R2_BRA_9.1: MFC State Change: Fwd 0 -> Fwd 3
1173629mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1173687mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1173687mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 1 (tone 17)
1173779mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1173779mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1173779mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.10 - "0"
1173779mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1173837mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1173838mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 10 (tone 26)
1173930mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1173930mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1173930mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.10 - "0"
1173930mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1173988mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1173988mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 10 (tone 26)
1174080mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174080mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174081mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.3 - "3"
1174081mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174141mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174141mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 3 (tone 19)
1174233mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174233mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174233mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.1 - "1"
1174233mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174290mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174290mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 1 (tone 17)
1174382mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174382mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174382mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.10 - "0"
1174382mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174442mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174442mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 10 (tone 26)
1174533mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174533mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174533mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.10 - "0"
1174533mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174592mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174593mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 10 (tone 26)
1174683mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174684mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174684mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.10 - "0"
1174684mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174742mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174742mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 10 (tone 26)
1174834mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x05
1174834mS R2Dialler: R2_BRA_9.1: State: Fwd 3 RX Bwd MFC: A.5 - GrpII_ANIAndNextANI
1174834mS R2Dialler: R2_BRA_9.1: TX Fwd MFC: I.16 - "@"
1174835mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1174893mS R2DSP: PRIU DSP 3: read tone, port 0, channel 1, tone 0x10
1174893mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1177225mS CD: CALL: 11.1021.1 BState=Ringing Cut=3 Music=0.0 Aend="Line 11" (0.0) Bend="Line 9" [Line 9] (5.2) CalledNum=35296143 () CallingNum=0031000@M2K.celistics.com (Adolfo Blanco - Celistics) Internal=0 Time=4020 AState=Dialled
1179532mS PRN: SCNTFTP::SendPacket (3) seq=1691 len=111 retries=3 dest 172.16.81.200
1181466mS PRN: SCNTFTP::Process (3) DATA seq=1813 repeated len 252 dest 172.16.73.200
1182340mS SIP Reg/Opt Rx: 11
OPTIONS sip:172.16.160.17 SIP/2.0
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac112622915
Max-Forwards: 70
From: <sip:172.16.160.17>;tag=1c112598738
To: <sip:M2K.celistics.com>
Call-ID: 1125975902612201217056@172.16.160.17
CSeq: 1 OPTIONS
Contact: <sip:172.16.160.17:5060>
Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE
User-Agent: Audiocodes-Sip-Gateway-Mediant 2000/v.6.40A.029.008
Accept: application/sdp, application/simple-message-summary, message/sipfrag
Content-Length: 0
1182342mS SIP Reg/Opt Tx: 11
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac112622915
From: <sip:172.16.160.17>;tag=1c112598738
To: <sip:M2K.celistics.com>;tag=38e31246f68dc746
Call-ID: 1125975902612201217056@172.16.160.17
CSeq: 1 OPTIONS
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Content-Type: application/sdp
Content-Length: 231
v=0
o=UserA 2882149376 87075679 IN IP4 0.0.0.0
s=Session SDP
c=IN IP4 0.0.0.0
t=0 0
m=audio 8000 RTP/AVP 18 8 0 4
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:4 G723/16000
1183935mS PRN: SCNTFTP::SendPacket (3) seq=1920 len=343 retries=3 dest 172.16.65.200
1185862mS PRN: SCNTFTP::SendPacket (3) seq=2126 len=330 retries=3 dest 172.16.110.200
1186436mS PRN: Config Write Wake Up
1186936mS PRN: Updates IO list size 0 updated list size 2
1186937mS PRN: Config Write Completed
1189893mS R2Dialler: R2_BRA_9.1: MFC State Change: Fwd 3 -> Idle
1189893mS R2Line: line: 9.1: State= OverlapSend RxMessage: Busy
1189894mS R2Line: line: 9.1: State Change OverlapSend -> Active
1189894mS CMLineRx: v=9
CMAlerting
Line: type=R2Line 9 Call: lid=0 id=1024 in=0
BChan: slot=5 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=935296143
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceR2Trunk type=0 number=9 channel=1 rx_gain=32 tx_gain=32 ep_callid=1024 ipaddr=172.16.60.200 apps=0
1189894mS CMCallEvt: 0.1024.0 6 R2 Trunk:9 CHAN=1: StateChange: END=B CMCSAccept->CMCSRinging
1189895mS CMCallEvt: 11.1021.1 6 SIPTrunk Endpoint: StateChange: END=A CMCSDialled->CMCSRingBack
1189898mS CMLineTx: v=0
CMAlerting
Line: type=SIPLine 11 Call: lid=11 id=1021 in=1
BChan: slot=5 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=935296143
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceR2Trunk type=0 number=9 channel=1 rx_gain=32 tx_gain=32 ep_callid=1024 ipaddr=172.16.60.200 apps=0
IE CMIEFastStartInfoData (6) 2 item(s)
1189898mS Sip: 11.1021.1 6 SIPTrunk Endpoint(f4910174) received CMAlerting
1189899mS Sip: 11.1021.1 6 SIPTrunk Endpoint(f490ef30) SetLocalRTPAddress to 172.16.60.200:49152 (index 0)
1189900mS SIP Call Tx: 11
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac2109129077
From: "Adolfo Blanco - Celistics" <sip:+31000@M2K.celistics.com>;tag=1c2109117812
To: <sip:935296143@172.16.60.200;user=phone>;tag=0f3767a06a7dfdf9
Call-ID: 21091165202612201217047@172.16.160.17
CSeq: 1 INVITE
Contact: "935296143" <sip:935296143@172.16.60.200:5060;transport=udp>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Content-Length: 0
1189902mS CMLineRx: v=9
CMReleaseComp
Line: type=R2Line 9 Call: lid=0 id=1024 in=0
BChan: slot=5 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=935296143
IE CMIEDeviceDetail (231) LOCALE=ptb HW=15 VER=8 class=CMDeviceR2Trunk type=0 number=9 channel=1 rx_gain=32 tx_gain=32 ep_callid=1024 ipaddr=172.16.60.200 apps=0
Cause=17, User busy
1189902mS CMCallEvt: 0.1024.0 6 R2 Trunk:9 CHAN=1: StateChange: END=B CMCSRinging->CMCSCompleted
1189904mS CMLOGGING: CALL:2012/12/2619:02,00:00:00,000,0031000@M2K.celistics.com,I,35296143,935296143,AdolfoBlanco-Celistics,,,0,,""n/a,0
1189905mS CD: CALL: 11.1021.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 11" (0.0) Bend="Line 9" [Line 9] (5.2) CalledNum=35296143 () CallingNum=0031000@M2K.celistics.com (Adolfo Blanco - Celistics) Internal=0 Time=16699 AState=Ringing
1189905mS CD: CALL: 11.1021.1 Deleted
1189906mS CMCallEvt: 11.1021.1 -1 SIPTrunk Endpoint: StateChange: END=X CMCSRingBack->CMCSCompleted
1189907mS SIP Call Tx: 11
SIP/2.0 486 Busy Here
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac2109129077
From: "Adolfo Blanco - Celistics" <sip:+31000@M2K.celistics.com>;tag=1c2109117812
To: <sip:935296143@172.16.60.200;user=phone>;tag=0f3767a06a7dfdf9
Call-ID: 21091165202612201217047@172.16.160.17
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Content-Length: 0
1189908mS CMCallEvt: 0.1024.0 -1 R2 Trunk:9 CHAN=1: StateChange: END=X CMCSCompleted->CMCSDelete
1189908mS CMCallEvt: END CALL:6 (f490ada8)
1189909mS CMCallEvt: 0.1024.0 -1 BaseEP: DELETE CMEndpoint f4900074 TOTAL NOW=1 CALL_LIST=0
1189909mS R2Line: line: 9.1: Clear Call
1189910mS R2Line: line: 9.1: State Change Active -> DiscReq
1189910mS R2Line: line: 9.1: Sending LL Message Drop
1189911mS R2Channel R2_BRA_9.1: EventTx: Clear Forward State: Dialling
1189912mS PRN: R2 CAS: R2_BRA_9.1:: Transmit: 0001 -> 1001
1189912mS R2Channel R2_BRA_9.1: State Change Dialling -> Blocked
1189912mS R2DSP: PRIU DSP 3: channel 1 (timeslot 2), send digit 16 (tone 16)
1189912mS R2Channel R2_BRA_9.1: EventTx: Blocked State: Blocked
1190046mS PRN: R2 CAS: R2_BRA_9.1:: Receive: 1101 -> 1001
1190046mS R2Channel R2_BRA_9.1: EventRx: Idle State: Blocked
1190311mS SIP Call Rx: 11
ACK sip:935296143@172.16.60.200;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac2109129077
Max-Forwards: 70
From: "Adolfo Blanco - Celistics" <sip:+31000@M2K.celistics.com>;tag=1c2109117812
To: <sip:935296143@172.16.60.200;user=phone>;tag=0f3767a06a7dfdf9
Call-ID: 21091165202612201217047@172.16.160.17
CSeq: 1 ACK
Contact: <sip:172.16.160.17:5060>
Supported: em,timer,replaces,path,early-session,resource-priority
Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE
User-Agent: Audiocodes-Sip-Gateway-Mediant 2000/v.6.40A.029.008
Content-Length: 0
1190412mS R2Channel R2_BRA_9.1: EventTx: Idle State: Blocked
********** Warning: Logging to Screen Stopped **********
********** Warning: Logging to Screen Started **********
1231348mS PRN: SCNTFTP::SendPacket (3) seq=2135 len=343 retries=3 dest 172.16.120.200
1232432mS PRN: SCNTFTP::SendPacket (3) seq=2167 len=317 retries=3 dest 172.16.20.200
1233332mS PRN: SCNTFTP::SendPacket (3) seq=2556 len=343 retries=3 dest 172.16.130.200
1234934mS PRN: SCNTFTP::Process (2) RESET received from 172.16.200.200
********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
1234934mS PRN: VPNN: PBX 172.16.200.200 Not Responding or Reset AU=106
1240326mS PRN: SCNTFTP::SendPacket (3) seq=2214 len=330 retries=3 dest 172.16.110.200
1241619mS PRN: Config Write Wake Up
1242123mS PRN: Updates IO list size 0 updated list size 1
1242124mS PRN: Config Write Completed
1242761mS SIP Reg/Opt Rx: 11
OPTIONS sip:172.16.160.17 SIP/2.0
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac1109638626
Max-Forwards: 70
From: <sip:172.16.160.17>;tag=1c1109619778
To: <sip:M2K.celistics.com>
Call-ID: 11096186552612201217156@172.16.160.17
CSeq: 1 OPTIONS
Contact: <sip:172.16.160.17:5060>
Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE
User-Agent: Audiocodes-Sip-Gateway-Mediant 2000/v.6.40A.029.008
Accept: application/sdp, application/simple-message-summary, message/sipfrag
Content-Length: 0
1242763mS SIP Reg/Opt Tx: 11
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.160.17;branch=z9hG4bKac1109638626
From: <sip:172.16.160.17>;tag=1c1109619778
To: <sip:M2K.celistics.com>;tag=50bf277f5307f7c7
Call-ID: 11096186552612201217156@172.16.160.17
CSeq: 1 OPTIONS
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 570895200 2664430634 IN IP4 0.0.0.0
s=Session SDP
c=IN IP4 0.0.0.0
t=0 0
m=audio 8000 RTP/AVP 18 8 0 4
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:4 G723/16000
1244114mS PRN: VPNN: last_activity set for pbx 172.16.200.200
1244114mS PRN: ======= VPNN_RIP_PLATFORM_INFO 7.0.36 ========
1244116mS PRN: VPNN: - New connection 172.16.200.200
1245094mS PRN: SCNTFTP::SendPacket (3) seq=1776 len=330 retries=3 dest 172.16.81.200
1246147mS PRN: ParseRemoteBLF from 172.16.200.200: non-matching lengths? expected=0 len=28
1246190mS PRN: SCNTFTP::Process (3) DATA seq=2327 repeated len 291 dest 172.16.50.200
1246864mS PRN: SCNTFTP::SendPacket (3) seq=1751 len=343 retries=3 dest 172.16.100.200
1249881mS PRN: SCNTFTP::SendPacket (3) seq=2760 len=304 retries=3 dest 172.16.90.200
********** Warning: Logging to Screen Stopped **********