Fix memcached exception out of range stacktrace

When a memecached server goes offline in the middle of a
MemcahceRing (swift memcache client) session then a request
to memcached returns nothing and the client inside swift
leaves an "IndexError: list index out of range" stacktrace.

This change corrects that in all the places of MemcacheRing
that is susceptible to it, and added some tests to stop
regression.

Clay added a diff to the bug that pretty much did the same
thing I did, so I'll co-author him.

Change-Id: I97c5420b4b4ecc127e9e94e9d0f91fbe92a5f623
Co-Authored-By: Clay Gerrard <clay.gerrard@gmail.com>
Closes-Bug: #897451

swift/common/memcached.py

@@ -164,7 +164,7 @@ class MemcacheRing(object):
         if isinstance(e, Timeout):
             logging.error("Timeout %(action)s to memcached: %(server)s",
                           {'action': action, 'server': server})
-        elif isinstance(e, socket.error):
+        elif isinstance(e, (socket.error, MemcacheConnectionError)):
             logging.error("Error %(action)s to memcached: %(server)s: %(err)s",
                           {'action': action, 'server': server, 'err': e})
         else:
@@ -283,7 +283,11 @@ class MemcacheRing(object):
                 with Timeout(self._io_timeout):
                     sock.sendall('get %s\r\n' % key)
                     line = fp.readline().strip().split()
-                    while line[0].upper() != 'END':
+                    while True:
+                        if not line:
+                            raise MemcacheConnectionError('incomplete read')
+                        if line[0].upper() == 'END':
+                            break
                         if line[0].upper() == 'VALUE' and line[1] == key:
                             size = int(line[3])
                             value = fp.read(size)
@@ -329,6 +333,8 @@ class MemcacheRing(object):
                 with Timeout(self._io_timeout):
                     sock.sendall('%s %s %s\r\n' % (command, key, delta))
                     line = fp.readline().strip().split()
+                    if not line:
+                        raise MemcacheConnectionError('incomplete read')
                     if line[0].upper() == 'NOT_FOUND':
                         add_val = delta
                         if command == 'decr':
@@ -444,7 +450,11 @@ class MemcacheRing(object):
                     sock.sendall('get %s\r\n' % ' '.join(keys))
                     line = fp.readline().strip().split()
                     responses = {}
-                    while line[0].upper() != 'END':
+                    while True:
+                        if not line:
+                            raise MemcacheConnectionError('incomplete read')
+                        if line[0].upper() == 'END':
+                            break
                         if line[0].upper() == 'VALUE':
                             size = int(line[3])
                             value = fp.read(size)

test/unit/common/test_memcached.py

@@ -19,6 +19,7 @@
 from collections import defaultdict
 import errno
 from hashlib import md5
+import six
 import socket
 import time
 import unittest
@@ -76,6 +77,7 @@ class MockMemcached(object):
         self.down = False
         self.exc_on_delete = False
         self.read_return_none = False
+        self.read_return_empty_str = False
         self.close_called = False
 
     def sendall(self, string):
@@ -148,6 +150,8 @@ class MockMemcached(object):
             self.outbuf += 'NOT_FOUND\r\n'
 
     def readline(self):
+        if self.read_return_empty_str:
+            return ''
         if self.read_return_none:
             return None
         if self.down:
@@ -336,6 +340,31 @@ class TestMemcached(unittest.TestCase):
         _junk, cache_timeout, _junk = mock.cache[cache_key]
         self.assertAlmostEqual(float(cache_timeout), esttimeout, delta=1)
 
+    def test_get_failed_connection_mid_request(self):
+        memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'])
+        mock = MockMemcached()
+        memcache_client._client_cache['1.2.3.4:11211'] = MockedMemcachePool(
+            [(mock, mock)] * 2)
+        memcache_client.set('some_key', [1, 2, 3])
+        self.assertEqual(memcache_client.get('some_key'), [1, 2, 3])
+        self.assertEqual(mock.cache.values()[0][1], '0')
+
+        # Now lets return an empty string, and make sure we aren't logging
+        # the error.
+        fake_stdout = six.StringIO()
+        not_expected = "Traceback"
+
+        # force the logging through the debug_handler instead of the nose
+        # handler. This will use stdout, so we can access the IndexError stack
+        # trace if there is one raised.
+        logger = debug_logger()
+        with patch("sys.stdout", fake_stdout),\
+                patch('logging.exception', logger.exception),\
+                patch('logging.error', logger.error):
+            mock.read_return_empty_str = True
+            self.assertEqual(memcache_client.get('some_key'), None)
+            self.assertNotIn(not_expected, fake_stdout.getvalue())
+
     def test_incr(self):
         memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'])
         mock = MockMemcached()
@@ -356,6 +385,33 @@ class TestMemcached(unittest.TestCase):
                           memcache_client.incr, 'some_key', delta=-15)
         self.assertTrue(mock.close_called)
 
+    def test_incr_failed_connection_mid_request(self):
+        memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'])
+        mock = MockMemcached()
+        memcache_client._client_cache['1.2.3.4:11211'] = MockedMemcachePool(
+            [(mock, mock)] * 2)
+        self.assertEqual(memcache_client.incr('some_key', delta=5), 5)
+        self.assertEqual(memcache_client.get('some_key'), '5')
+        self.assertEqual(memcache_client.incr('some_key', delta=5), 10)
+        self.assertEqual(memcache_client.get('some_key'), '10')
+
+        # Now lets return an empty string, and make sure we aren't logging
+        # the error.
+        fake_stdout = six.StringIO()
+        not_expected = "IndexError: list index out of range"
+
+        # force the logging through the debug_handler instead of the nose
+        # handler. This will use stdout, so we can access the IndexError stack
+        # trace if there is one raised.
+        logger = debug_logger()
+        with patch("sys.stdout", fake_stdout), \
+                patch('logging.exception', logger.exception), \
+                patch('logging.error', logger.error):
+            mock.read_return_empty_str = True
+            self.assertRaises(memcached.MemcacheConnectionError,
+                              memcache_client.incr, 'some_key', delta=1)
+            self.assertFalse(not_expected in fake_stdout.getvalue())
+
     def test_incr_w_timeout(self):
         memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'])
         mock = MockMemcached()
@@ -481,6 +537,17 @@ class TestMemcached(unittest.TestCase):
             ('some_key2', 'some_key1', 'not_exists'), 'multi_key'),
             [[4, 5, 6], [1, 2, 3], None])
 
+        # Now lets simulate a lost connection and make sure we don't get
+        # the index out of range stack trace when it does
+        mock_stderr = six.StringIO()
+        not_expected = "IndexError: list index out of range"
+        with patch("sys.stderr", mock_stderr):
+            mock.read_return_empty_str = True
+            self.assertEqual(memcache_client.get_multi(
+                ('some_key2', 'some_key1', 'not_exists'), 'multi_key'),
+                None)
+            self.assertFalse(not_expected in mock_stderr.getvalue())
+
     def test_serialization(self):
         memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'],
                                                  allow_pickle=True)