Repository: python/mypy
Pull request: Fix the stubgen test flake.
The core problem is that `importlib.invalidate_caches()` is full of
lies and does not actually invalidate all of the relevant
caches. Python maintains sys.path_importer_cache, which maps from
directory names on the sys.path to "importer" objects for that path
entry. `importlib.invalidate_caches()` invalidates the caches inside
each of the per-directory importer objects, but there is an additional
negative cache that is *not* cleared: sys.path entries whose directory
doesn't exist have their importer set to None, which prevents that
path entry from ever being searched unless it is manually cleared.

This failure comes up rarely, because it only occurs if the following
events occur in sequence:

 1. 'stubgen-test-path' is added to sys.path, but no new import is
    done while there is a 'stubgen-test-path' subdirectory in the working
    directory. This is done by all the stubgen tests that don't end with
    `_import`.
 2. Some non-stubgen test does an import of a previously unimported
    module. This will cause
    `sys.path_importer_cache['stubgen-test-path']` to be set to None
    when the directory doesn't exist during the module search.
    This can happen the *first* time that a `_python2` test is run
    since `parse.parse()` dynamically imports `mypy.fastparse2`
    when asked to parse python 2.
 3. A stubgen test tries to use importlib to import a module in
    'stubgen-test-path'. All of the `_import` tests do this.

We fix this by clearing out the relevant entry from
`sys.path_importer_cache` ourselves.

Fixes #4635

Problem statement:
stubgen tests are flaking
I had noticed this a few days ago, it seems that stugen tests are flaking every once in a while, I just was able to get a repro:

```
_________________________ testVarDefsNotInAll_import __________________________
[gw3] win32 -- Python 3.6.4 C:\Python36\python.exe
data: C:\Users\ethanhs\Documents\mypy\test-data\unit\stubgen.test:369:
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:97: in run_case
    test_stubgen(testcase)
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:136: in test_stubgen
    a = load_output(out_dir)
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:158: in load_output
    assert entries, 'No files generated'
E   AssertionError: No files generated
E   assert []
---------------------------- Captured stdout call -----------------------------
Failed to import prog_ha2bjeqt; skipping it
_______________________ testIncludeClassNotInAll_import _______________________
[gw3] win32 -- Python 3.6.4 C:\Python36\python.exe
data: C:\Users\ethanhs\Documents\mypy\test-data\unit\stubgen.test:379:
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:97: in run_case
    test_stubgen(testcase)
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:136: in test_stubgen
    a = load_output(out_dir)
..\..\..\..\Documents\mypy\mypy\test\teststubgen.py:158: in load_output
    assert entries, 'No files generated'
E   AssertionError: No files generated
E   assert []
---------------------------- Captured stdout call -----------------------------
Failed to import prog_fp1d8vup; skipping it
```

I haven't looked into what is causing the issue yet.

Hints from issue discussion:
I believe this may have to do with https://github.com/python/mypy/issues/4571? Since it is failing to import programs.
See also this Travis log: https://gist.github.com/ethanhs/5169bf3bc1ecee491b1cd9bd3f1ebcc6
How did you repro this? I did

```bash
until ! ./runtests.py stubgen; do :; done
```

for 20 minutes and nothing came up. I'm on `064c8d33` commit, Python 3.6.4, macOS 10.3.3.
It happens ephemerally, and I'm not doing anything to repro at the moment, the errrors that have come up are random. If it was reproducible I would have looked at what was causing it :)

Taking a look at the stubgen tests [this seems like it could cause trouble](https://github.com/python/mypy/blob/master/mypy/test/teststubgen.py#L145) since AIUI they are run concurrently
That was my first hunch as well, @ethanhs, but each test is run in its own temp dir. 

I made a testing branch that reraised the exception from importlib in stubgen and managed to get it to flake once: https://travis-ci.org/python/mypy/jobs/347964924
There is a `ModuleNotFound` error coming from importlib. I then added a bunch more debug code to that branch, but haven't been able to get it to flake since.
I think I'm going to merge a variant of that debug code into master and wait for another flake.

It looks like there are actually only 11 tests that use the code path that tries to import modules with importlib, and it looks like they tend to fail all together.

Commit message: Fix the stubgen test flake.

The core problem is that `importlib.invalidate_caches()` is full of
lies and does not actually invalidate all of the relevant
caches. Python maintains sys.path_importer_cache, which maps from
directory names on the sys.path to "importer" objects for that path
entry. `importlib.invalidate_caches()` invalidates the caches inside
each of the per-directory importer objects, but there is an additional
negative cache that is *not* cleared: sys.path entries whose directory
doesn't exist have their importer set to None, which prevents that
path entry from ever being searched unless it is manually cleared.

This failure comes up rarely, because it only occurs if the following
events occur in sequence:

 1. 'stubgen-test-path' is added to sys.path, but no new import is
    done while there is a 'stubgen-test-path' subdirectory in the working
    directory. This is done by all the stubgen tests that don't end with
    `_import`.
 2. Some non-stubgen test does an import of a previously unimported
    module. This will cause
    sys.path_importer_cache['stubgen-test-path'] to be set to None
    when the directory doesn't exist during the module search.
    This can happen the *first* time that a `_python2` test is run
    since `parse.parse()` dynamically imports `mypy.fastparse2`
    when asked to parse python 2.
 3. A stubgen test tries to use importlib to import a module in
    'stubgen-test-path'. All of the `_import` tests do this.

We fix this by clearing out the relevant entry from
`sys.path_importer_cache` ourselves.

Patch to review:
diff --git a/mypy/stubgen.py b/mypy/stubgen.py
index c0afb4f380ec..5cb7a10c9145 100755
--- a/mypy/stubgen.py
+++ b/mypy/stubgen.py
@@ -153,13 +153,6 @@ def find_module_path_and_all(module: str, pyversion: Tuple[int, int],
             try:
                 mod = importlib.import_module(module)
             except Exception:
-                # Print some debugging output that might help diagnose problems.
-                print('=== debug dump follows ===')
-                traceback.print_exc()
-                dump_sys_path()
-                print('PYTHONPATH: %s' % os.getenv("PYTHONPATH"))
-                dump_dir(os.getcwd())
-                print('=== end of debug dump ===')
                 raise CantImport(module)
             if is_c_module(mod):
                 return None
@@ -175,31 +168,6 @@ def find_module_path_and_all(module: str, pyversion: Tuple[int, int],
     return module_path, module_all
 
 
-def dump_sys_path() -> None:
-    print('sys.path:')
-    for entry in sys.path:
-        print('    %r' % entry)
-        if entry in sys.path_importer_cache:
-            x = sys.path_importer_cache[entry]
-            print('      path_importer: %r / %r' % (x, getattr(x, '__dict__', None)))
-            try:
-                print('      stat: %s ' % str(os.stat(entry)))
-            except Exception as e:
-                pass
-
-
-def dump_dir(path: str) -> None:
-    for root, dirs, files in os.walk(os.getcwd()):
-        print('%s:' % root)
-        for d in dirs:
-            print('    %s/' % d)
-        for f in files:
-            path = os.path.join(root, f)
-            print('    %s (%d bytes)' % (f, os.path.getsize(path)))
-        if not dirs and not files:
-            print('    (empty)')
-
-
 def load_python_module_info(module: str, interpreter: str) -> Tuple[str, Optional[List[str]]]:
     """Return tuple (module path, module __all__) for a Python 2 module.
 
diff --git a/mypy/test/teststubgen.py b/mypy/test/teststubgen.py
index 6d84e66ba701..828169107e98 100644
--- a/mypy/test/teststubgen.py
+++ b/mypy/test/teststubgen.py
@@ -1,5 +1,4 @@
 import glob
-import importlib
 import os.path
 import shutil
 import sys
@@ -125,7 +124,7 @@ def test_stubgen(testcase: DataDrivenTestCase) -> None:
         handle.close()
         # Without this we may sometimes be unable to import the module below, as importlib
         # caches os.listdir() results in Python 3.3+ (Guido explained this to me).
-        reset_importlib_caches()
+        reset_importlib_cache('stubgen-test-path')
         try:
             if testcase.name.endswith('_import'):
                 generate_stub_for_module(name, out_dir, quiet=True,
@@ -145,11 +144,13 @@ def test_stubgen(testcase: DataDrivenTestCase) -> None:
         shutil.rmtree(out_dir)
 
 
-def reset_importlib_caches() -> None:
-    try:
-        importlib.invalidate_caches()
-    except (ImportError, AttributeError):
-        pass
+def reset_importlib_cache(entry: str) -> None:
+    # importlib.invalidate_caches() is insufficient, since it doesn't
+    # clear cache entries indicate that a directory on the path does
+    # not exist, which can cause failures.
+    # Just directly clear the sys.path_importer_cache entry ourselves.
+    if entry in sys.path_importer_cache:
+        del sys.path_importer_cache[entry]
 
 
 def load_output(dirname: str) -> List[str]:


Code review comments:
diff_hunk: @@ -145,11 +144,13 @@ def test_stubgen(testcase: DataDrivenTestCase) -> None:
         shutil.rmtree(out_dir)
 
 
-def reset_importlib_caches() -> None:
-    try:
-        importlib.invalidate_caches()
-    except (ImportError, AttributeError):
-        pass
+def reset_importlib_cache(entry: str) -> None:
+    # importlib.invalidate_caches() is insufficient, since it doesn't
+    # clear cache entries indicate that a directory on the path does
path: mypy/test/teststubgen.py
text: @user1:
There is something missing in this sentence. Maybe this should be "... clear cache entries *that* indicate ..."