Hi Simon, Thanks for the logs! We've checked them, it is the same cause, and we've raised an issue to track fixing this up in Chronos as well (https://github.com/Metaswitch/chronos/issues/85).
We release new stable builds regularly (currently it's roughly every two weeks). We post the release notes to the Project Clearwater blog (you can see this at http://www.projectclearwater.org/), and we also post them to the mailing list. The release note contains the new features and bug fixes in the release (you can see the last note at http://www.projectclearwater.org/sprint-omar-sharif-bridge-release-notes/). To upgrade your system, you can simply run 'sudo clearwater-upgrade' on each of your nodes. For your second question, we use Ellis as a provisioning server, and it provides a web GUI and HTTP API for user creation. Creating users in Ellis will create a user in the Ellis database *and* in the Homestead/Homer databases. When Sprout does a lookup for a subscriber it queries the Homestead/Homer databases, not the Ellis database. If you are using an external HSS (which isn't provided by Project Clearwater) then this provisions subscribers through its own management interface, and Ellis should not be used. You can find details of how to integrate with a HSS at: https://github.com/Metaswitch/clearwater-docs/wiki/External-HSS-Integration, and https://github.com/Metaswitch/clearwater-docs/wiki/OpenIMSCore%20HSS%20Integration. Ellie -----Original Message----- From: simon connolly [mailto:[email protected]] Sent: 29 September 2014 19:26 To: Eleanor Merry; [email protected] Subject: Re: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Ellie ive attached the latest 2 chronos trace file, let me know if you need more I restarted chronos and memcache and now successfully registered :) regarding latest code, I actually thought I had latest, can you give me some info about new releases ie how often do you put out new releases, whats procedure to upgrade to new package, how can I be notified about new releases etc other question I have is relating to using homer/homestead usage, is my understanding correct that ellis, due to limitations of mysql, is just a kind of beginners database to get phones registered out of the box so to speak, but homer and homestead are the real databases that should be sued for advance users ? how can I create subscribers in those databases, are there instructions ? when I register what is causing clearwater to check subscriber data in ellis database rather than homer/homestead databases, is it a setting ? rgs Simon -----Original Message----- From: Eleanor Merry Sent: Monday, September 29, 2014 6:44 PM To: simon connolly ; [email protected] Subject: RE: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Simon, This looks like you're hitting an issue with the system time. The authentication vector is successfully written to memcached ("Debug memcachedstore.cpp:542: Conditional write succeeded to replica 0") - however it's missing when Sprout comes to read it back ("Read for av\\[email protected]\0a55eab763c3eaed on replica 0 returned NOTFOUND"). This suggests that it's been expired. We've seen this issue before where there's been an NTP step change shortly after memcached has started - please see https://github.com/Metaswitch/cpp-common/issues/160 for more details. To work around this, you can kill and restart memcached. Alternatively, a fix to use relative time rather than absolute time for memcached expiry has been released, so if you update your node to the latest code you can use this fix (we recommend running up to date code as well!). There is also an issue where the Chronos timer (https://github.com/Metaswitch/chronos) is triggering immediately. This likely has the same cause (and so can be fixed by restarting Chronos) - but it would be really useful if you could send me the Chronos logs to check. These are in /var/log/chronos, and you turn on debug logging by adding the following to /etc/clearwater/chronos.conf: [logging] level = 5 On Windows, the base Zoiper UI only lets you set three parameters as you discovered. But you should be able to do Settings > Preferences and set the Auth username for the account that you set up. Thanks, Ellie -----Original Message----- From: simon connolly [mailto:[email protected]] Sent: 29 September 2014 09:53 To: Eleanor Merry; [email protected] Subject: Re: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Zoiper version is 3.6.25251 running on windows 7 here is the log trace requested OPTIONS sip:[email protected]:5054 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.68;rport;branch=z9hG4bK-2787 Max-Forwards: 2 To: <sip:[email protected]:5054> From: poll-sip <sip:[email protected]>;tag=2787 Call-ID: poll-sip-2787 CSeq: 2787 OPTIONS Contact: <sip:192.168.20.68> Accept: application/sdp Content-Length: 0 User-Agent: poll-sip --end msg-- 29-09-2014 08:45:59.903 UTC Debug statistic.cpp:103: Send new value for statistic incoming_requests, size 1 29-09-2014 08:45:59.903 UTC Debug zmq_lvc.cpp:167: Update to incoming_requests statistic 29-09-2014 08:45:59.903 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c02a170 29-09-2014 08:45:59.903 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f8924095e28 for worker threads 29-09-2014 08:45:59.903 UTC Debug statistic.cpp:103: Send new value for statistic queue_size, size 5 29-09-2014 08:45:59.903 UTC Debug zmq_lvc.cpp:167: Update to queue_size statistic 29-09-2014 08:45:59.903 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c0334b0 29-09-2014 08:45:59.903 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f8924095e28 29-09-2014 08:45:59.903 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=2787 (rdata0x7f8924095e28) 29-09-2014 08:45:59.903 UTC Debug pjsip: endpoint Response msg 200/OPTIONS/cseq=2787 (tdta0x7f8938000900) created 29-09-2014 08:45:59.904 UTC Verbose stack.cpp:248: TX 276 bytes Response msg 200/OPTIONS/cseq=2787 (tdta0x7f8938000900) to TCP 192.168.20.68:50873: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.20.68;rport=50873;received=192.168.20.68;branch=z9hG4bK-2787 Call-ID: poll-sip-2787 From: "poll-sip" <sip:[email protected]>;tag=2787 To: <sip:[email protected]>;tag=z9hG4bK-2787 CSeq: 2787 OPTIONS Content-Length: 0 --end msg-- 29-09-2014 08:45:59.904 UTC Debug pjsip: tdta0x7f893800 Destroying txdata Response msg 200/OPTIONS/cseq=2787 (tdta0x7f8938000900) 29-09-2014 08:45:59.904 UTC Debug stack.cpp:197: Worker thread completed processing message 0x7f8924095e28 29-09-2014 08:45:59.904 UTC Debug stack.cpp:203: Request latency = 133us 29-09-2014 08:45:59.904 UTC Debug statistic.cpp:103: Send new value for statistic latency_us, size 5 29-09-2014 08:45:59.904 UTC Debug zmq_lvc.cpp:167: Update to latency_us statistic 29-09-2014 08:45:59.904 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c013100 29-09-2014 08:46:00.912 UTC Verbose pjsip: tcps0x7f892409 TCP connection closed 29-09-2014 08:46:00.914 UTC Debug connection_tracker.cpp:91: Connection 0x7f89240914a8 has been destroyed 29-09-2014 08:46:00.914 UTC Verbose pjsip: tcps0x7f892409 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) 29-09-2014 08:46:01.517 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7f892406ede8) 29-09-2014 08:46:01.517 UTC Verbose stack.cpp:232: RX 814 bytes Request msg REGISTER/cseq=1 (rdata0x7f892406ede8) from TCP 192.168.20.68:49358: --start msg-- REGISTER sip:example.com SIP/2.0 Path: sip:[email protected]:5058;transport=TCP;lr;ob Via: SIP/2.0/TCP 192.168.20.68:49358;rport;branch=z9hG4bKPj4ioEyxnzVoaJN5mYM9xcW.suEUajmgKJ Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-6a40613a09e5ea33-1---d8754z- Max-Forwards: 69 Contact: <sip:[email protected]:5060;rinstance=8a6c503517a7e66d> To: "1005" <sip:[email protected]> From: "1005" <sip:[email protected]>;tag=1010416b Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc CSeq: 1 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO User-Agent: X-Lite release 4.5.5 stamp 71236 Session-Expires: 600 Route: <sip:192.168.20.68:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 29-09-2014 08:46:01.517 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f8924095e28 for worker threads 29-09-2014 08:46:01.517 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f8924095e28 29-09-2014 08:46:01.517 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7f8924095e28) 29-09-2014 08:46:01.517 UTC Debug acr.cpp:48: Created ACR (0x7f893403ab10) 29-09-2014 08:46:01.517 UTC Debug authentication.cpp:650: No authentication information in request or stale nonce, so reject with challenge 29-09-2014 08:46:01.517 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=1 (tdta0x7f89340009c0) created 29-09-2014 08:46:01.517 UTC Debug pjutils.cpp:439: Private identity defaulted from public identity = [email protected] 29-09-2014 08:46:01.518 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f893407fe90 29-09-2014 08:46:01.518 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 8888, family 2 29-09-2014 08:46:01.518 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.518 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.518 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:8888/impi/0000001005%40example.com/av?impu=sip%3A0000001005%40example.com (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.520 UTC Debug httpconnection.cpp:545: Received HTTP response : {"digest":{"ha1":"78b9f6376646ef8411472d40530519e0","realm":"example.com","qop":"auth"}} 29-09-2014 08:46:01.520 UTC Debug statistic.cpp:103: Send new value for statistic connected_homesteads, size 2 29-09-2014 08:46:01.520 UTC Debug zmq_lvc.cpp:167: Update to connected_homesteads statistic 29-09-2014 08:46:01.520 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c009dc0 29-09-2014 08:46:01.520 UTC Debug statistic.cpp:103: Send new value for statistic hss_latency_us, size 5 29-09-2014 08:46:01.520 UTC Debug zmq_lvc.cpp:167: Update to hss_latency_us statistic 29-09-2014 08:46:01.521 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c017a90 29-09-2014 08:46:01.521 UTC Debug statistic.cpp:103: Send new value for statistic hss_digest_latency_us, size 5 29-09-2014 08:46:01.521 UTC Debug zmq_lvc.cpp:167: Update to hss_digest_latency_us statistic 29-09-2014 08:46:01.521 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c01c430 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:147: Digest specified 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:309: Valid AV - generate challenge 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:315: Create WWW-Authenticate header 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:361: Add Digest information 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:390: Write AV to store 29-09-2014 08:46:01.521 UTC Debug avstore.cpp:66: Set AV for [email protected]\0a55eab763c3eaed {"branch":"z9hG4bKPj4ioEyxnzVoaJN5mYM9xcW.suEUajmgKJ","digest":{"ha1":"78b9f6376646ef8411472d40530519e0","qop":"auth","realm":"example.com"}} 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:449: Writing 142 bytes to table av key [email protected]\0a55eab763c3eaed, CAS = 0, expiry = 40 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:175: Set up new view 1 for thread 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:184: Setting up server 0 for connection 0x7f893404e610 (--CONNECT-TIMEOUT=10 --SUPPORT-CAS) 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:186: Set up connection 0x7f8934051730 to server 192.168.20.68:11211 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:228: Setting server to IP address 192.168.20.68 port 11211 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\0a55eab763c3eaed hashes to vbucket 104 via hash 0x1a977768 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:468: 1 write replicas for key av\\[email protected]\0a55eab763c3eaed 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:506: Attempt conditional write to replica 0 (connection 0x7f8934051730), CAS = 0 29-09-2014 08:46:01.521 UTC Debug memcachedstore.cpp:542: Conditional write succeeded to replica 0 29-09-2014 08:46:01.521 UTC Debug authentication.cpp:400: Sending {"impi": "[email protected]", "impu": "sip:[email protected]", "nonce": "0a55eab763c3eaed"} to Chronos to set AV timer 29-09-2014 08:46:01.521 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f89340bbe30 29-09-2014 08:46:01.523 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 7253, family 2 29-09-2014 08:46:01.523 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.523 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.523 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:7253/timers (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.523 UTC Debug httpconnection.cpp:825: Received header http/1.1200ok with value 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:825: Received header location with value /timers/000aa3a6400000068000000800600500 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:825: Received header date with value Mon,29Sep201408:46:01GMT 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:825: Received header content-length with value 0 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:825: Received header content-type with value text/html;charset=ISO-8859-1 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:825: Received header with value 29-09-2014 08:46:01.524 UTC Debug httpconnection.cpp:545: Received HTTP response : 29-09-2014 08:46:01.524 UTC Verbose stack.cpp:248: TX 630 bytes Response msg 401/REGISTER/cseq=1 (tdta0x7f89340009c0) to TCP 192.168.20.68:49358: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.20.68:49358;rport=49358;received=192.168.20.68;branch=z9hG4bKPj4ioEyxnzVoaJN5mYM9xcW.suEUajmgKJ Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-6a40613a09e5ea33-1---d8754z- Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc From: "1005" <sip:[email protected]>;tag=1010416b To: "1005" <sip:[email protected]>;tag=z9hG4bKPj4ioEyxnzVoaJN5mYM9xcW.suEUajmgKJ CSeq: 1 REGISTER WWW-Authenticate: Digest realm="example.com",nonce="0a55eab763c3eaed",opaque="2103703938968978",algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 29-09-2014 08:46:01.524 UTC Debug pjsip: tdta0x7f893400 Destroying txdata Response msg 401/REGISTER/cseq=1 (tdta0x7f89340009c0) 29-09-2014 08:46:01.524 UTC Debug acr.cpp:82: Sending Null ACR (0x7f893403ab10) 29-09-2014 08:46:01.524 UTC Debug acr.cpp:53: Destroyed ACR (0x7f893403ab10) 29-09-2014 08:46:01.524 UTC Debug stack.cpp:197: Worker thread completed processing message 0x7f8924095e28 29-09-2014 08:46:01.524 UTC Debug stack.cpp:203: Request latency = 6849us 29-09-2014 08:46:01.531 UTC Verbose httpstack.cpp:259: Process request for URL /authentication-timeout, args (null) 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\0a55eab763c3eaed hashes to vbucket 104 via hash 0x1a977768 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:304: 1 read replicas for key av\\[email protected]\0a55eab763c3eaed 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:337: Attempt to read from replica 0 (connection 0x7f8930010970) 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:343: Fetch result 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:373: Read for av\\[email protected]\0a55eab763c3eaed on replica 0 returned NOTFOUND 29-09-2014 08:46:01.531 UTC Debug memcachedstore.cpp:413: At least one replica returned not found, so return NOT_FOUND 29-09-2014 08:46:01.531 UTC Warning handlers.cpp:573: Could not find AV for [email protected]:0a55eab763c3eaed when checking authentication timeout 29-09-2014 08:46:01.531 UTC Debug handlers.cpp:167: Unable to handle callback from Chronos 29-09-2014 08:46:01.531 UTC Verbose httpstack.cpp:68: Sending response 500 to request for URL /authentication-timeout, args (null) 29-09-2014 08:46:01.532 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=2 (rdata0x7f89240778d8) 29-09-2014 08:46:01.532 UTC Verbose stack.cpp:232: RX 1094 bytes Request msg REGISTER/cseq=2 (rdata0x7f89240778d8) from TCP 192.168.20.68:40950: --start msg-- REGISTER sip:example.com SIP/2.0 Path: sip:[email protected]:5058;transport=TCP;lr;ob Via: SIP/2.0/TCP 192.168.20.68:40950;rport;branch=z9hG4bKPjzNFLAAN8lX9vyYgd-so-0.vLlfRKsJ64 Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-885d2d18b696975b-1---d8754z- Max-Forwards: 69 Contact: <sip:[email protected]:5060;rinstance=8a6c503517a7e66d> To: "1005" <sip:[email protected]> From: "1005" <sip:[email protected]>;tag=1010416b Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc CSeq: 2 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO User-Agent: X-Lite release 4.5.5 stamp 71236 Authorization: Digest username="[email protected]", realm="example.com", nonce="0a55eab763c3eaed", uri="sip:example.com", response="edaaac248b0ef5967db9ec09d4c387d3", algorithm=MD5, cnonce="8265ecf23493a455bcfb7f47d7eabe4e", opaque="2103703938968978", qop=auth, nc=00000001 Session-Expires: 600 Route: <sip:192.168.20.68:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 29-09-2014 08:46:01.532 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f8924095e28 for worker threads 29-09-2014 08:46:01.532 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f8924095e28 29-09-2014 08:46:01.532 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=2 (rdata0x7f8924095e28) 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:175: Set up new view 1 for thread 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:184: Setting up server 0 for connection 0x7f893c055e60 (--CONNECT-TIMEOUT=10 --SUPPORT-CAS) 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:186: Set up connection 0x7f893c055ec0 to server 192.168.20.68:11211 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:228: Setting server to IP address 192.168.20.68 port 11211 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\0a55eab763c3eaed hashes to vbucket 104 via hash 0x1a977768 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:304: 1 read replicas for key av\\[email protected]\0a55eab763c3eaed 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:337: Attempt to read from replica 0 (connection 0x7f893c055ec0) 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:343: Fetch result 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:373: Read for av\\[email protected]\0a55eab763c3eaed on replica 0 returned NOTFOUND 29-09-2014 08:46:01.532 UTC Debug memcachedstore.cpp:413: At least one replica returned not found, so return NOT_FOUND 29-09-2014 08:46:01.532 UTC Debug authentication.cpp:531: Verify authentication information in request 29-09-2014 08:46:01.532 UTC Warning authentication.cpp:205: Received an authentication request for [email protected] with nonce 0a55eab763c3eaed, but no matching AV found 29-09-2014 08:46:01.532 UTC Debug acr.cpp:48: Created ACR (0x7f893c05def0) 29-09-2014 08:46:01.533 UTC Debug authentication.cpp:650: No authentication information in request or stale nonce, so reject with challenge 29-09-2014 08:46:01.533 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=2 (tdta0x7f893c05df10) created 29-09-2014 08:46:01.533 UTC Debug pjutils.cpp:432: Private identity from authorization header = [email protected] 29-09-2014 08:46:01.533 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f893c05efa0 29-09-2014 08:46:01.534 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 8888, family 2 29-09-2014 08:46:01.534 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.534 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.534 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:8888/impi/0000001005%40example.com/av?impu=sip%3A0000001005%40example.com (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.536 UTC Debug httpconnection.cpp:545: Received HTTP response : {"digest":{"ha1":"78b9f6376646ef8411472d40530519e0","realm":"example.com","qop":"auth"}} 29-09-2014 08:46:01.536 UTC Debug statistic.cpp:103: Send new value for statistic connected_homesteads, size 2 29-09-2014 08:46:01.536 UTC Debug zmq_lvc.cpp:167: Update to connected_homesteads statistic 29-09-2014 08:46:01.536 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c009dc0 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:147: Digest specified 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:309: Valid AV - generate challenge 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:315: Create WWW-Authenticate header 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:361: Add Digest information 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:390: Write AV to store 29-09-2014 08:46:01.536 UTC Debug avstore.cpp:66: Set AV for [email protected]\20f6cb34339810b4 {"branch":"z9hG4bKPjzNFLAAN8lX9vyYgd-so-0.vLlfRKsJ64","digest":{"ha1":"78b9f6376646ef8411472d40530519e0","qop":"auth","realm":"example.com"}} 29-09-2014 08:46:01.536 UTC Debug memcachedstore.cpp:449: Writing 142 bytes to table av key [email protected]\20f6cb34339810b4, CAS = 0, expiry = 40 29-09-2014 08:46:01.536 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\20f6cb34339810b4 hashes to vbucket 31 via hash 0x834b2a1f 29-09-2014 08:46:01.536 UTC Debug memcachedstore.cpp:468: 1 write replicas for key av\\[email protected]\20f6cb34339810b4 29-09-2014 08:46:01.536 UTC Debug memcachedstore.cpp:506: Attempt conditional write to replica 0 (connection 0x7f893c055ec0), CAS = 0 29-09-2014 08:46:01.536 UTC Debug memcachedstore.cpp:542: Conditional write succeeded to replica 0 29-09-2014 08:46:01.536 UTC Debug authentication.cpp:400: Sending {"impi": "[email protected]", "impu": "sip:[email protected]", "nonce": "20f6cb34339810b4"} to Chronos to set AV timer 29-09-2014 08:46:01.536 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f893c097ff0 29-09-2014 08:46:01.537 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 7253, family 2 29-09-2014 08:46:01.537 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.537 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.537 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:7253/timers (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header http/1.1200ok with value 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header location with value /timers/000aa3a9c00000078000000800600500 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header date with value Mon,29Sep201408:46:01GMT 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header content-length with value 0 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header content-type with value text/html;charset=ISO-8859-1 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:825: Received header with value 29-09-2014 08:46:01.538 UTC Debug httpconnection.cpp:545: Received HTTP response : 29-09-2014 08:46:01.538 UTC Verbose stack.cpp:248: TX 630 bytes Response msg 401/REGISTER/cseq=2 (tdta0x7f893c05df10) to TCP 192.168.20.68:40950: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.20.68:40950;rport=40950;received=192.168.20.68;branch=z9hG4bKPjzNFLAAN8lX9vyYgd-so-0.vLlfRKsJ64 Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-885d2d18b696975b-1---d8754z- Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc From: "1005" <sip:[email protected]>;tag=1010416b To: "1005" <sip:[email protected]>;tag=z9hG4bKPjzNFLAAN8lX9vyYgd-so-0.vLlfRKsJ64 CSeq: 2 REGISTER WWW-Authenticate: Digest realm="example.com",nonce="20f6cb34339810b4",opaque="38e5df0d3d3d7da1",algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 29-09-2014 08:46:01.538 UTC Debug pjsip: tdta0x7f893c05 Destroying txdata Response msg 401/REGISTER/cseq=2 (tdta0x7f893c05df10) 29-09-2014 08:46:01.538 UTC Debug acr.cpp:82: Sending Null ACR (0x7f893c05def0) 29-09-2014 08:46:01.538 UTC Debug acr.cpp:53: Destroyed ACR (0x7f893c05def0) 29-09-2014 08:46:01.539 UTC Debug stack.cpp:197: Worker thread completed processing message 0x7f8924095e28 29-09-2014 08:46:01.539 UTC Debug stack.cpp:203: Request latency = 6651us 29-09-2014 08:46:01.541 UTC Verbose httpstack.cpp:259: Process request for URL /authentication-timeout, args (null) 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\20f6cb34339810b4 hashes to vbucket 31 via hash 0x834b2a1f 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:304: 1 read replicas for key av\\[email protected]\20f6cb34339810b4 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:337: Attempt to read from replica 0 (connection 0x7f8930010970) 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:343: Fetch result 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:373: Read for av\\[email protected]\20f6cb34339810b4 on replica 0 returned NOTFOUND 29-09-2014 08:46:01.541 UTC Debug memcachedstore.cpp:413: At least one replica returned not found, so return NOT_FOUND 29-09-2014 08:46:01.541 UTC Warning handlers.cpp:573: Could not find AV for [email protected]:20f6cb34339810b4 when checking authentication timeout 29-09-2014 08:46:01.541 UTC Debug handlers.cpp:167: Unable to handle callback from Chronos 29-09-2014 08:46:01.541 UTC Verbose httpstack.cpp:68: Sending response 500 to request for URL /authentication-timeout, args (null) 29-09-2014 08:46:01.550 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=3 (rdata0x7f8924026818) 29-09-2014 08:46:01.550 UTC Verbose stack.cpp:232: RX 1094 bytes Request msg REGISTER/cseq=3 (rdata0x7f8924026818) from TCP 192.168.20.68:38457: --start msg-- REGISTER sip:example.com SIP/2.0 Path: sip:[email protected]:5058;transport=TCP;lr;ob Via: SIP/2.0/TCP 192.168.20.68:38457;rport;branch=z9hG4bKPjj1VhM1fm-CSapcMiua.WV7Jq9UmhH4qa Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-b49d5e7d2feccc32-1---d8754z- Max-Forwards: 69 Contact: <sip:[email protected]:5060;rinstance=8a6c503517a7e66d> To: "1005" <sip:[email protected]> From: "1005" <sip:[email protected]>;tag=1010416b Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc CSeq: 3 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO User-Agent: X-Lite release 4.5.5 stamp 71236 Authorization: Digest username="[email protected]", realm="example.com", nonce="20f6cb34339810b4", uri="sip:example.com", response="b8d4d81c116c8fbce5e9c5dd39869edd", algorithm=MD5, cnonce="41134ec7947e98cf255bdb50a16df389", opaque="38e5df0d3d3d7da1", qop=auth, nc=00000001 Session-Expires: 600 Route: <sip:192.168.20.68:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 29-09-2014 08:46:01.550 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f8924095e28 for worker threads 29-09-2014 08:46:01.550 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f8924095e28 29-09-2014 08:46:01.550 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=3 (rdata0x7f8924095e28) 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:175: Set up new view 1 for thread 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:184: Setting up server 0 for connection 0x1ab95d0 (--CONNECT-TIMEOUT=10 --SUPPORT-CAS) 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:186: Set up connection 0x1a0eab0 to server 192.168.20.68:11211 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:228: Setting server to IP address 192.168.20.68 port 11211 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\20f6cb34339810b4 hashes to vbucket 31 via hash 0x834b2a1f 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:304: 1 read replicas for key av\\[email protected]\20f6cb34339810b4 29-09-2014 08:46:01.550 UTC Debug memcachedstore.cpp:337: Attempt to read from replica 0 (connection 0x1a0eab0) 29-09-2014 08:46:01.551 UTC Debug memcachedstore.cpp:343: Fetch result 29-09-2014 08:46:01.551 UTC Debug memcachedstore.cpp:373: Read for av\\[email protected]\20f6cb34339810b4 on replica 0 returned NOTFOUND 29-09-2014 08:46:01.551 UTC Debug memcachedstore.cpp:413: At least one replica returned not found, so return NOT_FOUND 29-09-2014 08:46:01.551 UTC Debug authentication.cpp:531: Verify authentication information in request 29-09-2014 08:46:01.551 UTC Warning authentication.cpp:205: Received an authentication request for [email protected] with nonce 20f6cb34339810b4, but no matching AV found 29-09-2014 08:46:01.551 UTC Debug acr.cpp:48: Created ACR (0x1b00d70) 29-09-2014 08:46:01.551 UTC Debug authentication.cpp:650: No authentication information in request or stale nonce, so reject with challenge 29-09-2014 08:46:01.551 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=3 (tdta0x1b00d90) created 29-09-2014 08:46:01.551 UTC Debug pjutils.cpp:432: Private identity from authorization header = [email protected] 29-09-2014 08:46:01.551 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x1b01e20 29-09-2014 08:46:01.553 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 8888, family 2 29-09-2014 08:46:01.553 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.553 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.553 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:8888/impi/0000001005%40example.com/av?impu=sip%3A0000001005%40example.com (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.557 UTC Debug httpconnection.cpp:545: Received HTTP response : {"digest":{"ha1":"78b9f6376646ef8411472d40530519e0","realm":"example.com","qop":"auth"}} 29-09-2014 08:46:01.558 UTC Debug statistic.cpp:103: Send new value for statistic connected_homesteads, size 2 29-09-2014 08:46:01.558 UTC Debug zmq_lvc.cpp:167: Update to connected_homesteads statistic 29-09-2014 08:46:01.558 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f893c009dc0 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:147: Digest specified 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:309: Valid AV - generate challenge 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:315: Create WWW-Authenticate header 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:361: Add Digest information 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:390: Write AV to store 29-09-2014 08:46:01.558 UTC Debug avstore.cpp:66: Set AV for [email protected]\16fd02d5209472a5 {"branch":"z9hG4bKPjj1VhM1fm-CSapcMiua.WV7Jq9UmhH4qa","digest":{"ha1":"78b9f6376646ef8411472d40530519e0","qop":"auth","realm":"example.com"}} 29-09-2014 08:46:01.558 UTC Debug memcachedstore.cpp:449: Writing 142 bytes to table av key [email protected]\16fd02d5209472a5, CAS = 0, expiry = 40 29-09-2014 08:46:01.558 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\16fd02d5209472a5 hashes to vbucket 102 via hash 0x7bdc1666 29-09-2014 08:46:01.558 UTC Debug memcachedstore.cpp:468: 1 write replicas for key av\\[email protected]\16fd02d5209472a5 29-09-2014 08:46:01.558 UTC Debug memcachedstore.cpp:506: Attempt conditional write to replica 0 (connection 0x1a0eab0), CAS = 0 29-09-2014 08:46:01.558 UTC Debug memcachedstore.cpp:542: Conditional write succeeded to replica 0 29-09-2014 08:46:01.558 UTC Debug authentication.cpp:400: Sending {"impi": "[email protected]", "impu": "sip:[email protected]", "nonce": "16fd02d5209472a5"} to Chronos to set AV timer 29-09-2014 08:46:01.558 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x1b3aff0 29-09-2014 08:46:01.559 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 192.168.20.68, port 7253, family 2 29-09-2014 08:46:01.559 UTC Debug baseresolver.cpp:480: Attempt to parse 192.168.20.68 as IP address 29-09-2014 08:46:01.559 UTC Debug httpresolver.cpp:78: Target is an IP address 29-09-2014 08:46:01.559 UTC Debug httpconnection.cpp:532: Sending HTTP request : http://192.168.20.68:7253/timers (trying 192.168.20.68) on new connection 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header http/1.1200ok with value 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header location with value /timers/000aa3af400000088000000800600500 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header date with value Mon,29Sep201408:46:01GMT 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header content-length with value 0 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header content-type with value text/html;charset=ISO-8859-1 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:825: Received header with value 29-09-2014 08:46:01.560 UTC Debug httpconnection.cpp:545: Received HTTP response : 29-09-2014 08:46:01.560 UTC Verbose stack.cpp:248: TX 630 bytes Response msg 401/REGISTER/cseq=3 (tdta0x1b00d90) to TCP 192.168.20.68:38457: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.20.68:38457;rport=38457;received=192.168.20.68;branch=z9hG4bKPjj1VhM1fm-CSapcMiua.WV7Jq9UmhH4qa Via: SIP/2.0/UDP 192.168.20.50:5060;rport=5060;received=192.168.20.50;branch=z9hG4bK-d8754z-b49d5e7d2feccc32-1---d8754z- Call-ID: YTg4NTdjYmVmNDE3NjZkMmUyNGExNzQ4MmRiODMwZDc From: "1005" <sip:[email protected]>;tag=1010416b To: "1005" <sip:[email protected]>;tag=z9hG4bKPjj1VhM1fm-CSapcMiua.WV7Jq9UmhH4qa CSeq: 3 REGISTER WWW-Authenticate: Digest realm="example.com",nonce="16fd02d5209472a5",opaque="358037802bee54a4",algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 29-09-2014 08:46:01.560 UTC Debug pjsip: tdta0x1b00d90 Destroying txdata Response msg 401/REGISTER/cseq=3 (tdta0x1b00d90) 29-09-2014 08:46:01.560 UTC Debug acr.cpp:82: Sending Null ACR (0x1b00d70) 29-09-2014 08:46:01.560 UTC Debug acr.cpp:53: Destroyed ACR (0x1b00d70) 29-09-2014 08:46:01.560 UTC Debug stack.cpp:197: Worker thread completed processing message 0x7f8924095e28 29-09-2014 08:46:01.560 UTC Debug stack.cpp:203: Request latency = 10026us 29-09-2014 08:46:01.563 UTC Verbose httpstack.cpp:259: Process request for URL /authentication-timeout, args (null) 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:260: Key av\\[email protected]\16fd02d5209472a5 hashes to vbucket 102 via hash 0x7bdc1666 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:304: 1 read replicas for key av\\[email protected]\16fd02d5209472a5 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:337: Attempt to read from replica 0 (connection 0x7f8930010970) 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:343: Fetch result 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:373: Read for av\\[email protected]\16fd02d5209472a5 on replica 0 returned NOTFOUND 29-09-2014 08:46:01.563 UTC Debug memcachedstore.cpp:413: At least one replica returned not found, so return NOT_FOUND 29-09-2014 08:46:01.563 UTC Warning handlers.cpp:573: Could not find AV for [email protected]:16fd02d5209472a5 when checking authentication timeout 29-09-2014 08:46:01.563 UTC Debug handlers.cpp:167: Unable to handle callback from Chronos 29-09-2014 08:46:01.563 UTC Verbose httpstack.cpp:68: Sending response 500 to request for URL /authentication-timeout, args (null) rgds Simon -----Original Message----- From: Eleanor Merry Sent: Friday, September 26, 2014 2:50 PM To: simon connolly ; [email protected] Subject: RE: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Simon, Your X-Lite configuration looks correct. Can you please send me the debug logs from Sprout from an attempted register? You can turn on debug logging by creating/editing the file /etc/clearwater/user_settings, adding log_level=5 and then restarting Sprout (service sprout stop - it's automatically restarted by monit). The Sprout logs are output in /var/log/sprout/*. Also, what version of Zoiper are you using, and on what system? Thanks, Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of simon connolly Sent: 25 September 2014 15:48 To: [email protected] Subject: Re: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Ellie thanks for reply in the log I sent for sprout below I was using Zoiper softphone (which is recomended on clearwater website) but there doesnt seem to be a field to set authorization name, there are only 3 fields it allows you to set, which I set as below user / user host : [email protected] password: <password> Domain / Outbound proxy: 192.168.20.68 I have now tried using XLite which does have a field to set auth name, Ive set fields as below:- User ID: 0000001005 Domain : example.com Password: <password> Display name: 1005 Auth Name: [email protected] I tried again and this time I get 401 Unauthorised, but log is different, shows the correct format for the private identity i think 24-09-2014 08:29:43.360 UTC Warning authentication.cpp:205: Received24-09-2014 17:31:56.657 UTC Warning authentication.cpp:205: Received an authentication request for [email protected] with nonce 7883849902ac3e63, but no matching AV found 24-09-2014 17:31:56.670 UTC Warning authentication.cpp:205: Received an authentication request for [email protected] with nonce 734410286b986924, but no matching AV found what can be the reason for failed auth ? thanks Simon -----Original Message----- From: Eleanor Merry Sent: Wednesday, September 24, 2014 6:14 PM To: simon connolly ; [email protected] Subject: RE: [Clearwater] SIP Registration Failure: 403 Forbidden Hi Simon, You're right - the create_numbers script is used to tell Ellis which numbers are available for provisioning - it doesn't actually create any numbers on Homer/Homestead itself. Looking at the diagnostics, it looks like you've got three provisioned users (1001, 1008 and 1005), and 7 more numbers available for provisioning. For each provisioned number, the public identity is sip:[email protected] and the private identity is [email protected] When you register, you need to configure your client so that authentication name matches the private identity - it looks from the logs that you're using 0000001000x. What softphone are you using? Can you please try with [email protected] instead? Hope this helps, Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of simon connolly Sent: 24 September 2014 11:52 To: [email protected] Subject: [Clearwater] SIP Registration Failure: 403 Forbidden Hi I’ve recently installed the all-in-one version of clearwater and I am having trouble registering a user. When I installed the OVF there were 1000 users created automatically in Ellis database, but only a handful (about 50) of these 1000 were in other databases ie homer, homestead. I thought this might be due to some installation issue. To better understand how clearwater is working I decided to delete all the subscribers from Ellis and recreate just 10 (1000-1009) using the ‘create_numbers.py’ scipt, as I wanted to see if deleting / creating users in Ellis would propagate through to other databases, but I found this wasn’t the case. After search on internet I found info that the ‘create_numbers.py’ script doesn't actually create numbers on Homestead, it just provisions a pool of numbers on Ellis that Ellis can then select from during real number creation’, so now i’m confused how users are created in other databases...should this be done manually or is there some config issue which is stopping Ellis informing other databases about new users ? below are the 10 users I created mysql> select * from numbers; +--------------------------------------+----------------------------+----------+------------+------+ | number_id | number | owner_id | gab_listed | pstn | +--------------------------------------+----------------------------+----------+------------+------+ | 008ccc4a-1972-4510-9a3e-bcea60983ec4 | sip:[email protected] | NULL | 1 | 0 | | 070680ec-9934-4c21-8f84-fa3538e735a9 | sip:[email protected] | NULL | 1 | 0 | | 09218e54-4427-472f-bc6a-b00eac4464ed | sip:[email protected] | NULL | 1 | 0 | | 43cb9b77-7581-41bb-b1c8-1bc6aac4d9ba | sip:[email protected] | NULL | 1 | 0 | | 693e3271-525b-4002-9683-3e29816db695 | sip:[email protected] | NULL | 1 | 0 | | 6f35ccbf-3228-4d33-942b-147604a027fb | sip:[email protected] | NULL | 1 | 0 | | 96cf89c3-8f61-4ddc-a9fc-1ffcf0e00c4b | sip:[email protected] | NULL | 1 | 0 | | a2800cf0-10ef-4d65-ac3c-89e634c5617c | sip:[email protected] | NULL | 1 | 0 | | aef13d75-159f-4c4a-8d4f-420b539e4b93 | sip:[email protected] | NULL | 1 | 0 | | af3d3ca7-49aa-4b34-8750-d87a695a29d8 | sip:[email protected] | NULL | 1 | 0 | +--------------------------------------+----------------------------+----------+------------+------+ using the web interface I generated 3 private identities (1001, 1008, 1005), which worked and I got a password for each. Can see in mysql that owner-id field is now filled, so this part is working fine mysql> select * from numbers; +--------------------------------------+----------------------------+--------------------------------------+------------+------+ | number_id | number | owner_id | gab_listed | pstn | +--------------------------------------+----------------------------+--------------------------------------+------------+------+ | 008ccc4a-1972-4510-9a3e-bcea60983ec4 | sip:[email protected] | ad2dec28-eadc-4501-87d6-c74c2ed28676 | 1 | 0 | | 070680ec-9934-4c21-8f84-fa3538e735a9 | sip:[email protected] | ad2dec28-eadc-4501-87d6-c74c2ed28676 | 1 | 0 | | 09218e54-4427-472f-bc6a-b00eac4464ed | sip:[email protected] | ad2dec28-eadc-4501-87d6-c74c2ed28676 | 1 | 0 | | 43cb9b77-7581-41bb-b1c8-1bc6aac4d9ba | sip:[email protected] | NULL | 1 | 0 | | 693e3271-525b-4002-9683-3e29816db695 | sip:[email protected] | NULL | 1 | 0 | | 6f35ccbf-3228-4d33-942b-147604a027fb | sip:[email protected] | NULL | 1 | 0 | | 96cf89c3-8f61-4ddc-a9fc-1ffcf0e00c4b | sip:[email protected] | NULL | 1 | 0 | | a2800cf0-10ef-4d65-ac3c-89e634c5617c | sip:[email protected] | NULL | 1 | 0 | | aef13d75-159f-4c4a-8d4f-420b539e4b93 | sip:[email protected] | NULL | 1 | 0 | | af3d3ca7-49aa-4b34-8750-d87a695a29d8 | sip:[email protected] | NULL | 1 | 0 | +--------------------------------------+----------------------------+--------------------------------------+------------+------+ I then tried to register with softphone, clearwater first sends back 401 Unauthorised (so it recognises the user ), softphone then replies with sip register which includes auth parameters this time, but the clearwater sends back 403 forbidden. In sprout log i see errors below which seem to point at impi and impu tables in homestead_cache database, that they cant find matching record 24-09-2014 08:29:43.360 UTC Warning authentication.cpp:205: Received an authentication request for 0000001008 with nonce 5073304c580c6b04, but no matching AV found 24-09-2014 08:29:43.362 UTC Error httpconnection.cpp:561: http://192.168.20.68:8888/impi/0000001008/av?impu=sip%3A0000001008%40example.com failed at server 192.168.20.68 : HTTP response code said error (22 404) : fatal 24-09-2014 08:29:43.362 UTC Error httpconnection.cpp:659: cURL failure with cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 404 24-09-2014 08:29:43.362 UTC Error hssconnection.cpp:144: Failed to get Authentication Vector for 0000001008 this makes sense as there are no entries for the 10 users I created in either of these 2 tables please advise many thanks Simon _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
