Gate failure : AssertionError: Lists differ: [] != [<Thread(tpool_thread_0, started daemon 14[1123 chars]56)>]

Bug #1811663 reported by Rajat Dhasmana
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
In Progress
Undecided
Rajat Dhasmana

Bug Description

The gate failure logs are :

ft1.39: cinder.tests.unit.volume.test_volume.VolumeTestCase.test_tpool_sizetesttools.testresult.real._StringException: Empty attachments:
  stderr
  stdout

pythonlogging:'': {{{
2019-01-14 07:14:05,488 INFO [keystonemiddleware.auth_token] Starting Keystone auth_token middleware
2019-01-14 07:14:05,492 WARNING [keystonemiddleware._common.config] The option "auth_url" in conf is not known to auth_token
2019-01-14 07:14:05,493 WARNING [keystonemiddleware.auth_token] AuthToken middleware is set with keystone_authtoken.service_token_roles_required set to False. This is backwards compatible but deprecated behaviour. Please set this to True.
2019-01-14 07:14:05,495 WARNING [keystonemiddleware.auth_token] Configuring auth_uri to point to the public identity endpoint is required; clients may not be able to authenticate against an admin endpoint
2019-01-14 07:14:05,515 INFO [cinder.rpc] Automatically selected cinder-scheduler objects version 1.37 as minimum service version.
2019-01-14 07:14:05,518 INFO [cinder.rpc] Automatically selected cinder-scheduler RPC version 3.11 as minimum service version.
2019-01-14 07:14:05,584 INFO [cinder.volume.drivers.rbd] Purging trash for backend 'RBDDriver'
2019-01-14 07:14:05,597 INFO [cinder.volume.manager] Determined volume DB was empty at startup.
2019-01-14 07:14:05,606 INFO [cinder.volume.manager] Service not found for updating active_backend_id, assuming default for driver init.
2019-01-14 07:14:05,608 INFO [cinder.volume.manager] Image-volume cache disabled for host ubuntu-xenial-rax-dfw-0001677582.
2019-01-14 07:14:05,613 INFO [cinder.rpc] Automatically selected cinder-volume objects version 1.37 as minimum service version.
2019-01-14 07:14:05,616 INFO [cinder.rpc] Automatically selected cinder-volume RPC version 3.16 as minimum service version.
2019-01-14 07:14:05,620 WARNING [py.warnings] /home/zuul/src/git.openstack.org/openstack/cinder/.tox/lower-constraints/lib/python3.5/site-packages/oslo_policy/_checks.py:76: DeprecationWarning: inspect.getargspec() is deprecated, use inspect.signature() instead
  argspec = inspect.getargspec(rule.__call__)
}}}

Traceback (most recent call last):
  File "/home/zuul/src/git.openstack.org/openstack/cinder/cinder/tests/unit/volume/test_volume.py", line 3097, in test_tpool_size
    self.assertListEqual([], eventlet.tpool._threads)
  File "/home/zuul/src/git.openstack.org/openstack/cinder/.tox/lower-constraints/lib/python3.5/site-packages/unittest2/case.py", line 1032, in assertListEqual
    self.assertSequenceEqual(list1, list2, msg, seq_type=list)
  File "/home/zuul/src/git.openstack.org/openstack/cinder/.tox/lower-constraints/lib/python3.5/site-packages/unittest2/case.py", line 1014, in assertSequenceEqual
    self.fail(msg)
  File "/home/zuul/src/git.openstack.org/openstack/cinder/.tox/lower-constraints/lib/python3.5/site-packages/unittest2/case.py", line 690, in fail
    raise self.failureException(msg)
AssertionError: Lists differ: [] != [<Thread(tpool_thread_0, started daemon 14[1123 chars]56)>]

Second list contains 20 additional elements.
First extra element 0:
<Thread(tpool_thread_0, started daemon 140093889169152)>

Diff is 1235 characters long. Set self.maxDiff to None to see it.

------------------------------------------------------------------------------------------------

It occurs at [1] and my understanding of the problem is as follows:

The default tpool._nthreads size is 20 [2].
The default list tpool._threads is empty [2].
The tpool.execute method starts creating threads[3] (no of threads = tpool._nthreads) and adds them to the list(tpool._threads)
As per Gorka's comment[4]
"when you are dealing with a big project that relies on many libraries it may be
harder to control if any of those libraries have already called execute
before you try to set the initial its value."
The reason of the failure seems to be some other test(backup, image, volume) calling the tpool.execute filling up the tpool._threads list in [1].

Since i'm no expert in threads, this is just my observation of the situation, any feedback is appreciated. Thanks!

[1] https://github.com/openstack/cinder/blob/master/cinder/tests/unit/volume/test_volume.py#L3097
[2] https://github.com/Cue/eventlet/blob/master/eventlet/tpool.py#L226-L227
[3] https://github.com/Cue/eventlet/blob/master/eventlet/tpool.py#L262-L268
[4] https://github.com/eventlet/eventlet/pull/472

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (master)

Fix proposed to branch: master
Review: https://review.openstack.org/630648

Changed in cinder:
assignee: nobody → Rajat Dhasmana (whoami-rajat)
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to cinder (master)

Reviewed: https://review.openstack.org/630648
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=c841dce838397c0d1e57f5964eac699672536814
Submitter: Zuul
Branch: master

commit c841dce838397c0d1e57f5964eac699672536814
Author: whoami-rajat <email address hidden>
Date: Mon Jan 14 16:32:59 2019 +0530

    Temporary solution for fixing gate test_tpool_size

    This is a temporary solution to merge patches failing gate continiously
    due to an unrelated test.
    the test_tpool_size and test_default_tpool_size tests are basically
    to check the config param 'backend_native_threads_pool_size' which
    can be skipped temporarily.

    Change-Id: I9dad0d45c3c4600a6567f34bb851b10a3f5d966b
    Partial-Bug: #1811663

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.