Robottelo: HostTestCase setUpClass: Publish Task of CV with puppet modules failed

[lpramuk]

setUpClass failed for these tests:

• [ ] api.test_host.HostTestCase.test_positive_create_with_ip
• [ ] api.test_host.HostTestCase.test_positive_get_per_page
• [ ] api.test_host.HostTestCase.test_positive_update_managed_parameter

    @classmethod
    def setUpClass(cls):
        """Setup common entities."""
        super(HostTestCase, cls).setUpClass()
        cls.org = entities.Organization().create()
        cls.loc = entities.Location(organization=[cls.org]).create()
        # Content View and repository related entities
        cls.cv = publish_puppet_module(
            [{'author': 'robottelo', 'name': 'generic_1'}],
            CUSTOM_PUPPET_REPO,
>           organization_id=cls.org.id

Task of publishing CV with puppet module failed.

PG::Error: ERROR:  duplicate key value violates unique constraint "index_katello_puppet_modules_on_uuid"
DETAIL:  Key (uuid)=(1f23245d-7756-4077-842a-6d622b4990de) already exists.
: INSERT INTO "katello_puppet_modules" ("author", "created_at", "name", "sortable_version", "summary", "updated_at", "uuid", "version") VALUES ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING "id"'

This probably will be a bug, though not deterministic one (rhel6 is ok)
Yet I need to confirm.

[lpramuk]

I didn't get why only 3 tests failed when setUpClass had failed? (I would have expected all or nothing)

Investigation showed that setUpClass is run in every thread that needs it. Only [gw0] thread tests failed.
That means setUpClass can run multiple times and concurrently thus producing race conditions like this one.

Furthermore, increasing numbers of threads can lead to longer execution times as setUps are run for every thread separately. If we have expensive and long setup then it is better to have less threads. (Or you could end up in having setUp/setUpClass run for every single test)

Or is there any advanced option to control how pytest distributes tests among threads. To tell do not split one class among threads (= distribute whole class to a particular thread)

[rplevka]

lack of control over which tests got to be pinned to the same worker seems to be a known py.test flaw:
https://bitbucket.org/pytest-dev/pytest/issues/175

[lpramuk]

Not really race condition. Just 1 instance of setUpClass failed out of 8 instances.
I checked that api.test_host.HostTestCase was distributed among all 8 threads gw0-7
But only in gw0 thread it failed.

[rplevka]

here's the chronology of the executed tests with a worker mapping:

2017-02-08 12:06:20 - gw0 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
    # note: the above setUpClass has failed, flushing the other scheduled HostTestCase tests assigned to gw0

2017-02-08 12:07:00 - gw0 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_hostcollection/HostCollectionTestCase

2017-02-08 12:06:40 - gw1 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:08:04 - gw1 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_managed_parameter
2017-02-08 12:08:09 - gw1 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_managed_parameter
2017-02-08 12:08:09 - gw1 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_get_search
2017-02-08 12:08:09 - gw1 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_get_search
2017-02-08 12:08:09 - gw1 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_name
2017-02-08 12:08:14 - gw1 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_name
2017-02-08 12:08:14 - gw1 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:41 - gw2 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:07:59 - gw2 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_host_parameters
2017-02-08 12:08:00 - gw2 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_host_parameters
2017-02-08 12:08:00 - gw2 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_delete
2017-02-08 12:08:06 - gw2 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_delete
2017-02-08 12:08:06 - gw2 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_mac
2017-02-08 12:08:12 - gw2 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_mac
2017-02-08 12:08:12 - gw2 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:48 - gw3 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:08:05 - gw3 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_enabled_parameter
2017-02-08 12:08:10 - gw3 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_enabled_parameter
2017-02-08 12:08:10 - gw3 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_puppet_proxy
2017-02-08 12:08:14 - gw3 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_puppet_proxy
2017-02-08 12:08:14 - gw3 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_ip
2017-02-08 12:08:18 - gw3 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_ip
2017-02-08 12:08:18 - gw3 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:22 - gw4 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:07:45 - gw4 - robottelo - DEBUG - Started Test: HostTestCase/test_negative_update_mac
2017-02-08 12:07:53 - gw4 - robottelo - DEBUG - Finished Test: HostTestCase/test_negative_update_mac
2017-02-08 12:07:53 - gw4 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_name
2017-02-08 12:07:58 - gw4 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_name
2017-02-08 12:07:58 - gw4 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_build_parameter
2017-02-08 12:08:08 - gw4 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_build_parameter
2017-02-08 12:08:08 - gw4 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_owner_type
2017-02-08 12:08:12 - gw4 - robottelo.decorators - INFO - Bugzilla bug 1210001 not in cache. Fetching.
2017-02-08 12:08:13 - gw4 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_owner_type
2017-02-08 12:08:13 - gw4 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:44 - gw5 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:07:56 - gw5 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_comment
2017-02-08 12:08:01 - gw5 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_comment
2017-02-08 12:08:01 - gw5 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_puppet_ca_proxy
2017-02-08 12:08:06 - gw5 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_puppet_ca_proxy
2017-02-08 12:08:06 - gw5 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_host_parameters
2017-02-08 12:08:07 - gw5 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_host_parameters
2017-02-08 12:08:07 - gw5 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_puppet_proxy
2017-02-08 12:08:12 - gw5 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_puppet_proxy
2017-02-08 12:08:12 - gw5 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:28 - gw6 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:07:55 - gw6 - robottelo - DEBUG - Started Test: HostTestCase/test_negative_update_name
2017-02-08 12:08:00 - gw6 - robottelo - DEBUG - Finished Test: HostTestCase/test_negative_update_name
2017-02-08 12:08:00 - gw6 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_owner_type
2017-02-08 12:08:05 - gw6 - robottelo.decorators - INFO - Bugzilla bug 1203865 not in cache. Fetching.
2017-02-08 12:08:05 - gw6 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_owner_type
2017-02-08 12:08:05 - gw6 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_comment
2017-02-08 12:08:10 - gw6 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_comment
2017-02-08 12:08:10 - gw6 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_puppet_ca_proxy
2017-02-08 12:08:15 - gw6 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_puppet_ca_proxy
2017-02-08 12:08:15 - gw6 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

2017-02-08 12:06:25 - gw7 - robottelo - DEBUG - Started setUpClass: tests.foreman.api.test_host/HostTestCase
2017-02-08 12:07:48 - gw7 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_build_parameter
2017-02-08 12:07:53 - gw7 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_build_parameter
2017-02-08 12:07:53 - gw7 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_create_with_provision_method
2017-02-08 12:07:55 - gw7 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_create_with_provision_method
2017-02-08 12:07:56 - gw7 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_enabled_parameter
2017-02-08 12:08:06 - gw7 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_enabled_parameter
2017-02-08 12:08:06 - gw7 - robottelo - DEBUG - Started Test: HostTestCase/test_positive_update_puppet_class
2017-02-08 12:08:07 - gw7 - robottelo - DEBUG - Finished Test: HostTestCase/test_positive_update_puppet_class
2017-02-08 12:08:07 - gw7 - robottelo - DEBUG - Started tearDownClass: tests.foreman.api.test_host/HostTestCase

[rochacbruno]

So we should take care of this in setUpClass and perform get_or_create instead of creating the instance every time.

[rplevka]

@rochacbruno that won't be enough, since the setUpClass often takes minutes to complete.
Let's take the above example - publishing a content view - the tests rely on the fact, that they already have a CV which has been published.
So there goes a 1st test, which actually runs the setUpClass, which creates the CV and starts to publish it. Sincewe run this in multi-threaded fashion, another 4 tests are being executed at the same time by different workers, which also rely on that CV to be already published.
If we only do 'get', we'll reference to the (yet) unpublished CV.
The option is to make setUpClass blocking, which might lead to all workers being blocked by a single one, which is suboptimal.
If we could say, that we'd like to schedule all tests belonging to a specific TestCase suite to a single specific worker, we would unblock the rest of the workers - but since this is not supported currently.

[rochacbruno]

If we could say, that we'd like to schedule all tests belonging to a specific TestCase suite to a single specific worker, we would unblock the rest of the workers - but since this is not supported currently.

Looks like the solution might be separating tests_cases in specific classes and then marking as run_in_one_thread

We can also think in a solution of having defined thread numbers example:

@run_in_one_thread_1
def test...

@run_in_one_thread_2
def test...

_3 and _4 also available

Then when starting the run_in_one_thread build we can run all those in parallel selecting specific markers.

py.test /path -m "run_in_one_thread_1" &
py.test /path -m "run_in_one_thread_2" &
py.test /path -m "run_in_one_thread_3" &
py.test /path -m "run_in_one_thread_4" &

But I dont know yet how Jenkins will deal with this...

[lpramuk]

And again the same story:

• [ ] api.test_host.HostTestCase.test_negative_update_mac
• [ ] api.test_host.HostTestCase.test_positive_create_with_name
• [ ] api.test_host.HostTestCase.test_positive_update_build_parameter
• [ ] api.test_host.HostTestCase.test_positive_update_owner_type

The 1st test was attempted to run and setUpClass failed
Other 3 test weren't run at all, just marked failed due to failed setUpClass

In setUpClass publish_puppet_module produced Task and that failed:
TaskFailedError: Task e109119f-e8d9-46e4-94d3-9494e5d30ac5 did not succeed. ... PG::Error: ERROR: duplicate key value violates unique constraint "index_katello_puppet_modules_on_uuid" DETAIL: Key (uuid)=(5221bd7b-19e2-4b49-be3a-887a4bad0001) already exists. : INSERT INTO "katello_puppet_modules" ("author", "created_at", "name", "sortable_version", "summary", "updated_at", "uuid", "version") VALUES ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING "id"

[lpramuk]

During puppet repo sync:

3:Katello: Actions::Pulp::Repository::Sync passes
6:Actions::Katello::Repository::IndexContent fails when trying to insert puppet module uuid into katello_puppet_modules and failing due to unique constraint index_katello_puppet_modules_on_uuid

If the uuid is present why it just doesn't update it instead of insert?
Because it doesn't see it !!! in the meantime module uuids are inserted by another instance of reposync in another instance of setUpClass.
=> RACE CONDITION of Actions::Katello::Repository::IndexContent

[lpramuk]

https://bugzilla.redhat.com/show_bug.cgi?id=1422051
concurrent puppet reposyncs fail with PG::Error: ERROR: duplicate key value violates unique constraint "index_katello_puppet_modules_on_uuid"

[rochacbruno]

So we can skip_if_bug_open the whole class?

[lpramuk]

Whole ? Whoa? Do we really want it?
HostTestCase is not much related to puppet repositories.

run_in_one_thread if bz_bug_is_open?

[ldjebran]

think we can use locking mechanism and decorate the setUpClass with setUp() with 2 decorators
simple and not to complicate things

from threading import Lock

lock = Lock()


def ensure_locked(lock_object):
    pass


def wait_release(lock_object):
    # enter a loop waiting for lock to be released
    # using lock_object.locked()
    pass


class SomeTestCase(TestCase):

     @ensure_locked(lock)
     def setUpClass(cls):
          pass 

     @wait_release(lock)
     def setUp(self):
        pass

second method using threading Event

from threading import Event

event = Event()

def event_working(event_object):
    event_object.clear()   
    # do many things
    event_object.set()

def wait_event(event_object):
    # wait for the event to be set
    event_object.wait()

class SomeTestCase(TestCase):

     @event_working(event)
     def setUpClass(cls):
          pass 

     @wait_event(event)
     def setUp(self):
        pass

The second method is the cheaper and logical

this will block only the tests in this TestCase and only when setUpClass is running.
@rochacbruno @lpramuk @rplevka what do you think?

[rochacbruno]

I like the idea of having locking mechanism for tests,

I found this plugin pytest-services which provides some locker decorators based in xdist worker id https://github.com/pytest-dev/pytest-services/blob/master/pytest_services/locks.py

[ldjebran]

@rochacbruno @lpramuk @rplevka please read this issue https://github.com/pytest-dev/pytest-xdist/issues/17

have you played with --dist=load ?

If we have the tests in the same class or module running serially in the same process, we would have no problem at all, any way other tests will run in other processes also serially.
benefit, we always setup a class only once.

we have to write some tests to locate the behavior.

[rplevka]

@ldjebran that looks promising,
However, i'm not saying we strictly want to run all test from a single class to be executed serially. That is fin in the most of the cases. I think we only need to ensure the setUpClass is being run only once...and the rest of the tests (even on a different worker) wouldn't run it again.

Anyway, if we would decorate only the classes we have problems with, this solution might be the best one we have so far.

[ldjebran]

@rplevka let's talk about this tomorrow in MTG with the team, as there is many nuances, what do you think?

[ldjebran]

@rochacbruno @renzon @rplevka @lpramuk as promized , please comment on this sollution:

import functools
import tempfile
import os

from pytest_services.locks import file_lock

_temp_root = 'robottelo'
_class_lock_dir_name = 'lock_class'


def _init_class_lock_dir():
    tmp_lock_dir = os.path.join(tempfile.gettempdir(), _temp_root,
                                _class_lock_dir_name)
    if not os.path.exists(tmp_lock_dir):
        os.makedirs(tmp_lock_dir)
    return tmp_lock_dir


def _def_get_function_lock_path(context, function):
    names = []

    names.append(function.__module__)
    if context:
        if isinstance(context, type):
            names.append(context.__name__)
        elif isinstance(context, TestCase):
            names.append(context.__class__.__name__)

    names.append(function.__name__)

    func_file_name = '.'.join(names)

    return os.path.join(_init_class_lock_dir(), func_file_name)


def lock_function(function):
    """Generic function locker, lock any decorated function, any parallel
     pytest xdist worker will wait for this function to finish"""

    @functools.wraps(function)
    def function_wraper(*args, **kwargs):
        if args:
            context = args[0]
        else:
            context = None
        lock_file_path = _def_get_function_lock_path(context, function)
        with file_lock(lock_file_path):
            return function(*args, **kwargs)

    return function_wraper


# Usage

from unittest import TestCase


class SimpleTestCase(TestCase):

    @classmethod
    @lock_function
    def setUpClass(cls):
        # lock setUpClass method
        pass

    @lock_function
    def setUp(self):
        # lock setUp function
        pass

    @lock_function
    def test_locked(self):
        # any parallel test_locked will be locked
        pass

    def test_not_locked(self):
        pass


@lock_function
def test_a():
    pass

[lpramuk]

By this solution you will hold the lock till setup(class) finishes.
What about to have just context manager?:

with Lock.file_lock as lock:
    CV.publish()
    # or whatever

[ldjebran]

@lpramuk we will have the two solutions, I am working on

[rochacbruno]

I like @lpramuk context manager suggestion so it can release the lock ASAP.

[ldjebran]

@lpramuk @rochacbruno @renzon , I'am working on this too

for the context manager implementation:

and with this you can even lock an other test function

class SomeTestCase(TestCase):

    def setUpClass(cls):
        # some work here... 
        with locking_function(cls.setUpClass, context='publish')
            # this lock only in setUpClass and only with context='publish'
            CV.publish()
        # some work here ...

   @lock_function
   def test_to_lock(self):
      pass

   def test_that_conflict_test_to_lock(self)
        with locking_function(self.test_to_lock):
            # do some operations that conflict with  test_to_lock

[ldjebran]

@lpramuk @rochacbruno @renzon , I'am afraid that only locking the publish does not help, in some tests the error raised again, so need more testing with full setUpClass lock.

[ldjebran]

@rochacbruno @renzon @lpramuk @rplevka what do you think , we can close this issue now or wait for the next build to see the results and close

[rochacbruno]

@ldjebran lets wait for next build results

[ldjebran]

in PR https://github.com/SatelliteQE/robottelo/pull/4458 @svtkachenko explained that he encountered the same problem described here, and therefore decorated the setUpClass with lock_function.
so we have to track that module too at next build

[ldjebran]

@rochacbruno , @rplevka last build showed that all the tests passed in tests.foreman.api.test_host::HostTestCase passed

for the second PR tests.foreman.cli.test_host::HostCreateTestCase that @svtkachenko implemented it seems the tests are failing on assertions.

Think we can already close this issue, what do you think?

[ldjebran]

@rochacbruno , @rplevka all the tests are passing since we added the lock decorator, think we can close this issue