pytest_plugin doesn't work with pytest-xdist

[curzona]

When I run py.test -n 8 teamcity to parallelize my test; testSuiteStarted, testStarted, and testSuiteFinished messages are missing.

Without xdist:

##teamcity[testSuiteStarted timestamp='2013-09-15T16:46:48.153' name='test_hello.py']

##teamcity[testStarted timestamp='2013-09-15T16:46:48.168' name='test_eval[3+5-8|]']
.
##teamcity[testFinished timestamp='2013-09-15T16:46:48.169' duration='0' name='test_eval[3+5-8|]']

With xdist:

scheduling tests via LoadScheduling
.
##teamcity[testFinished timestamp='2013-09-15T16:47:01.311' duration='1' name='test_eval[2+4-6|]']
.
##teamcity[testFinished timestamp='2013-09-15T16:47:01.311' duration='0' name='test_eval[3+5-8|]']
F

[tt293]

I am encountering the exact same problem, which prevents us from running our tests on TC in an adequate amount of time

[leo-from-spb]

Which version of TC do you use?

[leo-from-spb]

In any case, the http://youtrack.jetbrains.com/issue/TW-4998 should help. Let's watch/vote for it.

[curzona]

@leo-from-spb
TeamCity 8.0.4
Python 2.7.5
pytest 2.4.2
pytest-xdist 1.9
teamcity-message 1.7

[leo-from-spb]

In TC 8.x.x we can use flow ids, so the TW-4998 must help. But this feature is not implemented yet. You're welcome to vote for.

[curzona]

Ooo :) I hadn't seen flow ids in the service messages documentation before, thanks for pointing that out.

The second part of the problem is that pytest-xdist is capturing some of the teamcity service messages.

[curzona]

I did some hacking. pytest-xdist has pytest_runtest_logstart commented out so the test start service messages aren't being sent. After pytest-xdist starts calling pytest_runtest_logstart the teamcity test counts still aren't correct.

[curzona]

I filed a bug against pytest-xdist here: https://bitbucket.org/hpk42/pytest/issue/382/pytest-xdist-doesnt-call

[tt293]

We are currently using TeamCity 7.1.5, the versions of the other components exactly match the ones curzona uses.

[tt293]

While the latest pytest-xdist release fixes the original issue, we are now facing the problem that teamcity-messages is not sending the messages about finishing a test suite and finishing a test in the correct order, which leads to tests being assigned to the wrong test suite.

For us, this destroys the value of the running time time series (which is linked to test suite + test name) which we use as a proxy for performance testing.

[shalupov]

Please tell me exact versions of pytest-xdist and teamcity-messages

[tt293]

teamcity-messages 1.8, xdist 1.11, pytest 2.6.3 on Python 2.7.8

[shalupov]

It was almost rewritten since then, could you try teamcity-messages from master branch?

If it is still fails, could you prepare a test case for me to reproduce the problem?

[tt293]

The problem still persists even when using the master branch. I tried uploading the test case into a github repo, but my employer blocks commits, so I'm afraid I'll have to paste it here.
I can reproduce it the problem by taking three of the following files (naming the other two TestSuite2 and TestSuite3):

import os, time, unittest

class TestSuite1(unittest.TestCase):
    """
    Sample test file 1
    """

    def test_2secs(self):
        """
        Check that we get we get back the MV status for an explicit non-quanto.
        """
        time.sleep(2)
        self.assertEqual(2,2)

    def test_1sec(self):
        """
        Check that we get we get back the MV status for an explicit self-quanto.
        """
        time.sleep(1)
        self.assertEqual(2,2)

    def test_instant(self):
        """
        Check that we get we get back the MV status for an explicit full-quanto.
        """
        self.assertEqual(2,2)

From a sample captured stdout:

##teamcity[testSuiteStarted timestamp='2014-12-29T11:40:23.716' name='TCMessages.test_suite_1_py']

##teamcity[testStarted timestamp='2014-12-29T11:40:23.716' name='TestSuite1.test_1sec']
.
##teamcity[testFinished timestamp='2014-12-29T11:40:24.730' duration='1000' name='TestSuite3.test_1sec']
.
##teamcity[testFinished timestamp='2014-12-29T11:40:24.732' duration='1000' name='TestSuite2.test_1sec']
.
##teamcity[testFinished timestamp='2014-12-29T11:40:24.733' duration='1000' name='TestSuite1.test_1sec']
.
##teamcity[testFinished timestamp='2014-12-29T11:40:25.697' duration='2000' name='TestSuite2.test_2secs']

##teamcity[testSuiteFinished timestamp='2014-12-29T11:40:25.714' name='TCMessages.test_suite_1_py']

It seems to us that here, TestSuite2.test_1sec for example, will be incorrectly attributed to the TCMessages/test_suite_1.py file.

[shalupov]

Ok, I see two problems (notes for myself):

• Tests should be reported with special "flowId" which helps TeamCity to separate output from different threads. See http://confluence.jetbrains.com/display/TCD8/Build+Script+Interaction+with+TeamCity (which is easy, just generate flowId for each thread)
• It badly interacts with testSuiteStarted/Finished. Is it required to call them per thread or smth else?

[shalupov]

Notes:

• py.test reports test status to main thread
• it's sufficient to report every test with flowId=test_id to make TeamCity happy

[shalupov]

Everyone, please check 1.10 release