Unit tests: mock some time.sleep and time.time

Similar to what Cinder did here [1], this patch mocks time.sleep
to make tests run faster. Some code actually measure the wall clock
to wait for a specific duration before raising a TimeoutError, so
we also need to mock time.time.

This removes ~5sec in unit test and also removes some busy waiting.

[1] https://review.openstack.org/#/c/285658/

Change-Id: I69ba35eff591a5df28049273f3aba15c31f52d00

tempest/tests/common/test_waiters.py

@@ -20,6 +20,7 @@ from tempest.common import waiters
 from tempest import exceptions
 from tempest.services.volume.base import base_volumes_client
 from tempest.tests import base
+import tempest.tests.utils as utils
 
 
 class TestImageWaiters(base.TestCase):
@@ -37,17 +38,24 @@ class TestImageWaiters(base.TestCase):
         # Ensure waiter returns before build_timeout
         self.assertTrue((end_time - start_time) < 10)
 
-    def test_wait_for_image_status_timeout(self):
+    @mock.patch('time.sleep')
+    def test_wait_for_image_status_timeout(self, mock_sleep):
+        time_mock = self.patch('time.time')
+        time_mock.side_effect = utils.generate_timeout_series(1)
+
         self.client.show_image.return_value = ({'status': 'saving'})
         self.assertRaises(exceptions.TimeoutException,
                           waiters.wait_for_image_status,
                           self.client, 'fake_image_id', 'active')
+        mock_sleep.assert_called_once_with(1)
 
-    def test_wait_for_image_status_error_on_image_create(self):
+    @mock.patch('time.sleep')
+    def test_wait_for_image_status_error_on_image_create(self, mock_sleep):
         self.client.show_image.return_value = ({'status': 'ERROR'})
         self.assertRaises(exceptions.AddImageException,
                           waiters.wait_for_image_status,
                           self.client, 'fake_image_id', 'active')
+        mock_sleep.assert_called_once_with(1)
 
     @mock.patch.object(time, 'sleep')
     def test_wait_for_volume_status_error_restoring(self, mock_sleep):

tempest/tests/lib/test_rest_client.py

@@ -25,6 +25,7 @@ from tempest.lib import exceptions
 from tempest.tests.lib import base
 from tempest.tests.lib import fake_auth_provider
 from tempest.tests.lib import fake_http
+import tempest.tests.utils as utils
 
 
 class BaseRestClientTestClass(base.TestCase):
@@ -511,11 +512,20 @@ class TestRestClientUtils(BaseRestClientTestClass):
     def test_wait_for_resource_deletion_not_deleted(self):
         self.patch('time.sleep')
         # Set timeout to be very quick to force exception faster
-        self.rest_client.build_timeout = 1
+        timeout = 1
+        self.rest_client.build_timeout = timeout
+
+        time_mock = self.patch('time.time')
+        time_mock.side_effect = utils.generate_timeout_series(timeout)
+
         self.assertRaises(exceptions.TimeoutException,
                           self.rest_client.wait_for_resource_deletion,
                           '1234')
 
+        # time.time() should be called twice, first to start the timer
+        # and then to compute the timedelta
+        self.assertEqual(2, time_mock.call_count)
+
     def test_wait_for_deletion_with_unimplemented_deleted_method(self):
         self.rest_client.is_resource_deleted = self.original_deleted_method
         self.assertRaises(NotImplementedError,

tempest/tests/lib/test_ssh.py

@@ -14,7 +14,6 @@
 
 from io import StringIO
 import socket
-import time
 
 import mock
 import six
@@ -23,6 +22,7 @@ import testtools
 from tempest.lib.common import ssh
 from tempest.lib import exceptions
 from tempest.tests.lib import base
+import tempest.tests.utils as utils
 
 
 class TestSshClient(base.TestCase):
@@ -79,7 +79,8 @@ class TestSshClient(base.TestCase):
         self.assertEqual(expected_connect, client_mock.connect.mock_calls)
         self.assertEqual(0, s_mock.call_count)
 
-    def test_get_ssh_connection_two_attemps(self):
+    @mock.patch('time.sleep')
+    def test_get_ssh_connection_two_attemps(self, sleep_mock):
         c_mock, aa_mock, client_mock = self._set_ssh_connection_mocks()
 
         c_mock.return_value = client_mock
@@ -89,15 +90,18 @@ class TestSshClient(base.TestCase):
         ]
 
         client = ssh.Client('localhost', 'root', timeout=1)
-        start_time = int(time.time())
         client._get_ssh_connection(sleep=1)
-        end_time = int(time.time())
+        # We slept 2 seconds: because sleep is "1" and backoff is "1" too
-        self.assertLess((end_time - start_time), 4)
+        sleep_mock.assert_called_once_with(2)
-        self.assertGreater((end_time - start_time), 1)
+        self.assertEqual(2, client_mock.connect.call_count)
 
     def test_get_ssh_connection_timeout(self):
         c_mock, aa_mock, client_mock = self._set_ssh_connection_mocks()
 
+        timeout = 2
+        time_mock = self.patch('time.time')
+        time_mock.side_effect = utils.generate_timeout_series(timeout + 1)
+
         c_mock.return_value = client_mock
         client_mock.connect.side_effect = [
             socket.error,
@@ -105,13 +109,16 @@ class TestSshClient(base.TestCase):
             socket.error,
         ]
 
-        client = ssh.Client('localhost', 'root', timeout=2)
+        client = ssh.Client('localhost', 'root', timeout=timeout)
-        start_time = int(time.time())
+        # We need to mock LOG here because LOG.info() calls time.time()
-        with testtools.ExpectedException(exceptions.SSHTimeout):
+        # in order to preprend a timestamp.
-            client._get_ssh_connection()
+        with mock.patch.object(ssh, 'LOG'):
-        end_time = int(time.time())
+            self.assertRaises(exceptions.SSHTimeout,
-        self.assertLess((end_time - start_time), 5)
+                              client._get_ssh_connection)
-        self.assertGreaterEqual((end_time - start_time), 2)
+
+        # time.time() should be called twice, first to start the timer
+        # and then to compute the timedelta
+        self.assertEqual(2, time_mock.call_count)
 
     @mock.patch('select.POLLIN', SELECT_POLLIN, create=True)
     def test_timeout_in_exec_command(self):

tempest/tests/utils.py

@@ -0,0 +1,29 @@
+#    Copyright 2016 OpenStack Foundation
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+#
+
+
+def generate_timeout_series(timeout):
+    """Generate a series of times that exceeds the given timeout.
+
+    Yields a series of fake time.time() floating point numbers
+    such that the difference between each pair in the series just
+    exceeds the timeout value that is passed in.  Useful for
+    mocking time.time() in methods that otherwise wait for timeout
+    seconds.
+    """
+    iteration = 0
+    while True:
+        iteration += 1
+        yield (iteration * timeout) + iteration