SIP Trunk weird behaviour - IPO500v2 behind Cisco NAT

[odhiambo0]

It's my first SIP Trunk ever, and it's my first IPO 500v2 ever so this is pretty new to me.

I have read so many articles enough to get my SIP Trunk up, but working with weird behavior. My IPO is connected using LAN1 behind a Cisco router. I has to forward port 5060 on the Cisco to the IP Address of the IPO (192.168.0.250). I also has to forward the RTP port range to IPO's address. Besides that, I also had to use one of those publicly available STUN servers.

I am still at the testing stage with this SIP provider - africaonline.co.ke. My Internet provider is a different company from them too. I have it in mind to get them to address routing issues so that it doesn't affect my traffic. However, before I get to that, I see some strange happenings. It's also my provider's first time to integrate an Avaya IPO with their SIP Switch. So both me and the VoIP engineer at their side are both rookies when it comes to this scenario.

When I dial the DID of the SIP Trunk, I can see packets read the IPO, but there is no ringing! If I do this a few times, then I get the ringing from the IPO. Below I paste the packets representing one such instance. Looking at this whole capture, the remote end did not yet give me a ring.

Any clues as to why this would be happening and how to solve?



257685mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=b5f1b21824
To: <sip:0206190790@192.168.0.250>
Call-ID: 102e8b34-1183fbaecfc7eed-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d227beb5d8181-43024396
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 177030584 177030585 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17662 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
258812mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=2ebbdc5fa6
To: <sip:0206190790@192.168.0.250>
Call-ID: 10354724-1183fbaecfc7eeb-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d22787463fd54-16f1c07c
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176959592 176959593 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17626 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
266953mS CMExtnEvt: OpsRanch Benaia: No user activity
272194mS H323Evt: Recv: RegistrationRequest 192.168.0.104; Endpoints registered: 3; Endpoints in registration: 0
272666mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
273248mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
273553mS H323Evt: Recv: RegistrationRequest 192.168.0.166; Endpoints registered: 3; Endpoints in registration: 0
273760mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=b5f1b21824
To: <sip:0206190790@192.168.0.250>
Call-ID: 102e8b34-1183fbaecfc7eed-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d227beb5d8181-43024396
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 177030584 177030585 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17662 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
274188mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
274969mS H323Evt: Recv: RegistrationRequest 192.168.40.99; Endpoints registered: 3; Endpoints in registration: 0
276224mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
280260mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
288250mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20

********** SysMonitor v10.1 (67) [connected to 192.168.0.250 (SEGERA-IPO500v2)] **********

********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********

********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
304291mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
INVITE sip:0206190790@192.168.0.250 SIP/2.0
From: <sip:732000004@41.207.65.195>;tag=6c8f0c0a68
To: <sip:0206190790@192.168.0.250>
Call-ID: 103dbb9c-1183fbaecfc7ef3-0022640775c4@41.207.65.197
CSeq: 1 INVITE
Via: SIP/2.0/UDP 41.207.65.197:5060;branch=z9hG4bK-d228307dcb1ba-4d373ef5
Max-Forwards: 69
Supported: timer
Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO
Contact: <sip:732000004@41.207.65.197:5060>
Min-SE: 90
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 278

v=0
o=Intel_IPCCLib 176882568 176882569 IN IP4 41.207.65.196
s=Dialogic_SIP_CCLLIB
i=session information
c=IN IP4 41.207.65.196
t=0 0
m=audio 17288 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=ptime:20
310644mS PRN: Monitor Status IP 500 V2 8.1(67)
310644mS PRN: LAW=A PRI=0, BRI=0, ALOG=0, VCOMP=32, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=0(TOT=1)
312553mS PRN: LoadCountControl: Marked As Successful Boot2
312818mS RES: Fri 17/5/2013 11:33:58 FreeMem=60218456 59939436(1) CachedMem=279020 CMMsg=5(5) Buff=5200 959 999 12479 5 Links=8182 BTree=0 CPU=3/4/44923/44923/50850/3
312818mS RES2: IP 500 V2 8.1(67) Tasks=44 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=49 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
312818mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
327195mS H323Evt: Recv: RegistrationRequest 192.168.0.104; Endpoints registered: 3; Endpoints in registration: 0
328554mS H323Evt: Recv: RegistrationRequest 192.168.0.166; Endpoints registered: 3; Endpoints in registration: 0

 

[holdmusic34]

Your SIP Provider may provide a full international number on their service, something like 254732000004(Check customer's account online with the carrier if possible).
You look to have entered only the national number in the SIP authentication tab (Users ->SIP).
If you can get the carrier to Peer the SIP service it makes things easier as well.

 

[IPOLackey]

Try disabling SIP ALG on the Cisco.

no ip nat service sip udp port 5060

 

[odhiambo0]

@holdmusic34, the SIP provider has given me the test number of +254206190790. I have entered this as-is on each extension's SIP authentication tab. Let me try again and see what happens. I am not sure I should have the (+) but most documents I've read during the exercise seem to say I can have it. Should I just enter 0206190790 without the +254, maybe?
Being a rookie with this, I am sorry to say I do not understand what you mean by "if you can get the carrier to Peer the SIP service". Could you kindly elaborate on that a little more? BTW, I am the customer here, configuring my own IPO since the SIP provider has no idea about it. It's my time to learn and I always value resources on this forum. I am sure I will get this hacked!

@IPOLackey, thanks for that. It seems like the piece that was missing in the jigsaw, though I need to test more..

Now my last (but not least) problem is getting outbound calls working. That has eaten into my two days with me struggling.

Here is what I have done:
I have the single test line as detailed before. It's been allocated some test credit - enough for the test.

Incoming call route works so far. It's configured as follows:
Line Group ID: 17 (Same as my SIP Line)
Incoming Number: 0206190790
Everything else is default, except the Destination = Extn4004

On my SIP Line, user URI, I have the following details on the only channel I have configured:
Channel 1
Local URI, Contact, Display Name, PAI - all are set to 0206190790
Registration : None
Incoming Group ID : 17
Outgoing Group ID : 17
Max Calls Per Channel : 30

Short Code is set as follows:

9N;
Dial
N@"41.207.65.197;
Line Group ID = 17

When I make a call, nothing appears to happen after I've dialed the last digit. However, if I remove the semicolon from the SC, I get INCOMPATIBLE ... with the second trace..

Trace 1:

856179mS PRN: 4004: Digit Pressed 9
856180mS CMCallEvt: 0.1008.0 -1 BaseEP: NEW CMEndpoint f51c99b0 TOTAL NOW=1 CALL_LIST=0
856180mS CMCallEvt: 0.1008.0 -1 OpsRanch Benaia.-1: NEW CMExtnEndpoint f51c99b0, Name=OpsRanch Benaia, Extn=4004, Phys Extn=3555
856181mS CMCallEvt: CREATE CALL:3 (f51c8df0)
856181mS CMCallEvt: 0.1009.0 -1 BaseEP: NEW CMEndpoint f51c7924 TOTAL NOW=2 CALL_LIST=0
856183mS CMExtnEvt: OpsRanch Benaia: CMExtnHandler::SetCurrent( id: 0->1008 )
856183mS CMExtnRx: v=4004, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
856184mS CMCallEvt: 272.1008.0 3 OpsRanch Benaia.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
856184mS CMExtnEvt: v=4 State, new=Dialling old=Idle,0,0,OpsRanch Benaia
856184mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=4004 dir=out complete=0 ses=0
856184mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
856185mS CMCallEvt: 272.1008.0 3 OpsRanch Benaia.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
856187mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 17/05/13 15:04
856188mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=4 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
856188mS CMExtnTx: v=4004, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Timed: 17/05/13 15:04
856189mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
856191mS CD: CALL: 272.1008.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=4004 (OpsRanch Benaia) Internal=1 Time=10 AState=Dialling
856192mS H323Evt: SetOperational 3 192.168.0.250:0 to 0
856287mS RES: Fri 17/5/2013 15:04:55 FreeMem=60195536 59886728(1) CachedMem=308808 CMMsg=6(6) Buff=5200 960 1000 12479 5 Links=7760 BTree=0 CPU=1/2/23569/49200/49721/3
856287mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=51 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=22 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
856287mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
856661mS PRN: 4004: Digit Pressed 0
856662mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
857081mS PRN: 4004: Digit Pressed 7
857082mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
857558mS PRN: 4004: Digit Pressed 3
857559mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
857909mS PRN: 4004: Digit Pressed 2
857909mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
858306mS PRN: 4004: Digit Pressed 0
858307mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
858613mS PRN: 4004: Digit Pressed 0
858614mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
859038mS PRN: 4004: Digit Pressed 0
859039mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
859354mS PRN: 4004: Digit Pressed 0
859354mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
859663mS PRN: 4004: Digit Pressed 0
859664mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
859981mS PRN: 4004: Digit Pressed 4
859982mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
860982mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: TimerExpired cause=CMTCDelayedProcessing
860982mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party=90732000004 sub= calling=4004 dir=out complete=0 ses=0
860982mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: ADD TARGET (N): number=90732000004 type=100 depth=1 nobar=1 setorig=1 ses=0
860982mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: SYS SC: 90732000004 2 0732000004 sc=type=Dial code=9N, num=N"@41.207.65.197" callinfop->sending_complete=0 secondary_dialtone=
860983mS CMARS: FindActiveARSByGroupID GroupID=17 - Not Found
860983mS CMLRQ: FindActiveLRQByGroupID GroupID=17 - Not Found
860984mS CMCallEvt: 0.1010.0 -1 BaseEP: NEW CMEndpoint f51b9c14 TOTAL NOW=3 CALL_LIST=1
860985mS CMTARGET: DIAL LINE: 3 GROUP = 17 SUCCESS = f51b9c14
860986mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: CancelTimer CMTCDialToneTimeout
860986mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: INITIAL TARGETING SUCCEEDED
860986mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: GetNoAnswerTimer:16
860986mS CMCallEvt: 0.1009.0 3 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
860987mS CMCallEvt: 17.1010.0 3 SIPTrunk Endpoint: StateChange: END=T CMCSIdle->CMCSOffering
860988mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 17 Call: lid=17 id=1010 in=0
Called[0732000004@41.207.65.197] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14626
user 'OpsRanch Benaia' presentation Allowed
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=4004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceH323Phone type=62 number=8021 channel=0 rx_gain=32 tx_gain=32 ep_callid=1008 ipaddr=192.168.0.250 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
Display [OpsRanch Benaia>0732000004]
Timed: 17/05/13 15:05
Locale: eng
860989mS CD: CALL: 272.1008.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="Line 17" [Line 17] (0.0) CalledNum=90732000004 () CallingNum=4004 (OpsRanch Benaia) Internal=0 Time=4808 AState=Dialling
861209mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
INVITE sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bKed604c2f50b67acc967bc369a08008ff
From: "254206190790" <sip:254206190790@41.207.65.197>;tag=e05f68ebdb6fa046
To: <sip:0732000004@41.207.65.197>
Call-ID: f0ed8552bb6a6e0532ac11352a2a677b
CSeq: 1426252164 INVITE
Contact: "254206190790" <sip:254206190790@41.215.76.82:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: timer
User-Agent: IP Office 8.1 (67)
P-Asserted-Identity: "Extn4004 - OpsRanch" <sip:+254206190790@41.215.76.82:5060>
Content-Length: 227

v=0
o=UserA 4236894816 3526259908 IN IP4 41.215.76.82
s=Session SDP
c=IN IP4 41.215.76.82
t=0 0
m=audio 16386 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
861255mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
SIP/2.0 404 Not Found
From: "254206190790"<sip:254206190790@41.207.65.197>;tag=e05f68ebdb6fa046
To: <sip:0732000004@41.207.65.197>;tag=15b5a8e0-c541cf29-13c4-55013-389b80-3fffa1e0-389b80
Call-ID: f0ed8552bb6a6e0532ac11352a2a677b
CSeq: 1426252164 INVITE
Via: SIP/2.0/UDP 41.215.76.82:5060;rport=5060;branch=z9hG4bKed604c2f50b67acc967bc369a08008ff
Content-Length: 0

861258mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
ACK sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bKed604c2f50b67acc967bc369a08008ff
From: "254206190790" <sip:254206190790@41.207.65.197>;tag=e05f68ebdb6fa046
To: <sip:0732000004@41.207.65.197>;tag=15b5a8e0-c541cf29-13c4-55013-389b80-3fffa1e0-389b80
Call-ID: f0ed8552bb6a6e0532ac11352a2a677b
CSeq: 1426252164 ACK
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
User-Agent: IP Office 8.1 (67)
Content-Length: 0

861259mS CMLineRx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=1010 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=90732000004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceSIPTrunk type=0 number=17 channel=1 rx_gain=32 tx_gain=32 ep_callid=1010 ipaddr=192.168.0.250 apps=0
Cause=1, Unallocated (unassigned) number
861259mS CMCallEvt: 0.1009.0 3 TargetingEP: RequestEnd 17.1010.0 3 SIPTrunk Endpoint
861259mS CMTARGET: 272.1008.0 3 OpsRanch Benaia.0: CancelTimer CMTCNoAnswerTimeout
861260mS CMCallEvt: 0.1009.0 -1 BaseEP: DELETE CMEndpoint f51c7924 TOTAL NOW=2 CALL_LIST=1
861260mS CMCallEvt: 17.1010.0 3 SIPTrunk Endpoint: StateChange: END=B CMCSOffering->CMCSCompleted
861261mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 15:05
861261mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=4 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
861263mS CMLOGGING: CALL:2013/05/1715:04,00:00:00,000,4004,O,0732000004@41.207.65.197,90732000004,OpsRanchBenaia,,,0,,""n/a,0
861263mS CD: CALL: 272.1008.0 BState=Disconnecting Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="Line 17" [Line 17] (0.0) CalledNum=0732000004@41.207.65.197 () CallingNum=4004 (OpsRanch Benaia) Internal=0 Time=5082 AState=Dialling
861263mS CD: CALL: 272.1008.0 Deleted
861265mS CMExtnEvt: OpsRanch Benaia: CALL LOST (CMCauseUnallocatedNumber)
861265mS CMExtnEvt: OpsRanch Benaia: Extn(4004) Calling Party Number(4004) Type(CMNTypeInternal)
861265mS CMCallEvt: 272.1008.0 -1 OpsRanch Benaia.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
861267mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1008 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 15:05
861267mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=4 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
861268mS CMExtnEvt: v=4 State, new=CMESCompleted old=Dialling,0,0,OpsRanch Benaia
861268mS CMCallEvt: 17.1010.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete
861268mS CMCallEvt: END CALL:3 (f51c8df0)
861269mS CMCallEvt: 17.1010.0 -1 BaseEP: DELETE CMEndpoint f51b9c14 TOTAL NOW=1 CALL_LIST=0
861271mS CMMap: PCG::AddToneGenerator g B3[6] for cp[94]b0r1 append pcp[96]b0r1 (total 1)
861271mS CMMap: a=6.1 b=0.0 IP::ReserveCodec pcp[96]b0r1 allocated CMRTVocoder resource busy 1, total 32, codec type 4
861271mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
861271mS CMMap: a=21.39 b=1.255 T
861271mS CMMap: a=21.39 b=6.1 M22
861272mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (connect) pcp[96]b0r1 echo_cancellation set to 0
861272mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[96]b0r1 Configure 6.1
861272mS CMMap: PlatformConnectionAudioSAP::ConnectVoice group 1 rtp_enc_codec 2 rtp_fwd_action 0X00000008 src_fwd_action 0X00000002
861272mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[96]b0r1 ConnectIndication 6.1
861272mS CMMap: a=0.0 b=0.0 pcp[94]b0r1 RTPB3
861272mS H323Evt: SetOperational 3 192.168.0.250:16384 to 1
861287mS RES: Fri 17/5/2013 15:05:00 FreeMem=60195600 59886204(1) CachedMem=309396 CMMsg=6(6) Buff=5200 950 1000 12479 5 Links=7750 BTree=0 CPU=1/3/23569/48720/49721/3
861287mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=53 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=22 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034

********** SysMonitor v10.1 (67) [connected to 192.168.0.250 (SEGERA-IPO500v2)] **********

********** Warning: Logging to Screen Stopped **********

Trace 2:

********** Warning: Missed 1 packet(s) Total late 0 packet(s) **********
1231958mS PRN: 4004: Digit Pressed 9
1231959mS CMCallEvt: 0.1034.0 -1 BaseEP: NEW CMEndpoint f51d261c TOTAL NOW=1 CALL_LIST=0
1231959mS CMCallEvt: 0.1034.0 -1 OpsRanch Benaia.-1: NEW CMExtnEndpoint f51d261c, Name=OpsRanch Benaia, Extn=4004, Phys Extn=3555
1231959mS CMCallEvt: CREATE CALL:14 (f51d1030)
1231960mS CMCallEvt: 0.1035.0 -1 BaseEP: NEW CMEndpoint f51cfb64 TOTAL NOW=2 CALL_LIST=0
1231961mS CMExtnEvt: OpsRanch Benaia: CMExtnHandler::SetCurrent( id: 0->1034 )
1231962mS CMExtnRx: v=4004, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
1231962mS CMCallEvt: 272.1034.0 14 OpsRanch Benaia.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
1231962mS CMExtnEvt: v=3 State, new=Dialling old=Idle,0,0,OpsRanch Benaia
1231963mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=4004 dir=out complete=0 ses=0
1231963mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
1231963mS CMCallEvt: 272.1034.0 14 OpsRanch Benaia.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
1231966mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 17/05/13 16:13
1231966mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1231967mS CMExtnTx: v=4004, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Timed: 17/05/13 16:13
1231967mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
1231970mS CD: CALL: 272.1034.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=4004 (OpsRanch Benaia) Internal=1 Time=11 AState=Dialling
1231971mS H323Evt: SetOperational 14 192.168.0.250:0 to 0
1232450mS RES: Fri 17/5/2013 16:13:44 FreeMem=60218896 59921760(1) CachedMem=297136 CMMsg=5(5) Buff=5200 960 1000 12479 5 Links=8222 BTree=0 CPU=1/1/17900/50862/51445/3
1232450mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=50 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
1232450mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
1232500mS PRN: 4004: Digit Pressed 0
1232500mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1232905mS PRN: 4004: Digit Pressed 7
1232905mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
1233415mS PRN: 4004: Digit Pressed 3
1233416mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
1233780mS PRN: 4004: Digit Pressed 2
1233781mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
1234288mS PRN: 4004: Digit Pressed 0
1234289mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1234561mS PRN: 4004: Digit Pressed 0
1234561mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1235075mS PRN: 4004: Digit Pressed 0
1235075mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1235360mS PRN: 4004: Digit Pressed 0
1235361mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1235959mS PRN: 4004: Digit Pressed 0
1235959mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
1236415mS PRN: 4004: Digit Pressed 4
1236415mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
1237415mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: TimerExpired cause=CMTCDelayedProcessing
1237415mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party=90732000004 sub= calling=4004 dir=out complete=0 ses=0
1237415mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: ADD TARGET (N): number=90732000004 type=100 depth=1 nobar=1 setorig=1 ses=0
1237416mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: SYS SC: 90732000004 2 0732000004 sc=type=Dial code=9N, num=N"@41.207.65.197" callinfop->sending_complete=0 secondary_dialtone=
1237416mS CMARS: FindActiveARSByGroupID GroupID=17 - Not Found
1237416mS CMLRQ: FindActiveLRQByGroupID GroupID=17 - Not Found
1237417mS CMCallEvt: 0.1036.0 -1 BaseEP: NEW CMEndpoint f51c33b4 TOTAL NOW=3 CALL_LIST=1
1237418mS CMTARGET: DIAL LINE: 14 GROUP = 17 SUCCESS = f51c33b4
1237419mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: CancelTimer CMTCDialToneTimeout
1237419mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: INITIAL TARGETING SUCCEEDED
1237419mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: GetNoAnswerTimer:16

********** Warning: Missed 2 packet(s) Total late 0 packet(s) **********
1237421mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 17 Call: lid=17 id=1036 in=0
Called[0732000004@41.207.65.197] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14631
user 'OpsRanch Benaia' presentation Allowed
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=4004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceH323Phone type=62 number=8021 channel=0 rx_gain=32 tx_gain=32 ep_callid=1034 ipaddr=192.168.0.250 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
Display [OpsRanch Benaia>0732000004]
Timed: 17/05/13 16:13
Locale: eng

********** Warning: Missed 4 packet(s) Total late 0 packet(s) **********
1237638mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
INVITE sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bK7fa91e5d50e1d19742a040693f08e2af
From: "0206190790" <sip:0206190790@41.207.65.197>;tag=53f097ba342309ce
To: <sip:0732000004@41.207.65.197>
Call-ID: 07b41202bec9c0e5f43b797ac1d6338a
CSeq: 2120888956 INVITE
Contact: "0206190790" <sip:0206190790@41.215.76.82:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: timer
User-Agent: IP Office 8.1 (67)
P-Asserted-Identity: "Extn4004 - OpsRanch" <sip:0206190790@41.215.76.82:5060>
Content-Length: 227

v=0
o=UserA 1627849794 2429922677 IN IP4 41.215.76.82
s=Session SDP
c=IN IP4 41.215.76.82
t=0 0
m=audio 16386 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
1237676mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
SIP/2.0 404 Not Found
From: "0206190790"<sip:0206190790@41.207.65.197>;tag=53f097ba342309ce
To: <sip:0732000004@41.207.65.197>;tag=15dea260-c541cf29-13c4-55013-38aba2-2131ded5-38aba2
Call-ID: 07b41202bec9c0e5f43b797ac1d6338a
CSeq: 2120888956 INVITE
Via: SIP/2.0/UDP 41.215.76.82:5060;rport=5060;branch=z9hG4bK7fa91e5d50e1d19742a040693f08e2af
Content-Length: 0

1237679mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
ACK sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bK7fa91e5d50e1d19742a040693f08e2af
From: "0206190790" <sip:0206190790@41.207.65.197>;tag=53f097ba342309ce
To: <sip:0732000004@41.207.65.197>;tag=15dea260-c541cf29-13c4-55013-38aba2-2131ded5-38aba2
Call-ID: 07b41202bec9c0e5f43b797ac1d6338a
CSeq: 2120888956 ACK
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
User-Agent: IP Office 8.1 (67)
Content-Length: 0

1237680mS CMLineRx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=1036 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=90732000004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceSIPTrunk type=0 number=17 channel=1 rx_gain=32 tx_gain=32 ep_callid=1036 ipaddr=192.168.0.250 apps=0
Cause=1, Unallocated (unassigned) number
1237681mS CMCallEvt: 0.1035.0 14 TargetingEP: RequestEnd 17.1036.0 14 SIPTrunk Endpoint
1237681mS CMTARGET: 272.1034.0 14 OpsRanch Benaia.0: CancelTimer CMTCNoAnswerTimeout
1237681mS CMCallEvt: 0.1035.0 -1 BaseEP: DELETE CMEndpoint f51cfb64 TOTAL NOW=2 CALL_LIST=1
1237681mS CMCallEvt: 17.1036.0 14 SIPTrunk Endpoint: StateChange: END=B CMCSOffering->CMCSCompleted
1237682mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 16:13
1237683mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1237684mS CMLOGGING: CALL:2013/05/1716:13,00:00:00,000,4004,O,0732000004@41.207.65.197,90732000004,OpsRanchBenaia,,,0,,""n/a,0
1237684mS CD: CALL: 272.1034.0 BState=Disconnecting Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="Line 17" [Line 17] (0.0) CalledNum=0732000004@41.207.65.197 () CallingNum=4004 (OpsRanch Benaia) Internal=0 Time=5725 AState=Dialling
1237684mS CD: CALL: 272.1034.0 Deleted
1237686mS CMExtnEvt: OpsRanch Benaia: CALL LOST (CMCauseUnallocatedNumber)
1237686mS CMExtnEvt: OpsRanch Benaia: Extn(4004) Calling Party Number(4004) Type(CMNTypeInternal)
1237686mS CMCallEvt: 272.1034.0 -1 OpsRanch Benaia.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
1237688mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1034 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 16:13
1237689mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
1237689mS CMExtnEvt: v=3 State, new=CMESCompleted old=Dialling,0,0,OpsRanch Benaia
1237689mS CMCallEvt: 17.1036.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete
1237690mS CMCallEvt: END CALL:14 (f51d1030)
1237691mS CMCallEvt: 17.1036.0 -1 BaseEP: DELETE CMEndpoint f51c33b4 TOTAL NOW=1 CALL_LIST=0
1237693mS CMMap: PCG::AddToneGenerator g B3[6] for cp[114]b0r1 append pcp[116]b0r1 (total 1)
1237694mS CMMap: a=6.1 b=0.0 IP::ReserveCodec pcp[116]b0r1 allocated CMRTVocoder resource busy 1, total 32, codec type 4
1237694mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
1237694mS CMMap: a=21.39 b=1.255 T

 

[tlpeter]

Yo need to put the @ after the "

So "@xxx.xxx.xxx.xxx" and not @"xxx.xxx.xxx.xxx"


BAZINGA!

I'm not insane, my mother had me tested!

 

[odhiambo0]

@tlpeter, mea culpa.

That was a typo, actually. As you can see, even the closing " was missing.

What I have is N"@41.207.65.197". Sorry for the misrepresentation. However, I believe the traces have the clue hidden in there.

 

[tlpeter]

Does it have a ; behind it or was that a typo too?

I do see a 404 in the trace:

v=0
o=UserA 4236894816 3526259908 IN IP4 41.215.76.82
s=Session SDP
c=IN IP4 41.215.76.82
t=0 0
m=audio 16386 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
861255mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
SIP/2.0 404 Not Found
From: "254206190790"<sip:254206190790@41.207.65.197>;tag=e05f68ebdb6fa046
To: <sip:0732000004@41.207.65.197>;tag=15b5a8e0-c541cf29-13c4-55013-389b80-3fffa1e0-389b80
Call-ID: f0ed8552bb6a6e0532ac11352a2a677b
CSeq: 1426252164 INVITE
Via: SIP/2.0/UDP 41.215.76.82:5060;rport=5060;branch=z9hG4bKed604c2f50b67acc967bc369a08008ff
Content-Length: 0

BAZINGA!

I'm not insane, my mother had me tested!

 

[odhiambo0]

Hmmm, lemme try this again.

When I have:
9N;
Dial
N"@41.207.65.197"
17

What does the 404 suggest in this scenario?

I get nothing happening. The dialed string stays on the phone screen until it times out:

Trace:


********** Warning: Missed 2 packet(s) Total late 0 packet(s) **********
4269823mS CMMap: a=6.1 b=0.0 IP::FreeCodec pcp[126]b0r1 freed CMRTVocoder resource busy 1, total 32
4271819mS CMExtnEvt: OpsRanch Benaia: Recover Timer reason=CMTRWrapUp
4271819mS CMExtnEvt: v=3 State, new=Idle old=PortRecoverDelay,0,0,OpsRanch Benaia
4271819mS CMExtnTx: v=4004, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[OpsRanch Benaia Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [OpsRanch Benaia Msgs=0]
Timed: 17/05/13 17:04
4274718mS RES: Fri 17/5/2013 17:04:26 FreeMem=60253332 59920828(1) CachedMem=332504 CMMsg=5(5) Buff=5200 960 1000 12479 5 Links=8414 BTree=0 CPU=1/2/17900/50848/51445/3
4274718mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=47 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4274718mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
4275350mS PRN: 4004: Digit Pressed 9
4275351mS CMCallEvt: 0.1048.0 -1 BaseEP: NEW CMEndpoint f51d261c TOTAL NOW=1 CALL_LIST=0
4275351mS CMCallEvt: 0.1048.0 -1 OpsRanch Benaia.-1: NEW CMExtnEndpoint f51d261c, Name=OpsRanch Benaia, Extn=4004, Phys Extn=3555
4275351mS CMCallEvt: CREATE CALL:19 (f51d1030)
4275352mS CMCallEvt: 0.1049.0 -1 BaseEP: NEW CMEndpoint f51cfb64 TOTAL NOW=2 CALL_LIST=0
4275353mS CMExtnEvt: OpsRanch Benaia: CMExtnHandler::SetCurrent( id: 0->1048 )
4275354mS CMExtnRx: v=4004, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
4275354mS CMCallEvt: 272.1048.0 19 OpsRanch Benaia.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
4275354mS CMExtnEvt: v=3 State, new=Dialling old=Idle,0,0,OpsRanch Benaia
4275355mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=4004 dir=out complete=0 ses=0
4275355mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
4275355mS CMCallEvt: 272.1048.0 19 OpsRanch Benaia.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
4275358mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 17/05/13 17:04
4275358mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4275359mS CMExtnTx: v=4004, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Timed: 17/05/13 17:04
4275359mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
4275362mS CD: CALL: 272.1048.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=4004 (OpsRanch Benaia) Internal=1 Time=11 AState=Dialling
4275363mS H323Evt: SetOperational 19 192.168.0.250:0 to 0
4275987mS PRN: 4004: Digit Pressed 0
4275987mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4276508mS PRN: 4004: Digit Pressed 7
4276509mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
4277002mS PRN: 4004: Digit Pressed 3
4277002mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
4277448mS PRN: 4004: Digit Pressed 2
4277448mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
4277797mS PRN: 4004: Digit Pressed 0
4277798mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4278269mS PRN: 4004: Digit Pressed 0
4278270mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4278800mS PRN: 4004: Digit Pressed 0
4278801mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4279163mS PRN: 4004: Digit Pressed 0
4279164mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4279653mS PRN: 4004: Digit Pressed 0
4279653mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4279718mS RES: Fri 17/5/2013 17:04:31 FreeMem=60218204 59920828(1) CachedMem=297376 CMMsg=5(5) Buff=5200 960 1000 12479 5 Links=8347 BTree=0 CPU=2/4/17900/49928/51445/3
4279718mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=53 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4279718mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
4280478mS PRN: 4004: Digit Pressed 4
4280479mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
4281479mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: TimerExpired cause=CMTCDelayedProcessing
4281479mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party=90732000004 sub= calling=4004 dir=out complete=0 ses=0
4281479mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: ADD TARGET (N): number=90732000004 type=100 depth=1 nobar=1 setorig=1 ses=0
4287496mS H323Evt: Recv: RegistrationRequest 192.168.0.104; Endpoints registered: 3; Endpoints in registration: 0
4288755mS H323Evt: Recv: RegistrationRequest 192.168.0.166; Endpoints registered: 3; Endpoints in registration: 0
4309720mS RES: Fri 17/5/2013 17:05:01 FreeMem=60217340 59920828(1) CachedMem=296512 CMMsg=5(5) Buff=5200 959 1000 12479 5 Links=8359 BTree=0 CPU=1/2/17900/50857/51445/3
4309720mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=47 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4309721mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)

********** SysMonitor v10.1 (67) [connected to 192.168.0.250 (SEGERA-IPO500v2)] **********
4310610mS PRN: Monitor Status IP 500 V2 8.1(67)
4310610mS PRN: LAW=A PRI=0, BRI=0, ALOG=0, VCOMP=32, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=1(TOT=19)
4315755mS RES: Fri 17/5/2013 17:05:08 FreeMem=60218204 59920432(1) CachedMem=297772 CMMsg=5(5) Buff=5200 960 1000 12479 5 Links=8365 BTree=0 CPU=1/2/10190/50752/51445/3
4315755mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=46 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4315756mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
4320594mS H323Evt: Recv: RegistrationRequest 192.168.40.127; Endpoints registered: 3; Endpoints in registration: 0
4340478mS CMExtnEvt: OpsRanch Benaia: No user activity
4341479mS CMTARGET: 272.1048.0 19 OpsRanch Benaia.0: TimerExpired cause=CMTCDialToneTimeout
4341479mS CMLOGGING: CALL:2013/05/1717:04,00:00:00,000,4004,O,90732000004,90732000004,OpsRanchBenaia,,,1,,""n/a,0
4341479mS CD: CALL: 272.1048.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="" [] (0.0) CalledNum=90732000004 () CallingNum=4004 (OpsRanch Benaia) Internal=1 Time=66128 AState=Dialling
4341479mS CD: CALL: 272.1048.0 Deleted
4341481mS CMExtnEvt: OpsRanch Benaia: CALL LOST (CMCauseDialToneTimeout)
4341481mS CMExtnEvt: OpsRanch Benaia: Extn(4004) Calling Party Number(4004) Type(CMNTypeInternal)
4341481mS CMCallEvt: 272.1048.0 -1 OpsRanch Benaia.0: StateChange: END=X CMCSDialling->CMCSCompleted
4341482mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 17:05
4341482mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4341483mS CMExtnEvt: v=3 State, new=PortRecoverDelay old=Dialling,0,0,OpsRanch Benaia
4341483mS CMExtnTx: v=4004, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=272 id=1048 in=0
Called[90732000004] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
Cause=171, Dial Tone Timeout(IPO)
Timed: 17/05/13 17:05
4341483mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4341483mS CMExtnEvt: OpsRanch Benaia: CMExtnHandler::SetCurrent( id: 1048->0 )
4341484mS CMCallEvt: 272.1048.0 -1 OpsRanch Benaia.-1: StateChange: END=X CMCSCompleted->CMCSDelete
4341485mS CMCallEvt: 0.1049.0 -1 BaseEP: DELETE CMEndpoint f51cfb64 TOTAL NOW=1 CALL_LIST=0
4341485mS CMCallEvt: END CALL:19 (f51d1030)
4341486mS CMTARGET: 272.1048.0 -1 BaseEP: ~CMTargetHandler f51c9c10 ep f51d261c
4341486mS CMCallEvt: 272.1048.0 -1 BaseEP: DELETE CMEndpoint f51d261c TOTAL NOW=0 CALL_LIST=0
4341487mS H323Evt: RTP(END): 192.168.0.250/16384 192.168.40.127/49770 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=66124 SENT=0 RECV=0 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
4341758mS RES: Fri 17/5/2013 17:05:33 FreeMem=60253332 59920432(1) CachedMem=332900 CMMsg=5(5) Buff=5200 956 1000 12479 5 Links=8446 BTree=0 CPU=8/13/10190/49755/51445/4
4341758mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=47 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4341758mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
4342496mS H323Evt: Recv: RegistrationRequest 192.168.0.104; Endpoints registered: 3; Endpoints in registration: 0
4343485mS CMExtnEvt: OpsRanch Benaia: Recover Timer reason=CMTRWrapUp
4343485mS CMExtnEvt: v=3 State, new=Idle old=PortRecoverDelay,0,0,OpsRanch Benaia
4343486mS CMExtnTx: v=4004, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[OpsRanch Benaia Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [OpsRanch Benaia Msgs=0]
Timed: 17/05/13 17:05
4343755mS H323Evt: Recv: RegistrationRequest 192.168.0.166; Endpoints registered: 3; Endpoints in registration: 0



I have also tried without the semicolon. That gives me INCOMPATIBLE:

4464779mS PRN: 4004: Digit Pressed 9
4464780mS CMCallEvt: 0.1050.0 -1 BaseEP: NEW CMEndpoint f51d261c TOTAL NOW=1 CALL_LIST=0
4464780mS CMCallEvt: 0.1050.0 -1 OpsRanch Benaia.-1: NEW CMExtnEndpoint f51d261c, Name=OpsRanch Benaia, Extn=4004, Phys Extn=3555
4464781mS CMCallEvt: CREATE CALL:20 (f51d1030)
4464781mS CMCallEvt: 0.1051.0 -1 BaseEP: NEW CMEndpoint f51cfb64 TOTAL NOW=2 CALL_LIST=0
4464783mS CMExtnEvt: OpsRanch Benaia: CMExtnHandler::SetCurrent( id: 0->1050 )
4464783mS CMExtnRx: v=4004, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
4464784mS CMCallEvt: 272.1050.0 20 OpsRanch Benaia.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
4464784mS CMExtnEvt: v=3 State, new=Dialling old=Idle,0,0,OpsRanch Benaia
4464784mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=4004 dir=out complete=0 ses=0
4464784mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
4464785mS CMCallEvt: 272.1050.0 20 OpsRanch Benaia.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
4464787mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 17/05/13 17:07
4464788mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4464788mS CMExtnTx: v=4004, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Timed: 17/05/13 17:07
4464789mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
4464791mS CD: CALL: 272.1050.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=4004 (OpsRanch Benaia) Internal=1 Time=10 AState=Dialling
4464792mS H323Evt: SetOperational 20 192.168.0.250:0 to 0
4464799mS RES: Fri 17/5/2013 17:07:36 FreeMem=60218228 59920432(1) CachedMem=297796 CMMsg=5(5) Buff=5200 957 1000 12479 5 Links=8573 BTree=0 CPU=12/17/10190/50021/51445/3
4464799mS RES2: IP 500 V2 8.1(67) Tasks=43 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=50 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=20 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
4464799mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
4465241mS PRN: 4004: Digit Pressed 0
4465241mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4465726mS PRN: 4004: Digit Pressed 7
4465727mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
4466161mS PRN: 4004: Digit Pressed 3
4466161mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
4466950mS PRN: 4004: Digit Pressed 2
4466950mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
4467091mS PRN: 4004: Digit Pressed 0
4467091mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4467248mS PRN: 4004: Digit Pressed 0
4467249mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4467806mS PRN: 4004: Digit Pressed 0
4467806mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4468156mS PRN: 4004: Digit Pressed 0
4468156mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4468538mS PRN: 4004: Digit Pressed 0
4468538mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
4468895mS PRN: 4004: Digit Pressed 4
4468895mS CMExtnRx: v=4004, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
4469895mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: TimerExpired cause=CMTCDelayedProcessing
4469895mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: LOOKUP CALL ROUTE: type=100 called_party=90732000004 sub= calling=4004 dir=out complete=0 ses=0
4469895mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: ADD TARGET (N): number=90732000004 type=100 depth=1 nobar=1 setorig=1 ses=0
4469895mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: SYS SC: 90732000004 2 0732000004 sc=type=Dial code=9N, num=N"@41.207.65.197" callinfop->sending_complete=0 secondary_dialtone=
4469896mS CMARS: FindActiveARSByGroupID GroupID=17 - Not Found
4469896mS CMLRQ: FindActiveLRQByGroupID GroupID=17 - Not Found
4469896mS CMCallEvt: 0.1052.0 -1 BaseEP: NEW CMEndpoint f51c33b4 TOTAL NOW=3 CALL_LIST=1
4469898mS CMTARGET: DIAL LINE: 20 GROUP = 17 SUCCESS = f51c33b4
4469898mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: CancelTimer CMTCDialToneTimeout
4469898mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: INITIAL TARGETING SUCCEEDED
4469898mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: GetNoAnswerTimer:16
4469899mS CMCallEvt: 0.1051.0 20 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
4469900mS CMCallEvt: 17.1052.0 20 SIPTrunk Endpoint: StateChange: END=T CMCSIdle->CMCSOffering
4469901mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 17 Call: lid=17 id=1052 in=0
Called[0732000004@41.207.65.197] Type=Default (100) Reason=CMDRdirect Calling[4004] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14635
user 'OpsRanch Benaia' presentation Allowed
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=OpsRanch Benaia
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=4004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceH323Phone type=62 number=8021 channel=0 rx_gain=32 tx_gain=32 ep_callid=1050 ipaddr=192.168.0.250 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
Display [OpsRanch Benaia>0732000004]
Timed: 17/05/13 17:07
Locale: eng
4469902mS CD: CALL: 272.1050.0 BState=Idle Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="Line 17" [Line 17] (0.0) CalledNum=90732000004 () CallingNum=4004 (OpsRanch Benaia) Internal=0 Time=5121 AState=Dialling
4470161mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
INVITE sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bKbe172cdbf25469a46807205d0019966c
From: "0206190790" <sip:0206190790@41.207.65.197>;tag=6277cb49dbb49bbf
To: <sip:0732000004@41.207.65.197>
Call-ID: 20edfb423178cddc2c07eb61fd213059
CSeq: 1414060381 INVITE
Contact: "0206190790" <sip:0206190790@41.215.76.82:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: timer
User-Agent: IP Office 8.1 (67)
P-Asserted-Identity: "Extn4004 - OpsRanch" <sip:0206190790@41.215.76.82:5060>
Content-Length: 226

v=0
o=UserA 2390565737 733839820 IN IP4 41.215.76.82
s=Session SDP
c=IN IP4 41.215.76.82
t=0 0
m=audio 16386 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
4470273mS SIP Rx: UDP 41.207.65.197:5060 -> 192.168.0.250:5060
SIP/2.0 404 Not Found
From: "0206190790"<sip:0206190790@41.207.65.197>;tag=6277cb49dbb49bbf
To: <sip:0732000004@41.207.65.197>;tag=15776820-c541cf29-13c4-55013-38b843-88ea841-38b843
Call-ID: 20edfb423178cddc2c07eb61fd213059
CSeq: 1414060381 INVITE
Via: SIP/2.0/UDP 41.215.76.82:5060;rport=5060;branch=z9hG4bKbe172cdbf25469a46807205d0019966c
Content-Length: 0

4470276mS SIP Tx: UDP 192.168.0.250:5060 -> 41.207.65.197:5060
ACK sip:0732000004@41.207.65.197 SIP/2.0
Via: SIP/2.0/UDP 41.215.76.82:5060;rport;branch=z9hG4bKbe172cdbf25469a46807205d0019966c
From: "0206190790" <sip:0206190790@41.207.65.197>;tag=6277cb49dbb49bbf
To: <sip:0732000004@41.207.65.197>;tag=15776820-c541cf29-13c4-55013-38b843-88ea841-38b843
Call-ID: 20edfb423178cddc2c07eb61fd213059
CSeq: 1414060381 ACK
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
User-Agent: IP Office 8.1 (67)
Content-Length: 0

4470277mS CMLineRx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=1052 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=90732000004
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceSIPTrunk type=0 number=17 channel=1 rx_gain=32 tx_gain=32 ep_callid=1052 ipaddr=192.168.0.250 apps=0
Cause=1, Unallocated (unassigned) number
4470277mS CMCallEvt: 0.1051.0 20 TargetingEP: RequestEnd 17.1052.0 20 SIPTrunk Endpoint
4470278mS CMTARGET: 272.1050.0 20 OpsRanch Benaia.0: CancelTimer CMTCNoAnswerTimeout
4470278mS CMCallEvt: 0.1051.0 -1 BaseEP: DELETE CMEndpoint f51cfb64 TOTAL NOW=2 CALL_LIST=1
4470278mS CMCallEvt: 17.1052.0 20 SIPTrunk Endpoint: StateChange: END=B CMCSOffering->CMCSCompleted
4470279mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 17:07
4470279mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4470281mS CMLOGGING: CALL:2013/05/1717:07,00:00:00,000,4004,O,0732000004@41.207.65.197,90732000004,OpsRanchBenaia,,,0,,""n/a,0
4470281mS CD: CALL: 272.1050.0 BState=Disconnecting Cut=0 Music=0.0 Aend="OpsRanch Benaia(4004)" (0.0) Bend="Line 17" [Line 17] (0.0) CalledNum=0732000004@41.207.65.197 () CallingNum=4004 (OpsRanch Benaia) Internal=0 Time=5500 AState=Dialling
4470281mS CD: CALL: 272.1050.0 Deleted
4470283mS CMExtnEvt: OpsRanch Benaia: CALL LOST (CMCauseUnallocatedNumber)
4470283mS CMExtnEvt: OpsRanch Benaia: Extn(4004) Calling Party Number(4004) Type(CMNTypeInternal)
4470283mS CMCallEvt: 272.1050.0 -1 OpsRanch Benaia.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
4470285mS CMExtnTx: v=4004, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=272 id=1050 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 17/05/13 17:07
4470285mS CMExtnTx: v=3555, p1=8021
CMFacility
Line: type=IPLine 250 Call: lid=272 id=3 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
4470286mS CMExtnEvt: v=3 State, new=CMESCompleted old=Dialling,0,0,OpsRanch Benaia
4470286mS CMCallEvt: 17.1052.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete
4470287mS CMCallEvt: END CALL:20 (f51d1030)
4470288mS CMCallEvt: 17.1052.0 -1 BaseEP: DELETE CMEndpoint f51c33b4 TOTAL NOW=1 CALL_LIST=0
4470289mS CMMap: PCG::AddToneGenerator g B3[6] for cp[128]b0r1 append pcp[130]b0r1 (total 1)
4470290mS CMMap: a=6.1 b=0.0 IP::ReserveCodec pcp[130]b0r1 allocated CMRTVocoder resource busy 1, total 32, codec type 4
4470290mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
4470290mS CMMap: a=21.39 b=1.255 T
4470290mS CMMap: a=21.39 b=6.1 M22
4470290mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (connect) pcp[130]b0r1 echo_cancellation set to 0
4470290mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[130]b0r1 Configure 6.1
4470291mS CMMap: PlatformConnectionAudioSAP::ConnectVoice group 1 rtp_enc_codec 2 rtp_fwd_action 0X00000008 src_fwd_action 0X00000002
4470291mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[130]b0r1 ConnectIndication 6.1
4470291mS CMMap: a=0.0 b=0.0 pcp[128]b0r1 RTPB3
4470291mS H323Evt: SetOperational 20 192.168.0.250:16384 to 1
4470299mS RES: Fri 17/5/2013 17:07:41 FreeMem=60218592 59920364(1) CachedMem=298228 CMMsg=5(5) Buff=5200 950 1000 12479 5 Links=8559 BTree=0 CPU=2/3/10190/50831/51445/3

********** Warning: Logging to Screen Stopped **********

 

[tlpeter]

Still a 404 and that means that the number dialer is not know on the other end.
Perhaps you must send a + in front?

BAZINGA!

I'm not insane, my mother had me tested!

 

[odhiambo0]

I will pick that 404 up with the Engineer at the SIP Provider.

 

[tlpeter]

All you need to know is what does the provider expect to receive from the IPO.
Put that in to the system and it should work.


BAZINGA!

I'm not insane, my mother had me tested!

 

[odhiambo0]

A big up to everyone who helped advise me on this mission. I am greatly indebted to all of you for your support.
My system is now up and running. It's my 1st SIP setup ever so you can imagine how pleased I am with myself, but it's because of you that I got the confidence to carry on!

My next step is to get a few staff members using SIP extensions, so they can be reachable anywhere!
From the help menu, I see all that is needed is IP Endpoint LICs. All this time I was thinking 3rd Party

Have a nice weekend everyone. If you ever happen to be in KE, ping me for a beer!

 

[IPGuru]

SIP does not play nicely with NAT
You will not get sip extns registering to the IP office from a public IP connection without a VPN.



A Maintenance contract is essential, not a Luxury.
Do things on the cheap & it will cost you dear

 

[odhiambo0]

Thanks for that! You've cleared my mind on something I was reading from the help page - registration domain.
Anyway, I guess I can beat that dog using Cisco! Time to extend the reading again.