test_parallel_module_init() fails on Windows-64:

http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.x/builds/553/steps/test/logs/stdio

======================================================================
FAIL: test_parallel_module_init (test.test_threaded_import.ThreadedImportTests)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "C:\buildbot.python.org\3.x.kloth-win64\build\lib\test\test_threaded_import.py", line 125, in test_parallel_module_init
    self.check_parallel_module_init()
  File "C:\buildbot.python.org\3.x.kloth-win64\build\lib\test\test_threaded_import.py", line 120, in check_parallel_module_init
    self.assertFalse(errors)
AssertionError: [AttributeError("'module' object has no attribute 'randrange'",)] is not false

The buildbot in question uses -j4, and I can reproduce this on Linux
with:

./python -m test -uall -F -j4 -v test_threaded_import

======================================================================
FAIL: test_parallel_meta_path (test.test_threaded_import.ThreadedImportTests)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/stefan/hg/cpython/Lib/test/test_threaded_import.py", line 131, in test_parallel_meta_path
    self.check_parallel_module_init()
  File "/home/stefan/hg/cpython/Lib/test/test_threaded_import.py", line 120, in check_parallel_module_init
    self.assertFalse(errors)
AssertionError: [AttributeError("'module' object has no attribute 'randrange'",), AttributeError("'module' object has no attribute 'randrange'",)] is not false

Ran 6 tests in 4.221s

With
$ ./python -m test -uall -F -j16 -v test_threaded_import
I couldn't reproduce after 1000 test passes.

No joy here either - currently at 704 successful runs and counting with Stefan's command line.

$ uname -a
Linux lancre 3.5.1-1.fc17.x86_64 #1 SMP Thu Aug 9 17:50:43 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

$ cat /proc/cpuinfo | grep "model name"
model name      : Intel(R) Core(TM) i7-2677M CPU @ 1.80GHz
model name      : Intel(R) Core(TM) i7-2677M CPU @ 1.80GHz
model name      : Intel(R) Core(TM) i7-2677M CPU @ 1.80GHz
model name      : Intel(R) Core(TM) i7-2677M CPU @ 1.80GHz

I can only reproduce this on a Core i7. Native OS is Debian Wheezy,
also reproduced earlier on a FreeBSD VM hosted on that machine
(see msg167989). The machine has 4 physical cores, perhaps we
can blame hyper-threading. ;)

$ cat /proc/cpuinfo | grep "model name"
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz
model name      : Intel(R) Core(TM) i7 CPU         930  @ 2.80GHz

I can't reproduce it on a Core 2 Duo running Ubuntu natively.

Up to 2279 runs without a failure here - yay for elusive hardware specific threading bugs :P

I'll leave it running overnight and see what happens.

I can also reproduce it on the Core 2 machine with a ridiculuously
low switch interval:

 diff --git a/Lib/test/regrtest.py b/Lib/test/regrtest.py
--- a/Lib/test/regrtest.py
+++ b/Lib/test/regrtest.py
@@ -198,6 +198,8 @@
 except ImportError:
     multiprocessing = None
 
+sys.setswitchinterval(0.00000001)
+
 
 # Some times __path__ and __file__ are not absolute (e.g. while running from
 # Lib/) and, if we change the CWD to run the tests in a temporary dir, some

Oh, and as usual, my machines have all CPUs at 100% load.

So this was a random one-off (hardly even intermittent) failed test that passed on the retry. Ah, threads. Is there an easy way to find all other failures in test_threaded_import in the past, for this and for all buildbots? Do we have information about load during tests? Is there an easy way to run the test suite under load on a build bot?

With a large enough sample size we can make more sense of this. For instance, do failures predate the addition of per-module import locks or the importlib migration in 3.3? Are failures limited to particular platforms? Is the problem load related?

BTW, test_threaded_import had another (different) failure a week ago on FreeBSD: bpo-15599.

(sorry, only saw the first couple messages)

On the i7 machine with hyper-threading the issue occurs since
edb9ce3a6c2e.

The tests also got slower:

3430d7329a3b:

$ time ./python -m test -uall -v  test_threaded_import

real 0m3.195s
user 0m0.656s
sys 0m0.284s

edb9ce3a6c2e:

$ time ./python -m test -uall -v  test_threaded_import

real 0m24.032s
user 0m0.880s
sys 0m0.744s

Here most of the time is spent in test_parallel_meta_path.

DISCLAIMER: This machine runs Debian Wheezy, which is not
stable yet! On the other hand the Windows bot also reproduced
the issue.

Ok, I can now reproduce with setswitchinterval(). Here is a patch. There was a race between putting the new module in sys.modules and setting its __initializing__ attribute, so now __initializing__ is set before putting the module in sys.modules.

Also, there was another race when retrieving a module lock from the locks dict (the weakref could be destroyed between the __contains__ test and the actual fetch).

Didn't patch it in to evaluate the surrounding code, but otherwise the patch LGTM.

Looks good to me. Please commit to default and I'll cherry-pick to rc2.

If possible I would like to wait for Stefan's confirmation that it fixes the failures for him.

Sure.

Nice, on the finicky i7 machine test_threaded_import is fixed.

I'm getting another error in test_importlib, both with and without
the patch. I can open another issue for that if you think it's
completely unrelated:

$ ./python -m test -uall -F test_importlib      
[  1] test_importlib
test test_importlib failed -- Traceback (most recent call last):
  File "/home/stefan/hg/cpython/Lib/test/test_importlib/test_locks.py", line 80, in test_deadlock
    self.assertEqual(results.count((True, False)), 1)
AssertionError: 2 != 1

1 test failed:
test_importlib

I'm getting another error in test_importlib, both with and without
the patch. I can open another issue for that if you think it's
completely unrelated:

Please do. Thanks!

New changeset 7fa6336e9864 by Antoine Pitrou in branch 'default':
Issue bpo-15781: Fix two small race conditions in import's module locking.
http://hg.python.org/cpython/rev/7fa6336e9864

Looks fixed!

Now picked into 3.3.0 release clone as 85070f284fd2.

New changeset 85070f284fd2 by Antoine Pitrou in branch 'default':
Issue bpo-15781: Fix two small race conditions in import's module locking.
http://hg.python.org/cpython/rev/85070f284fd2