libcloud: autopkgtest is flaky due to racy "test_retry_*" tests

Bug #1977320 reported by Nick Rosbrook
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
libcloud (Ubuntu)
Fix Released
Undecided
Nick Rosbrook

Bug Description

This issue has appeared recently on ppc64el autopkgtest [1]. The issue is that some of the tests from libcloud/test/test_connection.py incorrectly assume the mock side effects will always finish within the specified timeouts, which may not happen depending on the execution environment.

The following autopkgtest log snippets demonstrate this:

Take from [2]:

=================================== FAILURES ===================================
__ ConnectionClassTestCase.test_retry_on_all_default_retry_exception_classes ___

self = <test.test_connection.ConnectionClassTestCase testMethod=test_retry_on_all_default_retry_exception_classes>
mock_connect = <MagicMock name='request' id='134056393449408'>

    @patch('libcloud.common.base.Connection.request')
    def test_retry_on_all_default_retry_exception_classes(self, mock_connect):
        con = Connection()
        con.connection = Mock()
        connect_method = 'libcloud.common.base.Connection.request'

        self.retry_counter = 0

        def mock_connect_side_effect(*args, **kwargs):
            self.retry_counter += 1

            if self.retry_counter < len(RETRY_EXCEPTIONS):
                raise RETRY_EXCEPTIONS[self.retry_counter]

            return 'success'

        mock_connect.__name__ = 'mock_connect'
        mock_connect.side_effect = mock_connect_side_effect
        retry_request = Retry(timeout=0.6, retry_delay=0.1,
                                backoff=1)
> result = retry_request(con.request)(action='/')

test/test_connection.py:583:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/usr/lib/python3/dist-packages/libcloud/utils/retry.py:127: in retry_loop
    raise last_exc
/usr/lib/python3/dist-packages/libcloud/utils/retry.py:103: in retry_loop
    return transform_ssl_error(func, *args, **kwargs)
/usr/lib/python3/dist-packages/libcloud/utils/retry.py:93: in transform_ssl_error
    raise exc
/usr/lib/python3/dist-packages/libcloud/utils/retry.py:88: in transform_ssl_error
    return function(*args, **kwargs)
/usr/lib/python3/dist-packages/mock/mock.py:1100: in __call__
    return _mock_self._mock_call(*args, **kwargs)
/usr/lib/python3/dist-packages/mock/mock.py:1104: in _mock_call
    return _mock_self._execute_mock_call(*args, **kwargs)
/usr/lib/python3/dist-packages/mock/mock.py:1167: in _execute_mock_call
    result = effect(*args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

args = (), kwargs = {'action': '/'}

    def mock_connect_side_effect(*args, **kwargs):
        self.retry_counter += 1

        if self.retry_counter < len(RETRY_EXCEPTIONS):
> raise RETRY_EXCEPTIONS[self.retry_counter]
E libcloud.utils.retry.TransientSSLError: ()

test/test_connection.py:575: TransientSSLError
---

Taken from [3]:

=================================== FAILURES ===================================
_______________ ConnectionClassTestCase.test_retry_with_timeout ________________

self = <test.test_connection.ConnectionClassTestCase testMethod=test_retry_with_timeout>
mock_connect = <MagicMock name='request' id='127398439136048'>

    @patch('libcloud.common.base.Connection.request')
    def test_retry_with_timeout(self, mock_connect):
        con = Connection()
        con.connection = Mock()

        mock_connect.side_effect = socket.gaierror('')
        retry_request = Retry(timeout=0.2, retry_delay=0.1,
                                backoff=1)
        self.assertRaises(socket.gaierror,
                          retry_request(con.request), action='/')

> self.assertGreater(mock_connect.call_count, 1,
                            'Retry logic failed')
E AssertionError: 1 not greater than 1 : Retry logic failed

test/test_connection.py:457: AssertionError
---

[1] https://autopkgtest.ubuntu.com/packages/libc/libcloud/kinetic/ppc64el
[2] https://autopkgtest.ubuntu.com/results/autopkgtest-kinetic/kinetic/ppc64el/libc/libcloud/20220528_194230_765c9@/log.gz
[3] https://autopkgtest.ubuntu.com/results/autopkgtest-kinetic/kinetic/ppc64el/libc/libcloud/20220526_090523_a6c63@/log.gz

Tags: fr-2446
Nick Rosbrook (enr0n)
Changed in libcloud (Ubuntu):
assignee: nobody → Nick Rosbrook (enr0n)
status: New → In Progress
Revision history for this message
Nick Rosbrook (enr0n) wrote :
Revision history for this message
Nick Rosbrook (enr0n) wrote :
Nick Rosbrook (enr0n)
tags: added: fr-2446
Revision history for this message
Benjamin Drung (bdrung) wrote :

Review result:
1) Can you forward the patch upstream (and refer to upstream in the patch header)?
2) IMO it makes sense to introduce a timeout constant as global variable (for making the timeout change a one-liner).

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Thanks for reviewing. I will send the patch upstream, and update the header to reflect this. As far as a constant global for timeout, I will send the patch without because there are various timeouts used based on the context. Of course, if upstream prefers that I will make the change.

Revision history for this message
Nick Rosbrook (enr0n) wrote :
Steve Langasek (vorlon)
Changed in libcloud (Ubuntu):
status: In Progress → Fix Committed
Revision history for this message
Benjamin Drung (bdrung) wrote :

Thanks. Uploaded libcloud 3.4.1-5 with your change to Debian unstable.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package libcloud - 3.4.1-5

---------------
libcloud (3.4.1-5) unstable; urgency=medium

  [ Nick Rosbrook ]
  * Team upload.
  * debian/patches/0008-tests-adjust-retry-timeouts.patch: Alleviate race
    conditions in test_retry_* tests (LP: #1977320).

 -- Benjamin Drung <email address hidden> Fri, 10 Jun 2022 11:52:59 +0200

Changed in libcloud (Ubuntu):
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.