Hi Sushant, Thanks for getting in touch with this.
In the Sprout logs, the sprout node can't resolve the Homestead node (hs.ims.hom) or the Ralf node (ralf.ims.hom), e.g. 10-09-2014 20:04:09.569 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host hs.ims.hom, port 8888, family 2 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:511: Attempt to parse hs.ims.hom as IP address 10-09-2014 20:04:09.570 UTC Debug dnscachedresolver.cpp:179: Pulling 0 records from cache for hs.ims.hom A 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:359: Found 0 A/AAAA records, randomizing 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:418: Adding 0 servers from blacklist 10-09-2014 20:04:09.570 UTC Error httpconnection.cpp:667: cURL failure with cURL error code 6 (see man 3 libcurl-errors) and HTTP error code 404 As Sprout can't reach Homestead, it can't generate a challenge for the REGISTER, so Sprout rejects the REGISTER with a 403. How have you set up the DNS? Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Sushant Hiray Sent: 10 September 2014 22:57 To: [email protected] Subject: [Clearwater] SIP Client Register not working [403 Forbidden] Dear All, I setup Clearwater using the manual install instructions and it appears to be running correctly. Currently I've just 6 VM's. 1 VM for each node. When I run "sudo monit status" in each of the nodes everything seems to be running . However, when I try to connect a softphone(Blink) to it using an account registered through Ellis, I am unable to register and consequently cannot make calls. Here is the basic error I'm getting: Using account [email protected] 2014-09-11 03:15:05 Registration failed at 10.129.34.51:5060;transport=tcp: 403 Forbidden 2014-09-11 03:15:05 Registration failed at 10.129.34.51:5060;transport=udp: 403 Forbidden 2014-09-11 03:15:05 Failed to register contact for sip:[email protected]: No more routes to try (retrying in 1.70 seconds) Here are node-wise logs from my basic inspection. I've updated the log_level to 5 in "/etc/clearwater/user_settings" 1. Bono 10-09-2014 20:36:44.659 UTC Call-Disconnected: CALL_ID=cM-QvK9iPcCGdIuVVaSYmYgTwEHNEBV8 REASON=403 2. Sprout (I've highlighted the lines which are throwing error) --start msg-- SIP/2.0 403 Forbidden^M Via: SIP/2.0/TCP 10.129.34.51:56015 ;rport=56015;received=10.129.34.51;branch=z9hG4bKPjlgUNAZEa.pR7eCZxDXOXaNW9Y3j1KCfR^M Via: SIP/2.0/TCP 10.3.96.32:32792 ;rport=32792;received=10.3.96.32;branch=z9hG4bKPjDD.3IT1km2RohmOkhOYI7OE9pdWrIeKH;alias^M Call-ID: G7lpmUOntKmjcxPrh3ZnUgKVWjoNH5Tt^M From: <sip:[email protected]>;tag=6leRxIq10h6kewEVgKAjTIhacS8mLJRf^M To: <sip:[email protected]>;tag=z9hG4bKPjlgUNAZEa.pR7eCZxDXOXaNW9Y3j1KCfR^M CSeq: 1 REGISTER^M Content-Length: 0^M ^M --end msg-- 10-09-2014 20:04:09.556 UTC Debug pjsip: tdta0x7f1adc00 Destroying txdata Response msg 403/REGISTER/cseq=1 (tdta0x7f1adc0031c0) 10-09-2014 20:04:09.556 UTC Verbose acr.cpp:646: Sending S-CSCF Ralf ACR (0x7f1adc002e50) 10-09-2014 20:04:09.556 UTC Debug acr.cpp:662: Building message 10-09-2014 20:04:09.558 UTC Debug acr.cpp:677: Adding peers meta-data, 0 ccfs, 0 ecfs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:694: Building event 10-09-2014 20:04:09.558 UTC Debug acr.cpp:698: Adding Account-Record-Type AVP 1 10-09-2014 20:04:09.558 UTC Debug acr.cpp:711: Adding Service-Information AVP group 10-09-2014 20:04:09.558 UTC Debug acr.cpp:720: Adding 1 Subscription-Id AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:732: Adding IMS-Information AVP group 10-09-2014 20:04:09.558 UTC Debug acr.cpp:736: Adding Event-Type AVP group 10-09-2014 20:04:09.558 UTC Debug acr.cpp:753: Adding 0 Calling-Party-Address AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:764: Adding Called-Party-Address AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:774: Adding Requested-Party-Address AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:764: Adding Called-Party-Address AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:774: Adding Requested-Party-Address AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:783: Adding 0 Called-Asserted-Identity AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:795: Adding 0 Associated-URI AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:805: Adding Time-Stamps AVP group 10-09-2014 20:04:09.558 UTC Debug acr.cpp:821: Adding 0 Application-Server-Information AVP groups 10-09-2014 20:04:09.558 UTC Debug acr.cpp:858: Adding 0 Transit-IOI-List AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:906: Adding 0 Early-Media-Description AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:929: Adding 0 Message-Body AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:994: Adding Cause-Code(403) AVP to ACR[Interim] 10-09-2014 20:04:09.558 UTC Debug acr.cpp:999: Adding 0 Reason-Header AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:1008: Adding 0 Access-Network-Information AVPs 10-09-2014 20:04:09.558 UTC Debug acr.cpp:1017: Adding From-Address AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:1030: Adding Route-Header-Received AVP 10-09-2014 20:04:09.558 UTC Debug acr.cpp:1042: Adding Instance-Id AVP 10-09-2014 20:04:09.562 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f1adc033bc0 10-09-2014 20:04:09.563 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host ralf.ims.hom, port 10888, family 2 10-09-2014 20:04:09.563 UTC Debug baseresolver.cpp:511: Attempt to parse ralf.ims.hom as IP address 10-09-2014 20:04:09.563 UTC Debug dnscachedresolver.cpp:136: Create cache entry pending query 10-09-2014 20:04:09.563 UTC Debug dnscachedresolver.cpp:148: Create and execute DNS query transaction 10-09-2014 20:04:09.563 UTC Debug dnscachedresolver.cpp:154: Wait for query responses 10-09-2014 20:04:09.564 UTC Debug dnscachedresolver.cpp:384: Received DNS response for ralf.ims.hom type A 10-09-2014 20:04:09.564 UTC Debug dnscachedresolver.cpp:533: Adding ralf.ims.hom to cache expiry list with expiry time of 1410379749 10-09-2014 20:04:09.564 UTC Debug dnscachedresolver.cpp:158: Received all query responses 10-09-2014 20:04:09.564 UTC Debug dnscachedresolver.cpp:179: Pulling 0 records from cache for ralf.ims.hom A 10-09-2014 20:04:09.564 UTC Debug baseresolver.cpp:359: Found 0 A/AAAA records, randomizing 10-09-2014 20:04:09.564 UTC Debug baseresolver.cpp:418: Adding 0 servers from blacklist 10-09-2014 20:04:09.564 UTC Error httpconnection.cpp:667: cURL failure with cURL error code 6 (see man 3 libcurl-errors) and HTTP error code 404 10-09-2014 20:04:09.564 UTC Warning acr.cpp:656: Failed to send Ralf ACR message (0x7f1adc002e50), rc = 404 10-09-2014 20:04:09.564 UTC Debug acr.cpp:53: Destroyed ACR (0x7f1adc002e50) 10-09-2014 20:04:09.564 UTC Debug stack.cpp:198: Worker thread completed processing message 0x7f1ab4018548 10-09-2014 20:04:09.564 UTC Debug stack.cpp:204: Request latency = 33327us 10-09-2014 20:04:09.564 UTC Debug statistic.cpp:103: Send new value for statistic latency_us, size 5 10-09-2014 20:04:09.564 UTC Debug zmq_lvc.cpp:167: Update to latency_us statistic 10-09-2014 20:04:09.564 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f1af0013100 10-09-2014 20:04:09.567 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7f1ab404ec58) 10-09-2014 20:04:09.567 UTC Verbose stack.cpp:233: RX 745 bytes Request msg REGISTER/cseq=1 (rdata0x7f1ab404ec58) from TCP 10.129.34.51:34283: --start msg-- REGISTER sip:ims.hom SIP/2.0^M Via: SIP/2.0/TCP 10.129.34.51:34283 ;rport;branch=z9hG4bKPjrktUIlEa5J7yEQ-Fr8YkHLT1Ea9F2Lj8^M Path: <sip:[email protected]:5058;transport=TCP;lr;ob>^M Via: SIP/2.0/UDP 10.3.96.32:38636 ;rport=38636;received=10.3.96.32;branch=z9hG4bKPjHdJHy.6MKsylufIZRgohgal6AHbR-ONI^M Max-Forwards: 70^M From: <sip:[email protected]>;tag=Q1MGvsfboqKvuaWqDF8si81f8yDmGwij^M /403 --end msg-- 10-09-2014 20:04:09.567 UTC Debug stack.cpp:457: Queuing cloned received message 0x7f1ab4018548 for worker threads 10-09-2014 20:04:09.567 UTC Debug stack.cpp:196: Worker thread dequeue message 0x7f1ab4018548 10-09-2014 20:04:09.567 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7f1ab4018548) 10-09-2014 20:04:09.567 UTC Debug acr.cpp:1495: Create RalfACR for node type S-CSCF with role Originating 10-09-2014 20:04:09.567 UTC Debug acr.cpp:48: Created ACR (0x7f1ae0000a60) 10-09-2014 20:04:09.567 UTC Debug acr.cpp:195: Created S-CSCF Ralf ACR 10-09-2014 20:04:09.567 UTC Debug acr.cpp:234: Set record type for P/S-CSCF 10-09-2014 20:04:09.567 UTC Debug acr.cpp:242: Non-dialog message => EVENT_RECORD 10-09-2014 20:04:09.567 UTC Debug acr.cpp:1229: Stored 0 subscription identifiers 10-09-2014 20:04:09.567 UTC Debug authentication.cpp:636: No authentication information in request or stale nonce, so reject with challenge 10-09-2014 20:04:09.567 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=1 (tdta0x7f1ae0000dd0) created 10-09-2014 20:04:09.567 UTC Debug pjutils.cpp:459: Private identity defaulted from public identity = [email protected] 10-09-2014 20:04:09.568 UTC Debug httpconnection.cpp:176: Allocated CURL handle 0x7f1ae0003aa0 10-09-2014 20:04:09.569 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host hs.ims.hom, port 8888, family 2 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:511: Attempt to parse hs.ims.hom as IP address 10-09-2014 20:04:09.570 UTC Debug dnscachedresolver.cpp:179: Pulling 0 records from cache for hs.ims.hom A 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:359: Found 0 A/AAAA records, randomizing 10-09-2014 20:04:09.570 UTC Debug baseresolver.cpp:418: Adding 0 servers from blacklist 10-09-2014 20:04:09.570 UTC Error httpconnection.cpp:667: cURL failure with cURL error code 6 (see man 3 libcurl-errors) and HTTP error code 404 10-09-2014 20:04:09.570 UTC Error hssconnection.cpp:144: Failed to get Authentication Vector for [email protected] 10-09-2014 20:04:09.570 UTC Debug authentication.cpp:422: Failed to get Authentication vector 10-09-2014 20:04:09.570 UTC Verbose stack.cpp:249: TX 487 bytes Response msg 403/REGISTER/cseq=1 (tdta0x7f1ae0000dd0) to TCP 10.129.34.51:34283: --start msg-- SIP/2.0 403 Forbidden^M Via: SIP/2.0/TCP 10.129.34.51:34283 ;rport=34283;received=10.129.34.51;branch=z9hG4bKPjrktUIlEa5J7yEQ-Fr8YkHLT1Ea9F2Lj8^M Via: SIP/2.0/UDP 10.3.96.32:38636 ;rport=38636;received=10.3.96.32;branch=z9hG4bKPjHdJHy.6MKsylufIZRgohgal6AHbR-ONI^M Call-ID: eMQF9EG1PRRDP2WTysSAWjwvaln6Dwdv^M From: <sip:[email protected]>;tag=Q1MGvsfboqKvuaWqDF8si81f8yDmGwij^M To: <sip:[email protected]>;tag=z9hG4bKPjrktUIlEa5J7yEQ-Fr8YkHLT1Ea9F2Lj8^M CSeq: 1 REGISTER^M Content-Length: 0^M ^M 3. Homestead. (Logs in homestead-prov) Unhandled error in Deferred: Unhandled Error Traceback (most recent call last): Failure: twisted.internet.error.ConnectionRefusedError: Connection was refused by other side: 111: Connection refused. These were the basic logs. As specified in the troubleshooting doc, I also checked the homestead mysql DB. It contains all the 3 test numbers. cqlsh:homestead_cache> select * from impi ; private_id | digest_ha1 | digest_qop | digest_realm | known_preferred --------------------+----------------------------------+------------+--------------+----------------- [email protected] | 39948702e7480ea84200b5b2b29b3a1b | auth | ims.hom | True [email protected] | 0975b0013ba477db4f4b7b3ca72b2510 | auth | ims.hom | True [email protected] | bc48418eb380632306472faaef6cf954 | auth | ims.hom | True Moreover, the DNS has been set up correctly and all the nodes can connect to each other via host names. Can you please suggest some further steps so that I can debug the setup. ps. My current setup is under institute firewall and so I'm not able to curl/wget to outside networks via the VM's. (for eg curl www.google.com doesn't work). Will this be an issue? Regards, Sushant Hiray, Senior Undergrad CSE, IIT Bombay _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
