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
