Hi Ellie,

Yes I have used hss_realm and I have set up the NAPTR/SRV records for the 
realm. This is on an external bind server that is on the same host as the 
OpenIMS HSS.

I have also used dig to verify that these are working. Looking in the homestead 
logs it would appear the realm is being resolved and homestead is connecting to 
the HSS.

As requested I have restarted the homestead service and captured the logs which 
I have attached.

I have also attached a pcap file which show the packets for the sip 
registration attempt.  NOTE: -The log and pcap files are from different 
instances. There is also exchange of diameter watch dog messages between 
homestead and the HSS.

If you use the following wireshark display filter it will show the relevant 
packets: -
(tcp.port==3868 && tcp.flags.push==1) || sip.from.user==6505550000 || 
(tcp.port==8888 && tcp.flags.push==1)

Looking in the logs and wireshark I can see that a diameter MAR message is sent 
to the HSS but it is timing out because it is not answered "within the timer 
delay" so an http 504 gateway timeout message is sent back to bono which 
translates this to a SIP 504 server timeout.

The diameter MAA message is received from the HSS though but outside of this 
"timer" so it is discarded as there is now no corresponding sent request. 

The MAA message is received no more than 15mS later.

Regards,
Graham

-----Original Message-----
From: Eleanor Merry [mailto:[email protected]] 
Sent: Thursday, 16 April 2015 12:16 a.m.
To: Graham Brown; [email protected]
Subject: RE: 504 Server Timeout

Hi Graham, 

It looks like your Homestead and your HSS haven't properly connected. 
How have you set up the external HSS? Have you used the hss_realm, and if so 
have you set up the NAPTR/SRV records for the realm?

Can you please restart Homestead (use 'sudo service homestead stop' and allow 
monit to restart Homestead), and then when Homestead has started up try to 
register your subscriber. Can you then send me the Homestead debug logs for 
this (they're in /var/log/homestead/)

Thanks, 

Ellie

-----Original Message-----
From: [email protected] 
[mailto:[email protected]] On Behalf Of Graham 
Brown
Sent: 15 April 2015 11:07
To: [email protected]
Subject: [Clearwater] 504 Server Timeout

Hi,

I have downloaded the all in one VM image and have successfully configured and 
run it up, then successfully registered two cisco 7960g sip phones. I was then 
able to call between these two phones.

Going to the next step I added an external HSS, that being the OpenIMSCore HSS.

Followed the guide for intergrating OpenIMS HSS at 
http://clearwater.readthedocs.org/en/latest/OpenIMSCore_HSS_Integration/index.html
 and 
http://clearwater.readthedocs.org/en/latest/External_HSS_Integration/index.html

Created an IMS subscription into OpenIMS HSS and then tried to sip register to 
it.

Using wireshark I can see a sip register arriving at bono and then being 
forwarded onto sprout.

An http get is then sent to homestead to retrieve authentication credentials 
but homestead replies with a 504 Gateway Timeout.

This is then translated into a sip 504 Server timout which is then sent back to 
the sip phone.

Increased the log level to 5 and the log from sprout output the following: -
15-04-2015 08:49:39.368 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg REGISTER/cseq=304 (rdata0x7f88380778c8)
15-04-2015 08:49:39.368 UTC Verbose common_sip_processing.cpp:120: RX 847 bytes 
Request msg REGISTER/cseq=304 (rdata0x7f88380778c8) from TCP 
192.168.4.119:46296:
--start msg--

REGISTER sip:example.com SIP/2.0
Via: SIP/2.0/TCP 
192.168.4.119:46296;rport;branch=z9hG4bKPjLfjWBNM0voZObNmC382lFGEWWkVkEaM-
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP 192.168.4.11:5060;received=192.168.4.11;branch=z9hG4bK44a86c03
From: <sip:[email protected]>;tag=00137fdb098600cd431abd83-6232fcdd
To: <sip:[email protected]>
Call-ID: [email protected]
Max-Forwards: 70
Date: Wed, 15 Apr 2015 08:49:39 GMT
CSeq: 304 REGISTER
User-Agent: Cisco-CP7960G/8.0
Contact: 
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00137fdb0986>";+u.sip!model.ccm.cisco.com="7"
Expires: 3600
P-Visited-Network-ID: example.com
Session-Expires: 600
Route: <sip:192.168.4.119:5054;transport=TCP;lr;orig>
Content-Length:  0


--end msg--
15-04-2015 08:49:39.369 UTC Debug statistic.cpp:103: Send new value for 
statistic incoming_requests, size 1
15-04-2015 08:49:39.369 UTC Debug zmq_lvc.cpp:172: Update to incoming_requests 
statistic
15-04-2015 08:49:39.369 UTC Debug zmq_lvc.cpp:256: Clearing message cache for 
0x7f886c02a270
15-04-2015 08:49:39.369 UTC Debug thread_dispatcher.cpp:236: Queuing cloned 
received message 0x7f883808e8f8 for worker threads
15-04-2015 08:49:39.369 UTC Debug statistic.cpp:103: Send new value for 
statistic queue_size, size 5
15-04-2015 08:49:39.369 UTC Debug zmq_lvc.cpp:172: Update to queue_size 
statistic
15-04-2015 08:49:39.369 UTC Debug zmq_lvc.cpp:256: Clearing message cache for 
0x7f886c0335b0
15-04-2015 08:49:39.369 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7f883808e8f8
15-04-2015 08:49:39.369 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg REGISTER/cseq=304 (rdata0x7f883808e8f8)
15-04-2015 08:49:39.369 UTC Debug acr.cpp:48: Created ACR (0x7f886c0ba4f0)
15-04-2015 08:49:39.369 UTC Debug authentication.cpp:644: No authentication 
information in request or stale nonce, so reject with challenge
15-04-2015 08:49:39.369 UTC Debug pjsip:       endpoint Response msg 
401/REGISTER/cseq=304 (tdta0x7f886c164210) created
15-04-2015 08:49:39.369 UTC Debug pjutils.cpp:470: Private identity defaulted 
from public identity = [email protected]
15-04-2015 08:49:39.370 UTC Debug httpconnection.cpp:191: Allocated CURL handle 
0x7f886c165220
15-04-2015 08:49:39.371 UTC Debug httpresolver.cpp:70: HttpResolver::resolve 
for host 192.168.4.119, port 8888, family 2
15-04-2015 08:49:39.371 UTC Debug baseresolver.cpp:501: Attempt to parse 
192.168.4.119 as IP address
15-04-2015 08:49:39.371 UTC Debug httpresolver.cpp:78: Target is an IP address
15-04-2015 08:49:39.371 UTC Debug httpconnection.cpp:604: Sending HTTP request 
: 
http://192.168.4.119:8888/impi/6505550000%40example.com/av?impu=sip%3A6505550000%40example.com
 (trying 192.168.4.119) on new connection
15-04-2015 08:49:39.373 UTC Debug httpconnection.cpp:619: Received HTTP 
response: status=504, doc=
15-04-2015 08:49:39.374 UTC Debug statistic.cpp:103: Send new value for 
statistic connected_homesteads, size 2
15-04-2015 08:49:39.374 UTC Debug zmq_lvc.cpp:172: Update to 
connected_homesteads statistic
15-04-2015 08:49:39.374 UTC Debug zmq_lvc.cpp:256: Clearing message cache for 
0x7f886c009cb0
15-04-2015 08:49:39.374 UTC Error httpconnection.cpp:738: cURL failure with 
cURL error code 0 (see man 3 libcurl-errors) and HTTP error code 504
15-04-2015 08:49:39.374 UTC Error hssconnection.cpp:145: Failed to get 
Authentication Vector for [email protected]
15-04-2015 08:49:39.374 UTC Debug authentication.cpp:408: Downstream node is 
overloaded or unresponsive, unable to get Authentication vector
15-04-2015 08:49:39.374 UTC Verbose common_sip_processing.cpp:136: TX 486 bytes 
Response msg 504/REGISTER/cseq=304 (tdta0x7f886c164210) to TCP 
192.168.4.119:46296:
--start msg--

SIP/2.0 504 Server Timeout
Via: SIP/2.0/TCP 
192.168.4.119:46296;rport=46296;received=192.168.4.119;branch=z9hG4bKPjLfjWBNM0voZObNmC382lFGEWWkVkEaM-
Via: SIP/2.0/UDP 192.168.4.11:5060;received=192.168.4.11;branch=z9hG4bK44a86c03
Call-ID: [email protected]
From: <sip:[email protected]>;tag=00137fdb098600cd431abd83-6232fcdd
To: <sip:[email protected]>;tag=z9hG4bKPjLfjWBNM0voZObNmC382lFGEWWkVkEaM-
CSeq: 304 REGISTER
Content-Length:  0


--end msg--
15-04-2015 08:49:39.374 UTC Debug pjsip: tdta0x7f886c16 Destroying txdata 
Response msg 504/REGISTER/cseq=304 (tdta0x7f886c164210)
15-04-2015 08:49:39.375 UTC Debug acr.cpp:82: Sending Null ACR (0x7f886c0ba4f0)
15-04-2015 08:49:39.375 UTC Debug acr.cpp:53: Destroyed ACR (0x7f886c0ba4f0)
15-04-2015 08:49:39.375 UTC Debug thread_dispatcher.cpp:176: Worker thread 
completed processing message 0x7f883808e8f8
15-04-2015 08:49:39.375 UTC Debug thread_dispatcher.cpp:182: Request latency = 
6176us
15-04-2015 08:49:39.375 UTC Debug statistic.cpp:103: Send new value for 
statistic latency_us, size 5
15-04-2015 08:49:39.375 UTC Debug zmq_lvc.cpp:172: Update to latency_us 
statistic
15-04-2015 08:49:39.375 UTC Debug zmq_lvc.cpp:256: Clearing message cache for 
0x7f886c012ff0
15-04-2015 08:49:39.375 UTC Debug load_monitor.cpp:184: Accepted 100.000000% of 
requests, latency error = -0.985710, overload responses = 3
15-04-2015 08:49:39.375 UTC Debug load_monitor.cpp:198: Decrease rate to 
19.380663

I can telnet to 192.168.4.119:8888 so quite sure socket is open: - # telnet 
192.168.4.119 8888 Trying 192.168.4.119...
Connected to 192.168.4.119.
Escape character is '^]'.
^]
telnet> quit
Connection closed.

Checked the logs on Cassandra and homestead but do not seem to see anything 
relevant to this??

What I have done wrong here?

Regards,
Graham Brown

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

Reply via email to