Hi Sushant, For memcached to consistently return “SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY” suggests that there’s something seriously wrong with the memcached process.
Can you check that it’s reliably running (‘monit status’ will show the uptime), and are there any memcached logs in /var/log/memcached.log or in /var/log/syslog? Also, can you check if there are any reported errors about memcached when Sprout initially attempts to connect to memcached – you’ll need to restart Sprout (‘sudo service sprout stop’ – it’ll be restarted by monit). Ellie From: Sushant Hiray [mailto:[email protected]] Sent: 27 January 2015 18:58 To: Eleanor Merry Cc: [email protected] Subject: Re: [Clearwater] [Sprout] Memcache Error : Fail to read/write Hi Ellie, We currently have a single sprout in our installment. We also see this for every register request. Also we changed our public IP to be equal to our private IP. And changed it in the /etc/clearwater/cluster_settings too. But we get the same error, only with the new private IP in case of the public IP. Thanks, Sushant Sushant Hiray, Senior Undergrad CSE, IIT Bombay On Wed, Jan 28, 2015 at 12:00 AM, Eleanor Merry <[email protected]<mailto:[email protected]>> wrote: Hi Sushant, Do you see this error on every register attempt, or is it intermittent? How many Sprouts do you have in your deployment? Also, can you check that the /etc/clearwater/cluster_settings file on each Sprout has the correct values - this should be a single line of the form 'memcached_servers=<sprout 1 IP address>:11211,<sprout 2 IP address>:11211,...', and the order of the IP addresses must be identical on each node. Ellie -----Original Message----- From: [email protected]<mailto:[email protected]> [mailto:[email protected]<mailto:[email protected]>] On Behalf Of Sushant Hiray Sent: 27 January 2015 09:35 To: [email protected]<mailto:[email protected]> Subject: [Clearwater] [Sprout] Memcache Error : Fail to read/write Hello, We recently shifted our clearwater infrastructure to Open Stack. We are facing an issue with the registration of a user. The following is the log at Sprout with log_level=5 I've highlighted the relevant error zones: REGISTER sip:ims.hom SIP/2.0 Via: SIP/2.0/TCP 192.168.1.41:54658<http://192.168.1.41:54658> ;rport;branch=z9hG4bKPjQhihJs.dF7ZqIk473L9ayKtDZZo-H3kw Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 192.168.1.39:5060<http://192.168.1.39:5060> ;rport=5060;received=192.168.1.39;branch=z9hG4bK107315516 From: <sip:[email protected]>;tag=1642292484 To: <sip:[email protected]> Call-ID: 1374014318 CSeq: 1 REGISTER Contact: <sip:[email protected]:5060<http://sip:[email protected]:5060> ;line=9002fc03804a36b>;+sip.instance="<urn:uuid:43be9c7e-a58e-11e4-955c-6ddd4f8d4915>" Authorization: Digest username="[email protected]<mailto:[email protected]>", realm="ims.hom", nonce=" ", uri="sip:ims.hom", response=" ",integrity-protected=ip-assoc-pending Max-Forwards: 70 User-Agent: eXosip/3.1.0 Expires: 600000 Supported: path, gruu P-Visited-Network-ID: ims.hom Session-Expires: 600 Route: <sip:sprout.ims.hom:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 26-01-2015 19:05:38.589 UTC Debug stack.cpp:470: Queuing cloned received message 0x7f8734097078 for worker threads 26-01-2015 19:05:38.589 UTC Debug stack.cpp:206: Worker thread dequeue message 0x7f8734097078 26-01-2015 19:05:38.589 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7f8734097078) 26-01-2015 19:05:38.589 UTC Debug authentication.cpp:486: Authorization header in request 26-01-2015 19:05:38.589 UTC Debug memcachedstore.cpp:174: Key av\\[email protected]\ hashes to vbucket 41 via hash 0xbdd4da29 26-01-2015 19:05:38.589 UTC Debug memcachedstore.cpp:373: 1 read replicas for key av\\[email protected]\ *26-01-2015 19:05:38.589 UTC Debug memcachedstore.cpp:406: Attempt to read from replica 0 (connection 0x7f870c056860)26-01-2015 19:05:38.589 UTC Debug memcachedstore.cpp:449: Read for av\\[email protected]\ on replica 0 returned error 47 (SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY)26-01-2015 19:05:38.589 UTC Error memcachedstore.cpp:519: Failed to read data for av\\[email protected]\ from 1 replicas*26-01-2015 19:05:38.589 UTC Debug authentication.cpp:539: Verify authentication information in request 26-01-2015 19:05:38.589 UTC Warning authentication.cpp:204: Received an authentication request for [email protected]<mailto:[email protected]> with nonce , but no matching AV found 26-01-2015 19:05:38.589 UTC Debug acr.cpp:48: Created ACR (0x7f870c1aa2b0) 26-01-2015 19:05:38.589 UTC Debug authentication.cpp:644: No authentication information in request or stale nonce, so reject with challenge 26-01-2015 19:05:38.589 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=1 (tdta0x7f870c1b6510) created 26-01-2015 19:05:38.589 UTC Debug pjutils.cpp:461: Private identity from authorization header = [email protected]<mailto:[email protected]> 26-01-2015 19:05:38.589 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host hs.ims.hom, port 8888, family 2 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:501: Attempt to parse hs.ims.hom as IP address 26-01-2015 19:05:38.589 UTC Debug dnscachedresolver.cpp:179: Pulling 1 records from cache for hs.ims.hom A 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:349: Found 1 A/AAAA records, randomizing 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:491: 192.168.1.43:8888<http://192.168.1.43:8888> transport 6 is not blacklisted 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:370: Added a server, now have 1 of 5 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:408: Adding 0 servers from blacklist 26-01-2015 19:05:38.589 UTC Debug baseresolver.cpp:501: Attempt to parse 192.168.1.43 as IP address 26-01-2015 19:05:38.589 UTC Debug httpconnection.cpp:553: Sending HTTP request : http://hs.ims.hom:8888/impi/user10%40ims.hom/av?impu=sip%3Auser10%40ims.hom (trying 192.168.1.43) 26-01-2015 19:05:38.591 UTC Debug httpconnection.cpp:568: Received HTTP response: status=200, doc={"digest":{"ha1":"4a4a6a1e2aad77dcb54cb43acd17c59d","realm":"ims.hom","qop":"auth"}} 26-01-2015 19:05:38.591 UTC Debug authentication.cpp:146: Digest specified 26-01-2015 19:05:38.591 UTC Debug authentication.cpp:309: Valid AV - generate challenge 26-01-2015 19:05:38.591 UTC Debug authentication.cpp:315: Create WWW-Authenticate header 26-01-2015 19:05:38.591 UTC Debug authentication.cpp:359: Add Digest information 26-01-2015 19:05:38.591 UTC Debug authentication.cpp:386: Write AV to store 26-01-2015 19:05:38.591 UTC Debug avstore.cpp:66: Set AV for [email protected]<mailto:[email protected]> \2ebbd3a10aba9cfa {"branch":"z9hG4bKPjQhihJs.dF7ZqIk473L9ayKtDZZo-H3kw","digest":{"ha1":"4a4a6a1e2aad77dcb54cb43acd17c59d","qop":"auth","realm":"ims.hom"}} 26-01-2015 19:05:38.591 UTC Debug memcachedstore.cpp:540: Writing 138 bytes to table av key [email protected]\2ebbd3a10aba9cfa<mailto:[email protected]\2ebbd3a10aba9cfa>, CAS = 0, expiry = 40 26-01-2015 19:05:38.591 UTC Debug memcachedstore.cpp:174: Key av\\[email protected]\2ebbd3a10aba9cfa hashes to vbucket 34 via hash 0x325860a2 26-01-2015 19:05:38.591 UTC Debug memcachedstore.cpp:560: 1 write replicas for key av\\[email protected]\2ebbd3a10aba9cfa 26-01-2015 19:05:38.591 UTC Debug memcachedstore.cpp:609: Attempt conditional write to replica 0 (connection 0x7f870c056860), CAS = 0 *26-01-2015 19:05:38.591 UTC Debug memcachedstore.cpp:652: memcached_add command for av\\[email protected]\2ebbd3a10aba9cfa failed on replica 0, rc = 47 (SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY), expiry = 40(140217998993504) SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY, host: 10.129.2.112:11211<http://10.129.2.112:11211> <http://10.129.2.112:11211> -> libmemcached/connect.cc:63326-01-2015 19:05:38.591 UTC Error memcachedstore.cpp:713: Failed to write data for av\\[email protected]\2ebbd3a10aba9cfa to 1 replicas26-01-2015 19:05:38.591 UTC Error avstore.cpp:71: Failed to write Authentication Vector for private_id [email protected]*26-01-2015<mailto:[email protected]*26-01-2015> 19:05:38.591 UTC Verbose stack.cpp:259: TX 545 bytes Response msg 401/REGISTER/cseq=1 (tdta0x7f870c1b6510) to TCP 192.168.1.41:54658<http://192.168.1.41:54658>: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.1.41:54658<http://192.168.1.41:54658> ;rport=54658;received=192.168.1.41;branch=z9hG4bKPjQhihJs.dF7ZqIk473L9ayKtDZZo-H3kw Via: SIP/2.0/UDP 192.168.1.39:5060<http://192.168.1.39:5060> ;rport=5060;received=192.168.1.39;branch=z9hG4bK107315516 Call-ID: 1374014318 From: <sip:[email protected]>;tag=1642292484 To: <sip:[email protected]>;tag=z9hG4bKPjQhihJs.dF7ZqIk473L9ayKtDZZo-H3kw CSeq: 1 REGISTER WWW-Authenticate: Digest realm="ims.hom",nonce="2ebbd3a10aba9cfa",opaque="1fafe52f54443250",stale=true,algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 26-01-2015 19:05:38.591 UTC Debug pjsip: tdta0x7f870c1b Destroying txdata Response msg 401/REGISTER/cseq=1 (tdta0x7f870c1b6510) 26-01-2015 19:05:38.591 UTC Debug acr.cpp:82: Sending Null ACR (0x7f870c1aa2b0) 26-01-2015 19:05:38.591 UTC Debug acr.cpp:53: Destroyed ACR (0x7f870c1aa2b0) 26-01-2015 19:05:38.591 UTC Debug stack.cpp:208: Worker thread completed processing message 0x7f8734097078 26-01-2015 19:05:38.591 UTC Debug stack.cpp:214: Request latency = 1927us 26-01-2015 19:05:38.593 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7f873400d328) 26-01-2015 19:05:38.593 UTC Verbose stack.cpp:243: RX 848 bytes Request msg REGISTER/cseq=1 (rdata0x7f873400d328) from TCP 192.168.1.41:42193<http://192.168.1.41:42193>: --start msg-- REGISTER sip:ims.hom SIP/2.0 Via: SIP/2.0/TCP 192.168.1.41:42193<http://192.168.1.41:42193> ;rport;branch=z9hG4bKPjqvLAEWzN3k7PI663pnNLz6zgU9Sk5XJ6 Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 192.168.1.39:5060<http://192.168.1.39:5060> ;rport=5060;received=192.168.1.39;branch=z9hG4bK1731639894 From: <sip:[email protected]>;tag=1334365898 To: <sip:[email protected]> Call-ID: 1090655798 CSeq: 1 REGISTER Contact: <sip:[email protected]:5060;line=9002fc03804a36b> Authorization: Digest username="[email protected]<mailto:[email protected]>", realm="ims.hom", nonce="2ebbd3a10aba9cfa", uri="sip:ims.hom", response="6da3503d6706fab2f9250a96ef9136b8", algorithm=MD5,integrity-protected=ip-assoc-pending Max-Forwards: 70 User-Agent: eXosip/3.1.0 Expires: 600000 P-Visited-Network-ID: ims.hom Session-Expires: 600 Route: <sip:sprout.ims.hom:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 26-01-2015 19:05:38.593 UTC Debug stack.cpp:470: Queuing cloned received message 0x7f8734097078 for worker threads 26-01-2015 19:05:38.593 UTC Debug stack.cpp:206: Worker thread dequeue message 0x7f8734097078 26-01-2015 19:05:38.593 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7f8734097078) 26-01-2015 19:05:38.593 UTC Debug authentication.cpp:486: Authorization header in request 26-01-2015 19:05:38.593 UTC Debug memcachedstore.cpp:174: Key av\\[email protected]\2ebbd3a10aba9cfa hashes to vbucket 34 via hash 0x325860a2 26-01-2015 19:05:38.593 UTC Debug memcachedstore.cpp:373: 1 read replicas for key av\\[email protected]\2ebbd3a10aba9cfa 26-01-2015 19:05:38.593 UTC Debug memcachedstore.cpp:406: Attempt to read from replica 0 (connection 0x7f87800cea30) *26-01-2015 19:05:38.593 UTC Debug memcachedstore.cpp:449: Read for av\\[email protected]\2ebbd3a10aba9cfa on replica 0 returned error 47 (SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY)26-01-2015 19:05:38.593 UTC Error memcachedstore.cpp:519: Failed to read data for av\\[email protected]\2ebbd3a10aba9cfa from 1 replicas*26-01-2015 19:05:38.593 UTC Debug authentication.cpp:539: Verify authentication information in request 26-01-2015 19:05:38.593 UTC Warning authentication.cpp:204: Received an authentication request for [email protected]<mailto:[email protected]> with nonce 2ebbd3a10aba9cfa, but no matching AV found 26-01-2015 19:05:38.593 UTC Debug acr.cpp:48: Created ACR (0x7f878014fea0) 26-01-2015 19:05:38.593 UTC Debug authentication.cpp:644: No authentication information in request or stale nonce, so reject with challenge 26-01-2015 19:05:38.593 UTC Debug pjsip: endpoint Response msg 401/REGISTER/cseq=1 (tdta0x7f87801a2070) created 26-01-2015 19:05:38.593 UTC Debug pjutils.cpp:461: Private identity from authorization header = [email protected]<mailto:[email protected]> 26-01-2015 19:05:38.593 UTC Debug httpresolver.cpp:70: HttpResolver::resolve for host hs.ims.hom, port 8888, family 2 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:501: Attempt to parse hs.ims.hom as IP address 26-01-2015 19:05:38.593 UTC Debug dnscachedresolver.cpp:179: Pulling 1 records from cache for hs.ims.hom A 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:349: Found 1 A/AAAA records, randomizing 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:491: 192.168.1.43:8888<http://192.168.1.43:8888> transport 6 is not blacklisted 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:370: Added a server, now have 1 of 5 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:408: Adding 0 servers from blacklist 26-01-2015 19:05:38.593 UTC Debug baseresolver.cpp:501: Attempt to parse 192.168.1.43 as IP address 26-01-2015 19:05:38.593 UTC Debug httpconnection.cpp:553: Sending HTTP request : http://hs.ims.hom:8888/impi/user10%40ims.hom/av?impu=sip%3Auser10%40ims.hom (trying 192.168.1.43) 26-01-2015 19:05:38.594 UTC Debug httpconnection.cpp:568: Received HTTP response: status=200, doc={"digest":{"ha1":"4a4a6a1e2aad77dcb54cb43acd17c59d","realm":"ims.hom","qop":"auth"}} 26-01-2015 19:05:38.594 UTC Debug authentication.cpp:146: Digest specified 26-01-2015 19:05:38.594 UTC Debug authentication.cpp:309: Valid AV - generate challenge 26-01-2015 19:05:38.594 UTC Debug authentication.cpp:315: Create WWW-Authenticate header 26-01-2015 19:05:38.594 UTC Debug authentication.cpp:359: Add Digest information 26-01-2015 19:05:38.595 UTC Debug authentication.cpp:386: Write AV to store 26-01-2015 19:05:38.595 UTC Debug avstore.cpp:66: Set AV for [email protected]<mailto:[email protected]> \256f5de87094a4d0 {"branch":"z9hG4bKPjqvLAEWzN3k7PI663pnNLz6zgU9Sk5XJ6","digest":{"ha1":"4a4a6a1e2aad77dcb54cb43acd17c59d","qop":"auth","realm":"ims.hom"}} 26-01-2015 19:05:38.595 UTC Debug memcachedstore.cpp:540: Writing 138 bytes to table av key [email protected]\256f5de87094a4d0<mailto:[email protected]\256f5de87094a4d0>, CAS = 0, expiry = 40 26-01-2015 19:05:38.595 UTC Debug memcachedstore.cpp:174: Key av\\[email protected]\256f5de87094a4d0 hashes to vbucket 127 via hash 0x8c22357f 26-01-2015 19:05:38.595 UTC Debug memcachedstore.cpp:560: 1 write replicas for key av\\[email protected]\256f5de87094a4d0 26-01-2015 19:05:38.595 UTC Debug memcachedstore.cpp:609: Attempt conditional write to replica 0 (connection 0x7f87800cea30), CAS = 0 *26-01-2015 19:05:38.595 UTC Debug memcachedstore.cpp:652: memcached_add command for av\\[email protected]\256f5de87094a4d0 failed on replica 0, rc = 47 (SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY), expiry = 40(140219945642544) SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY, host: 10.129.2.112:11211<http://10.129.2.112:11211> <http://10.129.2.112:11211> -> libmemcached/connect.cc:63326-01-2015 19:05:38.595 UTC Error memcachedstore.cpp:713: Failed to write data for av\\[email protected]\256f5de87094a4d0 to 1 replicas26-01-2015 19:05:38.595 UTC Error avstore.cpp:71: Failed to write Authentication Vector for private_id [email protected]<mailto:[email protected]> 19:05:38.595 UTC Verbose stack.cpp:259: TX 546 bytes Response msg 401/REGISTER/cseq=1 (tdta0x7f87801a2070) to TCP 192.168.1.41:42193<http://192.168.1.41:42193> <http://192.168.1.41:42193>:* The Memcached server is unable to read/write the data and hence we are facing the problem. Can you please suggest some steps so that we can curb this issue. Thanks, Sushant Hiray, Senior Undergrad CSE, IIT Bombay _______________________________________________ Clearwater mailing list [email protected]<mailto:[email protected]> http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
