Extensions Strange Behaviour

Discussion in '3CX Phone System - General' started by parts, Sep 20, 2013.

Thread Status:
Not open for further replies.
  1. parts

    Joined:
    Jul 30, 2013
    Messages:
    8
    Likes Received:
    0
    Extensions Strange Behaviour

    I have 5 extensions on my 3CX system V 12.

    1 VoIP connection outbound only

    I PSTN line connection via an OBi110 Gateway

    The System runs on a freestanding Atom based Windows 7 Box

    The Obi gateway and the VoIP are registered

    All extensions are registered

    All but one extension is in a ring group

    I can make calls via the VoIP trunk OK

    I can make calls between all extensions


    NOW HERE IS THE PROBLEM


    The system receives an incoming call and transfers it to an extension, but not an extension in the ring group, nor is it the operator extension

    If I direct the call to a specific extension from the inbound route the specified extension does not ring but the same extension as with the call group does.



    Help Please
     
  2. craigreilly

    craigreilly Well-Known Member

    Joined:
    Feb 1, 2012
    Messages:
    3,313
    Likes Received:
    249
    Are you setting this up in the DID routes or in the VOIP Gateway settings?

    Posting the log files may be helpful so we can trace the path. Otherwise, we are just throwing random ideas at you for a wild goose chase. Be sure to turn on verbose mode when showing the logs.
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  3. parts

    Joined:
    Jul 30, 2013
    Messages:
    8
    Likes Received:
    0
    Here are the log files
    I
    The ring group is made up of extension 201 (A2 x.x.x.161 ) and 213 (7B x.x.x.160) Extension 202 (C6 x.x.x.156) is not included

    the last 2 digits of the MAC address for the extensions is in the brackets followed by the last 3 digits of the IP address

    The IP the Obi is x.x.x.5



    3-Sep-2013 10:36:31.540 Currently active calls [none]
    23-Sep-2013 10:35:59.540 Currently active calls [none]
    23-Sep-2013 10:35:32.700 L:144.2[Extn]: Terminating targets, reason: SIP ;cause=487 ;text="Request Cancelled"
    23-Sep-2013 10:35:32.700 Leg L:144.2[Extn] is terminated: Cause: 487 Request Cancelled/INVITE from 10.0.0.156:50551
    23-Sep-2013 10:35:32.700 L:144.2[Extn] got Terminated Recv 487/INVITE from 10.0.0.156:50551 tid=bf04a06e222bca01 Call-ID=ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.:
    SIP/2.0 487 Request Cancelled
    Via: SIP/2.0/UDP 10.0.0.10:5060;branch=z9hG4bK-d8754z-bf04a06e222bca01-1---d8754z-;rport
    Contact: <sip:202@10.0.0.156:5061;transport=udp>
    To: <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50
    From: <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    Call-ID: ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.
    CSeq: 1 INVITE
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE
    Server: Cisco-CP7940G/8.0
    Content-Length: 0
    Remote-Party-ID: "202" <sip:202@10.0.0.10>;party=called;id-type=subscriber;privacy=off;screen=yes
    23-Sep-2013 10:35:32.700 Terminated from <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50 to <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f; reason: Error
    23-Sep-2013 10:35:32.699 L:144.2[Extn] got Failure: Failure Recv 487/INVITE from 10.0.0.156:50551 tid=bf04a06e222bca01 Call-ID=ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.:
    SIP/2.0 487 Request Cancelled
    Via: SIP/2.0/UDP 10.0.0.10:5060;branch=z9hG4bK-d8754z-bf04a06e222bca01-1---d8754z-;rport
    Contact: <sip:202@10.0.0.156:5061;transport=udp>
    To: <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50
    From: <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    Call-ID: ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.
    CSeq: 1 INVITE
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE
    Server: Cisco-CP7940G/8.0
    Content-Length: 0
    Remote-Party-ID: "202" <sip:202@10.0.0.10>;party=called;id-type=subscriber;privacy=off;screen=yes
    23-Sep-2013 10:35:32.699 [CM503003]: Call(C:144): Call to <sip:202@10.0.0.10:5060> has failed; Cause: 487 Request Cancelled/INVITE from 10.0.0.156:50551
    23-Sep-2013 10:35:32.699 Session 258844 has failed in leg L:144.2[Extn] ; Cause: 487 Request Cancelled/INVITE from 10.0.0.156:50551
    23-Sep-2013 10:35:32.699 Failure from <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50 to <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    23-Sep-2013 10:35:32.461 [CM503008]: Call(C:144): Call is terminated
    23-Sep-2013 10:35:32.461 L:144.2[Extn]: Terminating targets, reason: SIP ;cause=200 ;text="Call terminated on user request"
    23-Sep-2013 10:35:32.458 Blocking refers for the Call(C:144)
    23-Sep-2013 10:35:32.458 Call(C:144) is terminated
    23-Sep-2013 10:35:32.456 ~Target=Ext:Ext.202
    23-Sep-2013 10:35:32.456 ~Route=Dev:sip:202@10.0.0.156:5061;transport=udp
    23-Sep-2013 10:35:32.456 Reason: SIP ;cause=487 ;text="Request Terminated"
    23-Sep-2013 10:35:32.456 L:144.1[Line:10001<<08003289393]: Terminating targets, reason: SIP ;cause=487 ;text="Request Terminated"
    23-Sep-2013 10:35:32.456 Leg L:144.1[Line:10001<<08003289393] is terminated: Cause: CANCEL from 10.0.0.5:5080
    23-Sep-2013 10:35:32.453 L:144.1[Line:10001<<08003289393] got Terminated Recv Req CANCEL from 10.0.0.5:5080 tid=-23ea0349 Call-ID=b5ec3fc4@10.0.0.5:
    CANCEL sip:10.0.0.10:5060 SIP/2.0
    Via: SIP/2.0/UDP 10.0.0.5:5080;branch=z9hG4bK-23ea0349;rport=5080
    Max-Forwards: 70
    To: <sip:10.0.0.10>
    From: <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    Call-ID: b5ec3fc4@10.0.0.5
    CSeq: 8002 CANCEL
    Proxy-Authorization: DIGEST algorithm=MD5,nonce="414d535c08509c4429:5d93ef3d735c8c36c038306867ea9f0c",realm="3CXPhoneSystem",response="63c2604c2532c49a17d85781af861a7b",uri="sip:10.0.0.10:5060",username="10001"
    User-Agent: OBIHAI/OBi110-1.3.0.2776
    Content-Length: 0
    23-Sep-2013 10:35:32.453 Terminated from <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d to <sip:10.0.0.10>;tag=a34d1b07; reason: RemoteBye
    23-Sep-2013 10:35:32.453 L:144.1[Line:10001<<08003289393] Sending: OnSendResp Send 487/INVITE from 0.0.0.0:0 tid=-23ea0349 Call-ID=b5ec3fc4@10.0.0.5:
    SIP/2.0 487 Request Terminated
    Via: SIP/2.0/UDP 10.0.0.5:5080;branch=z9hG4bK-23ea0349;rport=5080
    To: <sip:10.0.0.10>;tag=a34d1b07
    From: <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    Call-ID: b5ec3fc4@10.0.0.5
    CSeq: 8002 INVITE
    Content-Length: 0
    23-Sep-2013 10:35:32.453 SendMsg from <sip:10.0.0.10>;tag=a34d1b07 to <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    23-Sep-2013 10:35:32.452 L:144.1[Line:10001<<08003289393] Sending: OnSendResp Send 200/CANCEL from 0.0.0.0:0 tid=-23ea0349 Call-ID=b5ec3fc4@10.0.0.5:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 10.0.0.5:5080;branch=z9hG4bK-23ea0349;rport=5080
    Contact: <sip:10.0.0.10:5060>
    To: <sip:10.0.0.10>;tag=a34d1b07
    From: <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    Call-ID: b5ec3fc4@10.0.0.5
    CSeq: 8002 CANCEL
    Content-Length: 0
    23-Sep-2013 10:35:32.452 SendMsg from <sip:10.0.0.10>;tag=a34d1b07 to <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    23-Sep-2013 10:35:27.540 Currently active calls - 1: [144]
    23-Sep-2013 10:35:01.390 L:144.1[Line:10001<<08003289393] Sending: OnSendResp Send 180/INVITE from 0.0.0.0:0 tid=-23ea0349 Call-ID=b5ec3fc4@10.0.0.5:
    SIP/2.0 180 Ringing
    Via: SIP/2.0/UDP 10.0.0.5:5080;branch=z9hG4bK-23ea0349;rport=5080
    Contact: <sip:10.0.0.10:5060>
    To: <sip:10.0.0.10>;tag=a34d1b07
    From: <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    Call-ID: b5ec3fc4@10.0.0.5
    CSeq: 8002 INVITE
    Content-Length: 0
    23-Sep-2013 10:35:01.389 SendMsg from <sip:10.0.0.10>;tag=a34d1b07 to <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    23-Sep-2013 10:35:01.389 Provisional response arrived for session 258844 of Leg L:144.2[Extn]
    23-Sep-2013 10:35:01.389 L:144.2[Extn] got Provisional Recv 180/INVITE from 10.0.0.156:50551 tid=bf04a06e222bca01 Call-ID=ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.:
    SIP/2.0 180 Ringing
    Via: SIP/2.0/UDP 10.0.0.10:5060;branch=z9hG4bK-d8754z-bf04a06e222bca01-1---d8754z-;rport
    Contact: <sip:202@10.0.0.156:5061;transport=udp>
    To: <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50
    From: <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    Call-ID: ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.
    CSeq: 1 INVITE
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE
    Server: Cisco-CP7940G/8.0
    Content-Length: 0
    Remote-Party-ID: "202" <sip:202@10.0.0.10>;party=called;id-type=subscriber;privacy=off;screen=yes
    23-Sep-2013 10:35:01.389 Provisional(180) from <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50 to <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    23-Sep-2013 10:35:01.389 [CM505001]: Endpoint Extn:202: Device info: Device Identified: [Man: Cisco;Mod: 7940;Rev: General] Capabilities:[reinvite, replaces, unable-no-sdp, no-recvonly] UserAgent: [Cisco-CP7940G/8.0] PBX contact: [sip:202@10.0.0.10:5060]
    23-Sep-2013 10:35:01.389 [CM503002]: Call(C:144): Alerting Extn:202 by contact <sip:202@10.0.0.156:5061>
    23-Sep-2013 10:35:01.387 UacSession 258844 has formed leg L:144.2[Extn]
    23-Sep-2013 10:35:01.386 Answer from <sip:202@10.0.0.10>;tag=0014a851f7c601204d630807-25b87d50 to <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    23-Sep-2013 10:35:01.106 [CM503025]: Call(C:144): Calling T:Extn:202@[Dev:sip:202@10.0.0.156:5061;transport=udp] for L:144.1[Line:10001<<08003289393]
    23-Sep-2013 10:35:01.106 Route to L:144.2[Extn] sends Invite-OUT Send Req INVITE from 0.0.0.0:0 tid=3f0744077179c76e Call-ID=ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.:
    INVITE sip:202@10.0.0.156:5061;transport=udp SIP/2.0
    Via: SIP/2.0/ ;branch=z9hG4bK-d8754z-3f0744077179c76e-1---d8754z-;rport
    Max-Forwards: 70
    Contact: <sip:08003289393@10.0.0.10:5060>
    To: <sip:202@10.0.0.10>
    From: <sip:08003289393@10.0.0.10:5060;nf=e>;tag=d51a0c1f
    Call-ID: ZTE3MDBmOTczNjYxZTExODMxZjk4MjYxZTBiZTYyZDI.
    CSeq: 1 INVITE
    Alert-Info: <http://www.notused.invalidtld>;info=external
    Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
    Content-Type: application/sdp
    Supported: replaces
    Content-Length: 351

    v=0
    o=3cxPS 445653188608 385238433793 IN IP4 10.0.0.10
    s=3cxPS Audio call
    c=IN IP4 10.0.0.10
    t=0 0
    m=audio 7018 RTP/AVP 0 8 3 13 9 110 99 101
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:3 GSM/8000
    a=rtpmap:13 CN/8000
    a=rtpmap:9 G722/8000
    a=rtpmap:110 iLBC/8000
    a=rtpmap:99 SPEEX/8000
    a=rtpmap:101 telephone-event/8000
    a=sendrecv
    23-Sep-2013 10:35:01.096 Outbound URI is used: sip:202@10.0.0.156:5061;transport=udp
    23-Sep-2013 10:35:01.096 SLA is globally disabled
    23-Sep-2013 10:35:01.095 Added leg L:144.2[Extn]
    23-Sep-2013 10:35:01.066 [Flow] Call(C:144): making call from L:144.1[Line:10001<<08003289393] to T:Extn:202@[Dev:sip:202@10.0.0.156:5061;transport=udp]
    23-Sep-2013 10:35:01.066 [CM503027]: Call(C:144): From: Line:10001<<08003289393 (<sip:08003289393@10.0.0.10:5060>) to T:Extn:202@[Dev:sip:202@10.0.0.156:5061;transport=udp]
    23-Sep-2013 10:35:01.066 [CM503004]: Call(C:144): Route 1: from L:144.1[Line:10001<<08003289393] to T:Extn:202@[Dev:sip:202@10.0.0.156:5061;transport=udp]
    23-Sep-2013 10:35:01.065 [Flow] Endpoint Extn:202 has no forwarding rule on reason 'All calls'
    23-Sep-2013 10:35:01.065 [Flow] Call(C:144): has built target endpoint: Extn:202 for call from L:144.1[Line:10001<<08003289393]
    23-Sep-2013 10:35:01.065 [Flow] Target endpoint for 202 is Extn:202
    23-Sep-2013 10:35:01.065 [Flow] Building target endpoint to 202 from <sip:08003289393@10.0.0.10:5060>
    23-Sep-2013 10:35:01.065 [CM503010]: Call(C:144): Making route(s) from Line:10001<<08003289393 to <sip:202@10.0.0.10:5060>
    23-Sep-2013 10:35:01.065 Remote SDP is set for leg L:144.1[Line:10001<<08003289393]
    23-Sep-2013 10:35:01.065 OnOffer from <sip:08003289393@10.0.0.10:5060;nf=e>
    23-Sep-2013 10:35:01.065 [CM505002]: Gateway:[OBi] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [OBIHAI/OBi110-1.3.0.2776] PBX contact: [sip:10001@10.0.0.10:5060]
    23-Sep-2013 10:35:01.063 Inbound DID: ''; Phonebook Name: ''
    23-Sep-2013 10:35:01.063 [CM500002]: Call(C:144): Info on incoming INVITE from Line:10001<<08003289393:
    Invite-IN Recv Req INVITE from 10.0.0.5:5080 tid=-23ea0349 Call-ID=b5ec3fc4@10.0.0.5:
    INVITE sip:10.0.0.10:5060 SIP/2.0
    Via: SIP/2.0/UDP 10.0.0.5:5080;branch=z9hG4bK-23ea0349;rport=5080
    Max-Forwards: 70
    Contact: <sip:10001@10.0.0.5:5080>
    To: <sip:10.0.0.10>
    From: <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d
    Call-ID: b5ec3fc4@10.0.0.5
    CSeq: 8002 INVITE
    Expires: 60
    Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
    Content-Type: application/sdp
    Proxy-Authorization: DIGEST algorithm=MD5,nonce="414d535c08509c4429:5d93ef3d735c8c36c038306867ea9f0c",realm="3CXPhoneSystem",response="8342d1f0243defbd3d11b86f30b1e722",uri="sip:10.0.0.10:5060",username="10001"
    Supported: replaces
    User-Agent: OBIHAI/OBi110-1.3.0.2776
    Content-Length: 304
    Remote-Party-ID: <sip:08003289393@10.0.0.10>;party=calling;privacy=off

    v=0
    o=- 26415681 1 IN IP4 10.0.0.5
    s=-
    c=IN IP4 10.0.0.5
    t=0 0
    m=audio 16634 RTP/AVP 0 8 18 104 101
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:18 G729/8000
    a=rtpmap:104 G726-32/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=sendrecv
    a=ptime:20
    a=xg726bitorder:big-endian
    23-Sep-2013 10:35:01.063 [CM503001]: Call(C:144): Incoming call from Line:10001<<08003289393 to <sip:202@10.0.0.10:5060>
    23-Sep-2013 10:35:01.058 Line limit check: Current # of calls for line Lc:10001(@OBi[<sip:10001@10.0.0.5:5080>]) is 1; limit is 1
    23-Sep-2013 10:35:01.058 Blacklist check: number '08003289393', list: ''; result = false
    23-Sep-2013 10:35:01.052 Outbound URI is used: sip:10001@10.0.0.5:5080
    23-Sep-2013 10:35:01.045 [CM503012]: Inbound office hours rule (unnamed) for 10001 forwards to DN:202
    23-Sep-2013 10:35:01.044 [Flow] Looking for inbound target: called=; caller=<sip:08003289393@:5060>
    23-Sep-2013 10:35:01.044 CallerNameAddr: <sip:08003289393;nf=e>
    23-Sep-2013 10:35:01.044 Tenant's phonebook has failed to load!
    23-Sep-2013 10:35:01.044 Looking for phone number 08003289393 in tenant's 'default' phonebook
    23-Sep-2013 10:35:01.044 No inbound caller ID reformat rule is defined, or it is disabled ()
    23-Sep-2013 10:35:01.044 Line 10001 has been updated from DB
    23-Sep-2013 10:35:01.044 IncomingCall: C:144 from <sip:08003289393@10.0.0.10:5060> to <sip:mad:10.0.0.10:5060>
    23-Sep-2013 10:35:01.044 Added leg L:C:144.1[No endpoint yet]
    23-Sep-2013 10:35:01.043 UasSession 258841 started
    23-Sep-2013 10:35:01.043 Call from <sip:08003289393@10.0.0.10>;tag=SP13c20e1b63c20153d to <sip:10.0.0.10>;tag=a34d1b07
    23-Sep-2013 10:34:55.540 Currently active calls [none]
    23-Sep-2013 10:34:23.540 Currently active calls [none]
    23-Sep-2013 10:34:07.833 Line 10001 got Device: Dev(51):[sip:10001@10.0.0.5:5080 / 10001]
    23-Sep-2013 10:33:51.540 Currently active calls [none]


    Thanks for looking at this

    Chris
     
  4. parts

    Joined:
    Jul 30, 2013
    Messages:
    8
    Likes Received:
    0
    My inbound route was not set up in Voip provider section. Incoming route is UK PSTN


    parts
     
  5. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    10,744
    Likes Received:
    281
    So...what you're saying ,is...you solved it?
     
  6. parts

    Joined:
    Jul 30, 2013
    Messages:
    8
    Likes Received:
    0
    Sorry i have not responded earlier, I have had a virus , all clear now.

    No such luck.
    Ive tried rejigging the handsets/Extensions combinations there is always one extension that rings even when it is not in the ring group and is not the operator extension. I'm not sure what to next any ideas ?
     
  7. lneblett

    lneblett Well-Known Member

    Joined:
    Sep 7, 2010
    Messages:
    2,083
    Likes Received:
    61
    This is the portion of the log of interest:

    23-Sep-2013 10:35:01.045 [CM503012]: Inbound office hours rule (unnamed) for 10001 forwards to DN:20223-Sep-2013 10:35:01.065 [Flow] Endpoint Extn:202 has no forwarding rule on reason 'All calls'

    The call is coming in from the Obi and is checked against certain parameters and not finding any of significance, is then routed to extension 202 by an inbound rule. The system is clearly building the route to that extension and delivers to same whereupon the extension rang for approx. 30 seconds. It does not appear to be a phone issue, but rather that you need to look at the rules for the Obi gateway and see how defined to deliver calls that the system does not recognize via DID.

    The system is doing exactly as you indicate, but the logs only confirm it. They do not show that there is an error as they only show the actions, not how the system was/is set-up and what you want it to do. You should look at port/line 10001 and see how this is directed. I am assuming that the time of day and date that the log shows is in keeping with the system being in office hours.
     
Thread Status:
Not open for further replies.