Hi Shiva, The logs you attached seem to be very short (covering only a 10-millisecond period, and one message in the REGISTER flow), so I haven’t been able to diagnose the issue from them. Is it possible for you to copy off and attach the full log files, rather than a short extract from them?
The only things that immediately come to mind as possible causes are: · If your environment uses DHCP, the IP addresses of your VMs may have changed, and you may need to change configuration to reflect this. · The Cassandra database on Homestead may not be running (or may be frequently restarting). Running ‘sudo monit status’ on Homestead should show whether this is the case. Best, Rob -- Rob Day Software Engineer, Project Clearwater From: Shiva Charan [mailto:[email protected]] Sent: 30 June 2015 15:25 To: Robert Day Subject: Re: [Clearwater] zoiper client number registration fails Hi Rob, Due to an infrastructure issue we had to restart all the virtual machines after which the calls( from zopier client) are not being registered. Attached here are the bono and sprout logs, any inputs? Shiva On Mon, Jun 22, 2015 at 12:23 PM, Shiva Charan <[email protected]<mailto:[email protected]>> wrote: Hi Rob, Its working now :). There was a IP mismatch in the cluster_settings file. Shiva On Fri, Jun 19, 2015 at 6:46 PM, Shiva Charan <[email protected]<mailto:[email protected]>> wrote: Hi Rob, Thanks for your reply, sorry about the bono log pleas find the log files attached along with the syslog of bono node. syslog shows an error regarding smtp and also few files missing in lib folder. Also attached the config file I am using, the clearwater version of nodes are follows, [ellis]clearwater1@Ellis1:/etc/clearwater$ dpkg-query -W ellis ellis 1.0-150605.133914 [bono]clearwater2@clearwater:~$ dpkg-query -W bono bono 1.0-150216.174621 [sprout]sprout1@sprout1:~$ dpkg-query -W sprout sprout 1.0-150329.161304 [homer]clearwater4@clearwater:~$ dpkg-query -W homer homer 1.0-150213.175004 [homestead]clearwater@ubuntu:~$ dpkg-query -W homestead homestead 1.0-150227.194739 [ralf]clearwater6@clearwater:~$ dpkg-query -W ralf ralf 1.0-150213.143613 Thanks, Shiva On Fri, Jun 19, 2015 at 1:10 AM, Robert Day <[email protected]<mailto:[email protected]>> wrote: Hi Shiva, It looks like those logs might have been truncated – they only contain about 30 lines each, but I’d expect more. Could you send the full log files through from Bono, Sprout and Homestead? (Homestead logs will be useful in investigating authentication failures like this, as they’ll contain information about the subscriber state.) Could you also send the contents of /var/log/syslog? We log high-level troubleshooting logs there, so if there are connectivity issues or similar configuration problems, that might show up in a log there. Thanks, Rob -- Rob Day Software Engineer, Project Clearwater From: [email protected]<mailto:[email protected]> [mailto:[email protected]<mailto:[email protected]>] On Behalf Of Shiva Charan Sent: 17 June 2015 19:26 To: [email protected]<mailto:[email protected]> Subject: [Clearwater] zoiper client number registration fails Hi, In my manual install setup all the services are running but when i try to register a number created from the UI the registration fails. Logs for Bono and Sprout are attached to mail. also the log_current for bono is as below. Bono log_current.txt 17-06-2015 18:00:01.267 UTC Call-Disconnected: CALL_ID=NDc4MjY4Nzk5NzkyMWExMWZiMGFhNzY4MDU4YTUzZDY. REASON=401 17-06-2015 18:00:01.328 UTC Call-Disconnected: CALL_ID=NDc4MjY4Nzk5NzkyMWExMWZiMGFhNzY4MDU4YTUzZDY. REASON=401 17-06-2015 18:00:01.390 UTC Call-Disconnected: CALL_ID=NDc4MjY4Nzk5NzkyMWExMWZiMGFhNzY4MDU4YTUzZDY. REASON=401 17-06-2015 18:00:01.451 UTC Call-Disconnected: Please suggest. Shiva
30-06-2015 14:17:15.400 UTC Debug stack.cpp:470: Queuing cloned received message 0x7f0b243b0f28 for worker threads 30-06-2015 14:17:15.400 UTC Debug stack.cpp:206: Worker thread dequeue message 0x7f0b243b0f28 30-06-2015 14:17:15.400 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=407999 (rdata0x7f0b243b0f28) 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:260: Proxy RX request 30-06-2015 14:17:15.400 UTC Debug pjutils.cpp:680: Cloned Request msg REGISTER/cseq=407999 (rdata0x7f0b243b0f28) to tdta0x7f0b1032c730 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:953: Request received on non-trusted port 5060 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:1225: Perform access proxy routing for REGISTER request 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:1262: Message requires outbound support 30-06-2015 14:17:15.400 UTC Debug flowtable.cpp:91: Find or create flow for transport udp0xa7fe00 (1), remote address 11.0.0.13:40488 30-06-2015 14:17:15.400 UTC Debug flowtable.cpp:115: Found flow record 0x7f0b18002b20 30-06-2015 14:17:15.400 UTC Debug flowtable.cpp:602: Dialog count now 2 for flow 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:1274: Found or created flow data record, token = 4CfMZSPaJr 30-06-2015 14:17:15.400 UTC Info pjutils.cpp:446: Adding integrity-protected=ip-assoc-pending indicator to message 30-06-2015 14:17:15.400 UTC Debug flowtable.cpp:619: Dialog count now 1 for flow 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:1183: Mark originating 30-06-2015 14:17:15.400 UTC Info stateful_proxy.cpp:1204: Route request to upstream proxy sip:11.0.0.9:5054;transport=TCP;lr;orig 30-06-2015 14:17:15.400 UTC Debug acr.cpp:1706: Create RalfACR for node type P-CSCF with role Originating 30-06-2015 14:17:15.400 UTC Debug acr.cpp:48: Created ACR (0x7f0b103dd150) 30-06-2015 14:17:15.400 UTC Debug acr.cpp:166: Created P-CSCF Ralf ACR 30-06-2015 14:17:15.400 UTC Debug acr.cpp:205: Set record type for P/S-CSCF 30-06-2015 14:17:15.400 UTC Debug acr.cpp:213: Non-dialog message => EVENT_RECORD 30-06-2015 14:17:15.400 UTC Debug acr.cpp:1434: Stored 0 subscription identifiers 30-06-2015 14:17:15.400 UTC Debug stateful_proxy.cpp:596: Trust mode INBOUND_EDGE_CLIENT(,-rsp,-pch), serving state None 30-06-2015 14:17:15.401 UTC Debug pjsip: tsx0x7f0b1032d Transaction created for Request msg REGISTER/cseq=407999 (rdata0x7f0b243b0f28) 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:2259: UASTransaction constructor (0x7f0b10055780) 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:2260: ACR (0x7f0b103dd150) 30-06-2015 14:17:15.401 UTC Debug pjsip: tsx0x7f0b1032d Incoming Request msg REGISTER/cseq=407999 (rdata0x7f0b243b0f28) in state Null 30-06-2015 14:17:15.401 UTC Debug pjsip: tsx0x7f0b1032d State changed from Null to Trying, event=RX_MSG 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:368: tsx0x7f0b1032d7e8 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 30-06-2015 14:17:15.401 UTC Debug pjsip: endpoint Response msg 408/REGISTER/cseq=407999 (tdta0x7f0b100cf9b0) created 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:3707: Report SAS start marker - trail (64385) 30-06-2015 14:17:15.401 UTC Debug trustboundary.cpp:67: Add P-Charging headers 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:3796: Allocating transaction and data for target 0 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:4205: Stripping loose routes from proxied message 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:4232: Adding a Route header to sip:11.0.0.9:5054;transport=TCP 30-06-2015 14:17:15.401 UTC Debug pjsip: tsx0x7f0b10109 Transaction created for Request msg REGISTER/cseq=407999 (tdta0x7f0b100e0570) 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:3823: Adding trail identifier 410501 to UAC transaction 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:3842: Updating request URI and route for target 0 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:4300: Transport tcpc0x7f0b0401d5f8 (TCP to 11.0.0.9:5054) pre-selected for transaction 30-06-2015 14:17:15.401 UTC Debug stateful_proxy.cpp:4318: Sending request for sip:11.0.0.7;transport=UDP 30-06-2015 14:17:15.401 UTC Debug pjsip: tsx0x7f0b10109 Sending Request msg REGISTER/cseq=407999 (tdta0x7f0b100e0570) in state Null 30-06-2015 14:17:15.401 UTC Debug pjsip: endpoint Request msg REGISTER/cseq=407999 (tdta0x7f0b100e0570): skipping target resolution because address is already set 30-06-2015 14:17:15.401 UTC Verbose stack.cpp:259: TX 1262 bytes Request msg REGISTER/cseq=407999 (tdta0x7f0b100e0570) to TCP 11.0.0.9:5054: --start msg-- REGISTER sip:11.0.0.7;transport=UDP SIP/2.0^M Via: SIP/2.0/TCP 11.0.0.7:58754;rport;branch=z9hG4bKPjvWSKP1-vkdyaPtEP81YYoOJz0BHoNSDQ^M Path: <sip:[email protected]:5058;transport=TCP;lr;ob>^M Via: SIP/2.0/UDP 11.0.0.13:40488;received=11.0.0.13;branch=z9hG4bK-d8754z-3d2ec6e441c0b6a4-1---d8754z-^M Max-Forwards: 70^M Contact: <sip:[email protected]:40488;transport=UDP;rinstance=5a29fc2688e6bca9>^M To: "2010000001" <sip:[email protected]>^M From: "2010000001" <sip:[email protected]>;tag=137d2d25^M Call-ID: NTcyNTUzYzJiMWJjMDU1N2IyMGViYzkzNWE1MGY4YWY.^M CSeq: 407999 REGISTER^M Expires: 3600^M Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE^M Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri^M User-Agent: Z 3.6.25251 r25476^M Authorization: Digest username="[email protected]", realm="11.0.0.7", nonce="33281da419588121", uri="sip:11.0.0.7;transport=UDP", response="b58f7fa07e00842eb5c054c89846dcae", algorithm=MD5, cnonce="a7b06934e5fe7eb3b72faf107514f8ad", opaque="623cd22659e42ade", qop=auth, nc=00000001,integrity-protected=ip-assoc-pending^M Allow-Events: presence, kpml^M P-Visited-Network-ID: 11.0.0.7^M Session-Expires: 600^M Route: <sip:11.0.0.9:5054;transport=TCP;lr;orig>^M Content-Length: 0^M --end msg--
30-06-2015 14:22:05.708 UTC Debug pjsip: tdta0x7fed8831 Destroying txdata Response msg 401/REGISTER/cseq=412836 (tdta0x7fed8831c5d0) 30-06-2015 14:22:05.708 UTC Verbose acr.cpp:617: Sending S-CSCF Ralf ACR (0x7fed88262ec0) 30-06-2015 14:22:05.708 UTC Debug acr.cpp:633: Building message 30-06-2015 14:22:05.708 UTC Debug acr.cpp:650: Adding peers meta-data, 0 ccfs, 0 ecfs 30-06-2015 14:22:05.708 UTC Debug acr.cpp:689: Building event 30-06-2015 14:22:05.708 UTC Debug acr.cpp:694: Adding Account-Record-Type AVP 1 30-06-2015 14:22:05.708 UTC Debug acr.cpp:714: Adding Service-Information AVP group 30-06-2015 14:22:05.709 UTC Debug acr.cpp:724: Adding 1 Subscription-Id AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:750: Adding IMS-Information AVP group 30-06-2015 14:22:05.709 UTC Debug acr.cpp:755: Adding Event-Type AVP group 30-06-2015 14:22:05.709 UTC Debug acr.cpp:784: Adding 0 Calling-Party-Address AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:804: Adding Called-Party-Address AVP 30-06-2015 14:22:05.709 UTC Debug acr.cpp:815: Adding Requested-Party-Address AVP 30-06-2015 14:22:05.709 UTC Debug acr.cpp:825: Adding 0 Called-Asserted-Identity AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:846: Adding 0 Associated-URI AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:865: Adding Time-Stamps AVP group 30-06-2015 14:22:05.709 UTC Debug acr.cpp:890: Adding 0 Application-Server-Information AVP groups 30-06-2015 14:22:05.709 UTC Debug acr.cpp:955: Adding 0 Transit-IOI-List AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1031: Adding 0 Early-Media-Description AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1059: Adding 0 Message-Body AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1139: Adding Cause-Code(401) AVP to ACR[Interim] 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1145: Adding 0 Reason-Header AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1163: Adding 0 Access-Network-Information AVPs 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1181: Adding From-Address AVP 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1188: Adding IMS-Visited-Network-Identifier AVP 30-06-2015 14:22:05.709 UTC Debug acr.cpp:1196: Adding Route-Header-Received AVP 30-06-2015 14:22:05.709 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host 11.0.0.10, port 10888, family 2 30-06-2015 14:22:05.709 UTC Debug baseresolver.cpp:501: Attempt to parse 11.0.0.10 as IP address 30-06-2015 14:22:05.709 UTC Debug httpresolver.cpp:78: Target is an IP address 30-06-2015 14:22:05.709 UTC Debug httpconnection.cpp:604: Sending HTTP request : http://11.0.0.10:10888/call-id/NTcyNTUzYzJiMWJjMDU1N2IyMGViYzkzNWE1MGY4YWY. (trying 11.0.0.10) on new connection 30-06-2015 14:22:05.710 UTC Debug httpconnection.cpp:904: Received header http/1.1400badrequest with value 30-06-2015 14:22:05.710 UTC Debug httpconnection.cpp:904: Received header content-length with value 0 30-06-2015 14:22:05.710 UTC Debug httpconnection.cpp:904: Received header with value 30-06-2015 14:22:05.710 UTC Debug httpconnection.cpp:619: Received HTTP response: status=400, doc= 30-06-2015 14:22:05.710 UTC Error httpconnection.cpp:738: cURL failure with cURL error code 0 (see man 3 libcurl-errors) and HTTP error code 400 30-06-2015 14:22:05.710 UTC Warning acr.cpp:627: Failed to send Ralf ACR message (0x7fed88262ec0), rc = 400 30-06-2015 14:22:05.710 UTC Debug acr.cpp:53: Destroyed ACR (0x7fed88262ec0) 30-06-2015 14:22:05.710 UTC Debug thread_dispatcher.cpp:176: Worker thread completed processing message 0x7fec880458a8 30-06-2015 14:22:05.710 UTC Debug thread_dispatcher.cpp:182: Request latency = 55675us 30-06-2015 14:22:05.715 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=412837 (rdata0x7fec88041ce8) 30-06-2015 14:22:05.715 UTC Verbose common_sip_processing.cpp:120: RX 1262 bytes Request msg REGISTER/cseq=412837 (rdata0x7fec88041ce8) from TCP 11.0.0.7:36334: --start msg-- REGISTER sip:11.0.0.7;transport=UDP SIP/2.0^M Via: SIP/2.0/TCP 11.0.0.7:36334;rport;branch=z9hG4bKPjUv7DsNjR59OhVajKVQzdHzyBIU4wkfAN^M Path: <sip:[email protected]:5058;transport=TCP;lr;ob>^M Via: SIP/2.0/UDP 11.0.0.13:40488;received=11.0.0.13;branch=z9hG4bK-d8754z-52fe58987a90f0df-1---d8754z-^M Max-Forwards: 70^M Contact: <sip:[email protected]:40488;transport=UDP;rinstance=5a29fc2688e6bca9>^M To: "2010000001" <sip:[email protected]>^M From: "2010000001" <sip:[email protected]>;tag=137d2d25^M Call-ID: NTcyNTUzYzJiMWJjMDU1N2IyMGViYzkzNWE1MGY4YWY.^M CSeq: 412837 REGISTER^M Expires: 3600^M Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE^M Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri^M User-Agent: Z 3.6.25251 r25476^M Authorization: Digest username="[email protected]", realm="11.0.0.7", nonce="3fdd0271041a8f87", uri="sip:11.0.0.7;transport=UDP", response="ec49e7bc67fddd77430e4b0a1d86e22d", algorithm=MD5, cnonce="9131e8ded7107759a18d808f5d7dda85", opaque="33d2bfb23b23e738", qop=auth, nc=00000001,integrity-protected=ip-assoc-pending^M Allow-Events: presence, kpml^M P-Visited-Network-ID: 11.0.0.7^M Session-Expires: 600^M Route: <sip:11.0.0.9:5054;transport=TCP;lr;orig>^M Content-Length: 0^M ^M --end msg--
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
