New user and I have hit a brick wall. Cannot make any calls

[politby]

Hi all,

I have just installed 3cx on my Windows 2012 r2 server which is running on a LAN behind a Sophos UTM. I have forwarded all the appropriate ports as per the manual. The firewall checker reports all Ports OK.

I have successfully registered the server with my SIP provider. I have also successfully registered 2 clients, one Android phone and one Gigaset S685IP DECT phone, as extensions with the server.

Unfortunately I am unable to make any calls, neither internal nor external, from either extension. Internal calls go straight to voicemail and external calls fail immediately. Below is an excerpt from the activity log. The messages about not being able to build an endpoint are the results failed external calls. Internal calls generate the temporarily not available message.

09-feb-2016 08:43:57.368   [Flow] Target endpoint for 020202020 can not be built!
09-feb-2016 08:43:42.630   Call to T:Extn:10@[Dev:sip:[email protected]:5060] from L:13.1[Extn] failed, cause: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 08:43:42.630   [CM503003]: Call(C:13): Call to <sip:[email protected]:5060> has failed; Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 08:30:53.207   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 213.136.78.48 because it is on blocked UAs list
09-feb-2016 08:27:01.682   [Flow] Target endpoint for 0703624036 can not be built!
09-feb-2016 08:26:41.435   [Flow] Target endpoint for 020202020 can not be built!
09-feb-2016 08:06:52.497   [Flow] Target endpoint for 90510 can not be built!
09-feb-2016 08:06:33.699   [Flow] Target endpoint for 020202020 can not be built!
09-feb-2016 08:05:45.103   [Flow] Target endpoint for 020202020 can not be built!
09-feb-2016 07:37:01.702   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 188.138.33.113 because it is on blocked UAs list
09-feb-2016 07:20:33.028   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 142.54.174.26 because it is on blocked UAs list
09-feb-2016 07:18:58.367   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 63.141.238.58 because it is on blocked UAs list
09-feb-2016 06:26:43.885   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 78.31.65.132 because it is on blocked UAs list
09-feb-2016 05:56:55.763   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 178.162.198.135 because it is on blocked UAs list
09-feb-2016 05:16:49.970   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 188.138.102.149 because it is on blocked UAs list
09-feb-2016 04:09:35.307   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 63.141.238.58 because it is on blocked UAs list
09-feb-2016 03:09:28.334   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 209.239.123.96 because it is on blocked UAs list
09-feb-2016 02:25:00.878   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 142.54.174.26 because it is on blocked UAs list
09-feb-2016 00:53:24.268   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 63.141.238.58 because it is on blocked UAs list
09-feb-2016 00:47:27.836   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 108.59.4.198 because it is on blocked UAs list
09-feb-2016 00:04:09.572   PBX has dropped a message with 'User-Agent: friendly-scanner' from IP 188.138.41.218 because it is on blocked UAs list

There are also numerous messages about blocked IP addresses. Not sure if this has anything to do with my problem though.

I doubt the problem is caused by my Sophos UTM, as my Gigaset phone works perfectly when directly connected to my provider, and because I am not able to make internal calls either.

I really have no idea why this is not working or what I can do to troubleshoot further. Would very much appreciate any help from the community!

Many thanks

 

[NickD_3CX]

What is on IP 192.168.2.102?

 

[politby]

What is on IP 192.168.2.102?

That's my Gigaset S685IP. Static IP. .2 is the 3cx machine. The Gigaset says "no IP connection" when attempting a call.

Also now getting this

09-feb-2016 12:51:56.830   Line Lc:10000(@Affinity[<sip:[email protected]:5060>]) has not assigned rinstance '66a24b1f92941cdc' in its list of registered contacts!

Attaching log from Android device.

 

[leejor]

Did you create outbound rules?

What happens if you call (from some other, outside line) your own PSTN number? Do you see a 3CX log of the incoming call?

 

[politby]

Just to rule out problems with my FQDN I wiped everything and made a complete reinstall using just the local IP and the abyss web server rather than IIS.

I think I have made a little bit of progress. The situation right now is that calls from outside to my external number are in fact reaching the 3cx system. But they go directly to voicemail regardless of which extension I have it set to route the calls to. Below is the log from such an incoming call.

Media session IP ('c=' attribute) is not equal to the IP specified in contact header:
      Media session IP:88.131.198.35
      Contact IP:62.80.216.2
   Media session IP ('c=' attribute) is not equal to the SIP packet source(IP:port):
      Media session IP: 88.131.198.35
      Received from: 62.80.216.2
09-feb-2016 16:13:37.151   [CM503012]: Inbound office hours rule (unnamed) for 10000 forwards to DN:11
09-feb-2016 16:12:47.461   Line Lc:10000(@Affinity[<sip:[email protected]:5060>]) has not assigned rinstance '530c67d4d191f1d4' in its list of registered contacts!
09-feb-2016 16:12:47.454   [CM504004]: Registration succeeded for: Lc:10000(@Affinity[<sip:[email protected]:5060>])
09-feb-2016 16:12:47.215   [CM504003]: Sent registration request for Lc:10000(@Affinity[<sip:[email protected]:5060>])
09-feb-2016 16:09:24.352   Leg L:11.3[VMail] is terminated: Cause: BYE from PBX
09-feb-2016 16:09:24.352   [CM503008]: Call(C:11): Call is terminated
09-feb-2016 16:09:24.351   Leg L:11.1[Line:10000<<0703624036] is terminated: Cause: BYE from 62.80.216.2:5060
09-feb-2016 16:09:19.850   [CM503007]: Call(C:11): VMail:99 has joined, contact <sip:[email protected]:5483>
09-feb-2016 16:09:19.847   [CM503007]: Call(C:11): Line:10000<<0703624036 has joined, contact <sip:[email protected]:5060>
09-feb-2016 16:09:19.840   L:11.3[VMail] has joined to L:11.1[Line:10000<<0703624036]
09-feb-2016 16:09:19.840   NAT/ALG check:L:11.3[VMail] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
09-feb-2016 16:09:19.688   [CM503025]: Call(C:11): Calling T:VMail:99@[Dev:sip:[email protected]:5483;rinstance=a0fc53ea311f621c] for L:11.1[Line:10000<<0703624036]
09-feb-2016 16:09:19.633   [CM503005]: Call(C:11): Forwarding: T:VMail:99@[Dev:sip:[email protected]:5483;rinstance=a0fc53ea311f621c]
09-feb-2016 16:09:19.633   L:11.1[Line:10000<<0703624036] forwards call from Extn:10 to VMail:99 based on rule Fwd[Available/NoAnsw]
09-feb-2016 16:09:19.633   L:11.1[Line:10000<<0703624036] failed to reach Extn:10, reason Temporarily Unavailable
09-feb-2016 16:09:19.633   Leg L:11.2[Extn] is terminated: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:09:19.632   Call to T:Extn:10@[Dev:sip:[email protected]:5060] from L:11.1[Line:10000<<0703624036] failed, cause: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:09:19.632   [CM503003]: Call(C:11): Call to <sip:[email protected]:5060> has failed; Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:09:11.511   [CM503025]: Call(C:11): Calling T:Extn:10@[Dev:sip:[email protected]:5060] for L:11.1[Line:10000<<0703624036]
09-feb-2016 16:09:11.469   [CM503027]: Call(C:11): From: Line:10000<<0703624036 ("0703624036" <sip:[email protected]:5060>)  to  T:Extn:10@[Dev:sip:[email protected]:5060]
09-feb-2016 16:09:11.469   [CM503004]: Call(C:11): Route 1: from L:11.1[Line:10000<<0703624036] to T:Extn:10@[Dev:sip:[email protected]:5060]
09-feb-2016 16:09:11.467   [CM505003]: Provider:[Affinity] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [LEICA-1.8.39-RC3] PBX contact: [sip:[email protected]:5060]
09-feb-2016 16:09:11.466   [CM503001]: Call(C:11): Incoming call from Line:10000<<0703624036 to <sip:[email protected]:5060>
09-feb-2016 16:09:11.466   Line limit check: Current # of calls for line Lc:10000(@Affinity[<sip:[email protected]:5060>]) is 1; limit is 2
09-feb-2016 16:09:11.466   NAT/ALG check:L:11.1[Line:10000<<0703624036] REQUEST 'INVITE' - some of SIP/SDP headers may contain inconsistent information or modified by intermediate hop

I can make internal calls from the Android client but not from the Gigaset, however they also go directly to voicemail. Log below.

09-feb-2016 16:36:36.267   [CM504002]: Endpoint Extn:11: a contact is unregistered. Contact(s): []
09-feb-2016 16:34:54.631   Leg L:20.3[VMail] is terminated: Cause: BYE from PBX
09-feb-2016 16:34:54.631   [CM503008]: Call(C:20): Call is terminated
09-feb-2016 16:34:54.624   Leg L:20.1[Extn] is terminated: Cause: BYE from 127.0.0.1:56901
09-feb-2016 16:34:50.620   [CM503007]: Call(C:20): VMail:99 has joined, contact <sip:[email protected]:5483>
09-feb-2016 16:34:50.612   [CM503007]: Call(C:20): Extn:11 has joined, contact <sip:[email protected]:50195>
09-feb-2016 16:34:50.604   L:20.3[VMail] has joined to L:20.1[Extn]
09-feb-2016 16:34:50.604   NAT/ALG check:L:20.3[VMail] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
09-feb-2016 16:34:50.425   [CM503025]: Call(C:20): Calling T:VMail:99@[Dev:sip:[email protected]:5483;rinstance=a0fc53ea311f621c] for L:20.1[Extn]
09-feb-2016 16:34:50.370   [CM503005]: Call(C:20): Forwarding: T:VMail:99@[Dev:sip:[email protected]:5483;rinstance=a0fc53ea311f621c]
09-feb-2016 16:34:50.370   L:20.1[Extn] forwards call from Extn:10 to VMail:99 based on rule Fwd[Available/NoAnsw]
09-feb-2016 16:34:50.369   Leg L:20.2[Extn] is terminated: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:34:50.369   L:20.1[Extn] failed to reach Extn:10, reason Temporarily Unavailable
09-feb-2016 16:34:50.369   Call to T:Extn:10@[Dev:sip:[email protected]:5060] from L:20.1[Extn] failed, cause: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:34:50.369   [CM503003]: Call(C:20): Call to <sip:[email protected]:5060> has failed; Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060
09-feb-2016 16:34:42.259   [CM503025]: Call(C:20): Calling T:Extn:10@[Dev:sip:[email protected]:5060] for L:20.1[Extn]
09-feb-2016 16:34:42.207   [CM503027]: Call(C:20): From: Extn:11 ("Per-Olof Litby" <sip:[email protected]:5060>)  to  T:Extn:10@[Dev:sip:[email protected]:5060]
09-feb-2016 16:34:42.207   [CM503004]: Call(C:20): Route 1: from L:20.1[Extn] to T:Extn:10@[Dev:sip:[email protected]:5060]
09-feb-2016 16:34:42.205   [CM503001]: Call(C:20): Incoming call from Extn:11 to <sip:[email protected]:5060>

Outside calls fail immediately and do not generate anything in the log. On the Android phone I get the "destination not found" message, on the Gigaset I get "no IP connection".

It appears the server cannot establish any connection with the clients when trying to route incoming calls, and the clients cannot contact the server when trying to make calls.

Like I said in my first post, both clients register fine with the server and the latter clearly shows them as registered.

I have not set up any rules.

 

[NickD_3CX]

This line of code seems to mean that the GigaSet on IP 192.168.2.102 is returning a "480 Temporarily not available" message:

9-feb-2016 16:34:50.369 Leg L:20.2[Extn] is terminated: Cause: 480 Temporarily not available/INVITE from 192.168.2.102:5060

Try 2 things:
1) From the Android call *777 (this is a test/echo extension) and see if that works.
2) If #1 works, try calling from the Android to the GigaSet to see if the issue is generally incoming calls to the GigaSet.

Also you might want to consider making a capture on the server to see exactly what is going on and of there are messages being sent to the GigaSet from the Phone System.

 

[politby]

Well, as much as I hate to admit it this was clearly a case of RTFM.

If I had read the instructions I would have understood that I needed to create an outbound rule directing my extension group to the outgoing SIP trunk. No wonder I could not make any outgoing calls...

And with regards to the Gigaset, I have had it for such a long time that I had completely forgotten that it has a separate settings page to specify which connection is used for incoming and outgoing calls, respectively. I had not switched those settings over to the 3cx server. Again no surprise nothing worked.

Everything seems to be working fine now.