autopkgtest fails in trusty: TestSmartTCPServer.test_graceful_shutdown_waits_for_clients_to_stop

[Martin Pitt]

Since January 11, bzr now consistently [1] fails this test:

FAIL: bzrlib.tests.test_smart_transport.TestSmartTCPServer.test_graceful_shutdown_waits_for_clients_to_stop
----------------------------------------------------------------------
Traceback (most recent call last):
_StringException: log: {{{
INFO Requested to stop gracefully
890.268 Stopping SmartServerSocketStreamMedium(client=('127.0.0.1', 58228))
    INFO Waiting for 1 client(s) to finish
    INFO Requested to stop gracefully
}}}

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bzrlib/tests/test_smart_transport.py", line 1458, in test_graceful_shutdown_waits_for_clients_to_stop
    self.assertFalse(server._fully_stopped.isSet())
  File "/usr/lib/python2.7/unittest/case.py", line 418, in assertFalse
    raise self.failureException(msg)
AssertionError: True is not false

This is consistent with the update of python 2.7 to some new upstream updates [3], so it's likely that this introduced some behavioural change.

[1] https://jenkins.qa.ubuntu.com/job/trusty-adt-bzr/
[2] https://jenkins.qa.ubuntu.com/job/trusty-adt-bzr/13/ARCH=i386,label=adt/console
[3] https://launchpad.net/ubuntu/+source/python2.7/2.7.6-5

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Vincent Ladeuil (vila)]

Bug #888629 and bug #888631 are two known transient failures caused by a race introduced in revno 6170.

That race condition has been diagnosed (unfortunately incompletely :-( ) long ago as being caused by running a TCP server and TCP client in the same process.

The strategy would be to run the test servers in their own process to avoid the race entirely. This is a significant work, unlikely to happen soon.

I'll try to reproduce it locally when time permits, who knows, we may be lucky and some change in python has made the race more obvious...

[Martin Pitt (pitti)]

For the record, this reproduces absolutely reliably (10 of 10) on my current trusty system as well:

 $ sudo apt-get install python-bzrlib.tests python-subunit
 $ apt-get source bzr
 $ cd bzr-*
 $ bzr selftest bzrlib.tests.test_smart_transport.TestSmartTCPServer.test_graceful_shutdown_waits_for_clients_to_stop

reproduces above test failure.

[Martin Pitt (pitti)]

I disabled this flaky test in the autopkgtest for now, as per discussion with Vincent.

[Vincent Ladeuil (vila)]

@Martin: Finally, found the time to add trusty to http://babune.ladeuil.net:24842/ which runs the tests from lp:bzr (i.e. from source) and I can't reproduce the issue :-/

So more racy than expected which is not that surprising, just unlucky. I'll try to dig a bit more when time permits now that I a have a trusty chroot though.

[Vincent Ladeuil (vila)]

Not reproduced with nor without extensions... (i.e. I noticed your reproducing recipe doesn't involve 'make' to build the C extensions but that doesn't seem relevant here).

I would guess that a trusty host may explain the difference (I'm still on saucy :-/)

[Martin Pitt (pitti)]

Vincent, I don't expect that you can ever reproduce this on saucy. As I wrote in the description this starts happening with a newer python2.7 version (2.7.6-5), so trying with the saucy one won't help.

[Vincent Ladeuil (vila)]

I'm trying in a trusty chroot:

vila:~ :) $ sudo schroot -c trusty
(trusty)root@saw:~# apt-cache policy python
python:
  Installed: 2.7.5-5ubuntu3
  Candidate: 2.7.5-5ubuntu3
  Version table:
 *** 2.7.5-5ubuntu3 0
        500 http://archive.ubuntu.com/ubuntu/ trusty/main amd64 Packages
        100 /var/lib/dpkg/status
(trusty)root@saw:~# apt-cache policy python2.7
python2.7:
  Installed: 2.7.6-5
  Candidate: 2.7.6-5
  Version table:
 *** 2.7.6-5 0
        500 http://archive.ubuntu.com/ubuntu/ trusty/main amd64 Packages
        100 /var/lib/dpkg/status

That's the correct python version right ?

[Andrew Starr-Bochicchio (andrewsomething)]

This was fixed awhile back. I missed the colon after the LP in the changelog, so it didn't get closed automatically.

bzr (2.6.0+bzr6591-1ubuntu1) trusty; urgency=medium

  * Merge from Debian unstable. Remaining changes:
   - Drop non-main build dependencies on python-{meliae,lzma,medusa}

bzr (2.6.0+bzr6591-1) unstable; urgency=low

  * New upstream snapshot.
   - Remove wrong assumption about how TCP server and client interact
     when run inside the same process. (Closes: #736158, LP #1269886).
   - The XDG Base Directory Specification uses the XDG_CACHE_HOME,
     not XDG_CACHE_DIR (Closes: #736448).
  * Drop 04_test_netrc_fix_perms, applied upstream.
  * Bump Standards-Version to 3.9.5, no changes needed.

 -- Andrew Starr-Bochicchio <email address hidden> Wed, 12 Feb 2014 22:53:07 -0500