From 17cef16133d12a42238b93c0d935b7a0210aa547 Mon Sep 17 00:00:00 2001 From: Tim Burke Date: Thu, 7 Jan 2021 21:00:59 -0800 Subject: [PATCH] memcache: Log errors encountered when setting keys This catches, for example, when memcached starts replying with SERVER_ERROR object too large for cache By then, of course, operators will already be in a world of hurt -- but at least now logs should make it obvious what the problem is. Change-Id: Ib241f4acd180fcb310cf134f01f08eff9b0cfbca --- swift/common/memcached.py | 9 ++++++++- test/unit/common/test_memcached.py | 24 +++++++++++++++++++++++- 2 files changed, 31 insertions(+), 2 deletions(-) diff --git a/swift/common/memcached.py b/swift/common/memcached.py index 6efe5669c5..bbdd40c85a 100644 --- a/swift/common/memcached.py +++ b/swift/common/memcached.py @@ -299,7 +299,14 @@ class MemcacheRing(object): with Timeout(self._io_timeout): sock.sendall(set_msg(key, flags, timeout, value)) # Wait for the set to complete - fp.readline() + msg = fp.readline().strip() + if msg != b'STORED': + if not six.PY2: + msg = msg.decode('ascii') + self.logger.error( + "Error setting value in memcached: " + "%(server)s: %(msg)s", + {'server': server, 'msg': msg}) self._return_conn(server, fp, sock) return except (Exception, Timeout) as e: diff --git a/test/unit/common/test_memcached.py b/test/unit/common/test_memcached.py index 61f9bf062c..a13cf637a1 100644 --- a/test/unit/common/test_memcached.py +++ b/test/unit/common/test_memcached.py @@ -62,6 +62,7 @@ class ExplodingMockMemcached(object): if self.should_explode: self.exploded = True raise socket.error(errno.EPIPE, os.strerror(errno.EPIPE)) + return b'STORED\r\n' def read(self, size): if self.should_explode: @@ -72,6 +73,10 @@ class ExplodingMockMemcached(object): pass +TOO_BIG_KEY = md5( + b'too-big', usedforsecurity=False).hexdigest().encode('ascii') + + class MockMemcached(object): # See https://github.com/memcached/memcached/blob/master/doc/protocol.txt # In particular, the "Storage commands" section may be interesting. @@ -104,7 +109,10 @@ class MockMemcached(object): self.cache[key] = flags, exptime, self.inbuf[:int(num_bytes)] self.inbuf = self.inbuf[int(num_bytes) + 2:] if noreply != b'noreply': - self.outbuf += b'STORED\r\n' + if key == TOO_BIG_KEY: + self.outbuf += b'SERVER_ERROR object too large for cache\r\n' + else: + self.outbuf += b'STORED\r\n' def handle_add(self, key, flags, exptime, num_bytes, noreply=b''): value = self.inbuf[:int(num_bytes)] @@ -366,6 +374,18 @@ class TestMemcached(unittest.TestCase): _junk, cache_timeout, _junk = mock.cache[cache_key] self.assertAlmostEqual(float(cache_timeout), esttimeout, delta=1) + def test_set_error(self): + memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'], + logger=self.logger) + mock = MockMemcached() + memcache_client._client_cache['1.2.3.4:11211'] = MockedMemcachePool( + [(mock, mock)] * 2) + memcache_client.set('too-big', [1, 2, 3]) + self.assertEqual( + self.logger.get_lines_for_level('error'), + ['Error setting value in memcached: 1.2.3.4:11211: ' + 'SERVER_ERROR object too large for cache']) + def test_get_failed_connection_mid_request(self): memcache_client = memcached.MemcacheRing(['1.2.3.4:11211'], logger=self.logger) @@ -847,11 +867,13 @@ class TestMemcached(unittest.TestCase): # fast. All ten (10) clients should try to talk to .5 first, and # then move on to .4, and we'll assert all that below. mock_conn = MagicMock(), MagicMock() + mock_conn[0].readline = lambda: b'STORED\r\n' mock_conn[1].sendall = lambda x: sleep(0.2) connections['1.2.3.5'].put(mock_conn) connections['1.2.3.5'].put(mock_conn) mock_conn = MagicMock(), MagicMock() + mock_conn[0].readline = lambda: b'STORED\r\n' connections['1.2.3.4'].put(mock_conn) connections['1.2.3.4'].put(mock_conn)