Michael,

The logs you show below suggests that OPTIONS polling is occurring, but there’s 
nothing suggesting that the registration attempt is working.

The STUN output suggests it’s unable to contact the STUN server? Is traffic 
allowed into the node on port 8888 – which is what you have configured, which 
is different from the default which is 3478? Can you see traffic on this port 
when you run tcpdump on the bono node?

It would be useful if you could provide the packet capture, taken from Bono. 
From what you’ve provided it looks like there’s still a connectivity issue 
between your client and the Bono node.


Richard

From: Clearwater [mailto:[email protected]] On 
Behalf Of ??????? ?ats?????
Sent: 23 August 2016 09:37
To: [email protected]
Cc: Chris Elford (projectclearwater.org) <[email protected]>
Subject: Re: [Project Clearwater] SIP Client cannot connect after Clearwater 
manual installation


Hi Chris,


thank you a lot for your answer.
I opened all needed ports in all the nodes as mentioned in 
http://clearwater.readthedocs.io/en/stable/Clearwater_IP_Port_Usage.html .
I also used tcpdump & netcat to monitor & test the connection and everything 
seems to be working fine.
Now i can see some interesting logs in Bono and Sprout but still the 
registration fails due to request timeout.

The logs from the nodes are the following:

Bono:

OPTIONS 
sip:[email protected]:5058<http://sip:[email protected]:5058> 
SIP/2.0
Via: SIP/2.0/TCP 192.168.99.131;rport;branch=z9hG4bK-108925
Max-Forwards: 2
To: <sip:[email protected]:5058<http://sip:[email protected]:5058>>
From: poll-sip 
<sip:[email protected]<mailto:sip%[email protected]>>;tag=108925
Call-ID: poll-sip-108925
CSeq: 108925 OPTIONS
Contact: <sip:192.168.99.131>
Accept: application/sdp
Content-Length: 0
User-Agent: poll-sip


--end msg--
05-08-2016 13:41:11.509 UTC Debug uri_classifier.cpp:169: home domain: false, 
local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
05-08-2016 13:41:11.509 UTC Debug uri_classifier.cpp:199: Classified URI as 3
05-08-2016 13:41:11.509 UTC Debug common_sip_processing.cpp:212: Skipping SAS 
logging for OPTIONS request
05-08-2016 13:41:11.509 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7f3e283eeb38 for worker threads
05-08-2016 13:41:11.509 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7f3e283eeb38
05-08-2016 13:41:11.509 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg OPTIONS/cseq=108925 (rdata0x7f3e283eeb38)
05-08-2016 13:41:11.509 UTC Debug uri_classifier.cpp:169: home domain: false, 
local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
05-08-2016 13:41:11.509 UTC Debug uri_classifier.cpp:199: Classified URI as 3
05-08-2016 13:41:11.509 UTC Debug pjsip:       endpoint Response msg 
200/OPTIONS/cseq=108925 (tdta0x7f3e2404d980) created
05-08-2016 13:41:11.509 UTC Verbose common_sip_processing.cpp:136: TX 290 bytes 
Response msg 200/OPTIONS/cseq=108925 (tdta0x7f3e2404d980) to TCP 
192.168.99.131:35677<http://192.168.99.131:35677>:
--start msg--

SIP/2.0 200 OK
Via: SIP/2.0/TCP 
192.168.99.131;rport=35677;received=192.168.99.131;branch=z9hG4bK-108925
Call-ID: poll-sip-108925
From: "poll-sip" 
<sip:[email protected]<mailto:sip%[email protected]>>;tag=108925
To: 
<sip:[email protected]<mailto:sip%[email protected]>>;tag=z9hG4bK-108925
CSeq: 108925 OPTIONS
Content-Length:  0


--end msg--
05-08-2016 13:41:11.509 UTC Debug common_sip_processing.cpp:254: Skipping SAS 
logging for OPTIONS response
05-08-2016 13:41:11.509 UTC Debug pjsip: tdta0x7f3e2404 Destroying txdata 
Response msg 200/OPTIONS/cseq=108925 (tdta0x7f3e2404d980)
05-08-2016 13:41:11.509 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7f3e283eeb38
05-08-2016 13:41:11.509 UTC Debug thread_dispatcher.cpp:199: Request latency = 
221us
05-08-2016 13:41:12.509 UTC Verbose pjsip: tcps0x7f3e283e TCP connection closed
05-08-2016 13:41:12.509 UTC Debug connection_tracker.cpp:92: Connection 
0x7f3e283ec298 has been destroyed
05-08-2016 13:41:12.509 UTC Verbose pjsip: tcps0x7f3e283e TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)


Sprout:

SIP/2.0 200 OK
Via: SIP/2.0/TCP 
192.168.99.132;rport=60774;received=192.168.99.132;branch=z9hG4bK-13204
Call-ID: poll-sip-13204
From: "poll-sip" 
<sip:[email protected]<mailto:sip%[email protected]>>;tag=13204
To: 
<sip:[email protected]<mailto:sip%[email protected]>>;tag=z9hG4bK-13204
CSeq: 13204 OPTIONS
Content-Length:  0


--end msg--
05-08-2016 13:21:30.373 UTC Debug common_sip_processing.cpp:254: Skipping SAS 
logging for OPTIONS response
05-08-2016 13:21:30.373 UTC Debug pjsip: tdta0x7fb31001 Destroying txdata 
Response msg 200/OPTIONS/cseq=13204 (tdta0x7fb310017c20)
05-08-2016 13:21:30.373 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7fb310097278
05-08-2016 13:21:30.373 UTC Debug thread_dispatcher.cpp:199: Request latency = 
225us
05-08-2016 13:21:30.380 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
05-08-2016 13:21:30.381 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
05-08-2016 13:21:30.907 UTC Verbose pjsip:    tcplis:5052 TCP listener 
192.168.99.132:5052<http://192.168.99.132:5052>: got incoming TCP connection 
from 192.168.99.131:50451<http://192.168.99.131:50451>, sock=753
05-08-2016 13:21:30.907 UTC Verbose pjsip: tcps0x7fb31009 TCP server transport 
created
05-08-2016 13:21:30.911 UTC Verbose pjsip: tcps0x7fb31000 TCP connection closed
05-08-2016 13:21:30.911 UTC Verbose pjsip: tcps0x7fb31000 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
05-08-2016 13:21:31.374 UTC Verbose pjsip: tcps0x7fb31007 TCP connection closed
05-08-2016 13:21:31.375 UTC Debug connection_tracker.cpp:92: Connection 
0x7fb31007ca08 has been destroyed
05-08-2016 13:21:31.375 UTC Verbose pjsip: tcps0x7fb31007 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
05-08-2016 13:21:33.268 UTC Debug alarm.cpp:253: Reraising all alarms with a 
known state
05-08-2016 13:21:33.268 UTC Status alarm.cpp:62: sprout issued 1001.1 alarm
^C
root@sprout:/var/log/sprout# netstat -tulpn | grep 7000
root@sprout:/var/log/sprout# tailf sprout_current.txt
05-08-2016 13:42:18.061 UTC Verbose pjsip: tcps0x7fb31004 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
05-08-2016 13:42:25.060 UTC Verbose pjsip:    tcplis:5052 TCP listener 
192.168.99.132:5052<http://192.168.99.132:5052>: got incoming TCP connection 
from 192.168.99.131:56176<http://192.168.99.131:56176>, sock=691
05-08-2016 13:42:25.060 UTC Verbose pjsip: tcps0x7fb31004 TCP server transport 
created
05-08-2016 13:42:25.067 UTC Verbose pjsip: tcps0x7fb31007 TCP connection closed
05-08-2016 13:42:25.067 UTC Verbose pjsip: tcps0x7fb31007 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
05-08-2016 13:42:25.989 UTC Verbose pjsip: tcps0x7fb31007 TCP transport 
destroyed normally
05-08-2016 13:42:26.060 UTC Verbose pjsip:    tcplis:5052 TCP listener 
192.168.99.132:5052<http://192.168.99.132:5052>: got incoming TCP connection 
from 192.168.99.131:36330<http://192.168.99.131:36330>, sock=693
05-08-2016 13:42:26.060 UTC Verbose pjsip: tcps0x7fb31007 TCP server transport 
created
05-08-2016 13:42:33.273 UTC Debug alarm.cpp:253: Reraising all alarms with a 
known state
05-08-2016 13:42:33.273 UTC Status alarm.cpp:62: sprout issued 1001.1 alarm
05-08-2016 13:42:34.989 UTC Verbose pjsip: tcps0x7fb31003 TCP transport 
destroyed normally
05-08-2016 13:42:35.061 UTC Verbose pjsip:    tcplis:5052 TCP listener 
192.168.99.132:5052<http://192.168.99.132:5052>: got incoming TCP connection 
from 192.168.99.131:52252<http://192.168.99.131:52252>, sock=707
05-08-2016 13:42:35.061 UTC Verbose pjsip: tcps0x7fb31003 TCP server transport 
created
05-08-2016 13:42:41.062 UTC Verbose pjsip:    tcplis:5052 TCP listener 
192.168.99.132:5052<http://192.168.99.132:5052>: got incoming TCP connection 
from 192.168.99.131:56261<http://192.168.99.131:56261>, sock=709
05-08-2016 13:42:41.062 UTC Verbose pjsip: tcps0x7fb31007 TCP server transport 
created
05-08-2016 13:42:41.064 UTC Verbose pjsip: tcps0x7fb31002 TCP connection closed
05-08-2016 13:42:41.064 UTC Verbose pjsip: tcps0x7fb31002 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)




Zoiper configuration:

domain: ims (or or bono_IP:port)
Username: 6505550731
Password: ***********
Caller ID Name: Clearwater

Auth.username:  6505550731@ims
Outbound Proxy: -

In Advanced options i choose "use custome STUN" option
with
Server Hostname/IP : bono_ip
Port: 8888



Zoiper logs:

Network discovered for STUN = 172.28.40.181; Blocked (STUN server could be 
down) (result =0)
Account registering. Account = '6505550731@ims' failed, protocol_code = 923, 
cause code =63 (service or option not available, unspecified)


I have checked restund service in my Bono node and it is running. If i restart 
the service the following logs appear.

httpdb: configured url 
http://hs.ims:8888/impi/%s/digest<http://hs.ims:8888/impi/%25s/digest>
httpd: using URI workaround
turn: server deployed behind static NAT 
addr=172.28.40.181:0<http://172.28.40.181:0>
turn: extended channels enabled


Could you help me ?

Thanks in advance,
Michael Katsoulis























2016-08-04 16:10 GMT+03:00 Chris Elford 
(projectclearwater.org<http://projectclearwater.org>) 
<[email protected]<mailto:[email protected]>>:
Hi Michael,

Thank you for getting in touch.

You say below that Zoiper and Ekiga are taking a long time to connect. From the 
fact that nothing is showing up in Bono’s logs, it sounds like the phones are 
never registering. Is that correct?

If the registrations are failing, and nothing is showing up in the Bono logs, 
it sounds like there may be something in your network stopping the 
registrations from getting through. This is possible even if the two machines 
can ping each other, as SIP traffic runs on a different port to pings. I would 
suggest using tcpdump to carry out a packet capture on Bono and check that all 
of the expected messages in the registration flow are getting through.

Yours,

Chris

From: Clearwater 
[mailto:[email protected]<mailto:[email protected]>]
 On Behalf Of ??????? ?ats?????
Sent: 04 August 2016 13:41
To: 
[email protected]<mailto:[email protected]>
Subject: [Project Clearwater] SIP Client cannot connect after Clearwater manual 
installation

Hi All,

i have just performed the manual installation of project Clearwater using 6 
nodes (1x ellis, 1x bono, 1x sprout, 1x homer, 1x homestead, 1x ralf)

Now I am trying to connect a SIP client (tried both with Zoiper and Ekiga). The 
VM in which Zoiper/Ekiga is installed has ping connectivity with the Clearwater 
nodes.


The system configuration is the following:

Shared Config:

 # Deployment definitions
home_domain=ims
sprout_hostname=sprout.ims
hs_hostname=hs.ims:8888
hs_provisioning_hostname=hs.im<http://hs.im>s:8889
ralf_hostname=ralf.ims:10888
xdms_hostname=homer.ims:7888


# Keys
signup_key=<secret>
turn_workaround=<secret>
ellis_api_key=<secret>
ellis_cookie_key=<secret>


local config : (for example in Bono node)

local_ip=192.168.99.131
public_ip=172.28.40.181
public_hostname=bono-1
etcd_cluster="192.168.99.130,192.168.99.131,192.168.88.132,192.168.99.133,192.168.99.134,192.168.99.135"


-----------------------------------------------------------------------------------
The process I follow to create the account is the following:

- Produce a number in Ellis dashboard:

Private Identity:

6505550731<tel:6505550731>@ims
Password: *******
only shown once


- Fill the required fields in the client:

  a) Ekiga
    name: Clearwater
    Registrar: ims (or bono_IP:port)
    User: 6505550731<tel:6505550731>
    Authentication user: 6505550731<tel:6505550731>@ims
    Password: ********

   b) Zoiper:
      user/user@host : 6505550731<tel:6505550731>
      Password: *********
      Domain / Outbound Proxy: ims (or bono_IP:port)

Both clients take a long time trying to connect but nothing (relative to the 
registration) seems to be written in the log files in any node.

The whole setup is behind a corporate proxy and I have configured the 
http[s]_proxy, no_proxy environment variables.

Can anyone help ?


Thanks,
Michael Katsoulis







_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org

Reply via email to