From 4e472a3e0241313bd4de1a189c8082934453260b Mon Sep 17 00:00:00 2001 From: Gorka Eguileor Date: Wed, 14 Apr 2021 19:43:16 +0200 Subject: [PATCH] Fix sporadic cleanup unit test failure From time to time we see unit test test_do_cleanup_not_cleaning_already_claimed_by_us failing at the gate with error: testtools.matchers._impl.MismatchError: 1 != 0 This happens because the test was assuming that the machine running the code would get different times in consecutive utcnow() calls, which sometimes is not the case if the machine is fast. The places where the call is expected to have different values are: - When the test assigns original_time - When the test assigns other_thread_claimed_time - When cinder.manager.CleanableManager.do_cleanup assigns until This patch fixes this issue by simulating that: - worker1 entry was created in the past (original_time is T-1) - db's worker_get_all is mocked to simulate that worker2 entry was created in the past (T-1) - simulate that another thread has picked up the worker2 entry by writing a newer time in the DB (other_thread_claimed_time) - making sure that the do_cleanup method uses a time between these two (T) This way we will no longer rely on the values returned by utcnow(). Change-Id: I45f1a057151e749e8c44f266ec8b41a80761ebec (cherry picked from commit 1c3cda154f85dd09041a8d93f4d29d9ebc57a47b) --- cinder/tests/unit/test_cleanable_manager.py | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/cinder/tests/unit/test_cleanable_manager.py b/cinder/tests/unit/test_cleanable_manager.py index 2dcd02bf026..043b2c98929 100644 --- a/cinder/tests/unit/test_cleanable_manager.py +++ b/cinder/tests/unit/test_cleanable_manager.py @@ -110,8 +110,15 @@ class TestCleanableManager(test.TestCase): def test_do_cleanup_not_cleaning_already_claimed_by_us(self): """Basic cleanup that doesn't touch other thread's claimed works.""" - original_time = timeutils.utcnow() - other_thread_claimed_time = timeutils.utcnow() + now = timeutils.utcnow() + delta = timeutils.datetime.timedelta(seconds=1) + original_time = now - delta + # Creating the worker in the future, and then changing the in-memory + # value of worker2.updated_at to an earlier time, we effectively + # simulate that the worker entry was created in the past and that it + # has been just updated between worker_get_all and trying + # to claim a work for cleanup + other_thread_claimed_time = now + delta vol = utils.create_volume(self.context, status='creating') worker1 = db.worker_create(self.context, status='creating', resource_type='Volume', resource_id=vol.id, @@ -124,14 +131,14 @@ class TestCleanableManager(test.TestCase): service_id=self.service.id, updated_at=other_thread_claimed_time) worker2 = db.worker_get(self.context, id=worker2.id) - - # Simulate that the change to vol2 worker happened between - # worker_get_all and trying to claim a work for cleanup + # This with the mock below simulates worker2 was created in the past + # and updated right between worker_get_all and worker_claim_for_cleanup worker2.updated_at = original_time clean_req = objects.CleanupRequest(service_id=self.service.id) mngr = FakeManager(self.service.id) - with mock.patch('cinder.db.worker_get_all') as get_all_mock: + with mock.patch('cinder.manager.timeutils.utcnow', return_value=now),\ + mock.patch('cinder.db.worker_get_all') as get_all_mock: get_all_mock.return_value = [worker1, worker2] mngr.do_cleanup(self.context, clean_req)