V5.1 Extension registered-idle but calls to it fail

Discussion in '3CX Phone System - General' started by mfaster, May 21, 2008.

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

    Joined:
    Jun 19, 2007
    Messages:
    21
    Likes Received:
    0
    I'm running 3cx version 5.1.4510 in test config. I moved(pointed IP addr) a grandstream GXP2000 to my new PBX. The extension shows registered and idle but calls to it from inside or outside lines fail, GXP2000 is running 1.1.6.16 firmware. After I restart PBX the phone registers and works, but after 30 minutes seems to stop working while showing that it is registered and idle. I have Verbose logging turned on 3cx. Here's sample from failed call. please advise what other logs I can provide to help troubleshoot.

    And from a couple of other topics in these forums I have tried this Extension 110 with "Supports Re-Invite" set to off and then tested again with it on. Same result. Same phone config and extension worked fine with older 3cx version(s)

    Thanks

    INVITE sip:110@192.168.64.235 SIP/2.0
    Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK0a4a69c8
    Max-Forwards: 70
    Contact: <sip:7b452e87-4496-4762-e11f-b26751a1884b@192.168.64.100:5060;transport=udp>
    To: <sip:110@192.168.64.235>
    From: "BullPen-1"<sip:161@192.168.64.235>;tag=00137f1637ab0005c47b04b2-c1d5cf23
    Call-ID: 00137f16-37ab0004-7a66a9cc-6e66ce61@192.168.64.100
    CSeq: 102 INVITE
    Expires: 180
    Accept: application/sdp
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE, SUBSCRIBE
    Date: Mon, 08 May 2006 GMT
    Proxy-Authorization: Digest username="161",realm="3CXPhoneSystem",uri="sip:110@192.168.64.235",response="8c2de9ad28f0edf7b637e7d6d62f3f7e",nonce="12855774783:2731b57971082caf5f0f6189b14b8f3a",algorithm=MD5
    Supported: replaces, join, norefersub
    User-Agent: Cisco-CP7970G/8.0
    Allow-Events: kpml, dialog
    Content-Length: 0
    Remote-Party-ID: "BullPen-1" <sip:161@192.168.64.235>;party=calling;id-type=subscriber;privacy=off;screen=yes

    <br>
    09:33:03.984|.\CallCtrl.cpp(100)|Log2||CallCtrl::eek:nIncomingCall:[CM503001]: Call(23): Incoming call from Ext.161 to <sip:110@192.168.64.235><br>
    09:33:03.999|.\Extension.cpp(680)|Log3||Extension::printEndpointInfo:[CM505001]: Ext.161: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [Cisco-CP7970G/8.0] Transport: [sip:192.168.64.235:5060]<br>
    09:33:03.999|.\CallLeg.cpp(622)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:23.1<br>
    09:33:03.999|.\SLServer.cpp(382)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:23.1:Offer received. RTP connection: 192.168.64.100:27114(27115)<br>
    09:33:03.999|.\CallCtrl.cpp(228)|Log3||CallCtrl::eek:nSelectRouteReq:[CM503010]: Making route(s) to <sip:110@192.168.64.235><br>
    09:33:03.999|.\CallCtrl.cpp(308)|Log2||CallCtrl::eek:nSelectRouteReq:[CM503004]: Call(23): Calling: Ext:110@[Dev:sip:110@192.168.64.101:5060;transport=udp]<br>
    09:33:04.015|.\SLServer.cpp(382)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210002] C:23.2:Offer provided. Connection(transcoding mode): 192.168.64.235:7104(7105)<br>
    09:33:04.140|.\CallLeg.cpp(192)|Log2||CallLeg::eek:nFailure:[CM503003]: Call(23): Call to sip:110@192.168.64.235 has failed; Cause: 481 No Such Call; from IP:192.168.64.101:5060<br>
    09:33:04.140|.\Call.cpp(502)|Log2||Call::RouteFailed:[CM503014]: Call(23): Attempt to reach <sip:110@192.168.64.235> failed. Reason: Reason Unknown<br>
    09:33:04.171|.\Call.cpp(653)|Log2||Call::Terminate:[CM503008]: Call(23): Call is terminated<br>
    09:33:26.624|.\CallLeg.cpp(111)|Log5||CallLeg::eek:nNewCall:[CM500002]: Info on incoming INVITE:
    INVITE sip:110@192.168.64.235 SIP/2.0
    Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK34a68b03
    Max-Forwards: 70
    Contact: <sip:7b452e87-4496-4762-e11f-b26751a1884b@192.168.64.100:5060;transport=udp>
    To: <sip:110@192.168.64.235>
    From: "BullPen-1"<sip:161@192.168.64.235>;tag=00137f1637ab00068d603e3d-725682b4
    Call-ID: 00137f16-37ab0005-f059c2a7-9cce0e46@192.168.64.100
    CSeq: 102 INVITE
    Expires: 180
    Accept: application/sdp
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE, SUBSCRIBE
    Date: Mon, 08 May 2006 GMT
    Proxy-Authorization: Digest username="161",realm="3CXPhoneSystem",uri="sip:110@192.168.64.235",response="d88c9eb2cf2d1ba3d2ba95c736cafc59",nonce="12855774806:9870b1595ae9efb5dcc339da73993eb9",algorithm=MD5
    Supported: replaces, join, norefersub
    User-Agent: Cisco-CP7970G/8.0
    Allow-Events: kpml, dialog
    Content-Length: 0
    Remote-Party-ID: "BullPen-1" <sip:161@192.168.64.235>;party=calling;id-type=subscriber;privacy=off;screen=yes

    <br>
    09:33:26.624|.\CallCtrl.cpp(100)|Log2||CallCtrl::eek:nIncomingCall:[CM503001]: Call(24): Incoming call from Ext.161 to <sip:110@192.168.64.235><br>
    09:33:26.640|.\Extension.cpp(680)|Log3||Extension::printEndpointInfo:[CM505001]: Ext.161: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [Cisco-CP7970G/8.0] Transport: [sip:192.168.64.235:5060]<br>
    09:33:26.640|.\CallLeg.cpp(622)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:24.1<br>
    09:33:26.640|.\SLServer.cpp(382)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:24.1:Offer received. RTP connection: 192.168.64.100:31482(31483)<br>
    09:33:26.640|.\CallCtrl.cpp(228)|Log3||CallCtrl::eek:nSelectRouteReq:[CM503010]: Making route(s) to <sip:110@192.168.64.235><br>
    09:33:26.640|.\CallCtrl.cpp(308)|Log2||CallCtrl::eek:nSelectRouteReq:[CM503004]: Call(24): Calling: Ext:110@[Dev:sip:110@192.168.64.101:5060;transport=udp]<br>
    09:33:26.655|.\SLServer.cpp(382)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210002] C:24.2:Offer provided. Connection(transcoding mode): 192.168.64.235:7108(7109)<br>
    09:33:26.765|.\CallLeg.cpp(192)|Log2||CallLeg::eek:nFailure:[CM503003]: Call(24): Call to sip:110@192.168.64.235 has failed; Cause: 481 No Such Call; from IP:192.168.64.101:5060<br>
    09:33:26.780|.\Call.cpp(502)|Log2||Call::RouteFailed:[CM503014]: Call(24): Attempt to reach <sip:110@192.168.64.235> failed. Reason: Reason Unknown<br>
    09:33:26.796|.\Call.cpp(653)|Log2||Call::Terminate:[CM503008]: Call(24): Call is terminated<br>



    09:33:26.640|.\MSEndPoint.cpp(2244)|Trace5||??:New state0000003B@ SILENCE
    09:33:26.640|.\MSEndPoint.cpp(1311)|Log2||??:[MS210000] C:24.1:Offer received. RTP connection: 192.168.64.100:31482(31483)
    09:33:26.655|.\MediaServer.cpp(494)|Trace5||??:EndPoint created: (destination=192.168.64.101)
    EndPoint: ID=0000003C@(LOCAL)
    LOGID=C:24.2 Status: MSEP_LOCAL
    RTP:192.168.64.235:7108
    RTCP:192.168.64.235:7109
    STUN RTP:0.0.0.0:0
    STUN RTCP:0.0.0.0:0
    Coder:
    NOT SET
    101:telephony-event
    Party ptime:20
    Party RTP:0.0.0.0:0
    Party RTCP:0.0.0.0:0
    Decoders:
    <empty>

    09:33:26.655|.\MediaServer.cpp(940)|Trace5||??:EP 0000003C@ joined to call 24
    09:33:26.655|.\MediaServer.cpp(985)|Trace5||??:EndPoint 0000003C@ removed from call 24
    09:33:26.655|.\MediaServer.cpp(940)|Trace5||??:EP 0000003C@ joined to call 24
    09:33:26.655|.\MSEndPoint.cpp(958)|Log2||??:[MS210002] C:24.2:Offer provided. Connection(transcoding mode): 192.168.64.235:7108(7109)
    09:33:26.655|.\MediaServer.cpp(529)|Trace5||??:Get Local SDP. EP:C:24.2SDP:v=0
    o=3cxPS 71605157888 47596961793 IN IP4 192.168.64.235
    s=3cxPS Audio call
    c=IN IP4 192.168.64.235
    t=0 0
    m=audio 7108 RTP/AVP 0 8 3 13 18 110 99 101
    c=IN IP4 192.168.64.235
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:3 GSM/8000
    a=rtpmap:13 CN/8000
    a=rtpmap:18 G729/8000
    a=fmtp:18 annexb=no
    a=rtpmap:110 iLBC/8000
    a=rtpmap:99 SPEEX/8000
    a=rtpmap:101 telephone-event/8000
    a=sendrecv
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  2. mfaster

    Joined:
    Jun 19, 2007
    Messages:
    21
    Likes Received:
    0
    One more time with a clean log:

    16:25:25.952 Call::Terminate [CM503008]: Call(38): Call is terminated
    16:25:25.937 Call::RouteFailed [CM503014]: Call(38): Attempt to reach [sip:110@192.168.64.235] failed. Reason: Reason Unknown
    16:25:25.937 CallLeg::eek:nFailure [CM503003]: Call(38): Call to sip:110@192.168.64.235 has failed; Cause: 481 No Such Call; from IP:192.168.64.101:5060
    16:25:25.796 MediaServerReporting::SetRemoteParty [MS210002] C:38.2:Offer provided. Connection(transcoding mode): 192.168.64.235:7166(7167)
    16:25:25.780 CallCtrl::eek:nSelectRouteReq [CM503004]: Call(38): Calling: Ext:110@[Dev:sip:110@192.168.64.101:5060;transport=udp]
    16:25:25.780 CallCtrl::eek:nSelectRouteReq [CM503010]: Making route(s) to [sip:110@192.168.64.235]
    16:25:25.780 MediaServerReporting::SetRemoteParty [MS210000] C:38.1:Offer received. RTP connection: 192.168.64.100:31106(31107)
    16:25:25.780 CallLeg::setRemoteSdp Remote SDP is set for legC:38.1
    16:25:25.780 Extension::printEndpointInfo [CM505001]: Ext.161: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [Cisco-CP7970G/8.0] Transport: [sip:192.168.64.235:5060]
    16:25:25.765 CallCtrl::eek:nIncomingCall [CM503001]: Call(38): Incoming call from Ext.161 to [sip:110@192.168.64.235]
    16:25:25.765 CallLeg::eek:nNewCall [CM500002]: Info on incoming INVITE:
    INVITE sip:110@192.168.64.235 SIP/2.0
    Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK3b26e9b2
    Max-Forwards: 70
    Contact: [sip:7b452e87-4496-4762-e11f-b26751a1884b@192.168.64.100:5060;transport=udp]
    To: [sip:110@192.168.64.235]
    From: "BullPen-1"[sip:161@192.168.64.235];tag=00137f1637ab00099d64a884-e6de21cf
    Call-ID: 00137f16-37ab0007-c6266d76-23ff4749@192.168.64.100
    CSeq: 102 INVITE
    Expires: 180
    Accept: application/sdp
    Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, UPDATE, SUBSCRIBE
    Date: Mon, 08 May 2006 GMT
    Proxy-Authorization: Digest username="161",realm="3CXPhoneSystem",uri="sip:110@192.168.64.235",response="6af70b103767bb13ec90901c7533e295",nonce="12855799525:b29a55c7cfe4e63bbba00aecdd11e688",algorithm=MD5
    Supported: replaces, join, norefersub
    User-Agent: Cisco-CP7970G/8.0
    Allow-Events: kpml, dialog
    Content-Length: 0
    Remote-Party-ID: "BullPen-1" [sip:161@192.168.64.235];party=calling;id-type=subscriber;privacy=off;screen=yes
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  3. mfaster

    Joined:
    Jun 19, 2007
    Messages:
    21
    Likes Received:
    0
    Same result calling from a softphone

    16:29:35.859 Call::Terminate [CM503008]: Call(39): Call is terminated
    16:29:35.827 Call::RouteFailed [CM503014]: Call(39): Attempt to reach [sip:110@192.168.64.235:5060] failed. Reason: Reason Unknown
    16:29:35.827 CallLeg::eek:nFailure [CM503003]: Call(39): Call to sip:110@192.168.64.235 has failed; Cause: 481 No Such Call; from IP:192.168.64.101:5060
    16:29:35.718 MediaServerReporting::SetRemoteParty [MS210002] C:39.2:Offer provided. Connection(transcoding mode): 192.168.64.235:7170(7171)
    16:29:35.702 CallCtrl::eek:nSelectRouteReq [CM503004]: Call(39): Calling: Ext:110@[Dev:sip:110@192.168.64.101:5060;transport=udp]
    16:29:35.702 MediaServerReporting::SetRemoteParty [MS210000] C:39.1:Offer received. RTP connection: 192.168.64.109:42016(42017)
    16:29:35.702 CallCtrl::eek:nSelectRouteReq [CM503010]: Making route(s) to [sip:110@192.168.64.235:5060]
    16:29:35.702 CallLeg::setRemoteSdp Remote SDP is set for legC:39.1
    16:29:35.702 Extension::printEndpointInfo [CM505001]: Ext.170: Device info: Device Identified: [Man: 3CX Ltd.;Mod: 3CX VoIP Client;Rev: 1] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Phone v5.1] Transport: [sip:192.168.64.235:5060]
    16:29:35.687 CallCtrl::eek:nIncomingCall [CM503001]: Call(39): Incoming call from Ext.170 to [sip:110@192.168.64.235:5060]
    16:29:35.687 CallLeg::eek:nNewCall [CM500002]: Info on incoming INVITE:
    INVITE sip:110@192.168.64.235:5060 SIP/2.0
    Via: SIP/2.0/UDP 192.168.64.109:5070;branch=z9hG4bK-d87543-f95c687ae04be943-1--d87543-;rport=5070
    Max-Forwards: 70
    Contact: [sip:170@192.168.64.109:5070]
    To: [sip:110@192.168.64.235:5060]
    From: "3CXPhone"[sip:170@192.168.64.235:5060];tag=085e465a
    Call-ID: YWMwZTAwYWQ0MzZkZTVmZTNkMTQyOTk4MWZmZTZiNWY.
    CSeq: 2 INVITE
    Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, OPTIONS
    Proxy-Authorization: Digest username="170",realm="3CXPhoneSystem",nonce="12855799775:36c3bb3856958a08bd9d60b71e3627cb",uri="sip:110@192.168.64.235:5060",response="db28899c3841143c48cadd1d39ce43e8",algorithm=MD5
    Supported: replaces
    User-Agent: 3CX Phone v5.1
    Content-Length: 0
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  4. mfaster

    Joined:
    Jun 19, 2007
    Messages:
    21
    Likes Received:
    0
    Matt,

    I wasn't clear on your question regarding XP Pro. But here's the OS's involved"

    Softphone running on Win xp SP2 - ext 170
    3cx running on clean Win2k3 sp2
    extenstion 161 runs on Cisco 7970
    Extenstion 110 runs on GXP2000
    all calls internal ext to ext

    Both GXP2000 and Cisco 7970 lose registration after about 30 minutes. Calls to these extensions fail with error codes given in the logs already included

    thanks
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
Thread Status:
Not open for further replies.