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

[mfaster]

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:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK0a4a69c8
Max-Forwards: 70
Contact: <sip:[email protected]:5060;transport=udp>
To: <sip:[email protected]>
From: "BullPen-1"<sip:[email protected]>;tag=00137f1637ab0005c47b04b2-c1d5cf23
Call-ID: [email protected]
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:[email protected]",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:[email protected]>;party=calling;id-type=subscriber;privacy=off;screen=yes

<br>
09:33:03.984|.\CallCtrl.cpp(100)|Log2||CallCtrl:nIncomingCall:[CM503001]: Call(23): Incoming call from Ext.161 to <sip:[email protected]><br>
09:33:03.999|.\Extension.cpp(680)|Log3||Extension:rintEndpointInfo:[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:nSelectRouteReq:[CM503010]: Making route(s) to <sip:[email protected]><br>
09:33:03.999|.\CallCtrl.cpp(308)|Log2||CallCtrl:nSelectRouteReq:[CM503004]: Call(23): Calling: Ext:110@[Dev:sip:[email protected]: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:nFailure:[CM503003]: Call(23): Call to sip:[email protected] 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:[email protected]> 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:nNewCall:[CM500002]: Info on incoming INVITE:
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK34a68b03
Max-Forwards: 70
Contact: <sip:[email protected]:5060;transport=udp>
To: <sip:[email protected]>
From: "BullPen-1"<sip:[email protected]>;tag=00137f1637ab00068d603e3d-725682b4
Call-ID: [email protected]
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:[email protected]",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:[email protected]>;party=calling;id-type=subscriber;privacy=off;screen=yes

<br>
09:33:26.624|.\CallCtrl.cpp(100)|Log2||CallCtrl:nIncomingCall:[CM503001]: Call(24): Incoming call from Ext.161 to <sip:[email protected]><br>
09:33:26.640|.\Extension.cpp(680)|Log3||Extension:rintEndpointInfo:[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:nSelectRouteReq:[CM503010]: Making route(s) to <sip:[email protected]><br>
09:33:26.640|.\CallCtrl.cpp(308)|Log2||CallCtrl:nSelectRouteReq:[CM503004]: Call(24): Calling: Ext:110@[Dev:sip:[email protected]: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:nFailure:[CM503003]: Call(24): Call to sip:[email protected] 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:[email protected]> 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

 

[mfaster]

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:[email protected]] failed. Reason: Reason Unknown
16:25:25.937 CallLeg:nFailure [CM503003]: Call(38): Call to sip:[email protected] 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:nSelectRouteReq [CM503004]: Call(38): Calling: Ext:110@[Dev:sip:[email protected]:5060;transport=udp]
16:25:25.780 CallCtrl:nSelectRouteReq [CM503010]: Making route(s) to [sip:[email protected]]
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:rintEndpointInfo [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:nIncomingCall [CM503001]: Call(38): Incoming call from Ext.161 to [sip:[email protected]]
16:25:25.765 CallLeg:nNewCall [CM500002]: Info on incoming INVITE:
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.64.100:5060;branch=z9hG4bK3b26e9b2
Max-Forwards: 70
Contact: [sip:[email protected]:5060;transport=udp]
To: [sip:[email protected]]
From: "BullPen-1"[sip:[email protected]];tag=00137f1637ab00099d64a884-e6de21cf
Call-ID: [email protected]
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:[email protected]",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:[email protected]];party=calling;id-type=subscriber;privacy=off;screen=yes

 

[mfaster]

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:[email protected]:5060] failed. Reason: Reason Unknown
16:29:35.827 CallLeg:nFailure [CM503003]: Call(39): Call to sip:[email protected] 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:nSelectRouteReq [CM503004]: Call(39): Calling: Ext:110@[Dev:sip:[email protected]: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:nSelectRouteReq [CM503010]: Making route(s) to [sip:[email protected]:5060]
16:29:35.702 CallLeg::setRemoteSdp Remote SDP is set for legC:39.1
16:29:35.702 Extension:rintEndpointInfo [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:nIncomingCall [CM503001]: Call(39): Incoming call from Ext.170 to [sip:[email protected]:5060]
16:29:35.687 CallLeg:nNewCall [CM500002]: Info on incoming INVITE:
INVITE sip:[email protected]: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:[email protected]:5070]
To: [sip:[email protected]:5060]
From: "3CXPhone"[sip:[email protected]: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:[email protected]:5060",response="db28899c3841143c48cadd1d39ce43e8",algorithm=MD5
Supported: replaces
User-Agent: 3CX Phone v5.1
Content-Length: 0

 

[mfaster]

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