From 8d23dd8ac657aa727cd01ccb739a54511a307c29 Mon Sep 17 00:00:00 2001 From: Clay Gerrard Date: Tue, 25 Apr 2023 17:04:44 -0500 Subject: Log (Watchdog's) Timeouts with duration ... and clean up WatchDog start a little. If this pattern proves useful we could consider extending it. Change-Id: Ia85f9321b69bc4114a60c32a7ad082cae7da72b3 --- test/unit/common/test_utils.py | 17 ++++++++++++----- test/unit/proxy/controllers/test_obj.py | 4 ++-- 2 files changed, 14 insertions(+), 7 deletions(-) (limited to 'test') diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index e477ee85d..300fdb021 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -1144,11 +1144,15 @@ class TestUtils(unittest.TestCase): # test eventlet.Timeout with ConnectionTimeout(42, 'my error message') \ as connection_timeout: - log_exception(connection_timeout) + now = time.time() + connection_timeout.created_at = now - 123.456 + with mock.patch('swift.common.utils.time.time', + return_value=now): + log_exception(connection_timeout) log_msg = strip_value(sio) self.assertNotIn('Traceback', log_msg) self.assertTrue('ConnectionTimeout' in log_msg) - self.assertTrue('(42s)' in log_msg) + self.assertTrue('(42s after 123.46s)' in log_msg) self.assertNotIn('my error message', log_msg) with MessageTimeout(42, 'my error message') as message_timeout: @@ -8744,13 +8748,16 @@ class TestWatchdog(unittest.TestCase): w._evt.send = mock.Mock(side_effect=w._evt.send) gth = object() + now = time.time() + timeout_value = 1.0 with patch('eventlet.greenthread.getcurrent', return_value=gth),\ - patch('time.time', return_value=10.0): + patch('time.time', return_value=now): # On first call, _next_expiration is None, it should unblock # greenthread that is blocked for ever - key = w.start(1.0, Timeout) + key = w.start(timeout_value, Timeout) self.assertIn(key, w._timeouts) - self.assertEqual(w._timeouts[key], (1.0, 11.0, gth, Timeout)) + self.assertEqual(w._timeouts[key], ( + timeout_value, now + timeout_value, gth, Timeout, now)) w._evt.send.assert_called_once() w.stop(key) diff --git a/test/unit/proxy/controllers/test_obj.py b/test/unit/proxy/controllers/test_obj.py index 0b8bf1568..38c40b2db 100644 --- a/test/unit/proxy/controllers/test_obj.py +++ b/test/unit/proxy/controllers/test_obj.py @@ -4927,7 +4927,7 @@ class TestECObjController(ECObjectControllerMixin, unittest.TestCase): for line in error_lines[:nparity]: self.assertIn('retrying', line) for line in error_lines[nparity:]: - self.assertIn('ChunkReadTimeout (0.01s)', line) + self.assertIn('ChunkReadTimeout (0.01s', line) for line in self.logger.logger.records['ERROR']: self.assertIn(req.headers['x-trans-id'], line) @@ -5012,7 +5012,7 @@ class TestECObjController(ECObjectControllerMixin, unittest.TestCase): error_lines = self.logger.get_lines_for_level('error') self.assertEqual(ndata, len(error_lines)) for line in error_lines: - self.assertIn('ChunkReadTimeout (0.01s)', line) + self.assertIn('ChunkReadTimeout (0.01s', line) for line in self.logger.logger.records['ERROR']: self.assertIn(req.headers['x-trans-id'], line) -- cgit v1.2.1